[Bug]: TestGoCodeScriptStopsHarnessdOnInterrupt flakes on Linux CI; double Process.Wait is a confirmed defect, root cause unconfirmed

[dennisonbertram]

Work type

Bug / regression

Observed behavior

TestGoCodeScriptStopsHarnessdOnInterrupt/wrapper-started_daemon_is_stopped fails intermittently in CI under the race suite:

--- FAIL: TestGoCodeScriptStopsHarnessdOnInterrupt (20.13s)
    --- FAIL: TestGoCodeScriptStopsHarnessdOnInterrupt/wrapper-started_daemon_is_stopped (10.11s)
        go_code_script_test.go:389: wrapper did not exit within 10s of SIGINT
make: *** [Makefile:21: test-race] Error 1

Observed on PR #1421, whose diff touches only cmd/harnesscli/tui/components/spinner and docs — nothing in cmd/harnesscli itself. It passed on re-run of the same commit, and passes 3/3 locally under -race on macOS. It passed CI when introduced in #1417.

Frequency: intermittent, load-dependent. Enough to red-flag unrelated PRs.

Expected behavior

The test asserts a real contract — a wrapper-started daemon must not outlive the wrapper — and should pass deterministically regardless of runner load. Its timing budget must not sit a hair above the wall-clock cost of the path it exercises.

Reproduction

go test ./cmd/harnesscli -run TestGoCodeScriptStopsHarnessdOnInterrupt -race on a loaded machine, or in CI under the full race suite. Does not reproduce reliably on an idle machine.

User and operational impact

No end-user impact; this is test-only. The operational cost is real: a flaky red check on main makes every unrelated PR look broken, and trains people to re-run rather than read failures. #1421 was merged on a re-run for exactly this reason, which is the habit worth not building.

Suspected seam and search evidence

The test itself, cmd/harnesscli/go_code_script_test.go, not the wrapper it tests. The stub daemon is written as:

#!/usr/bin/env bash
trap '' INT
echo $$ > "$DAEMON_PID_FILE"
sleep 300

Ignoring INT is deliberate and correct: it models the daemon surviving the process-group signal a real Ctrl+C delivers, so cleanup has to kill it explicitly. That part should stay.

The problem is sleep 300 in the foreground. When stop_server sends SIGTERM (scripts/go-code.sh), bash defers the signal until its foreground child finishes — which never happens. So the wrapper always falls through the full graceful-shutdown wait (25 iterations x 0.2 s = 5 s) and then force-kills.

That means every run of this test takes the 5-second worst-case path, leaving roughly 5 s of headroom inside the test's 10 s budget. Under -race on a loaded runner, that margin disappears.

Two consequences worth separating: the test is slower than it needs to be, and it exercises the force-kill path exclusively — never the graceful shutdown that real daemons actually take. The second is arguably the bigger loss, since graceful shutdown is the common case and currently has no coverage here.

Commands used: gh run view --job 102056137348 --log-failed; go test ./cmd/harnesscli -run TestGoCodeScriptStopsHarnessdOnInterrupt -race -count=1 x3 locally; reading stop_server in scripts/go-code.sh and the stub definitions in the test.

Blast-radius impact map

Callers and data flow: one test file. No production code.

Config/env/defaults: none.

API/CLI/wire formats/tools: none.

Persistence/schema/cache: none.

Concurrency/lifecycle: the point of the change — the stub becomes promptly killable, so the wrapper's graceful path is what runs.

Security/auth/permissions/privacy: none.

TUI/web/macOS/other clients: none.

Deployment/observability/runbooks: none.

Compatibility: none.

Existing tests/fixtures: the sibling case in the same test (pre-existing daemon is left alone) and TestGoCodeScriptStopsHarnessdWhenOutputPipeCloses, whose stub has the same shape and the same latent slowness, though it does not currently flake because it does not wait on the wrapper's exit the same way. Both should be treated consistently.

Documentation: engineering-log entry noting the flake and its cause.

Regression test first

This is a fix to a test, so the "test first" evidence is the failure itself plus a timing measurement rather than a new test. Before changing anything, record how long the wrapper actually takes to exit after SIGINT — expected around 5 s, dominated by the force-kill wait. After the change it should be well under 1 s, because the stub exits on TERM.

Add an assertion that the wrapper exits promptly (a budget comfortably under the old 5 s but not so tight it reintroduces flake), so a future regression that pushes cleanup back onto the force-kill path is caught as a failure rather than as a slow pass.

Fix boundaries

In scope:

• Make the stub daemon exit promptly on SIGTERM the way a real daemon does, e.g. trap 'exit 0' TERM with sleep 300 & wait $! so bash can run the trap instead of deferring it behind a foreground sleep.
• Keep trap '' INT: surviving the group SIGINT is the behavior under test.
• Widen the wrapper-exit budget for headroom, and assert prompt exit as described.
• Apply the same stub shape to TestGoCodeScriptStopsHarnessdWhenOutputPipeCloses so both tests exercise graceful shutdown.

Out of scope:

• scripts/go-code.sh. The wrapper is correct; its 5-second wait then force-kill is the right behavior for a daemon that will not exit.
• The STARTED_BY_US contract and the --server detachment.
• Any change to what the tests assert about orphaning.

Diagnostic and observability evidence

Before: the wrapper takes ~5 s to exit after SIGINT in this test, all of it inside stop_server's kill -0 polling loop, ending in SIGKILL.

After: the stub exits on the first SIGTERM, stop_server's loop returns on its first or second poll, and the wrapper exits in well under a second. The measured exit time is the signal that the fix worked.

