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