sandbox: prevent startContainer from hanging on timeout Close the pipe writer (pw) with the error returned by WaitOrStop in the container wait goroutine. This ensures that any pending reads on the pipe (such as those waiting for the container's ready header) are unblocked when the container exits or times out, preventing the process from hanging. To support testing this behavior, exec.Command is now assigned to a package-level variable execCommand that can be swapped during testing, and startTimeout is changed from a constant to a variable. Additionally, - prevent potential nil pointer references, - remove the -quiet flag from docker ps command, that is not compatible with the --format flag. - log errors when failing to parse docker output. For golang/go#80358 Change-Id: Ie3d419c813a33f32803435066d4791b8b3ec03e4 Reviewed-on: https://go-review.googlesource.com/c/playground/+/799361 Auto-Submit: Hyang-Ah Hana Kim <hyangah@gmail.com> Reviewed-by: Dmitri Shuralyov <dmitshur@golang.org> LUCI-TryBot-Result: golang-scoped@luci-project-accounts.iam.gserviceaccount.com <golang-scoped@luci-project-accounts.iam.gserviceaccount.com> Reviewed-by: Dmitri Shuralyov <dmitshur@google.com>
diff --git a/sandbox/sandbox.go b/sandbox/sandbox.go index c84e4db..69e093c 100644 --- a/sandbox/sandbox.go +++ b/sandbox/sandbox.go
@@ -50,13 +50,14 @@ const ( maxBinarySize = 100 << 20 - startTimeout = 30 * time.Second runTimeout = 5 * time.Second maxOutputSize = 100 << 20 memoryLimitBytes = 100 << 20 ) var ( + startTimeout = 30 * time.Second + execCommand = exec.Command errTooMuchOutput = errors.New("Output too large") errRunTimeout = errors.New("timeout running program") ) @@ -135,14 +136,14 @@ defer ms.Stop() } - if out, err := exec.Command("docker", "version").CombinedOutput(); err != nil { + if out, err := execCommand("docker", "version").CombinedOutput(); err != nil { log.Fatalf("failed to connect to docker: %v, %s", err, out) } if *dev { log.Printf("Running in dev mode; container published to host at: http://localhost:8080/") log.Printf("Run a binary with: curl -v --data-binary @/home/bradfitz/hello http://localhost:8080/run\n") } else { - if out, err := exec.Command("docker", "pull", *container).CombinedOutput(); err != nil { + if out, err := execCommand("docker", "pull", *container).CombinedOutput(); err != nil { log.Fatalf("error pulling %s: %v, %s", *container, err, out) } log.Printf("Listening on %s", *listenAddr) @@ -196,7 +197,7 @@ // listDockerContainers returns the current running play_run containers reported by docker. func listDockerContainers(ctx context.Context) ([]dockerContainer, error) { out := new(bytes.Buffer) - cmd := exec.Command("docker", "ps", "--quiet", "--filter", "name=play_run_", "--format", "{{json .}}") + cmd := execCommand("docker", "ps", "--filter", "name=play_run_", "--format", "{{json .}}") cmd.Stdout, cmd.Stderr = out, out if err := cmd.Start(); err != nil { return nil, fmt.Errorf("listDockerContainers: cmd.Start() failed: %w", err) @@ -220,7 +221,7 @@ for scanner.Scan() { var do dockerContainer if err := json.Unmarshal(scanner.Bytes(), &do); err != nil { - return nil, fmt.Errorf("parseDockerContainers: error parsing docker ps output: %w", err) + return nil, fmt.Errorf("parseDockerContainers: error parsing docker ps output on line %q: %w", scanner.Text(), err) } containers = append(containers, do) } @@ -348,7 +349,7 @@ log.Fatalf("writing header to stderr: %v", err) } - cmd := exec.Command(binPath) + cmd := execCommand(binPath) cmd.Args = append(cmd.Args, meta.Args...) cmd.Stdout = os.Stdout cmd.Stderr = os.Stderr @@ -368,17 +369,19 @@ func makeWorkers() { ctx := context.Background() + log.Printf("makeWorkers: starting %d workers", *numWorkers) stats.Record(ctx, mMaxContainers.M(int64(*numWorkers))) for i := 0; i < *numWorkers; i++ { - go workerLoop(ctx) + go workerLoop(ctx, i) } } -func workerLoop(ctx context.Context) { +func workerLoop(ctx context.Context, id int) { + log.Printf("workerLoop %d: started", id) for { c, err := startContainer(ctx) if err != nil { - log.Printf("error starting container: %v", err) + log.Printf("workerLoop %d: error starting container: %v", id, err) time.Sleep(5 * time.Second) continue } @@ -430,7 +433,7 @@ } } -func startContainer(ctx context.Context) (c *Container, err error) { +func startContainer(ctx context.Context) (_ *Container, err error) { start := time.Now() defer func() { status := "success" @@ -444,7 +447,7 @@ name := "play_run_" + randHex(8) setContainerWanted(name, true) - cmd := exec.Command("docker", "run", + cmd := execCommand("docker", "run", "--name="+name, "--rm", "--tmpfs=/tmpfs:exec", @@ -470,7 +473,7 @@ } ctx, cancel := context.WithCancel(ctx) - c = &Container{ + c := &Container{ name: name, stdin: stdin, stdout: stdout, @@ -480,7 +483,9 @@ waitErr: make(chan error, 1), } go func() { - c.waitErr <- internal.WaitOrStop(ctx, cmd, os.Interrupt, 250*time.Millisecond) + err := internal.WaitOrStop(ctx, cmd, os.Interrupt, 250*time.Millisecond) + c.waitErr <- err + pw.CloseWithError(err) }() defer func() { if err != nil {
diff --git a/sandbox/sandbox_test.go b/sandbox/sandbox_test.go index fac52bb..939a2c2 100644 --- a/sandbox/sandbox_test.go +++ b/sandbox/sandbox_test.go
@@ -7,9 +7,12 @@ import ( "bytes" "io" + "os" + "os/exec" "strings" "testing" "testing/iotest" + "time" "github.com/google/go-cmp/cmp" ) @@ -224,3 +227,44 @@ }) } } + +func TestStartContainer_TimeoutNoHang(t *testing.T) { + oldExecCommand := execCommand + oldStartTimeout := startTimeout + defer func() { + execCommand = oldExecCommand + startTimeout = oldStartTimeout + }() + + // Set a short timeout for the test to run quickly + startTimeout = 100 * time.Millisecond + + // Mock execCommand to run the test binary itself, behaving as a sleep command. + // This avoids depending on external "sleep" binary which is not available on Windows. + execCommand = func(name string, arg ...string) *exec.Cmd { + cmd := exec.Command(os.Args[0], "-test.run=TestHelperProcess") + cmd.Env = append(os.Environ(), "GO_WANT_HELPER_PROCESS=1") + return cmd + } + + // Call startContainer. It should timeout and return an error. + // If the hang bug is present, this call will block forever. + c, err := startContainer(t.Context()) + if err == nil { + t.Fatalf("startContainer succeeded unexpectedly; want timeout error") + c.Close() + } + if !strings.Contains(err.Error(), "timeout starting container") { + t.Errorf("startContainer error = %v; want timeout error", err) + } +} + +// TestHelperProcess is a helper process used to simulate long-running/stuck commands. +func TestHelperProcess(t *testing.T) { + if os.Getenv("GO_WANT_HELPER_PROCESS") != "1" { + return + } + var buf [1]byte + os.Stdin.Read(buf[:]) + os.Exit(0) +}