Skip to content

test(watcher): bound background process waits so stuck fixtures fail loudly - #30

Merged
withally merged 3 commits into
mainfrom
fm/fm-watcher-lock-test-flake-f1
Aug 14, 2026
Merged

test(watcher): bound background process waits so stuck fixtures fail loudly#30
withally merged 3 commits into
mainfrom
fm/fm-watcher-lock-test-flake-f1

Conversation

@withally

Copy link
Copy Markdown
Owner

Intent

Make test_watch_restart_attaches_to_healthy_peer in tests/fm-watcher-lock.test.sh reliable under full-suite load without weakening any assertion or the watcher-arm behaviors it proves: attach to a verified healthy peer and fail loudly when that attached cycle ends with no successor. The diagnosed defect is broader than a timing flake: bare shell waits on background processes can hang an entire CI shard indefinitely when a watcher or fixture never closes. Bound every background wait in tests/fm-watcher-lock.test.sh so a stuck process fails loudly within seconds, choosing evidence-based bounds from healthy timings; do not use blanket sleeps, whole-test retries, skips, allowed failures, unexplained timeout inflation, harness rewrites, shared-runner changes, unrelated retuning, or production behavior changes unless evidence proves a product bug. Demonstrate what the failed case was waiting on and distinguish attach-poll, wait-for-exit, readiness-race, ordering, and unbounded-wait hypotheses. Check tests/fm-secondmate-safety.test.sh for the same wait pattern. Treat tests/fm-watch-triage.test.sh as a suspect instance and apply the same bounded-wait repair only if it genuinely has the same defect. Preserve every existing assertion and ensure the affected suites pass repeatedly, bin/fm-lint.sh is clean, and no other watcher-lock cases destabilize. Keep every existing commit. Inventory the earlier commit explicitly: retain its arm-liveness early exit, but remove the 80-to-200 attach-poll expansion because it addressed the superseded narrow-flake hypothesis. In this PR body, explicitly correct forward the merged PR 27 environmental attribution by naming PR 27 and explaining that silent global-timeout cancellations were caused by unbounded waits, not merely a slow machine; do not edit PR 27. Yolo authorizes routine pipeline decisions only: never answer ask-user findings locally, never merge, drive every gate through CI-ready green, then stop at the green PR and report it.

What Changed

  • Added shared bounded-wait helpers to tests/lib.sh (fm_test_wait_for_exit, fm_test_wait_or_fail, fm_test_terminate_or_fail, fm_test_pid_live_non_zombie) and replaced every bare wait/kill-then-wait on background processes in tests/fm-watcher-lock.test.sh, tests/fm-secondmate-safety.test.sh, and tests/fm-watch-triage.test.sh, so a watcher or fixture that never exits now fails within the bound with a typed, named timeout (status 124) instead of hanging the shard; tests/wake-helpers.sh now delegates to the shared helpers.
  • Stabilized test_watch_restart_attaches_to_healthy_peer: the attach poll exits early if the arm process dies (keeping the earlier arm-liveness fix), and the previous 80-to-200 attach-poll expansion was removed since it addressed a superseded narrow-flake hypothesis; all existing assertions are preserved.
  • Added a self-test, test_background_wait_is_bounded, proving that a stuck background process is reported as a bounded timeout with a named not ok message rather than an indefinite hang.

Correction to PR #27: that PR attributed silent global-timeout cancellations of the watcher-lock suite to a slow machine. The actual cause was unbounded wait calls on background processes — reproduced at the base commit, where one run hung indefinitely at the bare wait in test_cycle_exit_ledger_links_successor_and_stays_bounded until an external 5-minute timeout killed it. This branch fixes that class of hang by bounding every background wait; PR #27 itself is left unedited.

Risk Assessment

✅ Low: Tests-only change that replaces unbounded background waits with bounded, self-tested helpers while preserving every existing assertion, keeping both commits, and correctly reverting the superseded 80-to-200 attach-poll expansion per the stated intent.

Testing

Exercised the three affected suites end-to-end: the target watcher-lock suite completed all 7 runs without ever hanging (worst case under artificial load was a loud bounded failure), while the base commit reproduced the diagnosed defect — an indefinite hang at a bare wait that needed an external kill; the healthy-peer attach test passed 15/15 under concurrent load, a stuck fixture demonstrably fails within ~2s with a typed timeout message, secondmate-safety passed fully, and the single triage failure is a pre-existing machine-speed latency assertion that fails identically at the base commit.

Evidence: Base commit hangs vs target bounded (full-suite run transcript)

base run 1: exit=0 in 90s (all ok) · base run 2: exit=124 — hung, killed by external 5-min timeout, stalled at the unbounded wait in test_cycle_exit_ledger_links_successor_and_stays_bounded · base run 3: exit=0 in 78s

# Base-commit (322764a) full-suite runs of tests/fm-watcher-lock.test.sh, 5-min external timeout each
=== base run 1 start 13:51:36 ===
exit=0 end 13:53:06
ok - cycle-exit ledger links a verified successor and remains size-capped
ok - SIGSTOP distinguishes live PID from stale beacon and termination records the exit class
=== base run 2 start 13:53:06 ===
exit=124 end 13:58:06
ok - arm reports FAILED and exits non-zero when no fresh watcher can be confirmed
Terminated: 15
=== base run 3 start 13:58:06 ===
exit=0 end 13:59:24
ok - cycle-exit ledger links a verified successor and remains size-capped
ok - SIGSTOP distinguishes live PID from stale beacon and termination records the exit class

[exited with code 0]

# Base run 2 tail (hung: exit 124 after 5 minutes; last completed test before the unbounded wait in test_cycle_exit_ledger_links_successor_and_stays_bounded):
ok - arm propagates an immediate watcher wake before confirmation
ok - arm attaches to a peer watcher after child stands down and surfaces a missing successor
watcher: lock held by live pid 7918 but heartbeat is stale for 840030856s (>300s); inspect or stop that watcher before re-arming.
ok - arm reports FAILED and exits non-zero when no fresh watcher can be confirmed
Terminated: 15
Evidence: Healthy-peer attach test 15/15 under concurrent load
run 01: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 02: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 03: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 04: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 05: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 06: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 07: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 08: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 09: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 10: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 11: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 12: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 13: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 14: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
run 15: ok - watch restart attaches to a verified healthy peer and later surfaces a successor gap
Evidence: Stuck fixture now fails loudly within its bound

$ sleep 300 & fm_test_wait_or_fail $! 20 "stuck fixture wait" not ok - stuck fixture wait timed out after 2.0s waiting for pid 97347 (S - sleep 300) (exited nonzero as required; wall time bounded at ~2s) ok - background process waits return a typed timeout instead of hanging

# Direct demonstration: a stuck background fixture now fails loudly within the bound instead of hanging
$ sleep 300 & fm_test_wait_or_fail $! 20 "stuck fixture wait"
not ok - stuck fixture wait timed out after 2.0s waiting for pid 97347 (S    -      sleep 300)
(exited nonzero as required; wall time bounded at ~2s)

# New in-suite self-test:
ok - background process waits return a typed timeout instead of hanging
- Outcome: ⚠️ 1 warning across 1 run (44m12s)

Pipeline

Updates from git push no-mistakes

✅ **intent** - passed

✅ No issues found.

✅ **Rebase** - passed

✅ No issues found.

