fix(supervision): close the watcher arm/guard identity-check race#408
Open
lukeforshort wants to merge 5 commits into
Open
fix(supervision): close the watcher arm/guard identity-check race#408lukeforshort wants to merge 5 commits into
lukeforshort wants to merge 5 commits into
Conversation
The turn-end guard and fm-guard.sh required a fully-written, identity-matched watch lock before treating supervision as present, but the watcher writes that lock's pid, then its fm-home/watcher-path/ pid-identity trio, as separate non-atomic steps before its first beacon touch. A guard sampled in that window false-alarmed against a healthy, in-progress arm cycle. Give the arm script a second liveness signal: a live, identity-matched arm marker it writes at start and refreshes every polling-loop iteration, cleared on exit. Both guard scripts now accept a fresh in-progress arm marker as an alternative to a healthy watcher lock, bounded by its own grace window so a wedged or dead arm still alarms. Also harden the lock's identity-match helper with a small bounded retry around its ps-based identity read: fresh evidence showed the same guard false-firing against a watcher that had been healthy for about fifteen minutes, with no arm involved, which points at a transient ps fork failure under a loaded fleet rather than the arm-timing race alone.
The previous commit's retry attributed a false alarm on a long-healthy watcher to a transient ps fork failure, but the real cause runs deeper: on this WSL2 host, /proc's own boot-time reference measurably drifts forward under continuous wall-clock sampling, so a live, never-restarted process's ps lstart silently walks forward over time even though the process never changed. That is a persistent, monotonically-growing mismatch a same-moment retry cannot fix. The identity comparison now reads /proc/<pid>/stat's starttime field (clock ticks since boot, set once at process creation and never recomputed from wall time) when /proc is available, falling back to the original lstart+command form only on hosts without /proc. Kept the bounded retry as a narrower, still-valid guard against a generic subprocess-fork hiccup, and kept the arm-marker signal from the prior commit since it still closes a real, independent race. Added tests proving the starttime primitive is stable across reads of an unchanged pid, and that identity comparison is unaffected by a simulated drifting ps lstart once /proc is available.
…inst jq path, system node, and harness env leaks
…s and watch-arm.marker state file
5 tasks
Owner
|
Thanks for the PR! This branch currently has a merge conflict with the base branch. When you get a chance, please rebase onto (or merge) the latest base branch, resolve the conflict, and push. After that, checks will re-run and the PR will get looked at again. Noted for firstmate#408 at |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Intent
Fix a watcher-arm/guard identity-check race that made the primary turn-end guard (and the pull-based fm-guard) false-alarm 'no live watcher holds this home lock' seconds to tens of seconds after a healthy arm, costing a verification round-trip almost every turn end.
Root cause 1: the watcher process claims the singleton lock's pid, then writes its home/watcher-path/identity trio as three separate non-atomic steps before its first liveness-beacon touch, so a guard sampled in that window sees a live pid but an incomplete identity and reports unhealthy even though the watcher is genuinely, successfully starting. Two prior fixes on other branches were tried and discarded before this one - deliberately not ported: one only self-heals a wedged incumbent watcher (a different problem); the other added a single fixed 2-second sleep-and-recheck in the guard, which failed because real observed race gaps ran 6-29 seconds, well past a fixed short window.
Fix for root cause 1: the shared wake library gained a second, independent liveness signal - a live, identity-matched marker that the arm helper writes the instant it starts and refreshes on every polling-loop iteration, always cleared on exit via a trap. It has its own bounded grace window (default 30s) so a wedged or dead arm still alarms - this is liveness-driven via continuous refresh, not a fixed sleep. Both guard scripts now accept that in-progress-arm signal as a fallback when the identity-matched watcher-healthy check fails.
Root cause 2, found via fresh live evidence and a deeper investigation mid-session: the guard also false-fired on a watcher that had been healthy for about 15 minutes with no arm involved at all. My first hypothesis (a transient subprocess fork failure in the identity check, addressed with a bounded retry) was superseded by a deeper, confirmed measurement: on this host, /proc's own boot-time reference (btime) measurably drifts forward under continuous wall-clock sampling (about 1 second per 20 seconds of wall time, confirmed via two direct /proc samples and a same-pid lstart shift over the same window), even though the system clock itself reports as synchronized. Since the previous identity check compared ps's lstart wall-clock string, this silently walked a live, never-restarted process's own recorded identity forward until it stopped matching a fresh read - a persistent, monotonically-growing mismatch, not a transient hiccup a retry can fix.
Fix for root cause 2: the identity comparison now reads /proc//stat's starttime field (clock ticks since boot, set once at process creation by the kernel and never recomputed from wall time on a later read) when /proc is available, falling back to the original lstart+command form only on hosts without /proc (macOS). Audited every start-time/lstart read across the codebase and confirmed this was the sole hazard - no other process-identity comparison in the repo depends on wall-clock time. Kept the bounded empty-read retry as a narrower, still-valid guard against a generic subprocess-fork hiccup (distinct from the drift bug), since it never masks a genuine identity mismatch, only a failed/empty subprocess invocation.
Regression tests added and passing: hermetic marker tests in the turn-end-guard suite (silent during a healthy in-progress arm with no watch lock yet; blocks on a dead arm-marker pid; blocks on a stale/wedged arm marker past grace); watcher-lock suite tests for guard arm-in-progress suppression and wedged-arm warning, identity-retry-recovers and identity-retry-still-fails-when-persistent, a real end-to-end repro spawning the actual arm helper against a deliberately slow watcher stub sampling the turn-end guard mid-startup (the literal reproduction recipe from the original bug report), a direct stability proof that the new /proc-based starttime primitive does not drift across reads of the same live pid, and a simulated-shifted-btime-read test using a fake ps whose lstart output deliberately drifts a full minute per call, confirming the fix ignores it once /proc is available. Both full suites (36 and 29 assertions respectively) are green; 7 other adjacent test suites were also verified green with no regressions both before and after the rework. One unrelated pre-existing test failure in the session-start suite was confirmed present on the unmodified baseline before any of these changes, so it is out of scope here. shellcheck -x is clean on every changed script. Also updated the turn-end-guard doc to document both the new arm-in-progress fallback and the /proc-based identity mechanism, since it previously stated the lstart-based watcher-healthy check as the sole and unconditional predicate.
What Changed
bin/fm-wake-lib.sh): the arm helper (bin/fm-watch-arm.sh) now writes an identity-matched in-progress marker the instant it starts, refreshes it on every polling-loop iteration, and clears it on exit via a trap, with its own bounded grace window (default 30s) so a wedged or dead arm still alarms; bothbin/fm-guard.shandbin/fm-turnend-guard.shaccept this arm-in-progress marker as a fallback when the identity-matched watcher-healthy check fails.pslstart wall-clock strings to/proc/<pid>/statstarttime ticks when/procis available, falling back to lstart+command only on hosts without/proc; this eliminates a persistent, monotonically-growing false-mismatch caused by btime drift walking a live process's recorded identity forward, and keeps the bounded empty-read retry as a narrower guard against subprocess-fork hiccups.tests/fm-turnend-guard.test.sh,tests/fm-watcher-lock.test.sh) for arm-in-progress suppression, dead/wedged arm-marker alarms, an end-to-end slow-watcher startup-race repro, starttime stability across reads, and a simulated btime-drift case; hardened the dispatch-select and session-start suites against jq path, system node, and harness env leaks; and documented the new arm-in-progress fallback and/proc-based identity mechanism (docs/turnend-guard.md,docs/configuration.md,AGENTS.md).Risk Assessment
✅ Low: A well-bounded, heavily-commented and test-backed supervision-race fix whose writers/readers stay consistent and whose new signal is best-effort with a bounded grace window; the only observations are cosmetic or a self-healing one-time rollout artifact.
Testing
Baseline ran the full e2e suite green; on top of that I exercised the two core regression suites and the two hardened suites for this change, plus seven adjacent supervision suites, all green with no regressions. The assertions are behavioral, not just unit checks: the turn-end-guard repro spawns the real fm-watch-arm.sh against a deliberately slow watcher stub and samples the guard mid-startup, proving the guard no longer false-alarms during a healthy arm (root cause 1), while dead/wedged arm markers still alarm past their grace window; and dedicated tests prove the new /proc-starttime identity primitive is stable across reads while ignoring a simulated btime-drifting ps lstart (root cause 2). This is a supervision/CLI change with no UI surface, so evidence is CLI test transcripts rather than screenshots.
Evidence: Core regression suite transcript (fm-turnend-guard + fm-watcher-lock, all assertions green)
Evidence: Race-fix highlight assertions (arm-in-progress silence, dead/wedged arm alarm, /proc starttime stability vs lstart drift)
ok - fm-turnend-guard: blocks on a wedged arm (live pid, marker stale past grace) ok - fm_pid_starttime_ticks is stable across reads of an unchanged live pid ok - fm_pid_identity ignores a drifting ps lstart once /proc is available (simulated btime-drift regression) ok - guard: silent with no fresh watcher beacon while a live in-progress arm marker exists ok - guard: still warns when the arm marker names a dead pid ok - fm_watcher_lock_matches_pid retries a transient ps failure and still confirms identity ok - fm_watcher_lock_matches_pid still fails (bounded retry) when ps never recovers ok - fm-turnend-guard: silent during a real fm-watch-arm.sh startup race (repro: sampled before the watch lock exists)Pipeline
Updates from git push no-mistakes
✅ **intent** - passed
✅ No issues found.
✅ **Rebase** - passed
✅ No issues found.
bin/fm-wake-lib.sh:163- fm_arm_marker_write doesrm -rf "$dir"thenmv "$tmp" "$dir"non-atomically. With two arms racing, the interleave (B rm -> A mv -> B mv) makes B'smvland inside A's now-existing directory as a nested.watch-arm.marker.XXXXXXsubdir rather than replacing it. The top-level marker files stay valid (last full writer wins) and the stray subdir is removed by the eventual pid-guarded clear, so impact is cosmetic clutter only. A directory-atomic swap is awkward cross-platform (macOS), so this is acceptable as-is.bin/fm-wake-lib.sh:69- Switching the identity format from ps-lstart to/procstarttime means a watcher armed before this deploy has an lstart-form identity stored in its lock, which the post-deploy fm_pid_identity reads in /proc form -> one-time identity mismatch -> a single false 'watcher down'/turn-end block until the next re-arm rewrites the lock in the new form. This is inherent to any identity-format change and self-heals within one turn (re-arm restarts the watcher), so no action is needed, but worth noting for the rollout.🔧 **Test** - 1 issue found → auto-fixed (3) ✅
command -v tmux >/dev/null || { echo "tmux is required for e2e tests" >&2; exit 1; }; tmux -V; rc=0; for t in tests/*.test.sh; do echo "== $t =="; bash "$t" || rc=1; done; exit "$rc"🔧 Fix: harden dispatch-select and session-start tests against jq path, system node, and harness env leaks
1 error still open:
command -v tmux >/dev/null || { echo "tmux is required for e2e tests" >&2; exit 1; }; tmux -V; rc=0; for t in tests/*.test.sh; do echo "== $t =="; bash "$t" || rc=1; done; exit "$rc"🔧 Fix: start default herdr session so tripwire-gated e2e tests pass
1 error still open:
command -v tmux >/dev/null || { echo "tmux is required for e2e tests" >&2; exit 1; }; tmux -V; rc=0; for t in tests/*.test.sh; do echo "== $t =="; bash "$t" || rc=1; done; exit "$rc"🔧 Fix: no changes needed; full test suite already passes
✅ Re-checked - no issues remain.
command -v tmux >/dev/null || { echo "tmux is required for e2e tests" >&2; exit 1; }; tmux -V; rc=0; for t in tests/*.test.sh; do echo "== $t =="; bash "$t" || rc=1; done; exit "$rc"bash tests/fm-turnend-guard.test.sh— 36 assertions green, incl. "silent no-op during a healthy in-progress arm with no watch lock yet", "blocks when the arm marker's pid is dead", "blocks on a wedged arm (live pid, marker stale past grace)"bash tests/fm-watcher-lock.test.sh— 29 assertions green, incl. "fm_pid_starttime_ticks is stable across reads of an unchanged live pid", "fm_pid_identity ignores a drifting ps lstart once /proc is available (simulated btime-drift regression)", "silent during a real fm-watch-arm.sh startup race (repro: sampled before the watch lock exists)", "guard: silent with no fresh watcher beacon while a live in-progress arm marker exists", "still warns when the arm marker names a dead pid", bounded-retry recover/still-fail casesbash tests/fm-dispatch-select.test.shandbash tests/fm-session-start.test.sh— hardened suites from commit 6136f6b, both greenbash tests/fm-arm-pretool-check.test.sh tests/fm-wake-queue.test.sh tests/fm-watch-triage.test.sh tests/fm-watch-checkpoint.test.sh tests/fm-tangle-guard.test.sh tests/fm-crew-state.test.sh tests/fm-supervision-instructions.test.sh— 7 adjacent supervision suites, all greenBaselinefor t in tests/*.test.sh; do bash "$t"; donealready ran green per the configured test command✅ **Document** - passed
✅ No issues found.
✅ **Lint** - passed
✅ No issues found.
✅ **Push** - passed
✅ No issues found.