Verification plan

• Measure and record wrapper exit time before and after.
• go test ./cmd/harnesscli -run TestGoCodeScript -race -count=5 — all seven tests, five times, to give the flake a chance to appear.
• Full regression: go test ./cmd/... ./internal/....
• CI: confirm green on the PR without a re-run. A pass that needed a re-run does not count as evidence here.

Rollout and rollback

Test-only. No deployment concern. Rollback is reverting the commit.

Documentation and handoff

docs/logs/engineering-log.md: the flake, its cause (a stub whose foreground sleep makes bash defer SIGTERM, forcing the 5 s worst-case path on every run), and the durable lesson — a test stub that ignores a signal must still be killable by the mechanism under test, or the test measures the timeout rather than the behavior.

Definition of done

• Wrapper exit time measured before and after
• Stub exits promptly on TERM while still ignoring INT
• Both cleanup tests use the same stub shape
• Prompt-exit assertion added so a regression fails rather than merely slows
• -count=5 race run green
• CI green without a re-run
• Engineering log updated

[dennisonbertram]

Correction: the diagnosis in the issue body is wrong. Do not implement against it.

I filed this claiming the stub daemon forces a 5-second force-kill path on every run, leaving too little headroom. Measured, that is false.

Disproven — the 5s path. Driving the wrapper exactly as the test does and timing the wrapper's exit after a process-group SIGINT:

wrapper exited 0.21s after SIGINT

Not ~5s. stop_server sends SIGTERM to the stub's bash, and a non-interactive bash does not defer SIGTERM behind its foreground sleep — it terminates immediately. The graceful-shutdown wait is never reached, so the "thin margin above a 5s path" story does not hold.

Confirmed — the test's premise. I briefly suspected the stub did not really survive SIGINT (that sleep, being a separate process, would die from the group signal and end the stub for the wrong reason). Checked directly:

stub daemon survived group SIGINT: True

It does survive. POSIX inherits an ignored disposition across exec, so trap '' INT in the stub makes sleep ignore INT too. The premise is sound and trap '' INT should stay.

Not reproduced locally. 8/8 passes under -race with four yes processes saturating CPU, and 3/3 idle. CI is Linux; the failure has not been reproduced on macOS. I do not currently know the Linux-specific mechanism, and I am not going to invent one.

What is provably wrong, and worth fixing regardless: the test calls cmd.Process.Wait() twice — once in the deferred cleanup and once in the goroutine feeding the timeout select:

defer func() {
    _ = cmd.Process.Kill()
    _, _ = cmd.Process.Wait()   // second waiter
}()
...
go func() { _, _ = cmd.Process.Wait(); close(waitDone) }()

os.Process.Wait is not safe to call concurrently or twice on the same process. That is a defect I introduced in #1417 and is the kind of thing that behaves differently across platforms and under the race detector.

Revised scope: remove the double Wait, give the exit assertion headroom that does not depend on an unproven timing story, and stop the stub orphaning its sleep child. The root cause of the Linux failure stays explicitly unconfirmed — the fix reduces the test's fragility and removes a real concurrency defect, and the issue should stay open until CI shows a clean run without a re-run, rather than being closed on a green that proves nothing.

[dennisonbertram]

PR #1423 merged as 2d86c6b. Both CI checks passed on the first run, without a re-run, which was the condition set for this issue.

What that does and does not establish:

• Fixed and proven: the double cmd.Process.Wait() is gone, the stub daemon no longer orphans its sleep child, and the exit budget has honest headroom.
• Still unconfirmed: whether any of that is what was failing on Linux CI. One clean run is weak evidence for an intermittent failure — the original flake also passed most of the time.

Leaving this open. It should be closed only after the interrupt test has gone a stretch of CI runs without a re-run, not on the strength of this one green. If it flakes again, the Process.Wait fix is ruled out as the cause and the search starts fresh — ideally on a Linux runner, since it has never reproduced on macOS (8/8 under -race with the CPU saturated, 3/3 idle).

[dennisonbertram]

It failed again, and the new data changes the diagnosis

PR #1429 — a docs-only change touching CLAUDE.md and the engineering log — failed on the race suite:

--- FAIL: TestGoCodeScriptStopsHarnessdOnInterrupt (40.13s)
    --- FAIL: TestGoCodeScriptStopsHarnessdOnInterrupt/wrapper-started_daemon_is_stopped (30.11s)

Two things follow, and both matter more than the original report.

The Process.Wait fix (#1423) did not resolve it. That defect was real and worth removing, but it was not the cause.

This is a hang, not a thin margin. The subtest took 30.11s — the full budget I widened it to in #1423. Under the old 10s budget it looked like a timing squeeze; at 30s it is unambiguous: on Linux the wrapper does not exit at all after SIGINT. Widening the budget did not buy headroom, it just made the failure take three times longer to report. That was the wrong fix for the wrong reason, and I should have treated a 10s timeout as "hangs" rather than "is slow" from the start.

It reproduces against main, on a diff that touches no code. So this is not incidental to any one PR — every PR is exposed to it.

Correcting the record again: the failure is a genuine hang on Linux in either the wrapper's SIGINT path or the test's driving of it, not flakiness under load, and not the double Wait.

Next step is to reproduce on Linux rather than keep inferring from CI logs — Docker is available locally, so the test can be run in a Linux container and the wrapper's state inspected while it is stuck. Anything else would be another confident story built on a macOS-only observation, which is exactly what produced the first two wrong diagnoses here.