Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

os/exec: exec.CommandContext(...).Output() does not respect context timeout #57129

Closed
lfyuomr-gylo opened this issue Dec 6, 2022 · 1 comment

Comments

@lfyuomr-gylo
Copy link

What version of Go are you using (go version)?

$ go version
go version go1.19 darwin/arm64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

I create the following two files

go env Output
$ go env
GO111MODULE="on"
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/levkhotov/Library/Caches/go-build"
GOENV="/Users/levkhotov/Library/Application Support/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/levkhotov/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/levkhotov/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="go1.19.4"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/levkhotov/anki-rest-helper/go.mod"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/3k/z3gl3j7n0p5cr2z0kh6xftcw0000gn/T/go-build1154024858=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

Create two files:

main.go
package main

import (
	"context"
	"fmt"
	"os/exec"
	"time"
)

func main() {
	ctx, cancel := context.WithTimeout(context.Background(), 1*time.Second)
	defer cancel()

	if _, err := exec.CommandContext(ctx, "./hang.sh").Output(); err != nil {
		fmt.Println("cmd: ", err.Error())
		fmt.Println("ctx: ", ctx.Err().Error())
	}
}
hang.sh
#!/usr/bin/env bash

sleep 100
echo 'foo'

Then run

chmod +x hang.sh
go run ./main.go

What did you expect to see?

I expect the program to complete in approximately 1 second with the following output:

cmd:  signal: killed
ctx:  context deadline exceeded

What did you see instead?

Program completes with the expected output, but only after 100 seconds.

Interestingly enough, when I replace .Output() with Run(), the program completes in 1 second as expected.

@seankhliao
Copy link
Member

Duplicate of #23019

@seankhliao seankhliao marked this as a duplicate of #23019 Dec 7, 2022
@seankhliao seankhliao closed this as not planned Won't fix, can't repro, duplicate, stale Dec 7, 2022
rm3l added a commit to rm3l/odo that referenced this issue May 10, 2023
This command is called at dependency injection time to initialize a (nil-able) Podman client,
even if users won't use Podman at all.
As discussed, this command is supposed to be
quite fast to return, hence this timeout of 1 second.

Initially, we were using cmd.Output to get the command output,
but as reported in [1], cmd.Output does not respect the context timeout.
This explains the workaround of reading from both stdout and stderr pipes,
*and* relying on cmd.Wait() to close those pipes properly when the program exits
(either as expected or when the timeout is reached).

[1] golang/go#57129
rm3l added a commit to rm3l/odo that referenced this issue May 10, 2023
This command is called at dependency injection time to initialize a (nil-able) Podman client,
even if users won't use Podman at all.
As discussed, this command is supposed to be
quite fast to return, hence this timeout of 1 second.

Initially, we were using cmd.Output to get the command output,
but as reported in [1], cmd.Output does not respect the context timeout.
This explains the workaround of reading from both stdout and stderr pipes,
*and* relying on cmd.Wait() to close those pipes properly when the program exits
(either as expected or when the timeout is reached).

[1] golang/go#57129

Co-authored-by: Philippe Martin <phmartin@redhat.com>
rm3l added a commit to rm3l/odo that referenced this issue May 10, 2023
This command is called at dependency injection time to initialize a (nil-able) Podman client,
even if users won't use Podman at all.
As discussed, this command is supposed to be
quite fast to return, hence this timeout of 1 second.

Initially, we were using cmd.Output to get the command output,
but as reported in [1], cmd.Output does not respect the context timeout.
This explains the workaround of reading from both stdout and stderr pipes,
*and* relying on cmd.Wait() to close those pipes properly when the program exits
(either as expected or when the timeout is reached).

[1] golang/go#57129

Co-authored-by: Philippe Martin <phmartin@redhat.com>
openshift-merge-robot pushed a commit to redhat-developer/odo that referenced this issue May 11, 2023
…ld not affect `odo dev` on cluster) (#6808)

* Add test highlighting the issue and setting the expectations

* Add a timeout of 1s to the 'podman version' command

This command is called at dependency injection time to initialize a (nil-able) Podman client,
even if users won't use Podman at all.
As discussed, this command is supposed to be
quite fast to return, hence this timeout of 1 second.

Initially, we were using cmd.Output to get the command output,
but as reported in [1], cmd.Output does not respect the context timeout.
This explains the workaround of reading from both stdout and stderr pipes,
*and* relying on cmd.Wait() to close those pipes properly when the program exits
(either as expected or when the timeout is reached).

[1] golang/go#57129

Co-authored-by: Philippe Martin <phmartin@redhat.com>

* Log the errors returned at dependency injection time when the optional Kubernetes/Podman clients could not be initialized

This helps debug such potential issues instead of swallowing the errors.

* Make the timeout configurable via the 'PODMAN_CMD_INIT_TIMEOUT' env var

This will allow setting a different value for environments like
in GitHub where the Podman client would take slightly more time to return
(I guess because of we are running a lot of Podman commands in parallel?).

* Increase the timeout for Podman tests to an arbitrary value of 10s

Some tests did not pass because the Podman client did not
initialize in 1s; I guess because we are running a lot of Podman commands in parallel?
This should hopefully improve this situation.

* fixup! Add a timeout of 1s to the 'podman version' command

---------

Co-authored-by: Philippe Martin <phmartin@redhat.com>
@golang golang locked and limited conversation to collaborators Dec 7, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants