diff --git a/internal/agenteval/agent_command.go b/internal/agenteval/agent_command.go index a07d32ef2..3c2a3f59e 100644 --- a/internal/agenteval/agent_command.go +++ b/internal/agenteval/agent_command.go @@ -3,9 +3,10 @@ package agenteval import ( "bytes" "context" - "errors" "os/exec" "strings" + + "github.com/Gitlawb/zero/internal/execution" ) type AgentRunInput struct { @@ -67,7 +68,7 @@ func (runner CommandAgentRunner) Run(ctx context.Context, input AgentRunInput) A cmd.Stdout = stdout cmd.Stderr = stderr - err := cmd.Run() + err := execution.RunCommand(ctx, cmd) result.Stdout = stdout.buf.String() result.Stderr = stderr.buf.String() result.Truncated = stdout.truncated || stderr.truncated @@ -81,8 +82,7 @@ func (runner CommandAgentRunner) Run(ctx context.Context, input AgentRunInput) A result.Error = ctxErr.Error() return result } - var exitErr *exec.ExitError - if errors.As(err, &exitErr) { + if exitErr, ok := execution.AsPureExitError(err); ok { result.ExitCode = exitErr.ExitCode() return result } diff --git a/internal/agenteval/materialize.go b/internal/agenteval/materialize.go index 71e683dfc..3ab705a4a 100644 --- a/internal/agenteval/materialize.go +++ b/internal/agenteval/materialize.go @@ -10,6 +10,8 @@ import ( "os/exec" "path/filepath" "strings" + + "github.com/Gitlawb/zero/internal/execution" ) type Materializer struct{} @@ -198,7 +200,7 @@ func initGitBaseline(ctx context.Context, workspace string) error { var output bytes.Buffer cmd.Stdout = &output cmd.Stderr = &output - if err := cmd.Run(); err != nil { + if err := execution.RunCommand(ctx, cmd); err != nil { if ctxErr := ctx.Err(); ctxErr != nil { return ctxErr } diff --git a/internal/agenteval/run.go b/internal/agenteval/run.go index e6f13a500..4e27cffaf 100644 --- a/internal/agenteval/run.go +++ b/internal/agenteval/run.go @@ -10,6 +10,8 @@ import ( "path/filepath" "strings" "time" + + "github.com/Gitlawb/zero/internal/execution" ) // defaultCommandTimeout bounds a single verification command so a hung command @@ -144,15 +146,14 @@ func execCommand(ctx context.Context, workspace string, command Command) Command var stderr bytes.Buffer cmd.Stdout = &stdout cmd.Stderr = &stderr - err := cmd.Run() + err := execution.RunCommand(ctx, cmd) result.Stdout = stdout.String() result.Stderr = stderr.String() if err == nil { result.ExitCode = 0 return result } - var exitErr *exec.ExitError - if errors.As(err, &exitErr) { + if exitErr, ok := execution.AsPureExitError(err); ok { result.ExitCode = exitErr.ExitCode() return result } @@ -167,14 +168,16 @@ func execCommand(ctx context.Context, workspace string, command Command) Command func defaultRunGit(ctx context.Context, workspace string, args ...string) ([]byte, error) { allArgs := append([]string{"-C", workspace}, args...) cmd := exec.CommandContext(ctx, "git", allArgs...) - output, err := cmd.Output() + var output bytes.Buffer + cmd.Stdout = &output + err := execution.RunCommand(ctx, cmd) if err != nil { if ctxErr := ctx.Err(); ctxErr != nil { return nil, ctxErr } return nil, err } - return output, nil + return output.Bytes(), nil } func parseGitStatusPorcelain(output []byte) []string { diff --git a/internal/dictation/runner.go b/internal/dictation/runner.go index 3db6eb156..43b250559 100644 --- a/internal/dictation/runner.go +++ b/internal/dictation/runner.go @@ -7,6 +7,8 @@ import ( "os" "os/exec" "time" + + "github.com/Gitlawb/zero/internal/execution" ) // commandSpec describes one capture-process invocation. Argv is always @@ -107,7 +109,7 @@ func runCommandOutput(ctx context.Context, name string, args ...string) ([]byte, var out bytes.Buffer cmd.Stdout = &out cmd.Stderr = &out - err := cmd.Run() + err := execution.RunCommand(ctx, cmd) return out.Bytes(), err } diff --git a/internal/execution/command_context.go b/internal/execution/command_context.go new file mode 100644 index 000000000..ca3ea9b0f --- /dev/null +++ b/internal/execution/command_context.go @@ -0,0 +1,152 @@ +package execution + +import ( + "context" + "errors" + "fmt" + "io" + "os" + "os/exec" + "reflect" + "sync" +) + +// RunCommand runs a context-bound command in a retained process tree and +// prevents inherited output handles from blocking Wait indefinitely. +func RunCommand(ctx context.Context, command *exec.Cmd) (err error) { + if command == nil { + return errors.New("execution: nil command") + } + if ctx == nil { + ctx = context.Background() + } + if err := ctx.Err(); err != nil { + return err + } + drains := observeOutputDrains(command) + tree, err := prepareCommandTree(command) + if err != nil { + return err + } + defer func() { err = errors.Join(err, tree.close()) }() + + command.WaitDelay = processWaitDelay + // Adapters may return exec.Command, which rejects a non-nil Cancel. + // The watcher below also owns cancellation for commands without that hook. + if command.Cancel != nil { + command.Cancel = tree.cancel + } + if err := command.Start(); err != nil { + _ = tree.attach(nil) + return err + } + if err := tree.attach(command.Process); err != nil { + killErr := command.Process.Kill() + waitErr := command.Wait() + return errors.Join(fmt.Errorf("execution: attach process tree: %w", err), killErr, waitErr) + } + waitComplete := make(chan struct{}) + type cancellation struct { + err error + canceled bool + } + cancelResult := make(chan cancellation, 1) + go func() { + select { + case <-ctx.Done(): + cancelResult <- cancellation{err: tree.cancel(), canceled: true} + case <-waitComplete: + cancelResult <- cancellation{} + } + }() + waitErr := command.Wait() + close(waitComplete) + canceled := <-cancelResult + if canceled.canceled { + return errors.Join(waitErr, ctx.Err(), canceled.err) + } + if waitErr != nil && drains.err() != nil { + // Cmd.Wait intentionally prefers an ExitError over a copying error. When + // WaitDelay forcibly closes an inherited output pipe after a nonzero root + // exit, retain that cleanup failure so result consumers cannot reconcile it + // as an ordinary command exit. + return errors.Join(waitErr, exec.ErrWaitDelay, tree.cancel()) + } + if waitErr != nil { + return errors.Join(waitErr, tree.cancel()) + } + return waitErr +} + +type outputDrains struct { + stdout *drainObserver + stderr *drainObserver +} + +func observeOutputDrains(command *exec.Cmd) outputDrains { + drains := outputDrains{} + sharedOutput := sameWriter(command.Stderr, command.Stdout) + if !isFile(command.Stdout) && command.Stdout != nil { + drains.stdout = &drainObserver{writer: command.Stdout} + command.Stdout = drains.stdout + } + if sharedOutput && drains.stdout != nil { + command.Stderr = drains.stdout + drains.stderr = drains.stdout + } else if !isFile(command.Stderr) && command.Stderr != nil { + drains.stderr = &drainObserver{writer: command.Stderr} + command.Stderr = drains.stderr + } + return drains +} + +func (drains outputDrains) err() error { + if drains.stdout != nil && drains.stdout.err() != nil { + return drains.stdout.err() + } + if drains.stderr != nil { + return drains.stderr.err() + } + return nil +} + +func isFile(writer io.Writer) bool { + _, ok := writer.(*os.File) + return ok +} + +func sameWriter(left io.Writer, right io.Writer) bool { + if left == nil || right == nil { + return false + } + leftType := reflect.TypeOf(left) + return leftType == reflect.TypeOf(right) && leftType.Comparable() && left == right +} + +// drainObserver records an error from os/exec's output-copying goroutine. +// Cmd.Wait drops that error when process exit itself fails. +type drainObserver struct { + writer io.Writer + mu sync.Mutex + copyErr error +} + +func (observer *drainObserver) Write(data []byte) (int, error) { + return observer.writer.Write(data) +} + +func (observer *drainObserver) ReadFrom(reader io.Reader) (int64, error) { + written, err := io.Copy(observer.writer, reader) + if err != nil { + observer.mu.Lock() + observer.copyErr = err + observer.mu.Unlock() + } + return written, err +} + +func (observer *drainObserver) err() error { + observer.mu.Lock() + defer observer.mu.Unlock() + return observer.copyErr +} diff --git a/internal/execution/command_context_process_unix_test.go b/internal/execution/command_context_process_unix_test.go new file mode 100644 index 000000000..3e23eb4d0 --- /dev/null +++ b/internal/execution/command_context_process_unix_test.go @@ -0,0 +1,100 @@ +//go:build !windows + +package execution + +import ( + "errors" + "os" + "strconv" + "strings" + "syscall" + "testing" + "time" +) + +type helperProcessOwner struct { + pidFile string + stopFile string + pid int + exited bool +} + +func ownHelperProcess(t *testing.T, pidFile, stopFile string) *helperProcessOwner { + t.Helper() + owner := &helperProcessOwner{pidFile: pidFile, stopFile: stopFile} + t.Cleanup(func() { owner.cleanup(t) }) + return owner +} + +func (owner *helperProcessOwner) waitReady(t *testing.T, timeout time.Duration) int { + t.Helper() + deadline := time.Now().Add(timeout) + for { + data, err := os.ReadFile(owner.pidFile) + if err == nil { + pid, parseErr := strconv.Atoi(strings.TrimSpace(string(data))) + if parseErr == nil && pid > 0 { + owner.pid = pid + return pid + } + } + if time.Now().After(deadline) { + t.Fatalf("helper did not hand off a valid PID within %s", timeout) + } + time.Sleep(10 * time.Millisecond) + } +} + +func (owner *helperProcessOwner) cleanup(t *testing.T) { + t.Helper() + if err := os.WriteFile(owner.stopFile, nil, 0o600); err != nil { + t.Errorf("request helper process stop: %v", err) + } + if owner.exited { + return + } + if owner.pid == 0 { + data, err := os.ReadFile(owner.pidFile) + if err == nil { + owner.pid, _ = strconv.Atoi(strings.TrimSpace(string(data))) + } + } + if owner.pid <= 0 { + return + } + deadline := time.Now().Add(2 * time.Second) + for time.Now().Before(deadline) { + err := syscall.Kill(owner.pid, syscall.Signal(0)) + if errors.Is(err, syscall.ESRCH) { + owner.pid = 0 + owner.exited = true + return + } + if err != nil { + t.Errorf("check helper process %d after cleanup: %v", owner.pid, err) + return + } + time.Sleep(10 * time.Millisecond) + } + t.Errorf("helper process %d survived cleanup", owner.pid) +} + +func (owner *helperProcessOwner) awaitExit(t *testing.T) { + t.Helper() + deadline := time.Now().Add(2 * time.Second) + for { + err := syscall.Kill(owner.pid, syscall.Signal(0)) + if errors.Is(err, syscall.ESRCH) { + owner.pid = 0 + owner.exited = true + return + } + if err != nil { + t.Fatalf("check helper process %d: %v", owner.pid, err) + } + if time.Now().After(deadline) { + t.Fatalf("helper process %d is still running after command cancellation", owner.pid) + } + time.Sleep(10 * time.Millisecond) + } +} diff --git a/internal/execution/command_context_process_windows_test.go b/internal/execution/command_context_process_windows_test.go new file mode 100644 index 000000000..9364062fb --- /dev/null +++ b/internal/execution/command_context_process_windows_test.go @@ -0,0 +1,174 @@ +//go:build windows + +package execution + +import ( + "errors" + "os" + "strconv" + "strings" + "testing" + "time" + + "golang.org/x/sys/windows" +) + +type helperProcessOwner struct { + pidFile string + stopFile string + pid int + handle windows.Handle + exited bool +} + +func ownHelperProcess(t *testing.T, pidFile, stopFile string) *helperProcessOwner { + t.Helper() + owner := &helperProcessOwner{pidFile: pidFile, stopFile: stopFile} + t.Cleanup(func() { owner.cleanup(t) }) + return owner +} + +func (owner *helperProcessOwner) waitReady(t *testing.T, timeout time.Duration) int { + t.Helper() + deadline := time.Now().Add(timeout) + for { + observed, err := owner.observeReady() + if err != nil { + t.Fatalf("retain helper process: %v", err) + } + if observed { + return owner.pid + } + if time.Now().After(deadline) { + t.Fatalf("helper did not hand off a valid PID within %s", timeout) + } + time.Sleep(10 * time.Millisecond) + } +} + +func (owner *helperProcessOwner) observeReady() (bool, error) { + data, err := os.ReadFile(owner.pidFile) + if err != nil { + return false, nil + } + pid, err := strconv.Atoi(strings.TrimSpace(string(data))) + if err != nil || pid <= 0 { + return false, nil + } + if owner.handle != 0 { + return true, nil + } + if err := owner.retainPID(pid); err != nil { + return true, err + } + return true, nil +} + +func (owner *helperProcessOwner) retainPID(pid int) error { + handle, err := windows.OpenProcess(windows.PROCESS_TERMINATE|windows.SYNCHRONIZE|windows.PROCESS_QUERY_LIMITED_INFORMATION, false, uint32(pid)) + if errors.Is(err, windows.ERROR_INVALID_PARAMETER) { + owner.pid = pid + owner.exited = true + return nil + } + if err != nil { + return err + } + owner.pid = pid + owner.handle = handle + return nil +} + +func (owner *helperProcessOwner) running() bool { + if owner.handle == 0 { + return false + } + var exitCode uint32 + return windows.GetExitCodeProcess(owner.handle, &exitCode) == nil && exitCode == processStillActive +} + +func (owner *helperProcessOwner) awaitExit(t *testing.T) { + t.Helper() + if owner.exited { + return + } + if owner.handle == 0 { + t.Fatal("helper process handle was not retained") + } + status, err := windows.WaitForSingleObject(owner.handle, 2_000) + if err != nil { + t.Fatalf("wait for helper process %d: %v", owner.pid, err) + } + if status != windows.WAIT_OBJECT_0 { + t.Fatalf("helper process %d is still running after command cancellation", owner.pid) + } +} + +func (owner *helperProcessOwner) cleanup(t *testing.T) { + t.Helper() + if err := os.WriteFile(owner.stopFile, nil, 0o600); err != nil { + t.Errorf("request helper process stop: %v", err) + } + if owner.handle == 0 { + observed, err := owner.observeReady() + if observed && err != nil { + t.Errorf("retain helper process for cleanup: %v", err) + } + } + if owner.handle == 0 { + return + } + if owner.running() { + status, err := windows.WaitForSingleObject(owner.handle, 2_000) + if err != nil { + t.Errorf("wait for helper process %d cooperative stop: %v", owner.pid, err) + } else if status == uint32(windows.WAIT_TIMEOUT) { + if err := windows.TerminateProcess(owner.handle, 1); err != nil { + t.Errorf("kill helper process %d: %v", owner.pid, err) + } + _, _ = windows.WaitForSingleObject(owner.handle, 2_000) + } + } + if err := windows.CloseHandle(owner.handle); err != nil { + t.Errorf("close helper process %d handle: %v", owner.pid, err) + } + owner.handle = 0 +} + +type helperHandleOwner struct { + handle windows.Handle + stopFile string +} + +func ownHelperHandle(t *testing.T, stopFile string) *helperHandleOwner { + t.Helper() + owner := &helperHandleOwner{stopFile: stopFile} + t.Cleanup(func() { owner.cleanup(t) }) + return owner +} + +func (owner *helperHandleOwner) retain(process windows.Handle) error { + current := windows.CurrentProcess() + return windows.DuplicateHandle(current, process, current, &owner.handle, windows.PROCESS_TERMINATE|windows.SYNCHRONIZE|windows.PROCESS_QUERY_LIMITED_INFORMATION, false, 0) +} + +func (owner *helperHandleOwner) cleanup(t *testing.T) { + t.Helper() + if err := os.WriteFile(owner.stopFile, nil, 0o600); err != nil { + t.Errorf("request suspended helper process stop: %v", err) + } + if owner.handle == 0 { + return + } + var exitCode uint32 + if windows.GetExitCodeProcess(owner.handle, &exitCode) == nil && exitCode == processStillActive { + if err := windows.TerminateProcess(owner.handle, 1); err != nil { + t.Errorf("kill suspended helper process: %v", err) + } + _, _ = windows.WaitForSingleObject(owner.handle, 2_000) + } + if err := windows.CloseHandle(owner.handle); err != nil { + t.Errorf("close suspended helper process handle: %v", err) + } + owner.handle = 0 +} diff --git a/internal/execution/command_context_test.go b/internal/execution/command_context_test.go new file mode 100644 index 000000000..c3a73a73a --- /dev/null +++ b/internal/execution/command_context_test.go @@ -0,0 +1,238 @@ +package execution + +import ( + "bytes" + "context" + "errors" + "os" + "os/exec" + "strconv" + "testing" + "time" +) + +func TestRunCommandCanceledBeforePlainCommandStart(t *testing.T) { + ctx, cancel := context.WithCancel(context.Background()) + cancel() + command := exec.Command(os.Args[0], "-test.run=^$") + err := RunCommand(ctx, command) + if !errors.Is(err, context.Canceled) || command.Process != nil { + t.Fatalf("canceled command must not start: err=%v process=%v", err, command.Process) + } +} + +func TestRunCommandKillsDescendantAfterRootExit(t *testing.T) { + switch os.Getenv("ZERO_COMMAND_TREE_HELPER") { + case "root": + child := exec.Command(os.Args[0], "-test.run=^TestRunCommandKillsDescendantAfterRootExit$") + child.Env = append(os.Environ(), + "ZERO_COMMAND_TREE_HELPER=child", + "ZERO_COMMAND_TREE_STOP_FILE="+os.Getenv("ZERO_COMMAND_TREE_STOP_FILE"), + ) + child.Stdout = os.Stdout + child.Stderr = os.Stderr + if err := child.Start(); err != nil { + os.Exit(2) + } + if err := os.WriteFile(os.Getenv("ZERO_COMMAND_TREE_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_COMMAND_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(3) + } + return + case "child": + waitForCommandTreeStop(os.Getenv("ZERO_COMMAND_TREE_STOP_FILE"), 30*time.Second) + return + } + + root := t.TempDir() + pidFile := root + string(os.PathSeparator) + "child.pid" + stopFile := root + string(os.PathSeparator) + "stop" + child := ownHelperProcess(t, pidFile, stopFile) + ctx, cancel := context.WithCancel(context.Background()) + t.Cleanup(cancel) + cmd := exec.CommandContext(ctx, os.Args[0], "-test.run=^TestRunCommandKillsDescendantAfterRootExit$") + cmd.Env = append(os.Environ(), + "ZERO_COMMAND_TREE_HELPER=root", + "ZERO_COMMAND_TREE_PID_FILE="+pidFile, + "ZERO_COMMAND_TREE_STOP_FILE="+stopFile, + ) + var output bytes.Buffer + cmd.Stdout = &output + cmd.Stderr = &output + + result := runCommandAsync(ctx, cmd) + child.waitReady(t, 2*time.Second) + cancel() + err := waitForRunCommand(t, result, 4*time.Second) + if err == nil { + t.Fatal("timed-out command unexpectedly succeeded") + } + child.awaitExit(t) +} + +func TestRunCommandKillsDescendantWhenWaitDelayExpires(t *testing.T) { + switch os.Getenv("ZERO_WAIT_DELAY_TREE_HELPER") { + case "root": + child := exec.Command(os.Args[0], "-test.run=^TestRunCommandKillsDescendantWhenWaitDelayExpires$") + child.Env = append(os.Environ(), + "ZERO_WAIT_DELAY_TREE_HELPER=child", + "ZERO_WAIT_DELAY_TREE_STOP_FILE="+os.Getenv("ZERO_WAIT_DELAY_TREE_STOP_FILE"), + ) + child.Stdout = os.Stdout + child.Stderr = os.Stderr + if err := child.Start(); err != nil { + os.Exit(2) + } + if err := os.WriteFile(os.Getenv("ZERO_WAIT_DELAY_TREE_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_WAIT_DELAY_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(3) + } + if os.Getenv("ZERO_WAIT_DELAY_TREE_EXIT_CODE") == "7" { + os.Exit(7) + } + return + case "child": + waitForCommandTreeStop(os.Getenv("ZERO_WAIT_DELAY_TREE_STOP_FILE"), 30*time.Second) + return + } + + root := t.TempDir() + pidFile := root + string(os.PathSeparator) + "child.pid" + stopFile := root + string(os.PathSeparator) + "stop" + child := ownHelperProcess(t, pidFile, stopFile) + ctx, cancel := context.WithCancel(context.Background()) + t.Cleanup(cancel) + cmd := exec.CommandContext(ctx, os.Args[0], "-test.run=^TestRunCommandKillsDescendantWhenWaitDelayExpires$") + cmd.Env = append(os.Environ(), + "ZERO_WAIT_DELAY_TREE_HELPER=root", + "ZERO_WAIT_DELAY_TREE_PID_FILE="+pidFile, + "ZERO_WAIT_DELAY_TREE_STOP_FILE="+stopFile, + ) + var output bytes.Buffer + cmd.Stdout = &output + cmd.Stderr = &output + + result := runCommandAsync(ctx, cmd) + child.waitReady(t, 2*time.Second) + err := waitForRunCommand(t, result, 4*time.Second) + if !errors.Is(err, exec.ErrWaitDelay) { + t.Fatalf("RunCommand error = %v, want exec.ErrWaitDelay", err) + } + child.awaitExit(t) +} + +func TestRunCommandPreservesWaitDelayAfterNonzeroRootExit(t *testing.T) { + root := t.TempDir() + pidFile := root + string(os.PathSeparator) + "child.pid" + stopFile := root + string(os.PathSeparator) + "stop" + child := ownHelperProcess(t, pidFile, stopFile) + cmd := exec.Command(os.Args[0], "-test.run=^TestRunCommandKillsDescendantWhenWaitDelayExpires$") + cmd.Env = append(os.Environ(), + "ZERO_WAIT_DELAY_TREE_HELPER=root", + "ZERO_WAIT_DELAY_TREE_PID_FILE="+pidFile, + "ZERO_WAIT_DELAY_TREE_STOP_FILE="+stopFile, + "ZERO_WAIT_DELAY_TREE_EXIT_CODE=7", + ) + var output bytes.Buffer + cmd.Stdout = &output + cmd.Stderr = &output + + result := runCommandAsync(context.Background(), cmd) + child.waitReady(t, 2*time.Second) + err := waitForRunCommand(t, result, 4*time.Second) + if !errors.Is(err, exec.ErrWaitDelay) { + t.Fatalf("RunCommand error = %v, want exec.ErrWaitDelay", err) + } + var exitErr *exec.ExitError + if !errors.As(err, &exitErr) || exitErr.ExitCode() != 7 { + t.Fatalf("RunCommand error = %v, want exit code 7", err) + } + child.awaitExit(t) +} + +func TestRunCommandKillsDescendantAfterNonzeroRootExit(t *testing.T) { + switch os.Getenv("ZERO_NONZERO_TREE_HELPER") { + case "root": + nullFile, err := os.OpenFile(os.DevNull, os.O_RDWR, 0) + if err != nil { + os.Exit(2) + } + defer nullFile.Close() + child := exec.Command(os.Args[0], "-test.run=^TestRunCommandKillsDescendantAfterNonzeroRootExit$") + child.Env = append(os.Environ(), + "ZERO_NONZERO_TREE_HELPER=child", + "ZERO_NONZERO_TREE_STOP_FILE="+os.Getenv("ZERO_NONZERO_TREE_STOP_FILE"), + ) + child.Stdin = nullFile + child.Stdout = nullFile + child.Stderr = nullFile + if err := child.Start(); err != nil { + os.Exit(3) + } + if err := os.WriteFile(os.Getenv("ZERO_NONZERO_TREE_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_NONZERO_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(4) + } + // Leave time for the parent test to retain an independent cleanup handle + // before the root's abnormal exit triggers production tree cleanup. + if waitForCommandTreeStop(os.Getenv("ZERO_NONZERO_TREE_STOP_FILE"), 500*time.Millisecond) { + _ = child.Wait() + return + } + os.Exit(7) + case "child": + waitForCommandTreeStop(os.Getenv("ZERO_NONZERO_TREE_STOP_FILE"), 30*time.Second) + return + } + + root := t.TempDir() + pidFile := root + string(os.PathSeparator) + "child.pid" + stopFile := root + string(os.PathSeparator) + "stop" + child := ownHelperProcess(t, pidFile, stopFile) + ctx := context.Background() + cmd := exec.CommandContext(ctx, os.Args[0], "-test.run=^TestRunCommandKillsDescendantAfterNonzeroRootExit$") + cmd.Env = append(os.Environ(), + "ZERO_NONZERO_TREE_HELPER=root", + "ZERO_NONZERO_TREE_PID_FILE="+pidFile, + "ZERO_NONZERO_TREE_STOP_FILE="+stopFile, + ) + result := runCommandAsync(ctx, cmd) + child.waitReady(t, 2*time.Second) + err := waitForRunCommand(t, result, 4*time.Second) + var exitErr *exec.ExitError + if !errors.As(err, &exitErr) || exitErr.ExitCode() != 7 { + t.Fatalf("RunCommand error = %v, want exit code 7", err) + } + child.awaitExit(t) +} + +func waitForCommandTreeStop(stopFile string, lifetime time.Duration) bool { + deadline := time.Now().Add(lifetime) + for time.Now().Before(deadline) { + if _, err := os.Stat(stopFile); err == nil { + return true + } + time.Sleep(10 * time.Millisecond) + } + return false +} + +func runCommandAsync(ctx context.Context, command *exec.Cmd) <-chan error { + result := make(chan error, 1) + go func() { result <- RunCommand(ctx, command) }() + return result +} + +func waitForRunCommand(t *testing.T, result <-chan error, timeout time.Duration) error { + t.Helper() + select { + case err := <-result: + return err + case <-time.After(timeout): + t.Fatalf("RunCommand did not return within %s", timeout) + return nil + } +} diff --git a/internal/execution/command_context_unix_test.go b/internal/execution/command_context_unix_test.go new file mode 100644 index 000000000..f74cb5e5c --- /dev/null +++ b/internal/execution/command_context_unix_test.go @@ -0,0 +1,65 @@ +//go:build !windows + +package execution + +import ( + "context" + "os" + "os/exec" + "path/filepath" + "strconv" + "testing" + "time" +) + +func TestRunCommandPreservesRedirectedChildAfterSuccessfulExit(t *testing.T) { + switch os.Getenv("ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_HELPER") { + case "root": + nullFile, err := os.OpenFile(os.DevNull, os.O_RDWR, 0) + if err != nil { + os.Exit(2) + } + defer nullFile.Close() + child := exec.Command(os.Args[0], "-test.run=^TestRunCommandPreservesRedirectedChildAfterSuccessfulExit$") + child.Env = append(os.Environ(), + "ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_HELPER=child", + "ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_STOP_FILE="+os.Getenv("ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_STOP_FILE"), + ) + child.Stdin = nullFile + child.Stdout = nullFile + child.Stderr = nullFile + if err := child.Start(); err != nil { + os.Exit(3) + } + if err := os.WriteFile(os.Getenv("ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(4) + } + return + case "child": + waitForCommandTreeStop(os.Getenv("ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_STOP_FILE"), 30*time.Second) + return + } + + root := t.TempDir() + pidFile := filepath.Join(root, "child.pid") + stopFile := filepath.Join(root, "stop") + child := ownHelperProcess(t, pidFile, stopFile) + ctx, cancel := context.WithCancel(context.Background()) + t.Cleanup(cancel) + command := exec.CommandContext(ctx, os.Args[0], "-test.run=^TestRunCommandPreservesRedirectedChildAfterSuccessfulExit$") + command.Env = append(os.Environ(), + "ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_HELPER=root", + "ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_PID_FILE="+pidFile, + "ZERO_SUCCESSFUL_UNIX_COMMAND_TREE_STOP_FILE="+stopFile, + ) + result := runCommandAsync(ctx, command) + pid := child.waitReady(t, 2*time.Second) + if err := waitForRunCommand(t, result, 4*time.Second); err != nil { + t.Fatalf("RunCommand failed: %v", err) + } + if !signalTargetRunning(pid) { + t.Fatalf("successful RunCommand terminated redirected child %d", pid) + } +} diff --git a/internal/execution/command_context_windows_test.go b/internal/execution/command_context_windows_test.go new file mode 100644 index 000000000..fbe862039 --- /dev/null +++ b/internal/execution/command_context_windows_test.go @@ -0,0 +1,73 @@ +//go:build windows + +package execution + +import ( + "context" + "os" + "os/exec" + "path/filepath" + "strconv" + "syscall" + "testing" + "time" + + "golang.org/x/sys/windows" +) + +const processStillActive = 259 + +func TestRunCommandPreservesDetachedChildAfterSuccessfulExit(t *testing.T) { + switch os.Getenv("ZERO_SUCCESSFUL_COMMAND_TREE_HELPER") { + case "root": + nullFile, err := os.OpenFile(os.DevNull, os.O_RDWR, 0) + if err != nil { + os.Exit(2) + } + defer nullFile.Close() + child := exec.Command(os.Args[0], "-test.run=^TestRunCommandPreservesDetachedChildAfterSuccessfulExit$") + child.Env = append(os.Environ(), + "ZERO_SUCCESSFUL_COMMAND_TREE_HELPER=child", + "ZERO_SUCCESSFUL_COMMAND_TREE_STOP_FILE="+os.Getenv("ZERO_SUCCESSFUL_COMMAND_TREE_STOP_FILE"), + ) + child.Stdin = nullFile + child.Stdout = nullFile + child.Stderr = nullFile + child.SysProcAttr = &syscall.SysProcAttr{ + CreationFlags: windows.DETACHED_PROCESS | windows.CREATE_NEW_PROCESS_GROUP, + } + if err := child.Start(); err != nil { + os.Exit(3) + } + if err := os.WriteFile(os.Getenv("ZERO_SUCCESSFUL_COMMAND_TREE_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_SUCCESSFUL_COMMAND_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(4) + } + return + case "child": + waitForCommandTreeStop(os.Getenv("ZERO_SUCCESSFUL_COMMAND_TREE_STOP_FILE"), 30*time.Second) + return + } + + root := t.TempDir() + pidFile := filepath.Join(root, "child.pid") + stopFile := filepath.Join(root, "stop") + child := ownHelperProcess(t, pidFile, stopFile) + ctx, cancel := context.WithCancel(context.Background()) + t.Cleanup(cancel) + command := exec.CommandContext(ctx, os.Args[0], "-test.run=^TestRunCommandPreservesDetachedChildAfterSuccessfulExit$") + command.Env = append(os.Environ(), + "ZERO_SUCCESSFUL_COMMAND_TREE_HELPER=root", + "ZERO_SUCCESSFUL_COMMAND_TREE_PID_FILE="+pidFile, + "ZERO_SUCCESSFUL_COMMAND_TREE_STOP_FILE="+stopFile, + ) + result := runCommandAsync(ctx, command) + pid := child.waitReady(t, 2*time.Second) + if err := waitForRunCommand(t, result, 4*time.Second); err != nil { + t.Fatalf("RunCommand failed: %v", err) + } + if !child.running() { + t.Fatalf("successful RunCommand terminated detached child %d", pid) + } +} diff --git a/internal/execution/command_tree_unix.go b/internal/execution/command_tree_unix.go new file mode 100644 index 000000000..02689bed6 --- /dev/null +++ b/internal/execution/command_tree_unix.go @@ -0,0 +1,92 @@ +//go:build !windows + +package execution + +import ( + "errors" + "io" + "os" + "os/exec" + "sync" + "syscall" +) + +type commandTree struct { + mu sync.Mutex + ready chan struct{} + readyOnce sync.Once + groupID int + anchor *exec.Cmd + anchorInput io.WriteCloser + signal func(int, syscall.Signal) error + canceled bool + cancelErr error + closed bool +} + +func prepareCommandTree(command *exec.Cmd) (*commandTree, error) { + // Keep the group leader alive until cleanup so an exited command cannot + // leave a reusable PID as the only identity for its live descendants. + anchor := exec.Command("/bin/sh", "-c", "read _") + anchor.SysProcAttr = &syscall.SysProcAttr{Setpgid: true} + anchorInput, err := anchor.StdinPipe() + if err != nil { + return nil, err + } + if err := anchor.Start(); err != nil { + _ = anchorInput.Close() + return nil, err + } + + tree := &commandTree{ + ready: make(chan struct{}), + groupID: anchor.Process.Pid, + anchor: anchor, + anchorInput: anchorInput, + signal: syscall.Kill, + } + if command.SysProcAttr == nil { + command.SysProcAttr = &syscall.SysProcAttr{} + } + command.SysProcAttr.Setpgid = true + command.SysProcAttr.Pgid = tree.groupID + return tree, nil +} + +func (tree *commandTree) attach(*os.Process) error { + tree.readyOnce.Do(func() { close(tree.ready) }) + return nil +} + +func (tree *commandTree) cancel() error { + <-tree.ready + tree.mu.Lock() + defer tree.mu.Unlock() + if tree.closed || tree.canceled || tree.groupID <= 1 { + return tree.cancelErr + } + tree.canceled = true + if err := tree.signal(-tree.groupID, syscall.SIGKILL); err != nil && !errors.Is(err, syscall.ESRCH) { + tree.cancelErr = err + } + return tree.cancelErr +} + +func (tree *commandTree) close() error { + tree.mu.Lock() + defer tree.mu.Unlock() + if tree.closed { + return nil + } + tree.closed = true + if tree.anchorInput != nil { + _ = tree.anchorInput.Close() + tree.anchorInput = nil + } + if tree.anchor != nil { + _ = tree.anchor.Wait() + tree.anchor = nil + } + tree.groupID = 0 + return nil +} diff --git a/internal/execution/command_tree_unix_test.go b/internal/execution/command_tree_unix_test.go new file mode 100644 index 000000000..289ed70c5 --- /dev/null +++ b/internal/execution/command_tree_unix_test.go @@ -0,0 +1,174 @@ +//go:build !windows + +package execution + +import ( + "context" + "errors" + "os/exec" + "sync" + "sync/atomic" + "syscall" + "testing" + "time" +) + +func TestRunCommandAbsolutePathWithEmptyPATH(t *testing.T) { + t.Setenv("PATH", "") + ctx := context.Background() + command := exec.CommandContext(ctx, "/bin/sh", "-c", "exit 0") + if err := RunCommand(ctx, command); err != nil { + t.Fatalf("RunCommand with absolute executable and empty PATH: %v", err) + } +} + +func TestPrepareCommandTreeRetainsGroupIdentity(t *testing.T) { + attributes := &syscall.SysProcAttr{Setsid: true} + command := exec.Command("sh", "-c", "exit 7") + command.SysProcAttr = attributes + tree, err := prepareCommandTree(command) + if err != nil { + t.Fatalf("prepare command tree: %v", err) + } + defer tree.close() + + if command.SysProcAttr != attributes { + t.Fatal("prepareCommandTree replaced existing SysProcAttr") + } + if !attributes.Setsid || !attributes.Setpgid || attributes.Pgid != tree.groupID { + t.Fatalf("command attributes = %#v, want preserved Setsid and group %d", attributes, tree.groupID) + } + if pgid, err := syscall.Getpgid(tree.anchor.Process.Pid); err != nil || pgid != tree.groupID { + t.Fatalf("anchor process group = %d, %v; want %d", pgid, err, tree.groupID) + } + + // Setsid and joining an existing process group are intentionally incompatible; + // it is retained above only to verify that unrelated caller fields survive. + attributes.Setsid = false + if err := command.Start(); err != nil { + t.Fatalf("start command: %v", err) + } + if err := tree.attach(command.Process); err != nil { + t.Fatalf("attach command: %v", err) + } + if pgid, err := syscall.Getpgid(command.Process.Pid); err != nil || pgid != tree.groupID { + t.Fatalf("command process group = %d, %v; want %d", pgid, err, tree.groupID) + } + if err := command.Wait(); err == nil { + t.Fatal("command unexpectedly succeeded") + } + if err := syscall.Kill(tree.anchor.Process.Pid, 0); err != nil { + t.Fatalf("anchor did not retain group identity after command exit: %v", err) + } +} + +func TestCommandTreeCancelSignalsOnce(t *testing.T) { + ready := make(chan struct{}) + close(ready) + wantErr := errors.New("signal failed") + var calls atomic.Int32 + tree := &commandTree{ + ready: ready, + groupID: 123, + signal: func(pid int, signal syscall.Signal) error { + calls.Add(1) + if pid != -123 || signal != syscall.SIGKILL { + t.Errorf("signal target = (%d, %v), want (-123, SIGKILL)", pid, signal) + } + return wantErr + }, + } + + const callers = 32 + var wait sync.WaitGroup + wait.Add(callers) + for range callers { + go func() { + defer wait.Done() + if err := tree.cancel(); !errors.Is(err, wantErr) { + t.Errorf("cancel error = %v, want %v", err, wantErr) + } + }() + } + wait.Wait() + if got := calls.Load(); got != 1 { + t.Fatalf("signal calls = %d, want 1", got) + } +} + +func TestCommandTreeCloseWaitsForCancelAndPreventsLaterSignals(t *testing.T) { + command := exec.Command("sh", "-c", "exit 0") + tree, err := prepareCommandTree(command) + if err != nil { + t.Fatalf("prepare command tree: %v", err) + } + if err := tree.attach(nil); err != nil { + t.Fatalf("attach command tree: %v", err) + } + anchorPID := tree.anchor.Process.Pid + + signalStarted := make(chan struct{}) + releaseSignal := make(chan struct{}) + var calls atomic.Int32 + tree.signal = func(int, syscall.Signal) error { + calls.Add(1) + close(signalStarted) + <-releaseSignal + return nil + } + cancelDone := make(chan error, 1) + go func() { cancelDone <- tree.cancel() }() + <-signalStarted + + closeDone := make(chan error, 1) + go func() { closeDone <- tree.close() }() + select { + case err := <-closeDone: + t.Fatalf("close returned while signal was in flight: %v", err) + case <-time.After(100 * time.Millisecond): + } + if err := syscall.Kill(anchorPID, 0); err != nil { + t.Fatalf("anchor was released while signal was in flight: %v", err) + } + + close(releaseSignal) + if err := <-cancelDone; err != nil { + t.Fatalf("cancel command tree: %v", err) + } + if err := <-closeDone; err != nil { + t.Fatalf("close command tree: %v", err) + } + if err := tree.cancel(); err != nil { + t.Fatalf("cancel after close: %v", err) + } + if err := tree.close(); err != nil { + t.Fatalf("repeated close: %v", err) + } + if got := calls.Load(); got != 1 { + t.Fatalf("signal calls after close = %d, want 1", got) + } +} + +func TestCommandTreeCancelAfterCloseDoesNotSignal(t *testing.T) { + ready := make(chan struct{}) + close(ready) + var calls atomic.Int32 + tree := &commandTree{ + ready: ready, + groupID: 123, + signal: func(int, syscall.Signal) error { + calls.Add(1) + return nil + }, + } + + if err := tree.close(); err != nil { + t.Fatalf("close command tree: %v", err) + } + if err := tree.cancel(); err != nil { + t.Fatalf("cancel after close: %v", err) + } + if got := calls.Load(); got != 0 { + t.Fatalf("signal calls after close = %d, want 0", got) + } +} diff --git a/internal/execution/command_tree_windows.go b/internal/execution/command_tree_windows.go new file mode 100644 index 000000000..db5a64ab3 --- /dev/null +++ b/internal/execution/command_tree_windows.go @@ -0,0 +1,108 @@ +//go:build windows + +package execution + +import ( + "errors" + "fmt" + "os" + "os/exec" + "syscall" + "unsafe" + + "golang.org/x/sys/windows" +) + +type commandTree struct { + job windows.Handle + processHandle windows.Handle + contained bool + ready chan struct{} +} + +func prepareCommandTree(command *exec.Cmd) (*commandTree, error) { + job, err := windows.CreateJobObject(nil, nil) + if err != nil { + return nil, fmt.Errorf("execution: create command job: %w", err) + } + if command.SysProcAttr == nil { + command.SysProcAttr = &syscall.SysProcAttr{} + } + command.SysProcAttr.CreationFlags |= windows.CREATE_SUSPENDED + return &commandTree{job: job, ready: make(chan struct{})}, nil +} + +func (tree *commandTree) attach(process *os.Process) error { + defer close(tree.ready) + if process == nil { + return nil + } + handle, err := windows.OpenProcess( + windows.PROCESS_SET_QUOTA|windows.PROCESS_TERMINATE|windows.PROCESS_QUERY_LIMITED_INFORMATION, + false, + uint32(process.Pid), + ) + if err != nil { + return fmt.Errorf("open suspended command process: %w", err) + } + tree.processHandle = handle + if err := assignCommandProcessToJob(tree.job, handle); err != nil { + // Without job containment, a root can exit before cancellation and + // leave no identity-safe way to find descendants holding output pipes. + // Fail while it is still suspended so no descendant can escape. + return fmt.Errorf("assign suspended command process to job: %w", err) + } + tree.contained = true + return resumeProcess(uint32(process.Pid)) +} + +func (tree *commandTree) cancel() error { + <-tree.ready + if tree.contained { + return windows.TerminateJobObject(tree.job, 1) + } + return nil +} + +func (tree *commandTree) close() (err error) { + if tree.job != 0 { + err = errors.Join(err, windows.CloseHandle(tree.job)) + tree.job = 0 + } + if tree.processHandle != 0 { + err = errors.Join(err, windows.CloseHandle(tree.processHandle)) + tree.processHandle = 0 + } + return err +} + +var assignCommandProcessToJob = windows.AssignProcessToJobObject + +func resumeProcess(pid uint32) (err error) { + snapshot, err := windows.CreateToolhelp32Snapshot(windows.TH32CS_SNAPTHREAD, 0) + if err != nil { + return err + } + defer func() { err = errors.Join(err, windows.CloseHandle(snapshot)) }() + + entry := windows.ThreadEntry32{Size: uint32(unsafe.Sizeof(windows.ThreadEntry32{}))} + if err := windows.Thread32First(snapshot, &entry); err != nil { + return err + } + for { + if entry.OwnerProcessID == pid { + thread, err := windows.OpenThread(windows.THREAD_SUSPEND_RESUME, false, entry.ThreadID) + if err != nil { + return err + } + _, resumeErr := windows.ResumeThread(thread) + return errors.Join(resumeErr, windows.CloseHandle(thread)) + } + if err := windows.Thread32Next(snapshot, &entry); err != nil { + if errors.Is(err, windows.ERROR_NO_MORE_FILES) { + return fmt.Errorf("execution: no thread found for suspended process %d", pid) + } + return err + } + } +} diff --git a/internal/execution/command_tree_windows_test.go b/internal/execution/command_tree_windows_test.go new file mode 100644 index 000000000..5c6969f20 --- /dev/null +++ b/internal/execution/command_tree_windows_test.go @@ -0,0 +1,76 @@ +//go:build windows + +package execution + +import ( + "context" + "errors" + "os" + "os/exec" + "path/filepath" + "strconv" + "testing" + "time" + + "golang.org/x/sys/windows" +) + +func TestRunCommandFailsBeforeDescendantCanEscapeWhenJobAssignmentFails(t *testing.T) { + switch os.Getenv("ZERO_ASSIGNMENT_FAILURE_TREE_HELPER") { + case "root": + child := exec.Command(os.Args[0], "-test.run=^TestRunCommandFailsBeforeDescendantCanEscapeWhenJobAssignmentFails$") + child.Env = append(os.Environ(), + "ZERO_ASSIGNMENT_FAILURE_TREE_HELPER=child", + "ZERO_ASSIGNMENT_FAILURE_TREE_STOP_FILE="+os.Getenv("ZERO_ASSIGNMENT_FAILURE_TREE_STOP_FILE"), + ) + child.Stdout = os.Stdout + child.Stderr = os.Stderr + if err := child.Start(); err != nil { + os.Exit(2) + } + if err := os.WriteFile(os.Getenv("ZERO_ASSIGNMENT_FAILURE_TREE_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_ASSIGNMENT_FAILURE_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(3) + } + return + case "child": + waitForCommandTreeStop(os.Getenv("ZERO_ASSIGNMENT_FAILURE_TREE_STOP_FILE"), 30*time.Second) + return + } + + root := t.TempDir() + stopFile := filepath.Join(root, "stop") + originalAssign := assignCommandProcessToJob + commandOwner := ownHelperHandle(t, stopFile) + assignCommandProcessToJob = func(_ windows.Handle, process windows.Handle) error { + if err := commandOwner.retain(process); err != nil { + return err + } + return windows.ERROR_ACCESS_DENIED + } + t.Cleanup(func() { assignCommandProcessToJob = originalAssign }) + + pidFile := filepath.Join(root, "child.pid") + escapedChild := ownHelperProcess(t, pidFile, stopFile) + ctx, cancel := context.WithCancel(context.Background()) + t.Cleanup(cancel) + command := exec.CommandContext(ctx, os.Args[0], "-test.run=^TestRunCommandFailsBeforeDescendantCanEscapeWhenJobAssignmentFails$") + command.Env = append(os.Environ(), + "ZERO_ASSIGNMENT_FAILURE_TREE_HELPER=root", + "ZERO_ASSIGNMENT_FAILURE_TREE_PID_FILE="+pidFile, + "ZERO_ASSIGNMENT_FAILURE_TREE_STOP_FILE="+stopFile, + ) + err := waitForRunCommand(t, runCommandAsync(ctx, command), 4*time.Second) + if !errors.Is(err, windows.ERROR_ACCESS_DENIED) { + t.Fatalf("RunCommand error = %v, want ERROR_ACCESS_DENIED", err) + } + if command.ProcessState == nil || !command.ProcessState.Exited() { + t.Fatalf("suspended command was not killed and reaped: state = %v", command.ProcessState) + } + observed, observeErr := escapedChild.observeReady() + _, statErr := os.Stat(pidFile) + if observeErr != nil || observed || !errors.Is(statErr, os.ErrNotExist) { + t.Fatalf("suspended command spawned a descendant after job assignment failed: observed = %t, observation error = %v, PID file error = %v", observed, observeErr, statErr) + } +} diff --git a/internal/execution/exit_error.go b/internal/execution/exit_error.go new file mode 100644 index 000000000..eab627889 --- /dev/null +++ b/internal/execution/exit_error.go @@ -0,0 +1,31 @@ +package execution + +import "os/exec" + +// AsPureExitError reports whether err is an ordinary process exit or a join +// tree containing only ordinary process exits. It does not unwrap single-error +// wrappers, which may carry a distinct lifecycle or cleanup failure. +func AsPureExitError(err error) (*exec.ExitError, bool) { + if exitErr, ok := err.(*exec.ExitError); ok { + return exitErr, exitErr != nil + } + joined, ok := err.(interface{ Unwrap() []error }) + if !ok { + return nil, false + } + causes := joined.Unwrap() + if len(causes) == 0 { + return nil, false + } + var first *exec.ExitError + for _, cause := range causes { + exitErr, ok := AsPureExitError(cause) + if !ok { + return nil, false + } + if first == nil { + first = exitErr + } + } + return first, first != nil +} diff --git a/internal/execution/exit_error_test.go b/internal/execution/exit_error_test.go new file mode 100644 index 000000000..323a87ad7 --- /dev/null +++ b/internal/execution/exit_error_test.go @@ -0,0 +1,41 @@ +package execution + +import ( + "context" + "errors" + "fmt" + "os/exec" + "testing" +) + +func TestAsPureExitError(t *testing.T) { + first := &exec.ExitError{} + second := &exec.ExitError{} + var nilExit *exec.ExitError + tests := []struct { + name string + err error + want *exec.ExitError + ok bool + }{ + {name: "nil"}, + {name: "direct", err: first, want: first, ok: true}, + {name: "joined", err: errors.Join(first, second), want: first, ok: true}, + {name: "nested joins", err: errors.Join(errors.Join(first, second), &exec.ExitError{}), want: first, ok: true}, + {name: "join with nil", err: errors.Join(first, nil), want: first, ok: true}, + {name: "ordinary error", err: errors.New("start failed")}, + {name: "mixed join", err: errors.Join(first, context.Canceled)}, + {name: "nested mixed join", err: errors.Join(first, errors.Join(second, context.DeadlineExceeded))}, + {name: "wrapped exit", err: fmt.Errorf("cleanup failed: %w", first)}, + {name: "join containing wrapped exit", err: errors.Join(first, fmt.Errorf("wrapped: %w", second))}, + {name: "typed nil exit", err: nilExit}, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + got, ok := AsPureExitError(test.err) + if got != test.want || ok != test.ok { + t.Fatalf("AsPureExitError(%v) = (%p, %v), want (%p, %v)", test.err, got, ok, test.want, test.ok) + } + }) + } +} diff --git a/internal/execution/runner.go b/internal/execution/runner.go index 9e3ecbf9a..94af93c1c 100644 --- a/internal/execution/runner.go +++ b/internal/execution/runner.go @@ -89,7 +89,7 @@ func (runner *Runner) ExecuteCaptured(ctx context.Context, input CapturedRequest stderr := &capturedBuffer{limit: maxCapturedStreamBytes} prepared.Command.Stdout = stdout prepared.Command.Stderr = stderr - runErr := prepared.Command.Run() + runErr := RunCommand(ctx, prepared.Command) report, reportErr := AdapterReport{}, error(nil) if prepared.Report != nil { report, reportErr = prepared.Report() @@ -174,8 +174,7 @@ func commandExitCode(err error) int { if err == nil { return 0 } - var exitErr *exec.ExitError - if errors.As(err, &exitErr) { + if exitErr, ok := AsPureExitError(err); ok { return exitErr.ExitCode() } return -1 diff --git a/internal/hooks/dispatch.go b/internal/hooks/dispatch.go index d5bb13e3c..f7bf6e6de 100644 --- a/internal/hooks/dispatch.go +++ b/internal/hooks/dispatch.go @@ -4,7 +4,6 @@ import ( "bytes" "context" "encoding/json" - "errors" "os" "os/exec" "strings" @@ -306,13 +305,12 @@ func execCommandRunner(ctx context.Context, command string, args []string, stdin var stdout, stderr bytes.Buffer cmd.Stdout = &stdout cmd.Stderr = &stderr - err := cmd.Run() + err := execution.RunCommand(ctx, cmd) result := commandResult{Stdout: stdout.String(), Stderr: stderr.String()} if err == nil { return result } - var exitErr *exec.ExitError - if errors.As(err, &exitErr) { + if exitErr, ok := execution.AsPureExitError(err); ok { result.ExitCode = exitErr.ExitCode() return result } diff --git a/internal/hooks/dispatch_test.go b/internal/hooks/dispatch_test.go index 40d6e295f..c058a6d81 100644 --- a/internal/hooks/dispatch_test.go +++ b/internal/hooks/dispatch_test.go @@ -2,9 +2,13 @@ package hooks import ( "context" + "fmt" + "io" + "os" "os/exec" "path/filepath" "runtime" + "strconv" "strings" "testing" "time" @@ -14,17 +18,251 @@ import ( type hookExecutionPreparer struct { request execution.Request + report func() (execution.AdapterReport, error) + cleanup func() } -func (preparer *hookExecutionPreparer) PrepareExecution(_ context.Context, request execution.Request) (execution.PreparedCommand, error) { +func (preparer *hookExecutionPreparer) PrepareExecution(ctx context.Context, request execution.Request) (execution.PreparedCommand, error) { preparer.request = request - return execution.PreparedCommand{Command: exec.Command(request.Command.Name, request.Command.Args...)}, nil + command := exec.CommandContext(ctx, request.Command.Name, request.Command.Args...) + command.Env = request.Command.Env + command.Dir = request.WorkingDirectory + return execution.PreparedCommand{Command: command, Report: preparer.report, Cleanup: preparer.cleanup}, nil } func beforeToolConfig(hooks ...Definition) Config { return Config{Enabled: true, Hooks: hooks} } +func TestExecCommandRunnerTimeoutKillsGrandchildHoldingOutput(t *testing.T) { + switch os.Getenv("ZERO_HOOK_TREE_HELPER") { + case "parent": + if err := os.WriteFile(os.Getenv("ZERO_HOOK_TREE_PARENT_PID_FILE"), []byte(strconv.Itoa(os.Getpid())), 0o600); err != nil { + os.Exit(2) + } + child := exec.Command(os.Args[0], "-test.run=^TestExecCommandRunnerTimeoutKillsGrandchildHoldingOutput$") + child.Env = append(os.Environ(), + "ZERO_HOOK_TREE_HELPER=grandchild", + "ZERO_HOOK_TREE_STOP_FILE="+os.Getenv("ZERO_HOOK_TREE_STOP_FILE"), + ) + child.Stdout = os.Stdout + child.Stderr = os.Stderr + if err := child.Start(); err != nil { + os.Exit(3) + } + if err := os.WriteFile(os.Getenv("ZERO_HOOK_TREE_GRANDCHILD_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_HOOK_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(4) + } + if err := os.WriteFile(os.Getenv("ZERO_HOOK_TREE_READY_FILE"), []byte("ready"), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_HOOK_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(5) + } + if exitFile := os.Getenv("ZERO_HOOK_TREE_EXIT_FILE"); exitFile != "" { + input, err := io.ReadAll(os.Stdin) + if err != nil { + os.Exit(6) + } + fmt.Fprintln(os.Stdout, string(input)) + fmt.Fprintln(os.Stderr, "hook diagnostic") + waitForHookTreeStop(exitFile, 30*time.Second) + os.Exit(0) + } + waitForHookTreeStop(os.Getenv("ZERO_HOOK_TREE_STOP_FILE"), 30*time.Second) + _ = child.Wait() + return + case "grandchild": + waitForHookTreeStop(os.Getenv("ZERO_HOOK_TREE_STOP_FILE"), 30*time.Second) + os.Exit(0) + } + + root := t.TempDir() + parentPIDFile := filepath.Join(root, "parent.pid") + grandchildPIDFile := filepath.Join(root, "grandchild.pid") + readyFile := filepath.Join(root, "ready") + stopFile := filepath.Join(root, "stop") + owner := newHookTestProcessOwner(t, stopFile, parentPIDFile, grandchildPIDFile) + ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second) + defer cancel() + resultChannel := make(chan commandResult, 1) + go func() { + resultChannel <- execCommandRunner( + ctx, + os.Args[0], + []string{"-test.run=^TestExecCommandRunnerTimeoutKillsGrandchildHoldingOutput$"}, + nil, + "", + append(os.Environ(), + "ZERO_HOOK_TREE_HELPER=parent", + "ZERO_HOOK_TREE_PARENT_PID_FILE="+parentPIDFile, + "ZERO_HOOK_TREE_GRANDCHILD_PID_FILE="+grandchildPIDFile, + "ZERO_HOOK_TREE_READY_FILE="+readyFile, + "ZERO_HOOK_TREE_STOP_FILE="+stopFile, + ), + ) + }() + parentPID, grandchildPID := awaitHookTreeReady(t, owner, readyFile, parentPIDFile, grandchildPIDFile) + started := time.Now() + var result commandResult + select { + case result = <-resultChannel: + case <-time.After(6 * time.Second): + cancel() + t.Fatal("execCommandRunner did not return within six seconds after its timeout") + } + if elapsed := time.Since(started); elapsed > 4*time.Second { + t.Fatalf("command remained blocked by grandchild output handles for %s", elapsed) + } + if result.Err == nil && result.ExitCode == 0 { + t.Fatalf("timed-out command unexpectedly succeeded: %#v", result) + } + for role, pid := range map[string]int{"parent": parentPID, "grandchild": grandchildPID} { + if err := owner.awaitExit(pid, 2*time.Second); err != nil { + t.Fatalf("%s process %d survived hook cancellation: %v", role, pid, err) + } + } +} + +// The test injects deadline expiry only after the process handoffs, independently +// of startup speed and of the watchdog that bounds a broken execution runner. +type hookDeadlineContext struct{ context.Context } + +// Prevent context.WithTimeout from bypassing Err via the embedded cancelCtx. +func (hookDeadlineContext) Value(any) any { return nil } + +func (ctx hookDeadlineContext) Err() error { + if ctx.Context.Err() != nil { + return context.DeadlineExceeded + } + return nil +} + +func TestDispatchConfiguredRunnerTimeoutKillsGrandchildHoldingOutput(t *testing.T) { + root := t.TempDir() + parentFile, childFile := filepath.Join(root, "parent.pid"), filepath.Join(root, "child.pid") + ready, stop, exit := filepath.Join(root, "ready"), filepath.Join(root, "stop"), filepath.Join(root, "exit") + owner := newHookTestProcessOwner(t, stop, parentFile, childFile) + ctx, cancel := context.WithCancel(context.Background()) + done := make(chan struct{}) + // Registered before launch: release the root and pipe holder even when the + // production lifecycle regresses or a readiness assertion aborts the test. + t.Cleanup(func() { + cancel() + for _, path := range []string{exit, stop} { + if err := os.WriteFile(path, nil, 0o600); err != nil { + t.Error(err) + } + } + select { + case <-done: + case <-time.After(5 * time.Second): + t.Error("dispatch did not finish after independent fixture cleanup") + } + }) + audit, err := NewAuditStore(AuditStoreOptions{AuditPath: filepath.Join(root, "audit.jsonl")}) + if err != nil { + t.Fatal(err) + } + reported, cleaned := false, false + preparer := &hookExecutionPreparer{ + report: func() (execution.AdapterReport, error) { + reported = true + return execution.AdapterReport{}, nil + }, + cleanup: func() { cleaned = true }, + } + dispatcher := NewDispatcher(DispatcherOptions{ + Config: beforeToolConfig(Definition{ID: "tree", Event: EventBeforeTool, Enabled: true, + Command: os.Args[0], Args: []string{"-test.run=^TestExecCommandRunnerTimeoutKillsGrandchildHoldingOutput$"}}), + Execution: execution.NewRunner(preparer), Audit: audit, Cwd: root, + Timeout: time.Minute, + Env: append(os.Environ(), "ZERO_HOOK_TREE_HELPER=parent", + "ZERO_HOOK_TREE_PARENT_PID_FILE="+parentFile, "ZERO_HOOK_TREE_GRANDCHILD_PID_FILE="+childFile, + "ZERO_HOOK_TREE_READY_FILE="+ready, "ZERO_HOOK_TREE_STOP_FILE="+stop, "ZERO_HOOK_TREE_EXIT_FILE="+exit), + }) + results := make(chan DispatchOutcome, 1) + go func() { + defer close(done) + results <- dispatcher.Dispatch(hookDeadlineContext{ctx}, DispatchInput{Event: EventBeforeTool, Payload: "payload"}) + }() + parentPID, childPID := awaitHookTreeReady(t, owner, ready, parentFile, childFile) + if err := os.WriteFile(exit, nil, 0o600); err != nil { + t.Fatal(err) + } + if err := owner.awaitExit(parentPID, 2*time.Second); err != nil { + t.Fatalf("root did not exit before deadline: %v", err) + } + cancel() + var outcome DispatchOutcome + select { + case outcome = <-results: + case <-time.After(4 * time.Second): + t.Fatal("configured hook remained blocked by inherited output after deadline") + } + if !outcome.Blocked || outcome.Ran != 1 || !strings.Contains(outcome.Reason, "hook timed out") { + t.Fatalf("deadline not reported: %#v", outcome) + } + if len(outcome.Messages) != 1 || outcome.Messages[0] != `"payload"` { + t.Fatalf("stdin/output not preserved: %#v", outcome) + } + if !reported || !cleaned { + t.Fatalf("adapter callbacks not preserved: report=%v cleanup=%v", reported, cleaned) + } + if err := owner.awaitExit(childPID, 2*time.Second); err != nil { + t.Fatalf("grandchild survived configured hook deadline: %v", err) + } + events, err := audit.ReadEvents() + if err != nil { + t.Fatal(err) + } + if len(events) != 2 || events[0].Type != "hook_execution_started" || events[1].Status != AuditBlocked || + len(events[1].Results) != 1 || strings.TrimSpace(events[1].Results[0].Stdout) != `"payload"` || + strings.TrimSpace(events[1].Results[0].Stderr) != "hook diagnostic" { + t.Fatalf("audit/output not preserved: %#v", events) + } +} + +func waitForHookTreeStop(stopFile string, lifetime time.Duration) { + deadline := time.Now().Add(lifetime) + for time.Now().Before(deadline) { + if _, err := os.Stat(stopFile); err == nil { + return + } + time.Sleep(10 * time.Millisecond) + } +} + +func awaitHookTreeReady(t *testing.T, owner *hookTestProcessOwner, readyFile string, pidFiles ...string) (int, int) { + t.Helper() + deadline := time.Now().Add(15 * time.Second) + for { + if _, err := os.Stat(readyFile); err == nil { + pids := make([]int, 0, len(pidFiles)) + for _, path := range pidFiles { + data, err := os.ReadFile(path) + if err != nil { + t.Fatalf("read helper PID handoff %q: %v", path, err) + } + pid, err := strconv.Atoi(string(data)) + if err != nil { + t.Fatalf("parse helper PID handoff %q: %v", data, err) + } + if err := owner.retain(pid); err != nil { + t.Fatalf("retain helper process %d: %v", pid, err) + } + pids = append(pids, pid) + } + return pids[0], pids[1] + } + if time.Now().After(deadline) { + t.Fatal("process-tree helper did not hand off parent and grandchild identities") + } + time.Sleep(10 * time.Millisecond) + } +} + func TestDispatchRunsMatchingHooksAndRecordsAudit(t *testing.T) { var calls []string runner := func(ctx context.Context, command string, args []string, stdin []byte, cwd string, env []string) commandResult { diff --git a/internal/hooks/process_unix_test.go b/internal/hooks/process_unix_test.go new file mode 100644 index 000000000..af6e6642f --- /dev/null +++ b/internal/hooks/process_unix_test.go @@ -0,0 +1,81 @@ +//go:build !windows + +package hooks + +import ( + "errors" + "os" + "strconv" + "syscall" + "testing" + "time" +) + +type hookTestProcessOwner struct { + pids map[int]struct{} + exited map[int]struct{} + stopFile string + pidFiles []string +} + +func newHookTestProcessOwner(t *testing.T, stopFile string, pidFiles ...string) *hookTestProcessOwner { + t.Helper() + owner := &hookTestProcessOwner{pids: make(map[int]struct{}), exited: make(map[int]struct{}), stopFile: stopFile, pidFiles: pidFiles} + t.Cleanup(func() { owner.cleanup(t) }) + return owner +} + +func (owner *hookTestProcessOwner) retain(pid int) error { + if pid <= 0 || pid == os.Getpid() { + return errors.New("invalid test process PID") + } + owner.pids[pid] = struct{}{} + return nil +} + +func (owner *hookTestProcessOwner) awaitExit(pid int, timeout time.Duration) error { + deadline := time.Now().Add(timeout) + for { + err := syscall.Kill(pid, syscall.Signal(0)) + if errors.Is(err, syscall.ESRCH) { + delete(owner.pids, pid) + owner.exited[pid] = struct{}{} + return nil + } + if err != nil { + return err + } + if time.Now().After(deadline) { + return errors.New("process is still running") + } + time.Sleep(10 * time.Millisecond) + } +} + +func (owner *hookTestProcessOwner) cleanup(t *testing.T) { + t.Helper() + if err := os.WriteFile(owner.stopFile, nil, 0o600); err != nil { + t.Errorf("request test process stop: %v", err) + } + owner.retainPIDFiles() + for pid := range owner.pids { + if err := owner.awaitExit(pid, 2*time.Second); err != nil { + t.Errorf("wait for test process %d: %v", pid, err) + } + } +} + +func (owner *hookTestProcessOwner) retainPIDFiles() { + for _, path := range owner.pidFiles { + data, err := os.ReadFile(path) + if err != nil { + continue + } + pid, err := strconv.Atoi(string(data)) + if err == nil && pid > 0 && pid != os.Getpid() { + if _, exited := owner.exited[pid]; !exited { + owner.pids[pid] = struct{}{} + } + } + } +} diff --git a/internal/hooks/process_windows_test.go b/internal/hooks/process_windows_test.go new file mode 100644 index 000000000..06796c923 --- /dev/null +++ b/internal/hooks/process_windows_test.go @@ -0,0 +1,95 @@ +//go:build windows + +package hooks + +import ( + "errors" + "fmt" + "os" + "strconv" + "testing" + "time" + + "golang.org/x/sys/windows" +) + +type hookTestProcessOwner struct { + handles map[int]windows.Handle + stopFile string + pidFiles []string +} + +func newHookTestProcessOwner(t *testing.T, stopFile string, pidFiles ...string) *hookTestProcessOwner { + t.Helper() + owner := &hookTestProcessOwner{handles: make(map[int]windows.Handle), stopFile: stopFile, pidFiles: pidFiles} + t.Cleanup(func() { owner.cleanup(t) }) + return owner +} + +func (owner *hookTestProcessOwner) retain(pid int) error { + if pid <= 0 || pid == os.Getpid() { + return errors.New("invalid test process PID") + } + if _, ok := owner.handles[pid]; ok { + return nil + } + handle, err := windows.OpenProcess(windows.PROCESS_TERMINATE|windows.SYNCHRONIZE|windows.PROCESS_QUERY_LIMITED_INFORMATION, false, uint32(pid)) + if err != nil { + return err + } + owner.handles[pid] = handle + return nil +} + +func (owner *hookTestProcessOwner) awaitExit(pid int, timeout time.Duration) error { + handle, ok := owner.handles[pid] + if !ok { + return errors.New("test process identity was not retained") + } + wait, err := windows.WaitForSingleObject(handle, uint32(timeout/time.Millisecond)) + if err != nil { + return err + } + if wait != windows.WAIT_OBJECT_0 { + return fmt.Errorf("process is still running (wait result %#x)", wait) + } + return nil +} + +func (owner *hookTestProcessOwner) cleanup(t *testing.T) { + t.Helper() + if err := os.WriteFile(owner.stopFile, nil, 0o600); err != nil { + t.Errorf("request test process stop: %v", err) + } + owner.retainPIDFiles() + for pid, handle := range owner.handles { + wait, err := windows.WaitForSingleObject(handle, 2_000) + if err == nil && wait == uint32(windows.WAIT_TIMEOUT) { + if err := windows.TerminateProcess(handle, 1); err != nil { + t.Errorf("terminate test process %d: %v", pid, err) + } + } + } + for pid, handle := range owner.handles { + if err := owner.awaitExit(pid, 2*time.Second); err != nil { + t.Errorf("wait for test process %d: %v", pid, err) + } + if err := windows.CloseHandle(handle); err != nil { + t.Errorf("close test process %d handle: %v", pid, err) + } + delete(owner.handles, pid) + } +} + +func (owner *hookTestProcessOwner) retainPIDFiles() { + for _, path := range owner.pidFiles { + data, err := os.ReadFile(path) + if err != nil { + continue + } + pid, err := strconv.Atoi(string(data)) + if err == nil { + _ = owner.retain(pid) + } + } +} diff --git a/internal/perfbench/perfbench.go b/internal/perfbench/perfbench.go index 31afe7b69..834bae99a 100644 --- a/internal/perfbench/perfbench.go +++ b/internal/perfbench/perfbench.go @@ -18,6 +18,7 @@ import ( "sync" "time" + "github.com/Gitlawb/zero/internal/execution" "github.com/Gitlawb/zero/internal/release" ) @@ -267,10 +268,13 @@ func MeasureColdStart(ctx context.Context, command []string) (float64, error) { startedAt := time.Now() cmd := exec.CommandContext(ctx, command[0], command[1:]...) cmd.Env = appendNoColor(os.Environ()) - output, err := cmd.CombinedOutput() + var output bytes.Buffer + cmd.Stdout = &output + cmd.Stderr = &output + err := execution.RunCommand(ctx, cmd) durationMs := RoundMetric(float64(time.Since(startedAt).Microseconds()) / 1000) if err != nil { - return 0, commandError(command, err, string(output), "") + return 0, commandError(command, err, output.String(), "") } return durationMs, nil } @@ -284,15 +288,6 @@ func MeasureFirstOutput(ctx context.Context, command []string) (firstOutputSampl cmd := exec.CommandContext(ctx, command[0], command[1:]...) cmd.Env = offlineBenchmarkEnv(os.Environ()) - stdout, err := cmd.StdoutPipe() - if err != nil { - return firstOutputSample{}, err - } - stderr, err := cmd.StderrPipe() - if err != nil { - return firstOutputSample{}, err - } - var once sync.Once var firstOutputAt time.Time markFirstOutput := func() { @@ -300,32 +295,19 @@ func MeasureFirstOutput(ctx context.Context, command []string) (firstOutputSampl firstOutputAt = time.Now() }) } - - if err := cmd.Start(); err != nil { - return firstOutputSample{}, err - } - stdoutChan := make(chan pipeResult, 1) - stderrChan := make(chan pipeResult, 1) - go readTimedPipe(stdout, markFirstOutput, stdoutChan) - go readTimedPipe(stderr, markFirstOutput, stderrChan) - - stdoutResult := <-stdoutChan - stderrResult := <-stderrChan - waitErr := cmd.Wait() + stdout := &timedBuffer{onFirstWrite: markFirstOutput} + stderr := &timedBuffer{onFirstWrite: markFirstOutput} + cmd.Stdout = stdout + cmd.Stderr = stderr + waitErr := execution.RunCommand(ctx, cmd) finishedAt := time.Now() - if stdoutResult.Err != nil { - return firstOutputSample{}, stdoutResult.Err - } - if stderrResult.Err != nil { - return firstOutputSample{}, stderrResult.Err - } if firstOutputAt.IsZero() { firstOutputAt = finishedAt } rssAfter := readHarnessMemoryMb() if waitErr != nil { - return firstOutputSample{}, commandError(command, waitErr, stdoutResult.Text, stderrResult.Text) + return firstOutputSample{}, commandError(command, waitErr, stdout.String(), stderr.String()) } return firstOutputSample{ FirstOutputMs: RoundMetric(float64(firstOutputAt.Sub(startedAt).Microseconds()) / 1000), @@ -421,29 +403,20 @@ func median(sortedSamples []float64) float64 { return RoundMetric((sortedSamples[middle-1] + sortedSamples[middle]) / 2) } -type pipeResult struct { - Text string - Err error +type timedBuffer struct { + buffer bytes.Buffer + onFirstWrite func() } -func readTimedPipe(reader io.Reader, onFirstChunk func(), result chan<- pipeResult) { - var buffer bytes.Buffer - chunk := make([]byte, 32*1024) - for { - n, err := reader.Read(chunk) - if n > 0 { - onFirstChunk() - _, _ = buffer.Write(chunk[:n]) - } - if err != nil { - if errors.Is(err, io.EOF) { - result <- pipeResult{Text: buffer.String()} - return - } - result <- pipeResult{Text: buffer.String(), Err: err} - return - } +func (buffer *timedBuffer) Write(data []byte) (int, error) { + if len(data) > 0 { + buffer.onFirstWrite() } + return buffer.buffer.Write(data) +} + +func (buffer *timedBuffer) String() string { + return buffer.buffer.String() } func commandError(command []string, err error, stdout string, stderr string) error { diff --git a/internal/perfbench/perfbench_test.go b/internal/perfbench/perfbench_test.go index 3d90e68c0..aaac8c499 100644 --- a/internal/perfbench/perfbench_test.go +++ b/internal/perfbench/perfbench_test.go @@ -6,6 +6,7 @@ import ( "os" "strings" "testing" + "time" ) func TestSummarizeSamplesSortsAndRounds(t *testing.T) { @@ -119,10 +120,39 @@ func TestPerfBenchHelperProcess(t *testing.T) { if os.Getenv("ZERO_PERF_HELPER") != "1" { return } - fmt.Println("zero 0.1.0") + if stream := os.Getenv("ZERO_PERF_HELPER_STREAM"); stream != "" { + if stream == "stderr" { + fmt.Fprintln(os.Stderr, "zero 0.1.0") + } else { + fmt.Println("zero 0.1.0") + } + time.Sleep(400 * time.Millisecond) + } else { + fmt.Println("zero 0.1.0") + } os.Exit(0) } +func TestMeasureFirstOutputCapturesFirstByteTiming(t *testing.T) { + for _, stream := range []string{"stdout", "stderr"} { + t.Run(stream, func(t *testing.T) { + command := []string{os.Args[0], "-test.run=^TestPerfBenchHelperProcess$"} + t.Setenv("ZERO_PERF_HELPER", "1") + t.Setenv("ZERO_PERF_HELPER_STREAM", stream) + sample, err := MeasureFirstOutput(context.Background(), command) + if err != nil { + t.Fatalf("MeasureFirstOutput returned error: %v", err) + } + if sample.FirstOutputMs >= 250 { + t.Fatalf("first output = %fms, want before delayed exit", sample.FirstOutputMs) + } + if sample.ProcessDrainMs < 250 { + t.Fatalf("process drain = %fms, want delayed exit time", sample.ProcessDrainMs) + } + }) + } +} + func equalFloatSlices(left []float64, right []float64) bool { if len(left) != len(right) { return false diff --git a/internal/perfbench/taskbench.go b/internal/perfbench/taskbench.go index cfcab1a86..73c3335bb 100644 --- a/internal/perfbench/taskbench.go +++ b/internal/perfbench/taskbench.go @@ -13,6 +13,8 @@ import ( "path/filepath" "strings" "time" + + "github.com/Gitlawb/zero/internal/execution" ) // TaskSchemaVersion is the schema version of a published task-benchmark result. @@ -335,7 +337,13 @@ func NewExecRunner(binary string, extraArgs ...string) TaskRunner { var stdout, stderr bytes.Buffer cmd.Stdout = &stdout cmd.Stderr = &stderr - runErr := cmd.Run() + runErr := execution.RunCommand(ctx, cmd) + if !runEndCanReconcile(runErr) { + if errors.Is(runErr, exec.ErrWaitDelay) { + return TaskOutcome{Err: fmt.Errorf("zero exec output cleanup failed: %w", runErr)} + } + return TaskOutcome{Err: fmt.Errorf("zero exec command failed: %w", runErr)} + } // The terminal run_end exit code is authoritative for pass/fail: a non-zero // agent exit is a normal task failure, not a harness error, even though @@ -365,6 +373,17 @@ func NewExecRunner(binary string, extraArgs ...string) TaskRunner { } } +// runEndCanReconcile reports whether a command result contains only an ordinary +// process exit status. A run_end may explain success or an *exec.ExitError, but +// it must not hide cancellation, startup, process-tree, or output-cleanup errors. +func runEndCanReconcile(err error) bool { + if err == nil { + return true + } + _, ok := execution.AsPureExitError(err) + return ok +} + func buildExecArgs(task BenchTask, rc RunContext, extraArgs []string) []string { args := []string{"exec", "--output-format", "stream-json"} if model := strings.TrimSpace(rc.Model); model != "" { @@ -390,9 +409,12 @@ func runVerification(ctx context.Context, task BenchTask) TaskOutcome { if dir := strings.TrimSpace(task.WorkspaceFixture); dir != "" { cmd.Dir = dir } - output, err := cmd.CombinedOutput() + var output bytes.Buffer + cmd.Stdout = &output + cmd.Stderr = &output + err := execution.RunCommand(ctx, cmd) if err != nil { - detail := strings.TrimSpace(string(output)) + detail := strings.TrimSpace(output.String()) if detail == "" { detail = err.Error() } diff --git a/internal/perfbench/taskbench_test.go b/internal/perfbench/taskbench_test.go index 4f08d072f..d9515fb62 100644 --- a/internal/perfbench/taskbench_test.go +++ b/internal/perfbench/taskbench_test.go @@ -3,12 +3,15 @@ package perfbench import ( "context" "errors" + "fmt" "os" + "os/exec" "path/filepath" "runtime" "strconv" "strings" "testing" + "time" ) func sampleTaskSet() TaskSet { @@ -276,6 +279,111 @@ func writeExecStub(t *testing.T, body string) string { return path } +func writeBlockingExecStub(t *testing.T) string { + t.Helper() + dir := t.TempDir() + source := filepath.Join(dir, "main.go") + if err := os.WriteFile(source, []byte(`package main + +import ( + "fmt" + "os" + "time" +) + +func main() { + fmt.Println("{\"type\":\"run_end\",\"exitCode\":0}") + if ready := os.Getenv("PERFBENCH_BLOCKING_STUB_READY"); ready != "" { + if err := os.WriteFile(ready, nil, 0600); err != nil { + panic(err) + } + } + for deadline := time.Now().Add(30 * time.Second); time.Now().Before(deadline); { + if _, err := os.Stat(os.Getenv("PERFBENCH_BLOCKING_STUB_STOP")); err == nil { + return + } + time.Sleep(10 * time.Millisecond) + } +} +`), 0o600); err != nil { + t.Fatalf("write blocking exec stub: %v", err) + } + binary := filepath.Join(dir, "zero-stub") + if runtime.GOOS == "windows" { + binary += ".exe" + } + if output, err := exec.Command("go", "build", "-o", binary, source).CombinedOutput(); err != nil { + t.Fatalf("build blocking exec stub: %v\n%s", err, output) + } + return binary +} + +// Override Err only after Done closes, allowing both context failures to be +// injected at the readiness handoff rather than racing process startup. +type stubFailureContext struct { + context.Context + failure error +} + +func (ctx stubFailureContext) Err() error { + if ctx.Context.Err() != nil { + return ctx.failure + } + return nil +} + +func runAfterStubReady[T any](t *testing.T, failure error, run func(context.Context) T) T { + t.Helper() + root := t.TempDir() + ready, stop := filepath.Join(root, "ready"), filepath.Join(root, "stop") + t.Setenv("PERFBENCH_BLOCKING_STUB_READY", ready) + t.Setenv("PERFBENCH_BLOCKING_STUB_STOP", stop) + ctx, cancel := context.WithCancel(context.Background()) + result := make(chan T, 1) + done := make(chan struct{}) + t.Cleanup(func() { + cancel() + // Independent of the production process-tree cleanup being tested. + if err := os.WriteFile(stop, nil, 0o600); err != nil { + t.Error(err) + } + select { + case <-done: + case <-time.After(5 * time.Second): + t.Error("stub did not stop after independent cleanup") + } + }) + go func() { + defer close(done) + result <- run(stubFailureContext{Context: ctx, failure: failure}) + }() + watchdog := time.NewTimer(15 * time.Second) + defer watchdog.Stop() + ticker := time.NewTicker(10 * time.Millisecond) + defer ticker.Stop() + for { + if _, err := os.Stat(ready); err == nil { + break + } + select { + case <-result: + t.Fatal("runner returned before run_end readiness handoff") + case <-watchdog.C: + t.Fatal("stub did not emit run_end before watchdog") + case <-ticker.C: + } + } + cancel() + select { + case outcome := <-result: + return outcome + case <-time.After(4 * time.Second): + t.Fatal("runner did not return after context failure") + } + var zero T + return zero +} + func TestNewExecRunnerNonZeroRunEndIsFailNotError(t *testing.T) { // A non-zero run_end exit code is a normal task failure, not a harness error, // even though the process itself exits non-zero. @@ -292,6 +400,62 @@ exit 1 } } +func TestRunEndCanReconcile(t *testing.T) { + exitErr := &exec.ExitError{} + tests := []struct { + name string + err error + want bool + }{ + {name: "success", want: true}, + {name: "exit error", err: exitErr, want: true}, + {name: "joined exit errors", err: errors.Join(exitErr, &exec.ExitError{}), want: true}, + {name: "ordinary error", err: errors.New("startup failed")}, + {name: "canceled", err: context.Canceled}, + {name: "deadline", err: context.DeadlineExceeded}, + {name: "wait delay", err: exec.ErrWaitDelay}, + {name: "exit plus cancellation", err: errors.Join(exitErr, context.Canceled)}, + {name: "wrapped exit error", err: fmt.Errorf("attachment failed: %w", exitErr)}, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + if got := runEndCanReconcile(test.err); got != test.want { + t.Fatalf("runEndCanReconcile(%v) = %v, want %v", test.err, got, test.want) + } + }) + } +} + +func TestNewExecRunnerRunEndCannotHideContextFailure(t *testing.T) { + stub := writeBlockingExecStub(t) + tests := []struct { + name string + wantErr error + }{ + { + name: "cancellation", + wantErr: context.Canceled, + }, + { + name: "deadline", + wantErr: context.DeadlineExceeded, + }, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + outcome := runAfterStubReady(t, test.wantErr, func(ctx context.Context) TaskOutcome { + return NewExecRunner(stub)(ctx, BenchTask{ID: "t1", Prompt: "p"}, RunContext{Model: "m"}) + }) + if outcome.Err == nil || !errors.Is(outcome.Err, test.wantErr) { + t.Fatalf("run_end must not hide %v, got %#v", test.wantErr, outcome) + } + if outcome.Passed { + t.Fatal("context failure must not reach task pass accounting") + } + }) + } +} + func TestNewExecRunnerMissingRunEndFailsClosed(t *testing.T) { // A clean exit with no terminal run_end event is a harness error: we cannot // claim the task passed when the agent never reported a terminal event. @@ -319,6 +483,36 @@ exit 0 } } +func TestNewExecRunnerWaitDelayCannotPassWithRunEnd(t *testing.T) { + stub := writeExecStub(t, `sleep 3 & +echo '{"type":"run_end","exitCode":0}' +exit 0 +`) + runner := NewExecRunner(stub) + outcome := runner(context.Background(), BenchTask{ID: "t1", Prompt: "p"}, RunContext{Model: "m"}) + if outcome.Err == nil || !strings.Contains(outcome.Err.Error(), "output cleanup failed") { + t.Fatalf("inherited output pipe must be a harness error, got %#v", outcome) + } + if outcome.Passed { + t.Fatal("run_end must not bypass an output cleanup failure") + } +} + +func TestNewExecRunnerNonzeroWaitDelayCannotReconcileRunEnd(t *testing.T) { + stub := writeExecStub(t, `sleep 3 & +echo '{"type":"run_end","exitCode":4}' +exit 4 +`) + runner := NewExecRunner(stub) + outcome := runner(context.Background(), BenchTask{ID: "t1", Prompt: "p"}, RunContext{Model: "m"}) + if outcome.Err == nil || !errors.Is(outcome.Err, exec.ErrWaitDelay) { + t.Fatalf("nonzero inherited output pipe must retain its cleanup failure, got %#v", outcome) + } + if outcome.Passed { + t.Fatal("run_end must not reconcile a nonzero command with an output cleanup failure") + } +} + func TestNewExecRunnerLaunchFailureIsHarnessError(t *testing.T) { // A binary that cannot be launched (no terminal event, process error) is a // genuine harness error. diff --git a/internal/perfbench/turn_bench.go b/internal/perfbench/turn_bench.go index a157b140b..ab4b5f87d 100644 --- a/internal/perfbench/turn_bench.go +++ b/internal/perfbench/turn_bench.go @@ -16,6 +16,7 @@ import ( "time" "github.com/Gitlawb/zero/internal/execprofile" + "github.com/Gitlawb/zero/internal/execution" "github.com/Gitlawb/zero/internal/trace" ) @@ -665,11 +666,20 @@ func NewTurnExecRunner(binary string, extraArgs ...string) TurnRunner { cmd.Stdout = &outBuf cmd.Stderr = &errBuf start := time.Now() - runErr := cmd.Run() + runErr := execution.RunCommand(ctx, cmd) wallMs := float64(time.Since(start).Microseconds()) / 1000 - exitCode, haveExit := streamJSONExitCode(outBuf.Bytes()) outcome := TurnTaskOutcome{WallMs: wallMs} + if !runEndCanReconcile(runErr) { + if errors.Is(runErr, exec.ErrWaitDelay) { + outcome.Err = fmt.Errorf("zero exec output cleanup failed: %w", runErr) + } else { + outcome.Err = fmt.Errorf("zero exec command failed: %w", runErr) + } + return outcome + } + + exitCode, haveExit := streamJSONExitCode(outBuf.Bytes()) if haveExit && exitCode != 0 { outcome.VerifyErr = fmt.Sprintf("agent run_end exit code %d", exitCode) } else if !haveExit { diff --git a/internal/perfbench/turn_bench_test.go b/internal/perfbench/turn_bench_test.go index 5b2295654..44617ac17 100644 --- a/internal/perfbench/turn_bench_test.go +++ b/internal/perfbench/turn_bench_test.go @@ -7,6 +7,7 @@ import ( "errors" "fmt" "os" + "os/exec" "path/filepath" "strings" "testing" @@ -643,6 +644,65 @@ func runTurnStub(t *testing.T, task BenchTask, stubBody string) TurnTaskOutcome return NewTurnExecRunner(stub)(context.Background(), task, RunContext{Model: "fake-model"}) } +func TestNewTurnExecRunnerWaitDelayCannotPassWithRunEnd(t *testing.T) { + task := BenchTask{ID: "wait-delay", Prompt: "p", WorkspaceFixture: t.TempDir()} + outcome := runTurnStub(t, task, `sleep 3 & +echo '{"type":"run_end","exitCode":0}' +exit 0 +`) + if outcome.Err == nil || !strings.Contains(outcome.Err.Error(), "output cleanup failed") { + t.Fatalf("inherited output pipe must be a harness error, got %#v", outcome) + } + if outcome.Passed { + t.Fatal("run_end must not bypass an output cleanup failure") + } +} + +func TestNewTurnExecRunnerNonzeroWaitDelayCannotReconcileRunEnd(t *testing.T) { + task := BenchTask{ID: "wait-delay-nonzero", Prompt: "p", WorkspaceFixture: t.TempDir()} + outcome := runTurnStub(t, task, `sleep 3 & +echo '{"type":"run_end","exitCode":4}' +exit 4 +`) + if outcome.Err == nil || !errors.Is(outcome.Err, exec.ErrWaitDelay) { + t.Fatalf("nonzero inherited output pipe must retain its cleanup failure, got %#v", outcome) + } + if outcome.Passed || outcome.VerifyErr != "" { + t.Fatalf("output cleanup failure must precede turn accounting, got %#v", outcome) + } +} + +func TestNewTurnExecRunnerRunEndCannotHideContextFailure(t *testing.T) { + task := BenchTask{ID: "context-failure", Prompt: "p", WorkspaceFixture: t.TempDir()} + stub := writeBlockingExecStub(t) + tests := []struct { + name string + wantErr error + }{ + { + name: "cancellation", + wantErr: context.Canceled, + }, + { + name: "deadline", + wantErr: context.DeadlineExceeded, + }, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + outcome := runAfterStubReady(t, test.wantErr, func(ctx context.Context) TurnTaskOutcome { + return NewTurnExecRunner(stub)(ctx, task, RunContext{Model: "m"}) + }) + if outcome.Err == nil || !errors.Is(outcome.Err, test.wantErr) { + t.Fatalf("run_end must not hide %v, got %#v", test.wantErr, outcome) + } + if outcome.Passed || outcome.VerifyErr != "" { + t.Fatalf("context failure must precede oracle accounting, got %#v", outcome) + } + }) + } +} + // assertVerifyFailed asserts an outcome failed specifically because the oracle // rejected the work — Passed is false, there is no harness error (Err nil), and // VerifyErr carries the surfaced failure detail. This is stronger than merely @@ -796,6 +856,7 @@ func TestOracleAuthoritativeOnIncompleteExit(t *testing.T) { task := loadBaselineTask(t, "edit-01") outcome := runTurnStub(t, task, `sed 's/const MaxRetries = 3/const RetryLimit = 3/' main.go > .zero-tmp && mv .zero-tmp main.go echo '{"type":"run_end","exitCode":4}' +exit 4 `) if outcome.Err != nil { t.Fatalf("incomplete-exit with a correct edit should pass, got harness error: %v", outcome.Err) @@ -822,7 +883,8 @@ func TestNonIncompleteExitStaysAuthoritative(t *testing.T) { task := loadBaselineTask(t, "edit-01") outcome := runTurnStub(t, task, fmt.Sprintf(`sed 's/const MaxRetries = 3/const RetryLimit = 3/' main.go > .zero-tmp && mv .zero-tmp main.go echo '{"type":"run_end","exitCode":%d}' -`, code)) +exit %d +`, code, code)) if outcome.Err != nil { t.Fatalf("a nonzero exit should be a task fail, not a harness error: %v", outcome.Err) } @@ -846,6 +908,7 @@ echo '{"type":"run_end","exitCode":%d}' func TestIncompleteExitStillFailsWhenOracleFails(t *testing.T) { task := loadBaselineTask(t, "edit-01") outcome := runTurnStub(t, task, `echo '{"type":"run_end","exitCode":4}' +exit 4 `) assertVerifyFailed(t, "incomplete exit with no edit applied", outcome) } @@ -858,6 +921,7 @@ func TestIncompleteExitStillFailsWhenOracleFails(t *testing.T) { func TestNonzeroExitStillFailsLatencyOnly(t *testing.T) { task := loadBaselineTask(t, "longproc-01") outcome := runTurnStub(t, task, `echo '{"type":"run_end","exitCode":4}' +exit 4 `) if outcome.Err != nil { t.Fatalf("latency-only nonzero exit should be a verify fail, not a harness error: %v", outcome.Err) diff --git a/internal/plugins/activate_test.go b/internal/plugins/activate_test.go index 7d100c9e7..385570e9a 100644 --- a/internal/plugins/activate_test.go +++ b/internal/plugins/activate_test.go @@ -572,7 +572,10 @@ func TestPluginCommandUsesTypedPluginExecutionOrigin(t *testing.T) { } preparer := &pluginExecutionPreparer{} command := pluginCommand{Command: os.Args[0], Args: []string{"-test.run=^$"}, Cwd: t.TempDir()} - output := execPluginCommandWithExecution(context.Background(), execution.NewRunner(preparer), command, time.Second) + // This checks origin wiring, not deadline enforcement. Allow startup and + // the race runtime's one-second exit delay now that even a plain exec.Command + // returned by the preparer is subject to the captured execution deadline. + output := execPluginCommandWithExecution(context.Background(), execution.NewRunner(preparer), command, 15*time.Second) if output.Err != nil || output.ExitCode != 0 { t.Fatalf("plugin execution output = %#v", output) } diff --git a/internal/verify/process_unix_test.go b/internal/verify/process_unix_test.go new file mode 100644 index 000000000..cdd5ff7f4 --- /dev/null +++ b/internal/verify/process_unix_test.go @@ -0,0 +1,81 @@ +//go:build !windows + +package verify + +import ( + "errors" + "os" + "strconv" + "syscall" + "testing" + "time" +) + +type verifyTestProcessOwner struct { + pids map[int]struct{} + exited map[int]struct{} + stopFile string + pidFiles []string +} + +func newVerifyTestProcessOwner(t *testing.T, stopFile string, pidFiles ...string) *verifyTestProcessOwner { + t.Helper() + owner := &verifyTestProcessOwner{pids: make(map[int]struct{}), exited: make(map[int]struct{}), stopFile: stopFile, pidFiles: pidFiles} + t.Cleanup(func() { owner.cleanup(t) }) + return owner +} + +func (owner *verifyTestProcessOwner) retain(pid int) error { + if pid <= 0 || pid == os.Getpid() { + return errors.New("invalid test process PID") + } + owner.pids[pid] = struct{}{} + return nil +} + +func (owner *verifyTestProcessOwner) awaitExit(pid int, timeout time.Duration) error { + deadline := time.Now().Add(timeout) + for { + err := syscall.Kill(pid, syscall.Signal(0)) + if errors.Is(err, syscall.ESRCH) { + delete(owner.pids, pid) + owner.exited[pid] = struct{}{} + return nil + } + if err != nil { + return err + } + if time.Now().After(deadline) { + return errors.New("process is still running") + } + time.Sleep(10 * time.Millisecond) + } +} + +func (owner *verifyTestProcessOwner) cleanup(t *testing.T) { + t.Helper() + if err := os.WriteFile(owner.stopFile, nil, 0o600); err != nil { + t.Errorf("request test process stop: %v", err) + } + owner.retainPIDFiles() + for pid := range owner.pids { + if err := owner.awaitExit(pid, 2*time.Second); err != nil { + t.Errorf("wait for test process %d: %v", pid, err) + } + } +} + +func (owner *verifyTestProcessOwner) retainPIDFiles() { + for _, path := range owner.pidFiles { + data, err := os.ReadFile(path) + if err != nil { + continue + } + pid, err := strconv.Atoi(string(data)) + if err == nil && pid > 0 && pid != os.Getpid() { + if _, exited := owner.exited[pid]; !exited { + owner.pids[pid] = struct{}{} + } + } + } +} diff --git a/internal/verify/process_windows_test.go b/internal/verify/process_windows_test.go new file mode 100644 index 000000000..a8612a25e --- /dev/null +++ b/internal/verify/process_windows_test.go @@ -0,0 +1,95 @@ +//go:build windows + +package verify + +import ( + "errors" + "fmt" + "os" + "strconv" + "testing" + "time" + + "golang.org/x/sys/windows" +) + +type verifyTestProcessOwner struct { + handles map[int]windows.Handle + stopFile string + pidFiles []string +} + +func newVerifyTestProcessOwner(t *testing.T, stopFile string, pidFiles ...string) *verifyTestProcessOwner { + t.Helper() + owner := &verifyTestProcessOwner{handles: make(map[int]windows.Handle), stopFile: stopFile, pidFiles: pidFiles} + t.Cleanup(func() { owner.cleanup(t) }) + return owner +} + +func (owner *verifyTestProcessOwner) retain(pid int) error { + if pid <= 0 || pid == os.Getpid() { + return errors.New("invalid test process PID") + } + if _, ok := owner.handles[pid]; ok { + return nil + } + handle, err := windows.OpenProcess(windows.PROCESS_TERMINATE|windows.SYNCHRONIZE|windows.PROCESS_QUERY_LIMITED_INFORMATION, false, uint32(pid)) + if err != nil { + return err + } + owner.handles[pid] = handle + return nil +} + +func (owner *verifyTestProcessOwner) awaitExit(pid int, timeout time.Duration) error { + handle, ok := owner.handles[pid] + if !ok { + return errors.New("test process identity was not retained") + } + wait, err := windows.WaitForSingleObject(handle, uint32(timeout/time.Millisecond)) + if err != nil { + return err + } + if wait != windows.WAIT_OBJECT_0 { + return fmt.Errorf("process is still running (wait result %#x)", wait) + } + return nil +} + +func (owner *verifyTestProcessOwner) cleanup(t *testing.T) { + t.Helper() + if err := os.WriteFile(owner.stopFile, nil, 0o600); err != nil { + t.Errorf("request test process stop: %v", err) + } + owner.retainPIDFiles() + for pid, handle := range owner.handles { + wait, err := windows.WaitForSingleObject(handle, 2_000) + if err == nil && wait == uint32(windows.WAIT_TIMEOUT) { + if err := windows.TerminateProcess(handle, 1); err != nil { + t.Errorf("terminate test process %d: %v", pid, err) + } + } + } + for pid, handle := range owner.handles { + if err := owner.awaitExit(pid, 2*time.Second); err != nil { + t.Errorf("wait for test process %d: %v", pid, err) + } + if err := windows.CloseHandle(handle); err != nil { + t.Errorf("close test process %d handle: %v", pid, err) + } + delete(owner.handles, pid) + } +} + +func (owner *verifyTestProcessOwner) retainPIDFiles() { + for _, path := range owner.pidFiles { + data, err := os.ReadFile(path) + if err != nil { + continue + } + pid, err := strconv.Atoi(string(data)) + if err == nil { + _ = owner.retain(pid) + } + } +} diff --git a/internal/verify/verify.go b/internal/verify/verify.go index 363cad6ba..3464d0f55 100644 --- a/internal/verify/verify.go +++ b/internal/verify/verify.go @@ -11,6 +11,7 @@ import ( "strings" "time" + "github.com/Gitlawb/zero/internal/execution" "github.com/Gitlawb/zero/internal/redaction" "github.com/Gitlawb/zero/internal/testrunner" ) @@ -304,11 +305,11 @@ func defaultRunner(ctx context.Context, dir string, command []string, timeout ti var stderr bytes.Buffer cmd.Stdout = &stdout cmd.Stderr = &stderr - err := cmd.Run() + err := execution.RunCommand(commandCtx, cmd) exitCode := 0 if err != nil { exitCode = -1 - if exitError, ok := err.(*exec.ExitError); ok { + if exitError, ok := execution.AsPureExitError(err); ok { exitCode = exitError.ExitCode() err = nil } diff --git a/internal/verify/verify_test.go b/internal/verify/verify_test.go index 5a9291614..2e49e1634 100644 --- a/internal/verify/verify_test.go +++ b/internal/verify/verify_test.go @@ -4,7 +4,9 @@ import ( "context" "errors" "os" + "os/exec" "path/filepath" + "strconv" "strings" "testing" "time" @@ -12,6 +14,120 @@ import ( "github.com/Gitlawb/zero/internal/testrunner" ) +func TestRunDefaultRunnerTimeoutKillsGrandchildHoldingOutput(t *testing.T) { + switch os.Getenv("ZERO_VERIFY_TREE_HELPER") { + case "parent": + if err := os.WriteFile(os.Getenv("ZERO_VERIFY_TREE_PARENT_PID_FILE"), []byte(strconv.Itoa(os.Getpid())), 0o600); err != nil { + os.Exit(2) + } + child := exec.Command(os.Args[0], "-test.run=^TestRunDefaultRunnerTimeoutKillsGrandchildHoldingOutput$") + child.Env = append(os.Environ(), + "ZERO_VERIFY_TREE_HELPER=grandchild", + "ZERO_VERIFY_TREE_STOP_FILE="+os.Getenv("ZERO_VERIFY_TREE_STOP_FILE"), + ) + child.Stdout = os.Stdout + child.Stderr = os.Stderr + if err := child.Start(); err != nil { + os.Exit(3) + } + if err := os.WriteFile(os.Getenv("ZERO_VERIFY_TREE_GRANDCHILD_PID_FILE"), []byte(strconv.Itoa(child.Process.Pid)), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_VERIFY_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(4) + } + if err := os.WriteFile(os.Getenv("ZERO_VERIFY_TREE_READY_FILE"), []byte("ready"), 0o600); err != nil { + _ = os.WriteFile(os.Getenv("ZERO_VERIFY_TREE_STOP_FILE"), nil, 0o600) + _ = child.Wait() + os.Exit(5) + } + waitForVerifyTreeStop(os.Getenv("ZERO_VERIFY_TREE_STOP_FILE"), 30*time.Second) + _ = child.Wait() + return + case "grandchild": + waitForVerifyTreeStop(os.Getenv("ZERO_VERIFY_TREE_STOP_FILE"), 30*time.Second) + return + } + + root := t.TempDir() + parentPIDFile := filepath.Join(root, "parent.pid") + grandchildPIDFile := filepath.Join(root, "grandchild.pid") + readyFile := filepath.Join(root, "ready") + stopFile := filepath.Join(root, "stop") + owner := newVerifyTestProcessOwner(t, stopFile, parentPIDFile, grandchildPIDFile) + t.Setenv("ZERO_VERIFY_TREE_HELPER", "parent") + t.Setenv("ZERO_VERIFY_TREE_PARENT_PID_FILE", parentPIDFile) + t.Setenv("ZERO_VERIFY_TREE_GRANDCHILD_PID_FILE", grandchildPIDFile) + t.Setenv("ZERO_VERIFY_TREE_READY_FILE", readyFile) + t.Setenv("ZERO_VERIFY_TREE_STOP_FILE", stopFile) + plan := Plan{Root: root, Checks: []Check{{ + ID: "tree.timeout", + Name: "process tree timeout", + Command: []string{os.Args[0], "-test.run=^TestRunDefaultRunnerTimeoutKillsGrandchildHoldingOutput$"}, + }}} + reportChannel := make(chan Report, 1) + go func() { + reportChannel <- Run(context.Background(), plan, RunOptions{TimeoutMS: 3000}) + }() + parentPID, grandchildPID := awaitVerifyTreeReady(t, owner, readyFile, parentPIDFile, grandchildPIDFile) + started := time.Now() + var report Report + select { + case report = <-reportChannel: + case <-time.After(6 * time.Second): + t.Fatal("defaultRunner did not return within six seconds after its timeout") + } + if elapsed := time.Since(started); elapsed > 4*time.Second { + t.Fatalf("defaultRunner remained blocked by grandchild output handles for %s", elapsed) + } + if report.OK || len(report.Results) != 1 || report.Results[0].Status == StatusPass { + t.Fatalf("timed-out defaultRunner command unexpectedly passed: %#v", report) + } + for role, pid := range map[string]int{"parent": parentPID, "grandchild": grandchildPID} { + if err := owner.awaitExit(pid, 2*time.Second); err != nil { + t.Fatalf("%s process %d survived verify cancellation: %v", role, pid, err) + } + } +} + +func waitForVerifyTreeStop(stopFile string, lifetime time.Duration) { + deadline := time.Now().Add(lifetime) + for time.Now().Before(deadline) { + if _, err := os.Stat(stopFile); err == nil { + return + } + time.Sleep(10 * time.Millisecond) + } +} + +func awaitVerifyTreeReady(t *testing.T, owner *verifyTestProcessOwner, readyFile string, pidFiles ...string) (int, int) { + t.Helper() + deadline := time.Now().Add(2 * time.Second) + for { + if _, err := os.Stat(readyFile); err == nil { + pids := make([]int, 0, len(pidFiles)) + for _, path := range pidFiles { + data, err := os.ReadFile(path) + if err != nil { + t.Fatalf("read helper PID handoff %q: %v", path, err) + } + pid, err := strconv.Atoi(string(data)) + if err != nil { + t.Fatalf("parse helper PID handoff %q: %v", data, err) + } + if err := owner.retain(pid); err != nil { + t.Fatalf("retain helper process %d: %v", pid, err) + } + pids = append(pids, pid) + } + return pids[0], pids[1] + } + if time.Now().After(deadline) { + t.Fatal("process-tree helper did not hand off parent and grandchild identities") + } + time.Sleep(10 * time.Millisecond) + } +} + func TestDetectPlanFindsBunAndGoChecks(t *testing.T) { root := t.TempDir() writeFile(t, filepath.Join(root, "go.mod"), "module example.com/zero\n")