Repository navigation
fix: recover watcher continuity and reduce decision-fold overhead - #73
Merged
Merged
Conversation
- Every whole-file open-decision fold starts read-only from the drain's per-task checkpoint, so drain, home summary, crew state, and captain-hold reads no longer refold megabyte status logs from line 1 (largest lane log: 19.8 s to 0.08 s, identical output); the snapshot carries the checkpoint onto its point-in-time copies. Closed decisions are compacted out of that checkpoint; the status logs themselves are not rewritten, because workers append without a lock, captain-hold divergence reads closing lines, and the presentation and wake cursors are byte offsets into those logs. - A declared pause for a still-open decision's own key is that decision's current state, so an idle worker waiting on its answer reads paused, not parked. - The omp and Pi primary watcher extensions record every lifecycle transition, heal a generation stopped without a successor, and keep one live instance per home. - Second-mate restarts are recorded durably and finished by supervision once the mate answers and its turn ends, replacing the fixed 900 s wait; the restart and the automatic relaunch share one per-mate lock. - Wake queue: watcher (`bin/fm-watch.sh`) appends rows; `bin/fm-wake-drain.sh` presents them, folds OPEN DECISIONS through the per-task checkpoint (`status_open_decisions_incremental`, the only checkpoint writer), and runs `fm-captain-hold.sh diverged` (whole-file folds). - Whole-file fold readers: fleet snapshot / home summary (`fm-fleet-snapshot.sh`, per task, plus `fm-crew-state.sh` -> `status_current_line`), `fm-captain-hold.sh` (complete, verify, diverged), `fm-send.sh --resolve-key`, `fm-pending-reply-lib.sh`, `fm-afk-return.sh`, `status_has_open_needs_decision`. All now start read-only from the checkpoint the drain keeps. - Arm and delivery: omp and Pi primary watcher extensions own one session generation each; the generation spawns `fm-watch-arm.sh` (or the supervision host) and delivers actionable closes to main; the replacement handoff file carries undelivered closes across session replacement. - Restart: `fm-secondmate-restart.sh` (persist request through `fm-send.sh` + pending-reply record) -> durable restart request -> service under the per-mate liveness lock -> `fm-control.sh relaunch` / `fm-remote-secondmate-relaunch.sh`. - Auto-relaunch: watcher `secondmate_liveness_tick` and the session-start sweep (`fm-bootstrap.sh`) probe and relaunch dead mates through `fm-secondmate-liveness-lib.sh` under the same per-mate lock. - (a) Fold: every open-decision reader. Output is byte-identical to the fold from line 1 by construction (the checkpoint is that fold of the prefix) and by the golden test; any doubt about a checkpoint falls back to line 1. Readers stay pure reads; only the drain writes checkpoints. A fold checkpoint is carried onto snapshot copies only when it describes that copy. The fold version moved to the fold's own library (no semantic change, no version bump). - (b) omp/Pi extensions: generation lifecycle and the arm tool. Self-heal binds exactly the generation `session_start` would, so a late real successor finds a live generation and arms nothing twice; terminal quit on Pi never heals; a superseded Pi instance keeps the stale refusal; a superseded omp instance forwards its arm call to the live one. Lifecycle logging never throws. - (c) Restart: the persist gate is unchanged (correlated answer); the clock is replaced by the turn-end event; unanswered requests stay with the pending-reply recovery ladder exactly as before; a turn that never ends wakes once after `FM_BUSY_TURN_MAX_SECS` and stays recorded. - Same-key pause: `status_current_line` reads a standing `paused` declaration for the same key as a still-open decision as that decision's current state; the decision stays open in the fold (OPEN DECISIONS, fleet snapshot), and an open decision under another key, a newer decision, a captain-held transfer, and an active turn keep their precedence. The watcher's stale path is unchanged: `pause_state_class` still answers `none` for a live ordinary crew by design and bounds it to once per declaration per `FM_PAUSE_RESURFACE_SECS`. - (d) Race: the restart holds the liveness lock across stop and relaunch, so the liveness probe cannot read the gap as a dead endpoint; a liveness relaunch in progress defers the restart; a successful auto-relaunch retires a waiting restart with an outcome instead of leaving it waiting on a dead agent. - Deleted: `FM_SECONDMATE_PERSIST_WAIT` (900 s). Its cause - a fixed wait on an event (the mate's turn end) that can be hours away - is removed by the event-driven restart (report sections 5 and 9, F9). - Added, each logging waiter, waited-on, bound, and actual once per expiry: `FM_OMP_SUCCESSOR_GRACE_MS` and `FM_PI_SUCCESSOR_GRACE_MS` (15 s, lifecycle log `event=bound-expired`), and the existing `FM_BUSY_TURN_MAX_SECS` reused for the long-turn restart notice (watcher triage log `bounded wait expired:`). - No timeout was raised. No composer recognizer was added. - New golden fold equivalence: every line boundary of a corpus covering every fold rule, for ship, scout, and secondmate, seeded fold == fold from line 1, and the seeded fold reads only the tail; refusal of foreign-reading checkpoints; snapshot carry; opt-in run over real status logs (`FM_FOLD_GOLDEN_DIRS`). - New restart: queued instead of timed out, finished by supervision, turn-end gate, shared lock with the auto-relaunch, request reuse; watcher surfacing, auto-relaunch retirement, long-turn notice. - New extension: omp shutdown without start -> exactly one re-arm; shutdown then start -> no double arm; arm call heals; double load -> one live generation and one arm; Pi replacement heal once, real successor no double arm, quit never heals. - New same-key pause: fold-level precedence cases plus the real `fm-crew-state.sh` and `crew_absorb_class` (parked/none before, paused/paused after; an active turn still reads working); both fail on the base as a negative control. - Existing suites rerun: fm-secondmate-restart, fm-omp-harness, fm-pi-watch-extension, fm-pi-primary-types (tsc 5.6.3, Pi 1.0.2), fm-wake-drain-open-decisions(-cursor), fm-wake-queue, fm-watch-triage, fm-watch-recovery-loop, fm-secondmate-liveness, and the others listed in the evidence.
…ion checkpoint boundaries
…completion replay
…ompletion fixture
… admitting secondmate restarts
…le-equivalent checkpoints
…bshell annotation
… successor handoff
MrGTV-love
force-pushed
the
fm/fm-lifecycle-phase3
branch
from
October 9, 2026 13:31
0cec3a3 to
a891a0a
Compare
MrGTV-love
changed the title
…Serial 1, 10, and 4: isolated C-locale byte counting so guarded status appends and annotation rendering preserve the caller’s locale when validating fold checkpoints; extended behavioral coverage for multibyte closes, quiet bookkeeping, later worker wakes, and annotation replay. Serial 3: Pi and omp expiry paths now enforce monotonic deadlines and record measured elapsed time, with deterministic early-callback and backwards-clock coverage. No timeout or bound changes; Pi diagnostic-only recovery remains unchanged. Verification passed: reported triage and multi-key send scenarios, six focused queue/annotation scenarios, eleven Pi lifecycle scenarios, eleven omp lifecycle/wake scenarios, and source-aware ShellCheck. The fold suite passed locale invalidation, UTF-8 byte offsets, golden equivalence, partial-line refusal, I/O recovery, and checkpoint carry before its local deadline. Complete local suites were not green: the broad run encountered unrelated lock-timing failures and timed out. Disposable verification files were removed; relevant docs updated
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
1 participant
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
when agents time out we need to understand why they timed out
and fix the root cause
When looking at the timeouts and harness issues, assess individual fixes, but also assess as a system with dependencies. We often fix one thing to break another. I want to fix without breaking. I want to fix without needing to fix again.
2. yes. build the fix plan
Context: data/timeout-rca-20261007/report.md (read it fully; sections 6-9 and 13). This task is its Phase 3, which must land together because all parts share the arm, delivery and relaunch path: (a) incremental decision fold plus closed-decision compaction (drain and home-summary re-parse ~5 MB of status logs from line 1 every time: 131-240 s wall), shipped with a golden equivalence test; (b) F8 omp extension lifecycle log, generation self-heal, single-instance guard (.omp/extensions/fm-primary-omp-watch.ts and the .pi sibling): d1 and d4 lanes show "watcher: not armed - omp session is shutting down" with no successor; (c) F9 event-driven secondmate restart replacing the fixed 900 s wait in bin/fm-secondmate-restart.sh; (d) open backlog fm-restart-autorelaunch-race; (e) firstmate PR 40 (fm-omp-lane-wake-unsubmitted, #40) is in CI now: build on it after it merges, do not duplicate it.
Substance of the referenced report (data/timeout-rca-20261007/report.md, a private record not in this repository):
Dependency map (section 6). The waits this phase touches: E13, the omp primary watcher extension waits forever for a session_start after a session_shutdown, failing as the "session is shutting down" dead end; E14, fm-secondmate-restart waits a fixed 900 s for the mate's persist answer, failing as "did not confirm within 900s"; E11, fm-send waits on worker inbox acknowledgement, and a lane that cannot restart or re-arm goes deaf so its messages escalate and stall (cycle of harm: E13/E14 feed E11); E18, every bounded wait competes for the same host CPU, so work that grows with history becomes a timeout under load.
Blast radius and proof (section 7):
History (section 8). Earlier fixes in this area were made at the symptom boundary: composer screen recognizers added seven or more times, watcher liveness bounds raised twelve or more times (several explicitly for slowness under load), and the dead-secondmate auto-relaunch and relaunch-on-session-end fixes were followed by a race between relaunch and restart (the open fm-restart-autorelaunch-race). The cause stays, so the next spike fails at the next weakest bound.
Fix plan (section 9, updated by section 16), Phase 3, together: incremental decision fold plus closed-decision compaction; F8; F9; fm-omp-lane-wake-unsubmitted; fm-restart-autorelaunch-race. Must not: raise any timeout (including the 900 s) before the cause behind it is fixed; add another composer recognizer for load-induced partial frames; restart the shared no-mistakes daemon to clear slowness. Throughout, F10 applies.
Timeout 4a (section 4, the F8 item). The omp primary watcher refuses every arm call with "watcher: not armed - omp session is shutting down" once a generation is stopped by session_shutdown, because a new generation is created only on a later session_start, which may never come for this extension instance. Unproven candidate causes: omp emitting session_shutdown for an internal event (such as a compaction pass) without a matching session_start, or a second instance of the extension loaded into the same process (the file header warns naming it both ways loads it twice) making the other instance's generation non-live. Fix: (1) log every session_start, session_shutdown and generation create, activate and stop with timestamps to state/extensions/omp-primary-watch/lifecycle.log; (2) remove the dead end: if a generation stopped without a successor and the process is still alive after a bounded grace, activate a fresh generation (idempotent self-heal) instead of refusing every arm call forever; (3) enforce a single extension instance per process; (4) land together with fm-omp-lane-wake-unsubmitted, same arm and delivery path.
Timeout 4b (section 5, the F9 item). bin/fm-secondmate-restart.sh sends a persist request and waits a fixed 900 s for the mate's own answer, but a mid-turn mate queues the request behind its turn, and lane turns can run for hours, so the fixed timer cannot succeed. Fix: (1) record the restart request durably and perform it at the lane's next turn end, deleting the 900 s limit; (2) the persist step must not need a model turn for state that is already durable (backlog, status, inbox); (3) fold in fm-restart-autorelaunch-race: the same durable request record is the lock the watcher auto-relaunch must honor.
fm-restart-autorelaunch-race: a secondmate restart driven by fm-secondmate-restart collided with the watcher's automatic relaunch of the same secondmate (the d3 restart), because the two relaunch paths did not coordinate.
Timeouts 5 and 6 (section 13, the fold item). The wake drain exceeded 120 s and the home-summary refresh exceeded its 60 s deadline in every run (276 times in one day). The cause: every drain, refresh, spawn, teardown and session start re-folds every append-only status log from line 1 in bash through the status_open_decisions fold; three lane logs alone took 131 s wall (d7 1,330 KB 50.3 s, d5 916 KB 66.2 s, d1 421 KB 15.0 s), the main home holds about 5 MB of status lines that are never compacted, and the cost grows with every status line forever while load multiplies it. Fix: (1) incremental fold: persist the open-decision set with the byte offset folded so far per status file, invalidated by inode change or size shrink, so each call folds only new bytes, removing the growth term; (2) compact closed decisions: a resolved key's lines can move to state/archive/ since the drain never needs them; (3) only then re-check whether the 60 s refresh deadline still fires, and do not raise it first. Blast radius: every reader of open decisions (drain, bearings snapshot, crew state, home summary, lane secondmates). Proof: a golden test comparing incremental and full fold on all current status logs gives identical output, and fold time on the d7 log is under 1 s.
PR 40 (fm-omp-lane-wake-unsubmitted): recovers omp lane wakes whose text was left unsubmitted in the composer. It has since landed on main as #48; this change builds on it and does not duplicate it.
Later decisions:
On the new open decision -- S -- split
(The open decision was whether to keep the event-driven secondmate restart (c) and fm-restart-autorelaunch-race (d) in this change. S = split: (c) and (d) are removed from this change and restored to their origin/main behavior; they ship separately. This change keeps (a) the decision fold, F8 and F10.)
On physical closed-decision compaction of status logs: A - checkpoint-only now; physical compaction comes later as a follow-up with a locked append helper.
What Changed
Risk Assessment
Testing
Targeted regressions and real drain, snapshot, omp, and Pi scenarios passed after correcting disposable setup/oracle issues and sharding the exhaustive golden check without reducing coverage. Warm production folds on a 1.4 MB synthetic log took 18–34 ms. CLI transcripts, lifecycle records, and screenshots rendered from actual ANSI captures were retained; fixtures were removed and no owned product processes remained. No full repository suite or other pipeline phase was run.
Evidence: Complete test-phase execution ledger
Source: Complete test-phase execution ledger
Evidence: Real drain surfaces buried decisions
Source: Real drain surfaces buried decisions
Evidence: Warm fold timings and returned blocker
Source: Warm fold timings and returned blocker
Evidence: Real locale-dependent parsing and checkpoint rebuilding
Source: Real locale-dependent parsing and checkpoint rebuilding
Evidence: Real fleet snapshot preserves secondmate decisions
Source: Real fleet snapshot preserves secondmate decisions
Evidence: omp lifecycle transitions before rotation
Source: omp lifecycle transitions before rotation
Evidence: Pi reload ownership and successor-missing expiry
Source: Pi reload ownership and successor-missing expiry
Evidence: Default omp readiness and retirement expiry records
Source: Default omp readiness and retirement expiry records
Evidence: Default Pi readiness and retirement expiry records
Source: Default Pi readiness and retirement expiry records
Evidence: Pi terminal-quit retirement expiry
Source: Pi terminal-quit retirement expiry
Evidence: Disposable fixture and process cleanup
Source: Disposable fixture and process cleanup
Pipeline
Updates from git push no-mistakes
... (15 earlier update rounds omitted to keep the PR body within GitHub's 65536-char limit; full history is in the run log.)
🔧 **Review** - 2 issues found → auto-fixed (6) ✅
🔧 Fix applied.
✅ Re-checked - no issues remain.
🔧 **Test** - 2 issues found → auto-fixed ✅
bin/fm-classify-lib.sh:291- The required under-one-second fold performance was not consistently demonstrated. Against a disposable 1,326,045-byte status log, three warm calls timed inside an already-loaded Bash process took 2.321s, 1.481s, and 0.541s. Functional output and incremental byte-read behavior were correct, but this loaded host still exceeded the target twice. The focused checkpoint suite also exceeded its 1800-second command deadline after completing its locale and golden-equivalence cases. These observations do not establish a new regression versus the base, but they leave the required performance acceptance unresolved. Profile the remaining warm-path cost under representative load and provide the private d7 corpus for the requested benchmark; do not raise product bounds.env TMPDIR="$PWD/.phase3-live" bash tests/fm-wake-drain-open-decisions-cursor.test.shwith 300-second and 1800-second command deadlines; both timed out, with the longer attempt completing locale, terminal/kind-transition, and golden-equivalence cases.bin/fm-wake-drain.shagainst disposable data: initial open decision, appended resolution/new decision, unchanged read, truncation, and inode replacement.Executedstatus_open_decisions_incrementalandstatus_open_decisionsunderCandC.UTF-8, comparing real incremental/read-only folds against checkpoint-free full folds.Compared real incremental and full folds across generated event prefixes, including keyed updates, resolution, captain-held transfer, UTF-8 whitespace, and an unfinished final line.Used Bash builtintimeto measure three warm folds of a 1,326,045-byte synthetic log after library loading.node .phase3-live/pi-runtime.mjsusing the installed Pi SDK: duplicate explicit entrypoints, idempotent arm tool, successful reload, and failed reload without a successor.bin/fm-herdr-lab.sh provision/run/teardownon a named non-default lab: real omp 18.8.1, duplicate entrypoints, actual production watcher scripts, a disposable local HTTP model, and injected lifecycle events using the live harness context.Drove recovered omp notification delivery behind an advisor note; observed the model receive the notification while the operator draft remained unsent.Exercised successor-before-grace behavior, inspected exactly one production watcher descendant, and verified lifecycle-log rotation.Injected a one-shot arm-launch delay and observed default 12000ms readiness and 1000ms retirement expiry records and the visible diagnostic.Ran targeted omp/Pi extension suites; encountered real-ancestor detection interference and an expiry-fixture startup race. Replaced the expiry fixture's Node child with a shell child that ignores TERM before publishing readiness, without changing bounds.NODE_NO_WARNINGS=1 node tests/watch-lifecycle-expiry.mjs omp <disposable-fixture> && NODE_NO_WARNINGS=1 node tests/watch-lifecycle-expiry.mjs pi <disposable-fixture>passed after the test-only fix.Captured the actual Herdr ANSI viewport, rendered it to HTML, captured a Chromium screenshot, closed the browser, verified guarded lab teardown, and removed all disposable worktree scaffolding.🔧 Fix applied.
✅ Re-checked - no issues remain.
bin/fm-wake-drain.shagainst disposable homes: bootstrap, append and resolve, unchanged read, truncation, and inode replacement.bash -c '. "$1"; TIMEFORMAT="seconds=%R"; for n in 1 2 3 4 5; do time status_open_decisions_incremental "$2"; printf "\n"; done'against a 1,357,598-byte synthetic status log.FM_TEST_ONLY=test_seeded_whole_file_fold_matches_a_fold_from_line_one bash tests/fm-wake-drain-open-decisions-cursor.test.sh.FM_TEST_ONLY=test_utf8_whitespace_uses_full_fold_locale bash tests/fm-wake-drain-open-decisions-cursor.test.sh.FM_TEST_ONLY=test_checkpoint_rejects_a_previous_parsing_locale bash tests/fm-wake-drain-open-decisions-cursor.test.sh.Realbin/fm-wake-drain.shcalls underLC_ALL=C,LC_ALL=C.UTF-8, andLC_ALL=Con identical status bytes, followed by UTF-8 keyed resolution.Realbin/fm-wake-drain.shseeded-versus-fresh output comparisons for ship, scout, and secondmate histories after completing an unterminated line.FM_PI_PACKAGE_DIR=~/.npm-global/lib/node_modules/@earendil-works/pi-coding-agent node .phase3-retest-Y4uDvp/pi-runtime-driver.mjs: real Pi resource loader, duplicate entrypoints, arm-tool execution, successful reload, and deliberately failed replacement loading.bin/fm-herdr-lab.sh provision/run/teardown fm-lab-phase3-retest-29921-24794: real omp 18.8.1 sessions with a sized foreground viewer, isolated homes, and a disposable local HTTP model provider.Real omp lifecycle handlers invoked through disposable fault-injection commands: shutdown without successor, shutdown followed by session start, retained-context wake delivery behind an advisor note, draft preservation, and singleton process inspection.Real omp expiry paths exercised with launch delays: default 12,000 ms arm readiness, 30,000 ms host readiness, and 1,000 ms retirement bounds; lifecycle rotation exercised across the size threshold.Captured the real Herdr ANSI viewport, rendered it to HTML, and saved a Chromium screenshot.Guarded Herdr teardown passed the fleet-state tripwire; disposable homes, drivers, and worktree fixtures were removed, the local provider stopped, and no owned watcher or supervision-host commands remained.✅ No issues found.
python3 .round3-fold-live-driver.py: real wake-drain growth, resolution, checkpoint invalidation, and loaded-Bash performance checks.node .phase3-live/fold-cli-golden.mjs: seeded versus unseeded real drain output for ship, scout, and secondmate.node .phase3-live/fold-cli-locale.mjs: real drain under C → C.UTF-8 → C using EM SPACE and UTF-8 text.node .phase3-live/fleet-snapshot-live.mjs: realbin/fm-fleet-snapshot.sh --jsonon a private tmux socket.node .phase3-live/omp-live.mjs: real omp duplicate loading, missing-successor recovery, successor handoff, advisor-tail wake delivery, draft preservation, rotation, and shutdown expiry.node .phase3-live/pi-cli.mjs: real Pi duplicate loading, three reload handoffs, and deliberately failed reload.node .phase3-live/omp-expiry-live.mjs: real default arm-readiness, host-readiness, and unready-retirement expiry paths.node .phase3-live/pi-expiry-cli.mjsandnode .phase3-live/pi-quit-expiry-cli.mjs: real Pi readiness, unready-retirement, and Ctrl-D shutdown expiry paths.Focused Pi regressions:test_watch_instance_rebind_releases_predecessors,test_pi_missing_successor_reports_without_rearming,test_pi_factory_replacement_retires_and_hands_off, andtest_pi_lifecycle_deadline_diagnostics.Focused omp regressions:test_watch_extension_heals_a_generation_stopped_without_a_successor,test_watch_extension_is_single_instance_per_home, andtest_watch_lifecycle_deadline_diagnostics.FM_TEST_ONLY=test_checkpoint_rejects_a_previous_parsing_localeandFM_TEST_ONLY=test_utf8_whitespace_uses_full_fold_localeagainst the existing checkpoint suite.The monolithictest_seeded_whole_file_fold_matches_a_fold_from_line_oneexceeded its 300-second command deadline; identical assertions subsequently passed in ship, scout, and secondmate shards, retaining every boundary and split offset.Exploratory SDK/loading attempts and disposable-driver setup corrections are recorded inround3/execution-ledger.json; final proofs used genuine CLIs and isolated local providers.Rendered actual private-tmux ANSI captures, captured reviewer-visible PNGs through Chromium, and removed disposable fixtures, local dependencies, and temporary test runners.✅ **Document** - passed
✅ No issues found.
✅ No issues found.
🔧 **Lint** - 1 issue found → auto-fixed ✅
🔧 Fix applied.
✅ Re-checked - no issues remain.
✅ No issues found.
✅ **Push** - passed
✅ No issues found.
✅ No issues found.