Skip to content

e2e: kill the whole process tree when a command times out #557

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.

Sign up for GitHub

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

Merged
zcsizmadia merged 1 commit into from
Oct 24, 2026
Merged

e2e: kill the whole process tree when a command times out #557

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
143 changes: 55 additions & 88 deletions test/e2e/e2e_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,14 +19,17 @@ package e2e

import (
"archive/zip"
"bytes"
"encoding/json"
"errors"
"fmt"
"io"
"net/http"
"os"
"os/exec"
"path/filepath"
"runtime"
"strconv"
"strings"
"testing"
"time"
Expand Down Expand Up @@ -170,23 +173,7 @@ func run(t *testing.T, timeout time.Duration, name string, args ...string) (stri
// bypasses that package by design: it drives the real binaries the way a
// user does.
cmd.Env = append(os.Environ(), "WSL_UTF8=1")
done := make(chan struct{})
var out []byte
var err error
go func() {
out, err = cmd.CombinedOutput()
close(done)
}()
select {
case <-done:
return strings.TrimSpace(string(out)), err
case <-time.After(timeout):
if cmd.Process != nil {
cmd.Process.Kill()
}
<-done
return strings.TrimSpace(string(out)), fmt.Errorf("%s timed out after %s", name, timeout)
}
return runBounded(cmd, timeout, name)
}

// runEnv is run() with an explicit environment, for subprocesses that shell
Expand All @@ -197,19 +184,52 @@ func runEnv(t *testing.T, env []string, timeout time.Duration, name string, args
t.Helper()
cmd := exec.Command(name, args...)
cmd.Env = env
done := make(chan struct{})
var out []byte
var err error
go func() { out, err = cmd.CombinedOutput(); close(done) }()
return runBounded(cmd, timeout, name)
}

// errTimedOut marks a runBounded timeout, for callers that add a hint to it.
var errTimedOut = errors.New("timed out")

// killGrace is how long runBounded still waits for output after killing a
// timed-out command's process tree.
const killGrace = 5 * time.Second

// runBounded runs cmd and returns its trimmed combined output, giving up after
// timeout with "<what> timed out after <timeout>". Every command the suite
// runs with a timeout goes through here.
//
// On timeout it kills the whole process tree, not only cmd's own process.
// Killing only the direct child is not enough (#554): a grandchild that
// inherited the output pipe keeps it open, and the wait for output then lasts
// until that grandchild exits on its own -- a 2s timeout took 29s. A process
// whose parent has already exited is outside the tree taskkill walks, so if
// the pipe is still held killGrace after the kill, it stops waiting and
// returns without the output.
func runBounded(cmd *exec.Cmd, timeout time.Duration, what string) (string, error) {
var buf bytes.Buffer
cmd.Stdout = &buf
cmd.Stderr = &buf
if err := cmd.Start(); err != nil {
return "", err
}
done := make(chan error, 1)
go func() { done <- cmd.Wait() }()
select {
case <-done:
return strings.TrimSpace(string(out)), err
case err := <-done:
return strings.TrimSpace(buf.String()), err
case <-time.After(timeout):
if cmd.Process != nil {
cmd.Process.Kill()
}
<-done
return strings.TrimSpace(string(out)), fmt.Errorf("%s timed out after %s", name, timeout)
}
// taskkill /T needs the process alive to find its descendants, so it goes
// first; Kill covers taskkill itself failing.
exec.Command("taskkill", "/T", "/F", "/PID", strconv.Itoa(cmd.Process.Pid)).Run()
cmd.Process.Kill()
select {
case <-done:
return strings.TrimSpace(buf.String()), fmt.Errorf("%s %w after %s", what, errTimedOut, timeout)
case <-time.After(killGrace):
// Wait is still copying into buf, so it cannot be read here.
return "", fmt.Errorf("%s %w after %s; output lost: something outside its process tree still held the pipe %s after the kill",
what, errTimedOut, timeout, killGrace)
}
}

Expand All @@ -226,24 +246,7 @@ func dockerE(t *testing.T, s *state, timeout time.Duration, args ...string) (str
t.Helper()
cmd := exec.Command(s.docker, args...)
cmd.Env = s.dockerEnv()
done := make(chan struct{})
var out []byte
var err error
go func() {
out, err = cmd.CombinedOutput()
close(done)
}()
select {
case <-done:
return strings.TrimSpace(string(out)), err
case <-time.After(timeout):
if cmd.Process != nil {
cmd.Process.Kill()
}
<-done
return strings.TrimSpace(string(out)), fmt.Errorf("docker %s timed out after %s",
strings.Join(args, " "), timeout)
}
return runBounded(cmd, timeout, "docker "+strings.Join(args, " "))
}

func wslProcCount(t *testing.T) int {
Expand Down Expand Up @@ -1630,21 +1633,11 @@ func dockerStdin(t *testing.T, s *state, stdin string, timeout time.Duration, ar
cmd := exec.Command(s.docker, args...)
cmd.Env = s.dockerEnv()
cmd.Stdin = strings.NewReader(stdin)
done := make(chan struct{})
var out []byte
var err error
go func() { out, err = cmd.CombinedOutput(); close(done) }()
select {
case <-done:
return strings.TrimSpace(string(out)), err
case <-time.After(timeout):
if cmd.Process != nil {
cmd.Process.Kill()
}
<-done
return strings.TrimSpace(string(out)), fmt.Errorf("docker %s timed out after %s (stdin EOF likely not propagating)",
strings.Join(args, " "), timeout)
out, err := runBounded(cmd, timeout, "docker "+strings.Join(args, " "))
if errors.Is(err, errTimedOut) {
err = fmt.Errorf("%w (stdin EOF likely not propagating)", err)
}
return out, err
}

func stageLogsFollow(t *testing.T, s *state) {
Expand Down Expand Up @@ -1729,20 +1722,7 @@ services:
cmd := exec.Command(s.docker, append([]string{"compose"}, args...)...)
cmd.Dir = dir
cmd.Env = s.dockerEnv()
done := make(chan struct{})
var out []byte
var err error
go func() { out, err = cmd.CombinedOutput(); close(done) }()
select {
case <-done:
return strings.TrimSpace(string(out)), err
case <-time.After(timeout):
if cmd.Process != nil {
cmd.Process.Kill()
}
<-done
return strings.TrimSpace(string(out)), fmt.Errorf("compose timed out after %s", timeout)
}
return runBounded(cmd, timeout, "compose")
}

defer composeCmd(3*time.Minute, "down", "--timeout", "5")
Expand Down Expand Up @@ -2192,20 +2172,7 @@ func (s *state) runDocker(t *testing.T, timeout time.Duration, args ...string) (
t.Helper()
cmd := exec.Command(s.docker, args...)
cmd.Env = s.hostEnv()
done := make(chan struct{})
var out []byte
var err error
go func() { out, err = cmd.CombinedOutput(); close(done) }()
select {
case <-done:
return strings.TrimSpace(string(out)), err
case <-time.After(timeout):
if cmd.Process != nil {
cmd.Process.Kill()
}
<-done
return strings.TrimSpace(string(out)), fmt.Errorf("docker timed out after %s", timeout)
}
return runBounded(cmd, timeout, "docker")
}

// stageAuditToggle is the regression test for #202: the audit setting has to
Expand Down
64 changes: 64 additions & 0 deletions test/e2e/harness_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,64 @@
//go:build e2e

package e2e

import (
"os"
"runtime"
"strings"
"testing"
"time"
)

// A timeout has to end the wait even when the command started something that
// inherited its output pipe. Killing only the direct child leaves that
// process holding the pipe, and the old harness then waited out its whole
// run: a 2s timeout that took 11s (#554).
func TestTimeoutEndsTheWait(t *testing.T) {
if runtime.GOOS != "windows" {
t.Skip("the harness's process-tree kill is Windows-specific")
}
const timeout = 2 * time.Second
cases := []struct {
name string
args []string
lostOK bool // whether the helper may give up on the output
}{
// cmd.exe waits on ping, its child, which inherited the pipe: the
// tree is intact when the timeout fires, so the tree kill closes the
// pipe and the output is kept.
{"grandchild", []string{"/c", "ping -n 30 127.0.0.1"}, false},
// cmd.exe exits at once and leaves ping running with the pipe: there
// is no live parent left to walk a tree from, so only the grace
// period ends the wait.
{"orphan", []string{"/c", "start /b ping -n 30 127.0.0.1"}, true},
}
helpers := []struct {
name string
run func(args []string) error
}{
{"run", func(a []string) error { _, err := run(t, timeout, "cmd", a...); return err }},
{"runEnv", func(a []string) error { _, err := runEnv(t, os.Environ(), timeout, "cmd", a...); return err }},
{"dockerE", func(a []string) error { _, err := dockerE(t, &state{docker: "cmd"}, timeout, a...); return err }},
}
for _, c := range cases {
for _, h := range helpers {
t.Run(c.name+"/"+h.name, func(t *testing.T) {
start := time.Now()
err := h.run(c.args)
took := time.Since(start)
if err == nil || !strings.Contains(err.Error(), "timed out") {
t.Errorf("err = %v, want a timeout", err)
}
if !c.lostOK && err != nil && strings.Contains(err.Error(), "output lost") {
t.Errorf("the tree kill did not close the pipe: %v", err)
}
// ping -n 30 runs ~29s; the bound leaves room for the kill
// and the grace period, and none for waiting ping out.
if took > 12*time.Second {
t.Errorf("a %s timeout returned after %s", timeout, took.Round(100*time.Millisecond))
}
})
}
}
}
Loading