fix(bin): keep the watcher beacon truthful and bound every herdr RPC - #2789
fix(bin): keep the watcher beacon truthful and bound every herdr RPC#2789Zuschaua wants to merge 9 commits into
Conversation
…rdr backend A wedged herdr server (seen after a machine-sleep window) accepts connections but responds after minutes or never. Every herdr control-socket RPC was unbounded, so the watcher's per-window reads stretched one supervision cycle far past FM_GUARD_GRACE while the loop was still absorbing wakes correctly; the beacon, touched only at the top of each cycle, went stale, and every guard declared a live watcher down, triggering arm churn. The same unbounded calls hung fm-peek and teardown chains through the capture path's server-ensure poll. - Bound every herdr RPC with FM_BACKEND_HERDR_CLI_TIMEOUT (default 20s, timeout/gtimeout/perl-alarm); only the long-lived backgrounded server launch bypasses the bound. - Bail out of the server-ensure poll after three consecutive failed status reads instead of multiplying the bound by the whole poll budget. - Bound the event-wait FIFO reads to the reader budget plus slack and classify a reader wedged past it unusable (rc 2), discriminating timeout from EOF by reader liveness (Bash 3.2 returns 1 for both); escalate a stopped reader's kill to KILL before reaping. - Refresh the beacon between backend reads (per window, per check, after the signal grace); the cycle counter in the beacon's content still advances only at cycle top so cycle-boundary consumers stay exact. Exit the cycle when the beacon cannot be written so no lock-holder survives with a beat that can never resume. - Replace the capability probe's printf-into-grep schema checks with pipeline-free case matches, removing the broken-pipe noise seen in arm outputs under ignored SIGPIPE. The watcher graph runs without errexit, so the printf EPIPE failures were never fatal; the beacon staleness came entirely from cycle elongation by unbounded RPCs.
Confidence Score: 5/5The PR appears safe to merge. No blocking failure remains. Reviews (2): Last reviewed commit: "no-mistakes(ci): raise the no-mistakes f..." | Re-trigger Greptile |
|
Speaking as Kun's firstmate: Corrective for the #2786 class: a living watcher must keep beating, and a Herdr RPC must be bounded so a hang cannot hold the lock with a stale beacon. Aligns (never hide a failure behind a living lock; restart is a non-event). Not merge-eligible yet: no Actions checks on this HEAD besides Greptile. Fork CI must run including no-mistakes. Overlap with watch/classify and #2786. Waiting on CI — not waiting on the captain. |
|
Speaking as Kun's firstmate: Corrective watcher/herdr honesty fix. Relates to #2786 (watcher stays alive but the beacon goes stale while the lock is held): the watcher now refreshes VISION (per rule):
Security: no. The beat hook is word-split, not evaluated as shell, and is not exported. Overlap: CI: first-time fork workflows approved after diff review (CI 32565306990, Require no-mistakes 32565306997). Greptile is green. Portable CI / no-mistakes have not finished. Body has the Ahead 8, behind 0, mergeable, mergeStateStatus UNSTABLE. Waiting on the author for attestation and green no-mistakes — not waiting on the captain. Merge-eligible: NO. Captain-flag NOW: NO. |
2 participants
Intent
The developer needed a liveness-reporting defect fixed in firstmate's watcher on the herdr backend: the watcher kept absorbing wakes but stopped touching its
state/.last-watcher-beatbeacon, so guards declared WATCHER DOWN/FAILED and turn-end auto-arms spawned duplicate cycles, causing restart churn without any real wake loss. They asked for the failure path to be causally pinned inbin/fm-watch.sh/bin/backends/herdr.sh(specifically the broken-pipe printf errors around herdr.sh:3052-3053, errexit interactions, and early continue/return after backend errors), and then fixed so a cycle that is alive keeps beating even when a backend read or write fails, with backend pipe errors guarded, bounded-logged, and non-fatal. They also wanted the separately observed herdr read hangs (a 120s+fm-peek, a stalled gh+teardown chain) investigated rather than assumed related — fixed or bounded if they shared the root cause, otherwise noted as a distinct finding in the PR body — plus machine-sleep resilience so a post-sleep watcher either resumes beating or exits cleanly instead of holding the lock with a stale beat. Constraints: load thefirstmate-coding-guidelinesskill before editing sharedbin/material and follow repo style (one sentence per line in docs, shellcheck-clean scripts, colocatedtests/regression tests covering beacon-touched-despite-write-failure and loop-survives-EPIPE, no agent co-author, maintainer-verification evidence); update only the doc that owns each changed contract (docs/turnend-guard.md,watcher-continuity.md, script headers); work only in the disposable worktree, never restart or touch any live watcher, neverpkill, and never use this home'sstate/. Definition of done was the full no-mistakes pipeline driven to a PR with CI green, with the developer later insisting explicitly that a green local gate was not delivery and that the pipeline, push, and PR had to be completed.What Changed
bin/fm-watch.shrefreshesstate/.last-watcher-beatthrough a newwatcher_beathelper that fires at the top of every cycle and between the bounded backend reads inside a cycle, so a slow backend can no longer age the beacon pastFM_GUARD_GRACEwhile the loop is still absorbing wakes; a beacon the watcher cannot write now ends that cycle instead of leaving a lock-holder whose beat can never resume. The shared loops whose wall time scales with the fleet (fm_pending_reply_tick,signal_crew_provably_working) reach the same beat through the newFM_LIVENESS_BEAT_HOOK/fm_liveness_beatcontract inbin/fm-classify-lib.sh, invoked as a command word plus arguments and never evaluated as shell source text.bin/backends/herdr.shnow runs underFM_BACKEND_HERDR_CLI_TIMEOUT(default 20s,0disables) viabin/fm-timeout-lib.sh, with only the backgrounded server launch exempt. The server-start poll cuts short only on consecutive RPC-bound hits — instant cold-socket failures keep it polling — and is additionally capped by a wall-clock budget so no mix of outcomes can multiply the per-RPC bound across the poll; event-FIFO reads are bounded by the reader's budget plusFM_BACKEND_HERDR_EVENT_READ_SLACKand classify a wedged reader's path unusable. The separately reported 120s+fm-peekand stalled teardown chain share this wedged-server root cause and are bounded by the same change;bin/fm-herdr-ci-cleanup.shstill callsherdrdirectly and remains outside the bound.fm_run_timednow reports 128+signal for a signal-killed command and 127 for one it cannot exec, so a killedpane readis never mistaken for a successful capture of an empty pane, and the capability probe matches the ~220KB schema withcaseinstead of agreppipeline that emitted broken-pipe noise under ignored SIGPIPE. Newtests/fm-watch-beacon.test.shplus RPC-bound, poll, reader, and signal-status cases intests/fm-backend-herdr.test.shcover the above, withdocs/watcher-continuity.md,docs/herdr-backend.md, anddocs/configuration.mdrecording the contracts and the two new knobs.Risk Assessment
✅ Low: Every concern raised across the prior rounds is now fixed with discriminating regression tests, and the remaining worst case for the one function that multiplies the per-RPC bound is roughly 50s against a 300s guard grace, leaving no substantiated outstanding risk despite the change touching every herdr call site.
Testing
I ran the intent-targeted suites (fm-watch-beacon, fm-backend-herdr, fm-watch-triage, fm-session-start) - all green - and then reproduced the reported failure end-to-end rather than relying on unit passes: a real watcher plus real fm-guard.sh against a herdr backend whose every call hangs, once from the base commit and once from the fix. On base the watcher stays ALIVE while its beacon ages past grace and the guard prints the WATCHER DOWN banner and keeps reminding; on the fix the beacon never exceeds 16s of a 20s grace, the guard stays silent for the whole run, and the watcher emits no wake and no stderr. I also showed the operator-facing read hang (fm-peek 150s+ on base, 18s with a typed error on the fix) and the machine-sleep shape (SIGSTOP past grace reads down, SIGCONT resumes the beat and the guard goes silent again). Timings are scaled (grace 20s vs prod 300s, RPC bound 5s vs prod 20s) so a run finishes in a minute while preserving the bound-inside-grace ratio the fix depends on. This is a CLI/state-file change with no rendered UI surface, so the artifacts are CLI transcripts of the actual guard banner and peek behavior rather than screenshots. One caveat: the fixed pipeline-free capability probe is silent and reports capable, but I could not reproduce the base-side "printf: write error: Broken pipe" noise locally (it needs a write still in flight when grep exits), so that artifact confirms the fixed behavior only. The single test failure seen, tests/fm-pending-reply.test.sh's concurrent-resolution case, reproduces 4/4 on an unmodified base tree and is unrelated to the added beat hook. Transient scratch trees were removed and the worktree is clean.
Evidence: Evidence index (what each artifact proves, scaling caveats)
Evidence: BEFORE (base 5b6d0fb): live watcher, stale beacon, guard raises WATCHER DOWN
=== BEFORE (base 5b6d0fb): watcher against a wedged herdr backend === t= 5s watcher=ALIVE beacon-age=5s guard: (silent) supervision healthy t= 15s watcher=ALIVE beacon-age=15s guard: (silent) supervision healthy t= 20s watcher=ALIVE beacon-age=21s guard: WATCHER DOWN banner | ● WATCHER DOWN - SUPERVISION IS OFF | ● 1 task(s) in flight, but no watcher has a fresh beacon (last beat: 20s ago, grace 20s). t= 30s watcher=ALIVE beacon-age=31s guard: watcher still down reminder t= 60s watcher=ALIVE beacon-age=62s guard: watcher still down reminderEvidence: AFTER (fix bdbfd91): same wedged backend, beacon keeps advancing, guard silent
=== AFTER (fix bdbfd91): watcher against a wedged herdr backend === t= 15s watcher=ALIVE beacon-age=14s guard: (silent) supervision healthy t= 20s watcher=ALIVE beacon-age=0s guard: (silent) supervision healthy t= 35s watcher=ALIVE beacon-age=16s guard: (silent) supervision healthy t= 40s watcher=ALIVE beacon-age=3s guard: (silent) supervision healthy t= 60s watcher=ALIVE beacon-age=5s guard: (silent) supervision healthy === AFTER (fix bdbfd91): done === (watcher stdout 0 bytes: no spurious wake)Evidence: Machine-sleep shape: frozen past grace, then resumes beating after SIGCONT
running normally watcher=ALIVE beacon-age=7s lock-holder=84842 guard: (silent) supervision healthy >>> machine sleep: SIGSTOP the watcher for 25s (grace is 20s) frozen, past grace watcher=ALIVE beacon-age=33s lock-holder=84842 guard: WATCHER DOWN banner >>> wake: SIGCONT 8s after wake watcher=ALIVE beacon-age=7s lock-holder=84842 guard: (silent) supervision healthy 24s after wake watcher=ALIVE beacon-age=5s lock-holder=84842 guard: (silent) supervision healthyEvidence: Operator read path: fm-peek hangs 150s+ on base, bounded to 18s with a typed error on the fix
=== BEFORE (base 5b6d0fb): bin/fm-peek.sh tsk against a wedged herdr server === RESULT: STILL HANGING after 150s - killed (this is the reported symptom) === AFTER (fix bdbfd91): bin/fm-peek.sh tsk against a wedged herdr server === RESULT: returned after 18s with exit 1 | error: herdr server for session 'sess' did not report running within its 10s poll budget (gave up after 12s)Evidence: Re-runnable demo drivers (beacon/guard, machine sleep, peek hang, pipe noise)
Evidence: Capability probe under ignored SIGPIPE (fixed tree silent and capable; base noise not reproducible locally)
Pipeline
Updates from git push no-mistakes
✅ **intent** - passed
✅ No issues found.
✅ **Rebase** - passed
✅ No issues found.
bin/backends/herdr.sh:1525- The new consecutive-failure bail in fm_backend_herdr_server_ensure treats any non-zeroherdr status --jsonthe same, but its stated rationale ("each such failure already costs a full RPC bound") only holds for a bound-hit (rc 124). A status that fails instantly - the shape a cold control socket produces while the just-launched server is still binding - costs nothing, so three of them plus two 0.5s sleeps abort the ensure after roughly one second, where the pre-change loop polled the fullseq 1 20/ 10s budget. Failing sequence:herdr serveris backgrounded, the socket is not listening yet, the first three poll RPCs return connect-refused non-zero, server_ensure returns 1, and every fm_backend_herdr_target_ready consumer on that cycle (capture, agent_alive, spawn/container_ensure) fails even though the server comes up 2s later. Gate the counter on the bound actually being hit (rc 124) or bail on elapsed wall time instead of a raw failure count, which is what the comment's own reasoning describes.bin/fm-classify-lib.sh:55- fm_liveness_beat runseval "$FM_LIVENESS_BEAT_HOOK", evaluating an environment-derived string as shell code in every consumer of fm-classify-lib.sh and fm-pending-reply-lib.sh (fm-crew-state.sh, fm-brief.sh, fm-inactive-reconcile.sh, fm-fleet-snapshot.sh, fm-captain-hold.sh, ...), none of which previously evaluated env content. Direct invocation -$FM_LIVENESS_BEAT_HOOKunquoted - keeps the documented "a command" contract including word-split arguments, without the eval. It also hardens the watcher-continuity.md claim that no helper process can freshen the beacon: if a hook name is already marked for export in the inherited environment, fm-watch.sh's reassignment inherits that export attribute and children would evaluate it rather than treat it as an unknown name.bin/backends/herdr.sh:3456- The EOF-versus-timeout discriminator useskill -0 "$reader_pid"immediately after a failed read. A child that has just exited closes its FIFO write end before the parent is notified, so a still-unreaped zombie answerskill -0successfully and a clean full-budget wait (reader exit 0, contract rc 1) would be reported as rc 2 "event path unusable", which makes the caller sleep and count toward the runtime-disable threshold. I probed this 40 times with both a subshell and an external python writer on this host and it never fired - Bash's SIGCHLD reaping consistently wins the race - so this is a residual hazard rather than an observed defect, and the existing clean-timeout test does not exercise it because its fake reader exits long before the drain loop. A sentinel line from the reader, or comparing elapsed time against read_bound, would remove the dependence on reap timing.bin/fm-herdr-ci-cleanup.sh:39- bin/fm-herdr-ci-cleanup.sh callsherdr session list/stop/deletedirectly rather than through the adapter, so it is the one remaining herdr caller the new FM_BACKEND_HERDR_CLI_TIMEOUT bound does not cover; a wedged server hangs it exactly as it hung fm-peek before this change. It is off the watcher path and outside the stated scope of this fix, so noting it rather than treating it as a gap in the delivered work.🔧 Fix: gate server-ensure bail on RPC bound hits, drop hook eval
1 warning still open:
bin/backends/herdr.sh:1539- Narrowing the bail to rc 124 (correct) removed the only thing capping this poll's total wall time, becausebound_hitsresets to 0 on every non-124 outcome - including a successful status that answersrunning:false. Concrete shape, and the realistic one for a server still binding: a herdr whose status alternates between a fastrunning:falseand a bound hit never accumulates three consecutive 124s, so the loop runs all 20 attempts; roughly 13 of them burn the full FM_BACKEND_HERDR_CLI_TIMEOUT (20s default) = 260s, plus 20 x 0.5s of sleeps = 270s, plus up to 20s for the pre-loop status call = about 290s. Two consequences. (1) The error message at this line still asserts "did not report running within 10s" after what can be a near-five-minute wait, so the operator-facing diagnostic is now false. (2) This whole span sits inside a single gap between two watcher_beat calls in fm-watch.sh's per-window loop (watcher_beat -> window_kind -> fm_backend_capture -> target_ready -> server_ensure ->|| continue), leaving about 10s of headroom against the FM_GUARD_GRACE=300s that this entire change exists to stay inside; raising FM_BACKEND_HERDR_CLI_TIMEOUT above ~28s or lowering FM_GUARD_GRACE re-opens the exact stale-beacon failure. It also means a partially responsive server can still block fm-peek and teardown chains for ~290s, versus the 120s+ hang the change set out to bound. server_ensure is the single place that multiplies the per-RPC bound, so capping the whole poll on elapsed wall time (bail once cumulative elapsed exceeds a budget, independent of which failures occurred) is the earliest shared boundary that makes the per-iteration bound hold for any failure mix - and it makes the message at this line honest again. This is not the count-versus-rc124 question already settled in the prior round; it is the missing ceiling on the loop as a whole.🔧 Fix: cap server-ensure poll with a wall-clock budget
1 info still open:
bin/backends/herdr.sh:1541- With the wall-clock deadline in place, the consecutive-bound-hit bail can only fire when FM_BACKEND_HERDR_CLI_TIMEOUT is below roughly 4.75s. Reachingbound_hits -ge 3requires attempts 1 and 2 to pass the deadline check, i.e. 2t + 0.5 < 10; at the stock default of 20s the very first bound hit already puts elapsed at 20 >= the 10s deadline, so the loop breaks and the generic "poll budget" message is what an operator sees - the "hit the 20s RPC bound 3 times in a row" message is unreachable in the default configuration. The outcome is identical and correct either way (return 1, bounded well inside the grace), so this is defense in depth rather than a defect, and the covering test pins the timeout at 1s precisely so the bail stays exercised. Worth knowing when reading docs/herdr-backend.md's "three sides" sentence: the consecutive-bound-hit side describes a path that only manifests under a small configured bound, not at stock settings. Noting the layering, not asking for a change - the bail was added deliberately in an earlier round and removing it would be churn.tests/fm-pending-reply.test.sh:487- tests/fm-pending-reply.test.sh:487test_concurrent_resolution_closes_escalation_onceis flaky under load: it failed once in three HEAD runs and 4 of 4 runs on an unmodified base-5b6d0fb tree, so it is a pre-existing race in the test's 8-way concurrentfm_pending_reply_try_resolvefan-out, not a regression from the fm_liveness_beat call added to fm_pending_reply_tick. Flagging it only so a red CI run on this suite is not misattributed to this change.bin/fm-test-run.sh tests/fm-watch-beacon.test.sh- 7/7 pass (beacon advances under failing and hanging backends, unwritable beacon ends the cycle, FM_LIVENESS_BEAT_HOOK per-record/per-task, word-split not evaluated, unset hook is a no-op)bin/fm-test-run.sh tests/fm-backend-herdr.test.sh- pass, including the new RPC-bound, signal-status (137/127), pipe-noise-free capability probe, hung-reader, and three server-ensure poll casesbin/fm-test-run.sh tests/fm-watch-triage.test.sh- pass (always-on triage plus the beacon-stays-fresh case)bin/fm-test-run.sh tests/fm-session-start.test.sh- pass (covers the fm_run_timed signal/exec status contract changed in bin/fm-timeout-lib.sh)bin/fm-test-run.sh tests/fm-pending-reply.test.shx3 on HEAD (1 intermittent failure) and x4 on a base-5b6d0fb tree (4 failures) to classifytest_concurrent_resolution_closes_escalation_onceas a pre-existing flakeManual E2E:beacon-guard-demo.shdrives a realbin/fm-watch.shwith SIGPIPE ignored against a herdr fake whose every call hangs, samplingbin/fm-guard.shevery 5s - run once from a base5b6d0fbtree and once from the fixbdbfd91treeManual E2E:sleep-resilience-demo.shfreezes the fixed watcher with SIGSTOP for 25s (past the 20s grace) and resumes it with SIGCONT, sampling guard verdict, beacon age, and lock holderManual E2E:peek-hang-demo.shrunsbin/fm-peek.sh tskagainst the wedged herdr fake on both trees, wall-clock timedManual probe:pipe-noise-demo.shrunsfm_backend_herdr_events_capableundertrap "" PIPEwith a large fake schema on both treesAGENTS.md:131- Judgment call, deliberately left unedited: AGENTS.md:131 ("touched every poll") and bin/fm-supervision-lib.sh:8 ("touched every poll cycle") still describe the beacon only as a per-cycle touch, while the watcher now also refreshes it mid-cycle and writes a cycle counter as content. Both statements remain true as written, and the beacon contract's owner (docs/watcher-continuity.md, plus the watcher_beat header comment for the mtime-versus-content split) states the full behavior, so expanding either pointer would duplicate the owner rather than fix a wrong fact.✅ **Lint** - passed
✅ No issues found.
✅ **Push** - passed
✅ No issues found.