⚠️ **Review** - 2 infos
  • ℹ️ tests/fm-watcher-lock.test.sh:268 - Cleanup/wait call sites use a uniform 600-tick (60s) ceiling (e.g. fm_test_wait_or_fail "$pid" 600). This bounds formerly infinite waits and is flake-safe, but is generous relative to the intent's "fails loudly within seconds, choosing evidence-based bounds from healthy timings" phrasing (healthy timings at these sites are sub-second). Deliberate safety margin; noting the tension rather than treating it as a violation since these are new bounds, not inflation of existing timeouts.
  • ℹ️ tests/wake-helpers.sh:258 - is_live_non_zombie in tests/wake-helpers.sh is now a verbatim duplicate of the new fm_test_pid_live_non_zombie in tests/lib.sh (wake-helpers.sh already sources lib.sh and wait_for_exit already delegates the same way). It can be reduced to is_live_non_zombie() { fm_test_pid_live_non_zombie "$@"; } to keep one definition of the zombie check.
⚠️ **Test** - 1 warning
  • ⚠️ tests/fm-watch-triage.test.sh:924 - Pre-existing flake, not caused by this change: tests/fm-watch-triage.test.sh test_nonterminal_stale_not_working_surfaced asserts a <=4s wall-clock bound and fails on this machine at 5-6s in every run at both the base commit (3/3 failures) and the target commit. The change does not touch this test; fixing it here would be the 'unrelated retuning' the user intent forbids, but it may also fail on slow CI shards and deserves its own evidence-based repair.
  • bash tests/fm-watcher-lock.test.sh — 7 full runs on target (3 quiet runs all 34 ok, ~90s each; earlier runs under deliberate concurrent load produced only loud bounded failures, never hangs)
  • bash tests/fm-watcher-lock.test.sh at base commit 322764a (5 runs from a temp checkout sharing the same bin/) — one run hung indefinitely and was killed by an external 5-minute timeout at the unbounded wait in test_cycle_exit_ledger_links_successor_and_stays_bounded
  • test_watch_restart_attaches_to_healthy_peer in isolation, 15 consecutive runs while other suites ran concurrently — 15/15 ok
  • test_cycle_exit_ledger_links_successor_and_stays_bounded in isolation, 8 consecutive runs — 8/8 ok
  • Manual demo: sleep 300 &amp; fm_test_wait_or_fail $! 20 &#34;stuck fixture wait&#34; — failed loudly in ~2s with not ok - stuck fixture wait timed out after 2.0s waiting for pid … (S - sleep 300)
  • test_background_wait_is_bounded (new self-test) in isolation — ok
  • bash tests/fm-secondmate-safety.test.sh — full pass
  • bash tests/fm-watch-triage.test.sh — 2 target runs and 3 base-commit runs to isolate the pre-existing three-observation latency flake (fails identically at base)
✅ **Document** - passed

✅ No issues found.

✅ **Lint** - passed

✅ No issues found.

✅ **Push** - passed

✅ No issues found.

@withally withally closed this Aug 14, 2026
@withally withally reopened this Aug 14, 2026
@withally

Copy link
Copy Markdown
Owner Author

Re-trigger: close/reopen produced no runs; pushing an empty commit next.

@withally
withally force-pushed the fm/fm-watcher-lock-test-flake-f1 branch from a87b22a to 50bd34a Compare August 14, 2026 06:56
The bounded ledger cycle in fm-watcher-lock.test.sh tore down the
successor arm with a bounded terminate but never bounded the successor
watcher's own death. Under CI load a TERM'd watcher lingers in its
fork-heavy cleanup while still holding the session lock with a beacon
fresh within the default 300s grace, so the next bounded cycle's arm
attached to that dying watcher and polled until the 60s wait bound
fired (reproduced deterministically by freezing the watcher: the arm
prints "watcher: attached" and never exits). Terminate the watcher with
the same bounded TERM-then-KILL helper before arming the next cycle.

The Pi generation-owner fixture published its child pid file before
appending its arm-ledger row, while the harness gates on the pid file
and then asserts exactly one live ledger row. Under load the assertion
read the ledger inside that gap and failed with "expected exactly one
live arm child, got (none)" (reproduced in 8 iterations under CPU load;
0 failures in 40 iterations after reordering). Append the ledger row
before publishing the pid file so the row is durable whenever the gate
opens.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@withally
withally merged commit 696bbbb into main Aug 14, 2026
13 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant