diff --git a/docs/results/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures-results.md b/docs/results/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures-results.md new file mode 100644 index 000000000..9bfa7e235 --- /dev/null +++ b/docs/results/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures-results.md @@ -0,0 +1,58 @@ + +> ↩ **[Change 0507 — Fix the observe-test hang and bring two test files back under their time limits](https://github.com/danielhanold/docket/blob/docket/docs/changes/active/0507-flaky-tests-track-and-stabilize-intermittent-suite-failures.md)** + +# Fix the observe-test hang and bring two test files back under their time limits — Results + +**Human action:** One decision is needed before merge: whether `tests/test_go_finalize_e2e.sh` keeps its 30s budget row or moves to 35s (see the Important item below). Nothing else needs a human. + +## Outcome + +This change targeted four suite problems. Each one now has a recorded outcome. + +- **The `TestObserveRunningThenTerminal` hang was not reproduced.** The test was looped 2,000 times under CPU stress (22 busy processes on 11 CPUs, load up to 53) and 2,000 more times next to a looping `go test -race ./internal/...`. There were no hangs and no other failures. So the root cause is still open. Instead, the test no longer discards two errors: a failed manifest read or a failed kill now fails the test immediately with the error. When the unchanged 30s wait expires, the failure message reports what was stuck: the last `Observe` state and error, whether the killed process group still has live members, and whether the run's live lock is still held. The 30s deadline was not changed. +- **`tests/test_go_integration_app_merge.sh` dropped from 42.6s to 10.0s** (quiet solo medians). Its 12 merge tests now run in parallel. They could not do so before because their shared fixture set an environment variable per test (`t.Setenv`), which Go refuses in parallel tests. The fixture now accepts a planning-node builder, and the merge tests use one that points the global config directory at an isolated empty directory once per process, the same way the e2e tests already do. A new test pins that the merge tests never read the developer's own config. Its budget row was lowered from 30s to 15s by the table's own sizing rule, so the guard catches future growth again. +- **`tests/test_go_finalize_e2e.sh`: Part C's 25s target is not clearly met, and no code was cut.** Two quiet-protocol medians on the identical tree came out 28.2s and 24.3s, and the build gate's own solo re-check recorded 23s. The 24.3s figure is machine noise, not the result of a cut. Each candidate cut was measured and rejected: vet is cached (no gain), the fake `gh` build costs about 0.2s, and per-test setup is not shareable. Almost all the time (about 27s) is one test, `TestE2EStack`. The 30s row was left unchanged; whether to apply the spec's fallback (35s) is left to a human. +- **`tests/test_go_race.sh` measured 44.6s** against its 60s row. The earlier 117s and 94s readings were taken while another suite was running on the same machine; they do not reflect growth. + +## Human actions and testing + +### Important — decide the e2e file's budget row + +The spec says a file that cannot reach 25s gets its row re-set by the sizing rule, with the evidence argued. This file's measurements straddle the line (23s, 24.3s, 28.2s), so the build left the row at 30s rather than pick one reading. If skipped, the row stays at 30s and a moderately loaded run may report a screening line for this file. + +1. Read the C-before / C-after numbers and the rejected levers in the commit message of `4e370c355` (`git log -1 4e370c355`). + Expected: medians 28.2s and 24.3s on an identical tree, test run about 27s of it. +2. Either accept 30s as is, or edit the `tests/test_go_finalize_e2e.sh` row in `tests/runtime-budgets.tsv` to 35 (ceil5(28.2) + 5) on this branch before merging. + Expected: if edited, `go test ./internal/suiterunner/` still passes. + +## Verification performed + +- Every timing was taken with the spec's protocol: from the feature worktree, with a private HOME/TMPDIR/XDG_CONFIG_HOME, the concurrency variables unset, one discarded warm-up run, then three runs with the median reported, each starting on a quiet machine (no other suite running, 1-minute load below the CPU count). +- New diagnostics for the observe test: unit tests for the stuck-run report, plus two mutation checks. When the group probe was forced to report absent, the report test went red. When a bad process group was signalled, the observe test failed in 0.05s, naming the error. +- Merge shard: the full shard, its `-race` run, the sibling rebase/evidence/state/ops integration shards that share the fixture, the integration contract, and the repository guards all passed. The new config-isolation test went red when its `os.Setenv` was removed. +- E2E completeness assert: a narrowed `-run` filter turned the file red, as designed. +- The hang reproduction was narrower than the spec allowed: the plan capped it at 2,000 iterations per profile (4,000 total, about 5 minutes of test time, against the spec's 5,000 iterations / one hour), and the second load profile was a looping `go test -race ./internal/...`, not a full suite run from another worktree. +- Build gate budget report (full suite, green): two `PARALLEL-SENSITIVE:` lines and no `BUDGET WATCH:` or `SERIAL CONFIRMED OVER BUDGET:` lines. `test_go_finalize_e2e.sh` took 98s under `-j11` with a last solo measurement of 23s, and `test_go_race.sh` took 222s under `-j11` with a last solo of 46s. Both solo numbers agree with this change's quiet measurements (24.3–28.2s and 44.6s), so these are parallel contention, not over-budget files. The merge file drew no line at its old 30s row. A second full-suite run after the row was lowered to 15s gave the same two `PARALLEL-SENSITIVE:` lines (97s and 216s) plus one `BUDGET WATCH:` for the merge file: 42s under `-j11`, parallel-overrun streak 1/5. That is a screening line under full parallel load; the file's quiet solo runs are 9–10.5s, well inside 15s. If the streak climbs, the runner's serial re-check decides whether it is real. +- Whole-branch review (deep tier): 4 findings (2 important, 2 minor). The merge row was lowered to 15s in-branch; the other three were results-file corrections, made here. Full table in the PR body. + +## Known issues and follow-ups + +### The observe-test hang's root cause is still unknown + +If the hang returns, the gate goes red on `TestObserveRunningThenTerminal` after 30s, as before. The difference is that the failure message now says what was stuck. Impact: an occasional false red on a gate; a re-run passes. Confirmed open (not reproduced in 4,000 loaded iterations). Next action: read the next sighting's stuck-run report against the reproduction record above and fix from there. + +### `test_go_finalize_e2e.sh` sits on its 25s target + +Measured medians on the same tree ranged from 23s to 28.2s depending on load, so a moderately loaded run can approach the 30s row. Nearly all of it is `TestE2EStack`. A further cut would need a cloned fixture snapshot that rewrites absolute paths, which the build judged risky. Suspected future screening noise, not a confirmed breach. Next action: the row decision above. + +### The e2e completeness assert misses a renamed test + +If a `TestE2E*` function is renamed to lower case, it drops out of both the declared count and the ran count, so the file stays green while the test silently stops running. This gap predates this change. Confirmed by mutation. Next action: a small guard fix. No existing change fits (checked 20) — capture a new change. + +### A non-canonical TMPDIR breaks the no-git guard tests + +When `TMPDIR` ends in `/`, a private temp dir made from it contains `//`. `TestNoGitGuardShadowsGitOnPath` compares paths as strings and then fails in several packages. Seen only in a hand-run measurement harness, not in gates. Next action: clean or resolve the path before comparing. No existing change fits (checked 20) — capture a new change. + +### Spec-listed discovered work + +The spec named two items for a human to capture: the runner's solo re-check cannot see another worktree's suite (so it certifies contended readings), and `TestProcessExitSitesAreAllowlisted` walks into `.worktrees/` when run from the primary checkout, giving a false red there. Both are unchanged by this branch. Contention-aware re-check: Related to #273 (host-relative budgets, deferred), which addresses a different cause — capture a new change and list #273 under `related:`. Exit-site guard: No existing change fits (checked 20) — capture a new change. diff --git a/docs/superpowers/plans/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures.md b/docs/superpowers/plans/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures.md new file mode 100644 index 000000000..3400150ca --- /dev/null +++ b/docs/superpowers/plans/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures.md @@ -0,0 +1,975 @@ + +> ↩ **[Change 0507 — Fix the observe-test hang and bring two test files back under their time limits](https://github.com/danielhanold/docket/blob/docket/docs/changes/active/0507-flaky-tests-track-and-stabilize-intermittent-suite-failures.md)** + +# Observe-Test Hang and Two Over-Limit Test Files — Implementation Plan + +> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking. In this repository the plan is executed by `docket-build`. + +**Goal:** Make `TestObserveRunningThenTerminal`'s 30s hang either fixed at its root cause or self-explaining, and bring `tests/test_go_integration_app_merge.sh` and `tests/test_go_finalize_e2e.sh` to a quiet solo median of 25s or less (or an argued row re-set), with every timing recorded before and after. + +**Architecture:** Part A tightens the test (no discarded errors) and adds a test-only `describeStuckRun` report printed when the 30s wait expires. A bounded reproduction under two load profiles then decides whether a root-cause fix (A3) follows. Part B lets the 12 `TestIntegrationFinalizeMerge*` tests call `t.Parallel()` by giving the shared fixture a planning-node builder that never calls `t.Setenv` (the `e2eNode` precedent). Part C measures the e2e file phase by phase and cuts only measured, redundant work. Part D measures the race file only. Measurements are taken by small scratch scripts that live outside the repo, under `${TMPDIR:-/tmp}/docket-0507/`. The numbers are carried in commit messages. + +**Tech Stack:** Go tests (`internal/process`, `internal/app` under the `integration` and `e2e` build tags), POSIX shell test wrappers under `tests/`, macOS `sysctl`/`pgrep`/`perl` for measurement. + +**Spec:** `docs/superpowers/specs/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures-design.md` (on the `docket` branch; read it from `/Users/homer/dev/docket/.docket/docs/superpowers/specs/2026-10-05-flaky-tests-track-and-stabilize-intermittent-suite-failures-design.md`). + +## Global Constraints + +- **Never** raise the 30s deadline in `TestObserveRunningThenTerminal`, add retries, loosen or remove an assertion, or skip the test under load (spec A5). +- Retry-on-failure machinery and any change to gate or budget policy (the 5/2 and 3/2 factors, exit codes, the screen-then-confirm regime) are out of scope. So is making the runner's solo re-check notice another suite, and so is #273. +- Every timing number is taken with the shared measurement protocol: from the feature worktree, `bash tests/.sh` with `DOCKET_GO_TEST_CONCURRENCY` unset, a private HOME, TMPDIR and XDG_CONFIG_HOME, and a quiet machine (no competing `docket development test` / `go test` / test binary, 1-minute load average below the CPU count). Take one discarded warm run, then three runs, and report the median. Record each run's seconds and starting load average. The `measure.sh` script embedded in Tasks 4, 5 and 6 implements this exactly. +- Target for Parts B and C: a quiet solo median of **25s or less**. Fallback: re-set the row by the table's own sizing rule (post-cut median rounded up to the next multiple of 5, plus a 5s margin) and argue it in the commit message: what was cut, what remains, and why the rest cannot be cut. Never raise a row without the cut attempt. +- Never cut assertions or coverage. For the e2e file, keep the `go vet -tags e2e ./internal/app/` coverage, the build-tag assert, and both completeness asserts. +- Every Go verification run uses `-count=1` (learning `cached-runner-serves-a-mutated-tree`). Every mutation is made on a backup copy and restored from it with `cp`, never with `git checkout --` (learning `mutation-restore-needs-a-backup-copy`). +- Run integration tests only with a `-run` prefix: `go test -tags integration -count=1 -run '^' ./internal/app/`. +- Measurement and reproduction scripts and notes live under `${TMPDIR:-/tmp}/docket-0507/`, never in the repo. Measurement numbers go into the task's commit message. A task with no code change records its numbers in an empty commit (`git commit --allow-empty`). +- Shell rules from AGENTS.md apply to the scratch scripts: no producer piped into an early-exiting consumer under pipefail, `grep -e` for patterns, templated `mktemp`. +- Cross-references in maintained source anchor on symbol names, never line numbers (`TestCommentAnchorStyle`). +- Every `os.MkdirTemp` in test code carries a `// tempdir-exempt: ` comment on the line above (`internal/repoguard/tempdir_fixture_test.go`). +- Stage explicit paths only; never `git add -A`. Do not edit anything on the `docket` metadata branch. +- Run tasks strictly in order. Task 2's load generators must be fully stopped before any measurement task (4, 5, 6) runs. + +## Review Focus + +1. **A parallelized merge test that shares mutable package state with another** (a package-level hook, seam, or shared fake). A person expects the shard to stay correct and race-free, not flaky in a new way. Pinned in Task 4 Step 6: the shard runs once under `-race`, and any test that swaps package state stays sequential with a comment. +2. **The parallel fixture silently dropping global-config isolation.** A person expects merge tests never to read their own `~/.config/docket/config.yml`. Pinned in Task 4 by `TestIntegrationFinalizeMergeParallelNodeIsolatesGlobalConfig`, mutation-tested. +3. **A stuck-run report that itself crashes or misleads when `Observe` never succeeded** (nil observation, error every poll) **or the manifest names no real group.** A person expects the report to say "" and "unknown", never to panic and never to call an unprovable probe "absent". Pinned in Task 1 by `TestDescribeStuckRunNamesEveryProbe`. +4. **A measurement taken while another worktree's suite is running.** A person expects every recorded number to say whether it was quiet. Pinned by `measure.sh`'s quiet check, which labels the run `CONTENDED` rather than passing it off as quiet (Tasks 4, 5, 6). +5. **An e2e cut that leaves the completeness or vet asserts vacuous.** A person expects a renamed `TestE2E*` function to still turn the file red. Pinned in Task 5 Step 7 by a rename mutation. + +## File Structure + +- Modify `internal/process/observe_test.go`: `TestObserveRunningThenTerminal` stops discarding the `readManifest`/`signalGroup` results and reports what was stuck on timeout. Adds the test-only helper `describeStuckRun` and its two tests. +- Possibly modify `internal/process/*` (Task 3 only, only if the hang reproduces): the root-cause fix. +- Modify `internal/app/finalize_rebase_test.go`: extract `setupRebaseFixtureWithNode` (planning-node builder injected); `setupRebaseFixtureStatus` delegates to it. +- Modify `internal/app/finalize_merge_test.go`: extract `setupMergeFixtureWithNode`; `setupMergeFixture` delegates to it. +- Modify `internal/app/finalize_merge_integration_test.go`: add `parallelPlanningNode` plus its isolation test, add `t.Parallel()` to the tests, and route fixtures through the no-Setenv builder. +- Modify `tests/test_go_finalize_e2e.sh` and/or `internal/app/finalize_e2e_test.go` (Task 5): only the measured cuts. +- Possibly modify `tests/runtime-budgets.tsv` (fallback only). + +--- + +### Task 1: The observe test stops discarding errors and reports what was stuck + +**Files:** +- Modify: `internal/process/observe_test.go` (`TestObserveRunningThenTerminal`; new `describeStuckRun`, `TestDescribeStuckRunNamesEveryProbe`, `TestDescribeStuckRunReportsLiveRun`) + +**Interfaces:** +- Consumes (existing, package `process`): `readManifest(runDir string) (*manifestRecord, error)`, `signalGroup(pgid int, sig syscall.Signal) error`, `groupAlive(pgid int) probeAnswer`, `processAlive(pid int) probeAnswer`, `probeFlock(path string) (held bool, answer probeAnswer)`, `liveLockFile`, `probeAnswer.String()` returning `live`/`absent`/`unknown`, `(*Service).Observe(runDir) (*Observation, error)`, `launchHelper`, `newTestService`, `waitFor`, `syscall_SIGKILL()`. +- Produces: `describeStuckRun(runDir string, m *manifestRecord, last *Observation, lastErr error) string` (test-only). Its output contains these exact fragments: `state=">`, `err=">`, `group : `, `supervisor pid : `, `live.lock: `. On timeout the hang test fails with a message starting `timed out waiting for vanished: `. Task 2's reproduction script counts that exact string. + +- [ ] **Step 1: Write the failing tests** + +Append to `internal/process/observe_test.go` (add `"errors"`, `"fmt"`, `"strings"` to the imports): + +```go +// TestDescribeStuckRunNamesEveryProbe pins the report's shape when nothing is +// provable: no observation ever succeeded, the manifest names no real group or +// supervisor, and no lock file exists. Unprovable probes must read "unknown", +// never "absent", and a nil observation must not panic. +func TestDescribeStuckRunNamesEveryProbe(t *testing.T) { + dir := testsupport.TempDir(t) + m := &manifestRecord{PGID: 0, SupervisorPID: 0} + got := describeStuckRun(dir, m, nil, errors.New("boom")) + for _, want := range []string{ + "state=", + "err=boom", + "group 0: unknown", + "supervisor pid 0: unknown", + "live.lock: free", + } { + if !strings.Contains(got, want) { + t.Fatalf("report %q missing %q", got, want) + } + } +} + +// TestDescribeStuckRunReportsLiveRun pins the report against a real, still +// running run: the group and supervisor are live and live.lock is held. +func TestDescribeStuckRunReportsLiveRun(t *testing.T) { + svc := newTestService(t) + out := launchHelper(t, svc, testsupport.TempDir(t), "sleep") + m, err := readManifest(out.RunDir) + if err != nil { + t.Fatalf("readManifest: %v", err) + } + obs, oerr := svc.Observe(out.RunDir) + got := describeStuckRun(out.RunDir, m, obs, oerr) + for _, want := range []string{ + "state=running", + "err=", + fmt.Sprintf("group %d: live", m.PGID), + fmt.Sprintf("supervisor pid %d: live", m.SupervisorPID), + "live.lock: held", + } { + if !strings.Contains(got, want) { + t.Fatalf("report %q missing %q", got, want) + } + } + // Teardown: launchHelperReq's drain (quiesceRun) kills the still-running group. +} +``` + +- [ ] **Step 2: Run the tests to verify they fail** + +Run: `cd /Users/homer/dev/docket/.worktrees/flaky-tests-track-and-stabilize-intermittent-suite-failures && go test -count=1 -run '^TestDescribeStuckRun' ./internal/process` +Expected: build failure `undefined: describeStuckRun`. + +- [ ] **Step 3: Implement `describeStuckRun`** + +Add to `internal/process/observe_test.go`, after `observeUntilTerminal`: + +```go +// describeStuckRun reports what was still stuck when a kill-then-wait-for-gone +// test's wait expired: the last Observe state and error, whether the killed +// group and its supervisor still have live members (zero-signal probes), and +// whether live.lock is still held. Every probe keeps its three-way answer; +// "unknown" is never folded into "absent". A pid or pgid <= 1 is not probed +// (kill(0, 0) would address the caller's own group) and reads "unknown". +func describeStuckRun(runDir string, m *manifestRecord, last *Observation, lastErr error) string { + state := "" + if last != nil { + state = string(last.State) + } + errText := "" + if lastErr != nil { + errText = lastErr.Error() + } + supervisor := probeUnknown + if m.SupervisorPID > 1 { + supervisor = processAlive(m.SupervisorPID) + } + held, ans := probeFlock(filepath.Join(runDir, liveLockFile)) + lock := "free" + switch { + case ans == probeUnknown: + lock = "unknown" + case held: + lock = "held" + } + return fmt.Sprintf("last observe state=%s err=%s; group %d: %v; supervisor pid %d: %v; live.lock: %s", + state, errText, m.PGID, groupAlive(m.PGID), m.SupervisorPID, supervisor, lock) +} +``` + +(`groupAlive` already returns `probeUnknown` for a pgid of 1 or less. That is why the group probe needs no guard of its own.) + +- [ ] **Step 4: Run the new tests to verify they pass** + +Run: `go test -count=1 -run '^TestDescribeStuckRun' ./internal/process` +Expected: `ok`. + +- [ ] **Step 5: Rewrite `TestObserveRunningThenTerminal` to stop discarding results and to report on timeout** + +Replace the body after the `obs.StdoutLog` check (the `m, _ := readManifest(...)` line through the end of the `waitFor` call) with: + +```go + m, err := readManifest(out.RunDir) + if err != nil { + t.Fatalf("readManifest: %v", err) + } + if err := signalGroup(m.PGID, syscall_SIGKILL()); err != nil { + t.Fatalf("SIGKILL group %d: %v", m.PGID, err) + } + // Supervisor dies with the child under KILL: no terminal record can + // exist, no stop intent was recorded -> vanished. An Observe error while + // polling is kept (lock release can race) and reported if the wait expires. + var last *Observation + var lastErr error + end := time.Now().Add(30 * time.Second) + for { + last, lastErr = svc.Observe(out.RunDir) + if lastErr == nil && last.State == StateVanished { + return + } + if time.Now().After(end) { + t.Fatalf("timed out waiting for vanished: %s", describeStuckRun(out.RunDir, m, last, lastErr)) + } + time.Sleep(20 * time.Millisecond) + } +``` + +The 30s deadline and the 20ms interval are unchanged. The function no longer calls `waitFor`. Leave `waitFor` itself untouched: other tests use it. + +- [ ] **Step 6: Run the package tests, including under the race detector** + +Run: `go test -count=1 ./internal/process && go test -race -count=20 -run '^TestObserveRunningThenTerminal$|^TestDescribeStuckRun' ./internal/process` +Expected: both `ok`. Each `TestObserveRunningThenTerminal` iteration takes well under 1s. + +- [ ] **Step 7: Mutation-test both changes (restore from a backup copy)** + +```bash +cd /Users/homer/dev/docket/.worktrees/flaky-tests-track-and-stabilize-intermittent-suite-failures +B="$(mktemp "${TMPDIR:-/tmp}/observe_test.go.XXXXXX")"; cp internal/process/observe_test.go "$B" +# Mutation A: the report claims the group is always absent -> TestDescribeStuckRunReportsLiveRun must redden. +perl -0pi -e 's/m\.PGID, groupAlive\(m\.PGID\), m\.SupervisorPID/m.PGID, probeAbsent, m.SupervisorPID/' internal/process/observe_test.go +go test -count=1 -run '^TestDescribeStuckRunReportsLiveRun$' ./internal/process; echo "rc=$? (want non-zero)" +cp "$B" internal/process/observe_test.go +# Mutation B: kill a non-real group -> the test must fail IMMEDIATELY naming the refusal, not after 30s. +perl -0pi -e 's/signalGroup\(m\.PGID, syscall_SIGKILL\(\)\)/signalGroup(0, syscall_SIGKILL())/' internal/process/observe_test.go +go test -count=1 -v -run '^TestObserveRunningThenTerminal$' ./internal/process 2>&1 | tail -n 5; echo "(want FAIL in well under 30s naming 'refusing to signal non-real group 0')" +cp "$B" internal/process/observe_test.go +git diff --stat # only the intended Task 1 edits remain +``` + +If either mutation stays green, the assert is defective. Fix it before going on. + +- [ ] **Step 8: Commit** + +```bash +git add internal/process/observe_test.go +git commit -m "test(process): observe hang test fails fast on discarded errors and reports what was stuck + +TestObserveRunningThenTerminal no longer discards readManifest's error or +signalGroup's result, and when its unchanged 30s wait expires it reports the +last Observe state/error, group and supervisor liveness, and live.lock state +(describeStuckRun). Mutation-tested: both mutations reddened." +``` + +--- + +### Task 2: Bounded reproduction of the hang under two load profiles (spec A1) + +No repository file changes. This task runs a bounded reproduction attempt against the Task 1 build, so any hang prints its stuck-run report. It records the attempts in an empty commit. + +**Files:** +- Create (scratch, outside the repo): `${TMPDIR:-/tmp}/docket-0507/repro.sh` +- Writes (scratch): `${TMPDIR:-/tmp}/docket-0507/repro-state.tsv`, `failure-*.log`, `measurements.md` + +**Interfaces:** +- Consumes: Task 1's failure text `timed out waiting for vanished: ` and the `describeStuckRun` report it carries. +- Produces for Task 3: `repro-state.tsv` rows `profileiterationshangsother_failuressecondsfirst_failure_atload1`. It also produces a recorded verdict line, either `REPRO-VERDICT reproduced profile=

first_failure_at=` or `REPRO-VERDICT not-reproduced`. + +**Bounds (the spec's A1 cap, kept smaller):** at most 2,000 iterations or 1,500 seconds per profile, two profiles. That is 4,000 iterations and 50 minutes overall, inside the spec's 5,000-iteration / one-hour bound. Stop at the first failure of any kind. + +- [ ] **Step 1: Write the reproduction script** + +```bash +mkdir -p "${TMPDIR:-/tmp}/docket-0507" +cat > "${TMPDIR:-/tmp}/docket-0507/repro.sh" <<'EOF' +#!/usr/bin/env bash +# repro.sh [slice-seconds] — one bounded slice of change +# 0507's A1 reproduction loop for TestObserveRunningThenTerminal. Re-run until the +# profile reports its cap or a failure. One row per batch goes to repro-state.tsv: +# profile iterations hangs other_failures seconds first_failure_at load1 +set -uo pipefail +set -m # background load jobs get their own process groups so stop_load kills whole trees +wt="$1"; profile="$2"; budget="${3:-480}" +case "$profile" in cpu|gosuite) ;; *) echo "profile must be cpu or gosuite" >&2; exit 2 ;; esac +S="${TMPDIR:-/tmp}/docket-0507"; mkdir -p "$S" +state="$S/repro-state.tsv"; touch "$state" +ncpu="$(sysctl -n hw.ncpu)" +BATCH=50; CAP_ITERS=2000; CAP_SECS=1500 +cum(){ awk -F'\t' -v p="$profile" -v c="$1" '$1==p{s+=$c} END{print s+0}' "$state"; } +anyfail(){ awk -F'\t' '($3+$4)>0{f=1} END{print f+0}' "$state"; } +if [ "$(anyfail)" = 1 ]; then echo "REPRO: a failure is already recorded; stop reproducing"; exit 0; fi +bin="$S/process.test" +( cd "$wt" && go test -race -c -o "$bin" ./internal/process ) || exit 1 +loadpids=() +stop_load(){ + local p + for p in ${loadpids[@]+"${loadpids[@]}"}; do kill -- "-$p" 2>/dev/null || kill "$p" 2>/dev/null; done + wait 2>/dev/null + loadpids=() +} +trap stop_load EXIT +if [ "$profile" = cpu ]; then + for ((i = 0; i < 2 * ncpu; i++)); do yes >/dev/null & loadpids+=("$!"); done +else + ( cd "$wt" && while :; do go test -race -count=1 ./internal/... >/dev/null 2>&1; done ) & + loadpids+=("$!") +fi +sleep 5 # let the load ramp up +start=$SECONDS +while :; do + it="$(cum 2)"; secs="$(cum 5)" + if [ "$it" -ge "$CAP_ITERS" ] || [ "$secs" -ge "$CAP_SECS" ]; then + echo "REPRO: profile $profile reached its cap ($it iterations, ${secs}s)"; break + fi + if [ $((SECONDS - start)) -ge "$budget" ]; then echo "REPRO: slice budget spent; re-run to continue"; break; fi + load="$(sysctl -n vm.loadavg | awk '{print $2}')" + b0=$SECONDS + out="$(cd "$wt/internal/process" && "$bin" -test.run '^TestObserveRunningThenTerminal$' \ + -test.count="$BATCH" -test.timeout=20m -test.v 2>&1)" + dur=$((SECONDS - b0)) + passes="$(grep -c -e '^--- PASS: TestObserveRunningThenTerminal' <<<"$out")" + fails="$(grep -c -e '^--- FAIL: TestObserveRunningThenTerminal' <<<"$out")" + hangs="$(grep -c -e 'timed out waiting for vanished' <<<"$out")" + other=$((fails - hangs)); [ "$other" -lt 0 ] && other=0 + ran=$((passes + fails)) + if [ "$ran" -lt "$BATCH" ] && [ "$fails" -eq 0 ]; then other=1; fi # crash / panic / timeout of the binary + first="-" + if [ $((hangs + other)) -gt 0 ]; then + pos="$(awk '/^--- PASS: TestObserveRunningThenTerminal/{n++} /^--- FAIL: TestObserveRunningThenTerminal/{print n+1; exit}' <<<"$out")" + first=$((it + ${pos:-$ran})) + log="$S/failure-$profile-$first.log"; printf '%s\n' "$out" >"$log" + echo "REPRO: failure in $profile at cumulative iteration $first; full output in $log" + fi + printf '%s\t%s\t%s\t%s\t%s\t%s\t%s\n' "$profile" "$ran" "$hangs" "$other" "$dur" "$first" "$load" >>"$state" + if [ $((hangs + other)) -gt 0 ]; then echo "REPRO: FAILURE REPRODUCED"; break; fi +done +printf 'REPRO-TOTAL profile=%s iterations=%s hangs=%s other_failures=%s seconds=%s ncpu=%s\n' \ + "$profile" "$(cum 2)" "$(cum 3)" "$(cum 4)" "$(cum 5)" "$ncpu" +EOF +chmod +x "${TMPDIR:-/tmp}/docket-0507/repro.sh" +``` + +- [ ] **Step 2: Start from a clean state and confirm no stray load exists** + +```bash +rm -f "${TMPDIR:-/tmp}/docket-0507/repro-state.tsv" +pgrep -x yes || echo "no yes processes" +``` + +- [ ] **Step 3: Run the CPU-stress profile, slice by slice** + +Run in the foreground with a Bash timeout of 600000 ms. Do not background the command and do not yield: + +`"${TMPDIR:-/tmp}/docket-0507/repro.sh" /Users/homer/dev/docket/.worktrees/flaky-tests-track-and-stabilize-intermittent-suite-failures cpu 480` + +Repeat the same command until it prints `reached its cap` or `FAILURE REPRODUCED`. After each slice, confirm the load is gone: `pgrep -x yes || echo clean`. Kill any listed pid; they are this script's leftovers. + +- [ ] **Step 4: Run the Go-suite-load profile (only if Step 3 recorded no failure)** + +This profile stands in for "a full suite run alongside". It runs `go test -race ./internal/...` in a loop instead of `docket development test`, so no contended reading lands in the runner's budget history. + +`"${TMPDIR:-/tmp}/docket-0507/repro.sh" /Users/homer/dev/docket/.worktrees/flaky-tests-track-and-stabilize-intermittent-suite-failures gosuite 480` + +Repeat until `reached its cap` or `FAILURE REPRODUCED`. After each slice, confirm nothing is left running: capture `out="$(pgrep -fl 'go test -race -count=1 ./internal/' || true)"` and kill any pid it lists. + +- [ ] **Step 5: Record the verdict in the notes file** + +```bash +S="${TMPDIR:-/tmp}/docket-0507" +{ echo "## A1 reproduction ($(date -u +%FT%TZ))" + echo '```'; cat "$S/repro-state.tsv"; echo '```' + awk -F'\t' '{i[$1]+=$2; h[$1]+=$3; o[$1]+=$4; s[$1]+=$5} END{for (p in i) printf "REPRO-TOTAL profile=%s iterations=%d hangs=%d other_failures=%d seconds=%d\n", p, i[p], h[p], o[p], s[p]}' "$S/repro-state.tsv" + f="$(awk -F'\t' '$6!="-"{print $1" "$6; exit}' "$S/repro-state.tsv")" + if [ -n "$f" ]; then set -- $f; echo "REPRO-VERDICT reproduced profile=$1 first_failure_at=$2"; else echo "REPRO-VERDICT not-reproduced"; fi +} >>"$S/measurements.md" +tail -n 8 "$S/measurements.md" +``` + +If a failure was recorded, also copy the `t.Fatalf` line, which holds the stuck-run report, from the `failure-*.log` file into the notes. + +- [ ] **Step 6: Commit the record (empty commit)** + +```bash +git commit --allow-empty -F - </live.lock` lists the holders. Is every holder in the killed group? +- What did `Observe` return the whole time: a persistent error (which one), or a persistent `running`? + +Treat these as hypotheses (learning `groomed-root-cause-is-a-hypothesis`). Enumerate every code path in `(*Service).Observe` that can keep returning a non-vanished answer before fixing. + +- [ ] **Step 3: Write a test that fails for the identified cause** + +Where the cause can be forced deterministically, for example through an existing seam like `observePostProbeHook`, write a focused failing test for it. Where it cannot, the proof is the Step 5 streak. + +- [ ] **Step 4: Fix the real cause, then apply it to every same-shape site** + +Derive the sites from a grep, never from a hand list: + +`grep -n -e 'signalGroup(' internal/process/*_test.go` + +Today this includes `observe_test.go`, `recover_test.go`, `worktree_lock_test.go`, `leftover_test.go` and `launch_test.go`. Apply the fix to each site whose shape is "kill, then wait for gone". A5 still holds: never raise the 30s, add retries, or loosen an assert. + +- [ ] **Step 5: Prove the fix under the reproducing profile** + +Required streak: `max(1000, 3 × first_failure_at)` consecutive iterations with zero failures, under the profile named in `REPRO-VERDICT`. Reset the state, then re-run slices until the streak is reached. If the streak needs more than 2,000 iterations, raise `CAP_ITERS` and `CAP_SECS` in a copy of the script to fit: + +```bash +S="${TMPDIR:-/tmp}/docket-0507"; mv -f "$S/repro-state.tsv" "$S/repro-state-before-fix.tsv" +"$S/repro.sh" /Users/homer/dev/docket/.worktrees/flaky-tests-track-and-stabilize-intermittent-suite-failures 480 +``` + +Any failure resets the claim. Go back to Step 2. + +- [ ] **Step 6: Commit the fix (on `reproduced`)** + +`git add` the exact files changed, then commit with a message that states the cause, the fix, the sites it was applied to (with the grep that found them), and the before/after evidence. Before: the profile and `first_failure_at`. After: the streak length and profile. + +- [ ] **Step 7: On `not-reproduced`, record the no-op (empty commit)** + +```bash +git commit --allow-empty -m "test(process): A3 not triggered; observe hang root cause remains open + +The bounded A1 reproduction (see the previous commit) produced no failure, so +no root-cause fix is claimed. Task 1's diagnostics (no discarded errors, +stuck-run report on timeout) are the A4 outcome; the next sighting will name +what was stuck. The 30s deadline is unchanged." +``` + +--- + +### Task 4: The merge shard runs its tests in parallel (spec Part B) + +**Files:** +- Modify: `internal/app/finalize_rebase_test.go` (`setupRebaseFixtureStatus` → delegates to new `setupRebaseFixtureWithNode`) +- Modify: `internal/app/finalize_merge_test.go` (`setupMergeFixture` → delegates to new `setupMergeFixtureWithNode`) +- Modify: `internal/app/finalize_merge_integration_test.go` (`parallelPlanningNode`, its isolation test, `t.Parallel()` on every test that can take it, fixtures routed through the no-Setenv builder) +- Possibly modify (fallback only): `tests/runtime-budgets.tsv` row `tests/test_go_integration_app_merge.sh` +- Scratch: `${TMPDIR:-/tmp}/docket-0507/measure.sh` + +**Interfaces:** +- Consumes (existing): `planningDepsFor(t *testing.T, dir string) realNode` (its `newGitClient` calls `t.Setenv`, which panics under `t.Parallel()`), `realNode{dir string; deps PlanningDeps}`, `PlanningDeps{Client, Engine, Reader, Clock}`, `gitcli.NewClient()`, `transaction.NewEngine(client, clock)`, `NewGitStatusReader(client)`, `testClock()`, `mergePRRef()`, `(*mergeFixture).patchParent`. +- Produces: + - `setupRebaseFixtureWithNode(t *testing.T, m planRepoMode, status string, nodeFor func(*testing.T, string) realNode) *rebaseFixture` + - `setupMergeFixtureWithNode(t *testing.T, m planRepoMode, nodeFor func(*testing.T, string) realNode) *mergeFixture` + - `parallelPlanningNode(t *testing.T, dir string) realNode` (integration tag only) + +The spec says none of these tests calls `t.Setenv`. That is true only of the test bodies. Their fixture `setupMergeFixture` → `setupRebaseFixtureStatus` → `planningDepsFor` → `newGitClient` calls `t.Setenv("XDG_CONFIG_HOME", ...)`, so adding `t.Parallel()` alone panics. This task routes the fixture through a builder that isolates the global-config layer once per process, the same trade `e2eNode` makes in `internal/app/finalize_e2e_test.go`. + +- [ ] **Step 1: Create the measurement script (if missing) and take the baseline** + +```bash +mkdir -p "${TMPDIR:-/tmp}/docket-0507" +[ -x "${TMPDIR:-/tmp}/docket-0507/measure.sh" ] || { cat > "${TMPDIR:-/tmp}/docket-0507/measure.sh" <<'EOF' +#!/usr/bin/env bash +# measure.sh