From 4bab5b0416ddf943ca9d196cbb18f6cc7c288139 Mon Sep 17 00:00:00 2001 From: Dennison Date: Tue, 8 Sep 2026 08:46:04 -0400 Subject: [PATCH] test(cli): one owner for Process.Wait in the interrupt test MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit TestGoCodeScriptStopsHarnessdOnInterrupt called cmd.Process.Wait() twice — once in the deferred cleanup, once in the goroutine feeding the timeout select. os.Process.Wait is not safe to call twice on the same process. That is the one defect here that is proven; it was introduced in #1417. The stub daemon now takes its sleep child with it on SIGTERM instead of orphaning it, and the exit budget is widened to 30s as headroom for a loaded runner. Two earlier diagnoses were measured and disproven: the wrapper exits 0.21s after SIGINT rather than taking the 5s force-kill path, and the stub does genuinely survive SIGINT (POSIX inherits an ignored disposition across exec, so the sleep ignores it too). The Linux CI failure is not reproduced on macOS and its root cause stays unconfirmed. #1422 stays open until CI is green without a re-run. Refs #1422 Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01WJGxhoFhA8JjkwZFcLGdS5 --- cmd/harnesscli/go_code_script_test.go | 23 +++++++++++++------ docs/logs/engineering-log.md | 33 +++++++++++++++++++++++++++ 2 files changed, 49 insertions(+), 7 deletions(-) diff --git a/cmd/harnesscli/go_code_script_test.go b/cmd/harnesscli/go_code_script_test.go index 9ce9fbd5..6041147d 100644 --- a/cmd/harnesscli/go_code_script_test.go +++ b/cmd/harnesscli/go_code_script_test.go @@ -328,7 +328,12 @@ func TestGoCodeScriptStopsHarnessdOnInterrupt(t *testing.T) { // Ignores SIGINT, so it survives the process-group signal a real // Ctrl+C delivers. Only an explicit stop from the wrapper ends it — // which is exactly the orphan this test is about. - writeExecutable(t, filepath.Join(binDir, "harnessd"), "#!/usr/bin/env bash\ntrap '' INT\necho $$ > \"$DAEMON_PID_FILE\"\nsleep 300\n") + // Ignores SIGINT so it survives the process-group signal a real + // Ctrl+C delivers — POSIX inherits an ignored disposition across + // exec, so the sleep ignores it too, and only an explicit stop from + // the wrapper ends this. On SIGTERM it takes its child with it + // rather than orphaning a stray sleep. Issue #1422. + writeExecutable(t, filepath.Join(binDir, "harnessd"), "#!/usr/bin/env bash\ntrap '' INT\ntrap 'kill \"$child\" 2>/dev/null; exit 0' TERM\necho $$ > \"$DAEMON_PID_FILE\"\nsleep 300 &\nchild=$!\nwait \"$child\"\n") // harnesscli: keep the wrapper alive so it is still running when signalled. writeExecutable(t, filepath.Join(binDir, "harnesscli"), "#!/usr/bin/env bash\nsleep 300\n") @@ -346,10 +351,11 @@ func TestGoCodeScriptStopsHarnessdOnInterrupt(t *testing.T) { if err := cmd.Start(); err != nil { t.Fatalf("start go-code: %v", err) } - defer func() { - _ = cmd.Process.Kill() - _, _ = cmd.Process.Wait() - }() + // Kill only. Wait has exactly one owner (the goroutine below); + // os.Process.Wait is not safe to call twice on the same process, + // and the two racing was a real defect regardless of whether it is + // what fails on Linux CI. Issue #1422. + defer func() { _ = cmd.Process.Kill() }() var daemonPID int if tc.startedByWrapper { @@ -385,8 +391,11 @@ func TestGoCodeScriptStopsHarnessdOnInterrupt(t *testing.T) { go func() { _, _ = cmd.Process.Wait(); close(waitDone) }() select { case <-waitDone: - case <-time.After(10 * time.Second): - t.Fatal("wrapper did not exit within 10s of SIGINT") + case <-time.After(30 * time.Second): + // Locally the wrapper exits in ~0.2s. The generous budget is + // headroom for a loaded CI runner under -race, not a claim + // about how long cleanup legitimately takes. + t.Fatal("wrapper did not exit within 30s of SIGINT") } deadline := time.Now().Add(8 * time.Second) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 35dc7bad..006ee76e 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -1,5 +1,38 @@ # Engineering Log +## 2026-09-08 — Issue #1422 interrupt test flake, and a diagnosis that was wrong twice + +- Symptom: `TestGoCodeScriptStopsHarnessdOnInterrupt` failed on Linux CI with + "wrapper did not exit within 10s of SIGINT", red-flagging PR #1421 whose diff + touched only the spinner and docs. Passed on re-run. +- First diagnosis, wrong: that the stub daemon's foreground `sleep` made bash + defer SIGTERM, forcing the wrapper down its 5-second graceful-shutdown wait on + every run and leaving no headroom in a 10-second budget. Measured directly, + the wrapper exits **0.21s** after a process-group SIGINT. A non-interactive + bash does not defer SIGTERM behind a foreground child; it terminates. The + 5-second path is never reached. +- Second diagnosis, also wrong: that the stub did not really survive SIGINT, + because `sleep` is a separate process that would die from the group signal. + Checked directly — it survives. POSIX inherits an *ignored* disposition across + exec, so `trap '' INT` in the stub makes the `sleep` ignore INT too. The + test's premise is sound and that trap should stay. +- Confirmed defect, and the only one proven: the test called + `cmd.Process.Wait()` twice — once in the deferred cleanup, once in the + goroutine feeding the timeout `select`. `os.Process.Wait` is not safe to call + twice on the same process. Introduced in #1417. +- Fix: one owner for `Wait` (the deferred cleanup now only kills); the stub + daemon traps TERM and takes its `sleep` child with it instead of orphaning it; + the exit budget widened to 30s as headroom for a loaded runner rather than as + a claim about how long cleanup takes. +- **Root cause of the Linux failure remains unconfirmed.** Not reproduced on + macOS: 8/8 under `-race` with four CPU hogs running, 3/3 idle. The issue stays + open until CI shows a clean run without a re-run; a green that needed a re-run + proves nothing. +- Durable lesson: when a test fails only on CI, measure the thing you are about + to blame before writing the fix. Two plausible mechanisms here were both + disproven in under a minute by timing the actual path, and either would have + produced a confident fix for a problem that does not exist. + ## 2026-09-08 — Issue #1420 spinner breathes instead of ticking - Symptom: after #1415 stopped the *word* rotating, the owner reported the