Skip to content

test(fm-branch-mod): add live e2e cases for branch persistence and child-session rotation - #31

Merged
andrewesweet merged 4 commits into
mainfrom
fm/fm-branch-live-gaps
Sep 19, 2026
Merged

andrewesweet merged 4 commits into
mainfrom
fm/fm-branch-live-gaps

Conversation

@andrewesweet

Copy link
Copy Markdown
Owner

Intent

Add two live e2e cases to tests/fm-branch-claude-mod-live-e2e.test.sh covering the RCA blind spots: (1) with CLAUDE_CODE_CHILD_SESSION=1 inherited by the branch agent, a minutes-later wake must rotate with why=unresumable to a fresh agent (second agent.spawn) and the wake must still be delivered to that fresh agent, never passed to main and never dropped; (2) with persistence on (the default scrubbed launch), the same minutes-later wake must resume the SAME agent: the send succeeds, no rotation, no new spawn. Reuse the existing harness and keep every existing assertion; use two fully separate labs (fresh tmux socket and scratch home per case) so stale counters or locks cannot leak across cases. The test pins the module's Claude Code version, so run it end to end on the pinned version and quote the ok lines and duration as evidence. Then bin/fm-lint.sh, a one-line docs mention in docs/claude-supervision-branch.md Verification, commit on fm/fm-branch-live-gaps, rebase onto the default branch, and validate through this pipeline to a PR. Design decisions made during the work, all deliberate: count assertions settle across append lag because module event lines are appended by fire-and-forget shell spawns and can become visible to the test late under load (a settle helper re-reads a failing count up to ten times before failing); the rotation chain is asserted by invariant (every rotation why=unresumable and ok:true, agent.spawn >= 2, wake.passed=0, handback.dropped=0) rather than a frozen rotation count because every fresh agent inherits the broken launch shape; the redundant pre-gap-send success equality assertion was dropped in favor of the rotation event's own sendDetail as proof of the failed resume. The live test ran green end to end twice: on the 2.1.277 PATH shim pre-rebase (6/6 ok, 379s) and post-rebase on the shipped 2.1.278 pin (6/6 ok, 410s).

What Changed

  • tests/fm-branch-claude-mod-live-e2e.test.sh now runs two fully separate labs (own tmux socket and scratch home each) and adds two minutes-later-wake cases: with transcript persistence on the wake resumes the same agent with a successful send and no rotation; with CLAUDE_CODE_CHILD_SESSION=1 inherited by the branch agent the wake rotates with why=unresumable to a fresh agent (a second agent.spawn) and is delivered there, never passed to main or dropped.
  • The harness gained lab factories (make_lab, start_claude_session, teardown_lab), a pause flag for the stand-in crewmate so no wake flows during the gap, a settle helper that re-reads a failing count up to ten times to absorb append lag, a min-count argument on wait_event, and a scrubbed tmux server launch (with an intentional SC2046 disable) so an ambient child-session marker cannot mask the defect; all four existing assertions are retained.
  • Docs: docs/claude-supervision-branch.md Verification mentions the two-lab persistence and rotation proof, and docs/verification/runtime-backends.md records the six-case live run on the 2.1.278 pin (6/6 ok, exit 0) with per-lab event counts.

🤖 Generated with Claude Code

Risk Assessment

✅ Low: Test-only and one-line docs change; both new labs assert exactly the intent's required outcomes (same-agent resume with no rotation/spawn, and unresumable rotation with delivery to the fresh agent and wake.passed=0/handback.dropped=0), every prior assertion survives in settled form, lab isolation (fresh socket, scratch home, per-lab shim/dummy paths, idempotent teardown) traces correctly, and the only finding is an optional tail loop that exceeds the stated scope.

Testing

Drove tests/fm-branch-claude-mod-live-e2e.test.sh live against Claude Code 2.1.278 (the module pin) with FM_BRANCH_MOD_LIVE=1 FM_BRANCH_MOD_LIVE_KEEP=1 from inside a Claude session whose environment carries CLAUDE_CODE_CHILD_SESSION=1, so the new tmux-server scrub was exercised for real. All six ok lines printed, exit 0, 474 s. Kept lab logs confirm the intent: lab 1 shows one agent.spawn, two agent.send both success:true resuming the same agent id a9d3ae4abc23edf8c, zero agent.rotated, and a genuine 100 s pause in dummy.status; lab 2 shows two agent.rotated why=unresumable ok:true with sendDetail "No transcript found for agent ID", three agent.spawn, three wake.delivered via spawn, wake.passed=0, handback.dropped=0, and a 95 s pause. A concurrent monitor read each lab's tmux server: show-environment -g carried no CLAUDE_CODE_CHILD_SESSION or CLAUDECODE on either socket, while the lab 2 pane child process did carry CLAUDE_CODE_CHILD_SESSION=1, proving the marker reaches only Claude's process env, not the ambient server. No UI surface; artifacts are CLI transcript and persisted event logs. Lab directories removed; worktree clean.

  • Live validation: ✅ go - 7 of 8 scenarios driven live against the product
Scenario Result Live Evidence
Lab 1 (scrubbed launch, persistence on): module loads on the pinned 2.1.278, main takes lock, first routine wake spawns the branch, captain wake passes to main with cover row, next routine wake reache… ✅ pass live live-e2e-run.log ok lines 1-3; lab1-persistence-on/branch-mod-events.jsonl
Lab 1: minutes-later wake after a real pause resumes the SAME agent: send success:true, agent.rotated=0, agent.spawn=1 ✅ pass live live-e2e-run.log ok line 4; lab1 events: 2 agent.send both success:true resumedAgentId a9d3ae4abc23edf8c, 0 agent.rotated, 1 agent.spawn; dummy.status shows a 100 s gap
Lab 1 whole run: one spawn, every send successful, no dropped hand-back, no backstop delivery ✅ pass live live-e2e-run.log ok line 5; lab1 events handback.dropped=0 backstop.delivered=0
Lab 2 (inherited CLAUDE_CODE_CHILD_SESSION=1): minutes-later wake rotates why=unresumable ok:true to a fresh agent (second agent.spawn), wake delivered via spawn, never passed to main, never dropped ✅ pass live live-e2e-run.log ok line 6; lab2 events: agent.rotated x2 why=unresumable ok:true sendDetail 'No transcript found for agent ID', agent.spawn=3, wake.delivered via spawn=3, wake.passed=0, handback.drop…
Adversarial: test run from a shell that itself carries CLAUDE_CODE_CHILD_SESSION=1; lab tmux servers must not inherit the marker into their global env (the round-1 false negative), while the lab 2 Cla… ✅ pass live tmux-env-scrub-check.log: both sockets server-global-env none; lab 2 pane child CLAUDE_CODE_CHILD_SESSION=1, lab 1 pane child none
Adversarial: the production gap actually elapses (stand-in paused, no status appends for >75 s) in both labs ✅ pass live lab1 dummy.status gap 100 s before step 23; lab2 dummy.status gap 95 s before step 7
Labs are fully separate: fresh tmux socket and scratch home per case, lab 1 torn down before lab 2, no lab directories left behind ✅ pass live live-e2e-run.log names two distinct lab roots /tmp/fm-branch-claude-live.eN4Mg0 and .yB8PJd; ls /tmp | grep fm-branch-claude-live empty after the run
Docs mention in docs/claude-supervision-branch.md Verification describes the two labs ⏸️ untested no Docs-only line; no runtime surface to drive. Read the diff only.
Evidence: Live e2e run on Claude Code 2.1.278 (6/6 ok, 474 s)

Source: Live e2e run on Claude Code 2.1.278 (6/6 ok, 474 s)

ok - Claude Code 2.1.278 loads the supervision-branch mod enabled and main holds the session lock ok - the first routine wake passes the classifier and spawns the branch agent, which reports it routine ok - the captain-class wake is passed to main by the classifier with a covering outcome row, and the next routine wake reaches the same agent through SendMessage ok - a wake after the in-memory window reaches the same persisted agent: the send succeeds, no rotation ok - one spawn, every send successful, no dropped hand-back, no backstop delivery across the run ok - a minutes-later wake on an inherited CLAUDE_CODE_CHILD_SESSION rotates to a fresh agent (why=unresumable) and keeps the wake EXIT=0 DURATION=474s

ok - Claude Code 2.1.278 loads the supervision-branch mod enabled and main holds the session lock
ok - the first routine wake passes the classifier and spawns the branch agent, which reports it routine
ok - the captain-class wake is passed to main by the classifier with a covering outcome row, and the next routine wake reaches the same agent through SendMessage
ok - a wake after the in-memory window reaches the same persisted agent: the send succeeds, no rotation
ok - one spawn, every send successful, no dropped hand-back, no backstop delivery across the run
ok - a minutes-later wake on an inherited CLAUDE_CODE_CHILD_SESSION rotates to a fresh agent (why=unresumable) and keeps the wake
# lab logs kept at /tmp/fm-branch-claude-live-logs.xaVs3m (lab /tmp/fm-branch-claude-live.eN4Mg0)
# lab logs kept at /tmp/fm-branch-claude-live-logs.jsrjzk (lab /tmp/fm-branch-claude-live.yB8PJd)
EXIT=0 DURATION=474s
Evidence: Lab 1 (persistence on) module events, dummy status, Claude debug log

Source: Lab 1 (persistence on) module events, dummy status, Claude debug log

{"t":"2026-09-19T13:43:08.704Z","kind":"session.start","data":{"cwd":"/tmp/fm-branch-claude-live.eN4Mg0/home","home":"/tmp/fm-branch-claude-live.eN4Mg0/home","state":"/tmp/fm-branch-claude-live.eN4Mg0/home/state","enabled":true,"generation":"cc1789825388309","version":"2.1.278"}}
{"t":"2026-09-19T13:43:11.942Z","kind":"prompt.submit","data":{"origin":{"kind":"composer"},"text":"Take this home's session lock with bin/fm-lock.sh, then reply ready."}}
{"t":"2026-09-19T13:43:12.016Z","kind":"turn.start","data":{"turnId":"4e96a437-ee9b-4093-a269-ad332d551517","text":"Take this home's session lock with bin/fm-lock.sh, then reply ready."}}
{"t":"2026-09-19T13:43:12.111Z","kind":"monitor.armed","data":{"why":"first prompt","monitorArms":1,"taskId":"bkxhujitd","text":"Monitor started (task bkxhujitd, expires in 30m unless the source ends first; you get one notice at expiry — re-arm if you still need the watch). You will be notified on each event. Keep working — do not poll or sleep. Events may arrive while you are waiting for the user — an event is not their repl"}}
{"t":"2026-09-19T13:43:16.222Z","kind":"turn.complete.main","data":{"reason":"answer","usage":{"input_tokens":4,"output_tokens":177,"cache_read_input_tokens":96577,"cache_creation_input_tokens":33740,"model":"claude-sonnet-5"}}}
{"t":"2026-09-19T13:43:38.322Z","kind":"prompt.submit","data":{"origin":{"kind":"task-notification"},"isWake":false,"text":"<task-notification>\n<summary>Stop hook feedback</summary>\n</task-notification>\n<system-reminder>\nStop hook blocking error from command \"Stop\": firstmate watcher auto-arm FAILED - the Stop-owned automatic supervision mechanism is broken after 2 bounded attempts, and no live watcher with a fresh beacon was verified.\nwatcher: already running pid 2269306\nwatcher: FAILED - cycle ended without an actionable reason\nDo not launch a manual background arm from this notice; investigate the automatic Stop hook and watcher startup before ending blind.\n\n</system-reminder>"}}
{"t":"2026-09-19T13:43:38.361Z","kind":"turn.start","data":{"turnId":"3ee5207f-dcd7-49bd-b892-7174025b2a59","text":"<task-notification>\n<summary>Stop hook feedback</summary>\n</task-notification>\n<system-reminder>\nStop hook blocking error from command \"Stop\": firstmate watcher auto-arm FAILED - the Stop-owned automatic supervision mechanism is broken after 2 bounded attempts, and no live watcher with a fresh beaco"}}
{"t":"2026-09-19T13:43:45.432Z","kind":"monitor.event","data":{"reasons":["signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status"],"expired":false,"text":"<task-notification>\n<task-id>bkxhujitd</task-id>\n<summary>Monitor event: \"fm-branch-mod watcher continuity\"</summary>\n<event>signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status</event>\nIf this event is something the user would act on now, send a PushNotification. Routine or benign output doesn't need one.\n</task-notification>"}}
{"t":"2026-09-19T13:43:45.439Z","kind":"wake.scope","data":{"reason":"signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status","scope":{"status":"safe","eligible":true,"eligibleSeqs":["1","2"],"eligibleTasks":["dummy"],"corrupted":false,"needsDecisionTasks":[],"allSeqs":["1","2"]},"source":"monitor"}}
{"t":"2026-09-19T13:43:46.647Z","kind":"classifier","data":{"seqs":["1","2"],"tasks":["dummy"],"verdict":"routine","reason":"All NEW lines are working: progress updates from a dummy loop task with no errors, blocks, or completion signals.","ms":1120,"promptChars":3139,"answer":"{\"verdict\": \"routine\", \"reason\": \"All NEW lines are working: progress updates from a dummy loop task with no errors, blocks, or completion signals.\"}","model":"haiku","estTokens":785}}
{"t":"2026-09-19T13:43:46.690Z","kind":"grant.activate","data":{"lockPid":"2268661","generation":"cc1789825388309","rc":0}}
{"t":"2026-09-19T13:43:46.737Z","kind":"grant.publish","data":{"seqs":["1","2"],"rc":0}}
{"t":"2026-09-19T13:43:46.763Z","kind":"agent.spawn","data":{"model":"sonnet","name":"fm-branch","branchGeneration":1,"result":{"model":"claude-sonnet-5","agentId":"a9d3ae4abc23edf8c"}}}
{"t":"2026-09-19T13:43:46.771Z","kind":"wake.delivered","data":{"wakeNo":1,"seqs":["1","2"],"ok":true,"via":"spawn","detail":"a9d3ae4abc23edf8c","spawnCount":1,"sendCount":0,"source":"monitor"}}
{"t":"2026-09-19T13:43:46.771Z","kind":"wake.dropped","data":{"wakeNo":1,"source":"monitor"}}
{"t":"2026-09-19T13:43:46.817Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":1,"model":"claude-sonnet-5","index":0,"effort":"xhigh","messageCount":10}}
{"t":"2026-09-19T13:43:48.125Z","kind":"tool.call.bash","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":1,"command":"bin/fm-wake-drain.sh"}}
{"t":"2026-09-19T13:43:48.754Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":1,"model":"claude-sonnet-5","index":1,"effort":"xhigh","messageCount":16}}
{"t":"2026-09-19T13:43:51.086Z","kind":"report.call","data":{"agentId":"a9d3ae4abc23edf8c","task":"dummy","verdict":"routine","summary":"Dummy loop progressing normally through step 5, no action needed.","silent":false,"wakeNo":1}}
{"t":"2026-09-19T13:43:51.222Z","kind":"deliver.routine","data":{"seq":1,"task":"dummy","summary":"Dummy loop progressing normally through step 5, no action needed.","silent":false,"wakeNo":1}}
{"t":"2026-09-19T13:43:51.230Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":1,"model":"claude-sonnet-5","index":2,"effort":"xhigh","messageCount":20}}
{"t":"2026-09-19T13:43:52.557Z","kind":"tool.call.bash","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":1,"command":"bin/fm-wake-drain.sh --ack-through 2 --recovery-generation 2276648.1789825422.IZjuWX"}}
{"t":"2026-09-19T13:43:52.775Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":1,"model":"claude-sonnet-5","index":3,"effort":"xhigh","messageCount":23}}
{"t":"2026-09-19T13:43:53.493Z","kind":"turn.complete.branch","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":1,"via":"spawn","reason":"answer","usage":{"input_tokens":8,"output_tokens":429,"cache_read_input_tokens":58267,"cache_creation_input_tokens":5034,"model":"claude-sonnet-5"},"wakeTokens":63309,"steps":4,"stepContext":15828,"elapsedMs":6753,"reportedSeqs":[1],"wake":"signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status","answer":"done"}}
{"t":"2026-09-19T13:43:53.579Z","kind":"backstop.check","data":{"task":"dummy","wakeNo":1,"rc":0,"lines":[],"stderr":""}}
{"t":"2026-09-19T13:44:42.187Z","kind":"turn.complete.main","data":{"reason":"answer","usage":{"input_tokens":10,"output_tokens":6276,"cache_read_input_tokens":361553,"cache_creation_input_tokens":18827,"model":"claude-sonnet-5"}}}
{"t":"2026-09-19T13:44:42.212Z","kind":"monitor.event","data":{"reasons":["signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status"],"expired":false,"text":"<task-notification>\n<task-id>bkxhujitd</task-id>\n<summary>Monitor event: \"fm-branch-mod watcher continuity\"</summary>\n<event>signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status</event>\nIf this event is something the user would act on now, send a PushNotification. Routine or benign output doesn't need one.\n</task-notification>"}}
{"t":"2026-09-19T13:44:42.228Z","kind":"wake.scope","data":{"reason":"signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status","scope":{"status":"safe","eligible":true,"eligibleSeqs":["3","4"],"eligibleTasks":["dummy"],"corrupted":false,"needsDecisionTasks":[],"allSeqs":["3","4"]},"source":"monitor"}}
{"t":"2026-09-19T13:44:43.326Z","kind":"classifier","data":{"seqs":["3","4"],"tasks":["dummy"],"verdict":"captain","reason":"A NEW `done:` line with a report reference requires captain attention, even though the task is named dummy and subsequent working lines follow.","ms":1005,"promptChars":3660,"answer":"{\"verdict\": \"captain\", \"reason\": \"A NEW `done:` line with a report reference requires captain attention, even though the task is named dummy and subsequent working lines follow.\"}","model":"haiku","estTokens":915}}
{"t":"2026-09-19T13:44:43.329Z","kind":"wake.passed","data":{"why":"classifier captain","reason":"signal: /tmp/fm-branch

... [4420 bytes truncated] ...

\", \"reason\": \"All NEW lines are working: progress updates from an ongoing dummy loop task.\"}","model":"haiku","estTokens":867}}
{"t":"2026-09-19T13:45:26.061Z","kind":"grant.publish","data":{"seqs":["5","6"],"rc":0}}
{"t":"2026-09-19T13:45:26.090Z","kind":"agent.send","data":{"to":"fm-branch","sendCount":1,"attempt":0,"text":"{\"success\":true,\"message\":\"Resuming agent fm-branch\",\"resumedAgentId\":\"a9d3ae4abc23edf8c\",\"pin\":{\"id\":\"a9d3ae4abc23edf8c\",\"name\":\"fm-branch\",\"ref\":\"42f32f\"}}"}}
{"t":"2026-09-19T13:45:26.090Z","kind":"wake.delivered","data":{"wakeNo":2,"seqs":["5","6"],"ok":true,"via":"send","detail":"a9d3ae4abc23edf8c","spawnCount":1,"sendCount":1,"source":"stop-hook"}}
{"t":"2026-09-19T13:45:26.090Z","kind":"wake.dropped","data":{"wakeNo":2,"source":"stop-hook"}}
{"t":"2026-09-19T13:45:26.136Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":2,"model":"claude-sonnet-5","index":0,"effort":"xhigh","messageCount":26}}
{"t":"2026-09-19T13:45:27.561Z","kind":"tool.call.bash","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":2,"command":"bin/fm-wake-drain.sh"}}
{"t":"2026-09-19T13:45:28.200Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":2,"model":"claude-sonnet-5","index":1,"effort":"xhigh","messageCount":29}}
{"t":"2026-09-19T13:45:30.142Z","kind":"report.call","data":{"agentId":"a9d3ae4abc23edf8c","task":"dummy","verdict":"routine","summary":"Dummy loop continuing normally through step 22, no action needed.","silent":false,"wakeNo":2}}
{"t":"2026-09-19T13:45:30.278Z","kind":"deliver.routine","data":{"seq":3,"task":"dummy","summary":"Dummy loop continuing normally through step 22, no action needed.","silent":false,"wakeNo":2}}
{"t":"2026-09-19T13:45:30.287Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":2,"model":"claude-sonnet-5","index":2,"effort":"xhigh","messageCount":33}}
{"t":"2026-09-19T13:45:31.691Z","kind":"tool.call.bash","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":2,"command":"bin/fm-wake-drain.sh --ack-through 6 --recovery-generation 2298057.1789825524.0DuBj2"}}
{"t":"2026-09-19T13:45:31.863Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":2,"model":"claude-sonnet-5","index":3,"effort":"xhigh","messageCount":36}}
{"t":"2026-09-19T13:45:32.504Z","kind":"turn.complete.branch","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":2,"via":"send","reason":"answer","usage":{"input_tokens":8,"output_tokens":421,"cache_read_input_tokens":67570,"cache_creation_input_tokens":1408,"model":"claude-sonnet-5"},"wakeTokens":68986,"steps":4,"stepContext":17247,"elapsedMs":6439,"reportedSeqs":[3],"wake":"signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status","answer":"done"}}
{"t":"2026-09-19T13:45:32.530Z","kind":"agent.notification.dropped","data":{"text":"<task-notification>\n<task-id>a9d3ae4abc23edf8c</task-id>\n<tool-use-id>toolu_plugin_de33a4377a544ec5a833d5f454bbb183</tool-use-id>\n<output-file>/tmp/claude-1000/-tmp-fm-branch-claude-live-eN4Mg0-home/d1200704-a208-4bad-aec3-257d0af4c8a4/tasks/a9d3ae4abc23edf8c.output</output-file>\n<status>completed</"}}
{"t":"2026-09-19T13:45:32.594Z","kind":"backstop.check","data":{"task":"dummy","wakeNo":2,"rc":0,"lines":[],"stderr":""}}
{"t":"2026-09-19T13:45:33.523Z","kind":"monitor.event","data":{"reasons":[],"expired":false,"text":"<task-notification>\n<task-id>bkxhujitd</task-id>\n<summary>Monitor event: \"fm-branch-mod watcher continuity\"</summary>\n<event>quiet: watcher: FAILED - cycle ended without an actionable reason</event>\nIf this event is something the user would act on now, send a PushNotification. Routine or benign output doesn't need one.\n</task-notification>"}}
{"t":"2026-09-19T13:47:38.680Z","kind":"monitor.event","data":{"reasons":["signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status"],"expired":false,"text":"<task-notification>\n<task-id>bkxhujitd</task-id>\n<summary>Monitor event: \"fm-branch-mod watcher continuity\"</summary>\n<event>signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status</event>\nIf this event is something the user would act on now, send a PushNotification. Routine or benign output doesn't need one.\n</task-notification>"}}
{"t":"2026-09-19T13:47:38.692Z","kind":"wake.scope","data":{"reason":"signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status","scope":{"status":"safe","eligible":true,"eligibleSeqs":["7","8"],"eligibleTasks":["dummy"],"corrupted":false,"needsDecisionTasks":[],"allSeqs":["7","8"]},"source":"monitor"}}
{"t":"2026-09-19T13:47:39.827Z","kind":"classifier","data":{"seqs":["7","8"],"tasks":["dummy"],"verdict":"routine","reason":"All NEW lines are working: progress updates from an ongoing dummy loop task; no done, blocked, needs-decision, or other captain-class signal present.","ms":1021,"promptChars":3419,"answer":"{\"verdict\": \"routine\", \"reason\": \"All NEW lines are working: progress updates from an ongoing dummy loop task; no done, blocked, needs-decision, or other captain-class signal present.\"}","model":"haiku","estTokens":855}}
{"t":"2026-09-19T13:47:39.871Z","kind":"grant.publish","data":{"seqs":["7","8"],"rc":0}}
{"t":"2026-09-19T13:47:39.915Z","kind":"agent.send","data":{"to":"fm-branch [42f32f]","sendCount":2,"attempt":0,"text":"{\"success\":true,\"message\":\"Resuming agent fm-branch\",\"resumedAgentId\":\"a9d3ae4abc23edf8c\",\"pin\":{\"id\":\"a9d3ae4abc23edf8c\",\"name\":\"fm-branch\",\"ref\":\"42f32f\"}}"}}
{"t":"2026-09-19T13:47:39.915Z","kind":"wake.delivered","data":{"wakeNo":3,"seqs":["7","8"],"ok":true,"via":"send","detail":"a9d3ae4abc23edf8c","spawnCount":1,"sendCount":2,"source":"monitor"}}
{"t":"2026-09-19T13:47:39.915Z","kind":"wake.dropped","data":{"wakeNo":3,"source":"monitor"}}
{"t":"2026-09-19T13:47:39.954Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":3,"model":"claude-sonnet-5","index":0,"effort":"xhigh","messageCount":39}}
{"t":"2026-09-19T13:47:41.498Z","kind":"tool.call.bash","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":3,"command":"bin/fm-wake-drain.sh"}}
{"t":"2026-09-19T13:47:42.148Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":3,"model":"claude-sonnet-5","index":1,"effort":"xhigh","messageCount":42}}
{"t":"2026-09-19T13:47:43.976Z","kind":"report.call","data":{"agentId":"a9d3ae4abc23edf8c","task":"dummy","verdict":"routine","summary":"Dummy loop continuing normally through step 29, no action needed.","silent":false,"wakeNo":3}}
{"t":"2026-09-19T13:47:44.112Z","kind":"deliver.routine","data":{"seq":4,"task":"dummy","summary":"Dummy loop continuing normally through step 29, no action needed.","silent":false,"wakeNo":3}}
{"t":"2026-09-19T13:47:44.121Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":3,"model":"claude-sonnet-5","index":2,"effort":"xhigh","messageCount":45}}
{"t":"2026-09-19T13:47:45.379Z","kind":"tool.call.bash","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":3,"command":"bin/fm-wake-drain.sh --ack-through 8 --recovery-generation 2320003.1789825658.teHPru"}}
{"t":"2026-09-19T13:47:45.535Z","kind":"turn.step","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":3,"model":"claude-sonnet-5","index":3,"effort":"xhigh","messageCount":48}}
{"t":"2026-09-19T13:47:46.229Z","kind":"turn.complete.branch","data":{"agentId":"a9d3ae4abc23edf8c","wakeNo":3,"via":"send","reason":"answer","usage":{"input_tokens":8,"output_tokens":397,"cache_read_input_tokens":73278,"cache_creation_input_tokens":1433,"model":"claude-sonnet-5"},"wakeTokens":74719,"steps":4,"stepContext":18680,"elapsedMs":6355,"reportedSeqs":[4],"wake":"signal: /tmp/fm-branch-claude-live.eN4Mg0/home/state/dummy.status","answer":"done"}}
{"t":"2026-09-19T13:47:46.259Z","kind":"agent.notification.dropped","data":{"text":"<task-notification>\n<task-id>a9d3ae4abc23edf8c</task-id>\n<tool-use-id>toolu_plugin_5f58c2ec35804f0c86fda7fc77e00029</tool-use-id>\n<output-file>/tmp/claude-1000/-tmp-fm-branch-claude-live-eN4Mg0-home/d1200704-a208-4bad-aec3-257d0af4c8a4/tasks/a9d3ae4abc23edf8c.output</output-file>\n<status>completed</"}}
{"t":"2026-09-19T13:47:46.338Z","kind":"backstop.check","data":{"task":"dummy","wakeNo":3,"rc":0,"lines":[],"stderr":""}}
Evidence: Lab 2 (inherited CLAUDE_CODE_CHILD_SESSION) module events: two why=unresumable rotations

Source: Lab 2 (inherited CLAUDE_CODE_CHILD_SESSION) module events: two why=unresumable rotations

{"kind":"agent.rotated","data":{"why":"unresumable","branchGeneration":2,"name":"fm-branch-2","ok":true,"sendDetail":"Agent \"fm-branch\" could not be resumed: No transcript found for agent ID: a1bbf98fc6137f491"}}
{"kind":"agent.rotated","data":{"why":"unresumable","branchGeneration":3,"name":"fm-branch-3","ok":true,"sendDetail":"Agent \"fm-branch-2\" could not be resumed: No transcript found for agent ID: ab1b00f7ff36e3e1f"}}
Evidence: tmux server global-env scrub check during the run

Source: tmux server global-env scrub check during the run

fm-branch-claude-2268063 server-global-env: none | pane-child(pid 2268661) CLAUDE_CODE_CHILD_SESSION: none fm-branch-claude-child-2268063 server-global-env: none | pane-child(pid 2324241) CLAUDE_CODE_CHILD_SESSION: CLAUDE_CODE_CHILD_SESSION=1

fm-branch-claude-2268063 server-global-env: none | pane-child(pid 2268661) CLAUDE_CODE_CHILD_SESSION: none
fm-branch-claude-child-2268063 server-global-env: none | pane-child(pid 2324241) CLAUDE_CODE_CHILD_SESSION: CLAUDE_CODE_CHILD_SESSION=1

[exited with code 0]
- Outcome: 🔧 3 issues found → auto-fixed ✅ across 2 runs (55m6s)

Pipeline

Updates from git push no-mistakes

✅ **intent** - passed

✅ No issues found.

✅ **Rebase** - passed

✅ No issues found.

⚠️ **Review** - 1 warning
  • ℹ️ tests/fm-branch-claude-mod-live-e2e.test.sh:319 - wait_branch_quiet declares the branch idle after turn.complete.branch is stable for five 2 s reads (~10 s), but a Sonnet turn dispatched just before pause_dummy can run longer than that. Sequence: send logged at t-1, pause at t, five stable reads by t+8, GAP_BASELINE/SENDS_BEFORE_GAP captured, turn completes at t+15 during sleep 75. After the gap, wait_branch_turn "$GAP_BASELINE" then passes on the pre-gap turn, so the 'turn after the gap' evidence in both labs can be vacuous. Not a wrong pass: lab 1 still fails on the send-equals-success check if the resume failed, and lab 2 is gated by wait_event agent.rotated and wake.delivered via:spawn count 2. Only the post-gap turn assertion is weakened. Remedy if wanted: also require count wake.delivered unchanged across the stability window, or lengthen the stable window past a turn.
  • ℹ️ tests/fm-branch-claude-mod-live-e2e.test.sh:462 - The lab-2 tail loop compares successful sends (count agent.send '&feat(bin): record shadow advisory facts and add the candidate gates scorer #34;success&feat(bin): record shadow advisory facts and add the candidate gates scorer #34;:true') against SENDS_BEFORE_GAP, which is the count of ALL agent.send lines (line 350). Any pre-gap failed attempt (e.g. a ref-retry attempt 0) makes the success count start below the baseline, so a post-gap successful send would not exit the loop and the test would rely solely on the third spawn. In a fresh lab no pre-gap failure is expected, so no wrong result today. One-token fix: capture SUCCESS_BEFORE_GAP=$(success_sends) in production_gap and compare against that.
  • ℹ️ tests/fm-branch-claude-mod-live-e2e.test.sh:400 - settle 10 '[ count agent.spawn = 1 ]' (lines 400, 406) cannot lag into failure: the single spawn line was already awaited in scenario 2, and a late second spawn line makes the condition false only after settle has already returned true. The settle wrapper is dead here; a plain equality (as before) is equivalent. Not required by intent; removal is the simplification.

🔧 No changes applied.
1 warning still open:

  • ⚠️ tests/fm-branch-claude-mod-live-e2e.test.sh:453 - The lab-2 tail loop (lines 453-471) is a component beyond the stated intent. Intent case (1) requires: rotation why=unresumable to a fresh agent (second agent.spawn), wake delivered to that agent, never passed to main, never dropped. Every one of those is already asserted by lines 434-452, and the stated invariant (every rotation unresumable and ok:true, agent.spawn >= 2, wake.passed=0, handback.dropped=0) is fully checked there too. The tail loop then waits up to 240 s more for either a THIRD spawn or a successful send, an acceptance path ("on a version that keeps agents warm, the send succeeds") the intent does not name, and adds run time to a test the intent measures at 379-410 s. No intent requirement needs it; the wake.passed=0 / handback.dropped=0 re-checks at lines 469-470 are equivalent to those at 449-450 for the wakes the intent covers. Remedy: remove lines 453-470 (keep the final pass line), or if the author wants the chain proven, say so and keep it as is.
🔧 **Test** - 3 issues found → auto-fixed ✅
  • 🚨 tests/fm-branch-claude-mod-live-e2e.test.sh:429 - Live lab 2 (CLAUDE_CODE_CHILD_SESSION=1 inherited) fails on the pinned Claude Code 2.1.278 in two consecutive runs: not ok - Claude Code 2.1.278 never reached the unresumable rotation. With a real 92 s gap (flag-file pause), the post-gap send still succeeded (&#34;success&#34;:true, &#34;message&#34;:&#34;Resuming agent fm-branch&#34;) and the subagent transcript was written to ~/.claude/projects/-tmp-fm-branch-claude-live-bKrEZ6-home/7ecbb7af-…/subagents/agent-a50513d76756d901c.jsonl, so the marker does not switch transcript persistence off here and the rotation the test asserts never happens. Either the premise (child-session marker breaks resume on 2.1.278) no longer holds on this host, or the lab needs a different way to make the agent unresumable. Author decision needed.
  • ⚠️ tests/fm-branch-claude-mod-live-e2e.test.sh:200 - pause_dummy/resume_dummy used pkill -STOP/-CONT -f &#34;$LAB/dummy.sh&#34;; tmux 3.4's server SIGCONTs a stopped pane process at once (reproduced: STAT stays Ss+ 0.3 s after kill -STOP, appends continue), so no gap ever elapsed and lab 1's minutes-later assertion passed vacuously (sends every ~43 s, no >10 s gap in dummy.status). Fixed in the worktree: the dummy loop now idles while state/dummy.pause exists; run 2 shows 102 s / 92 s gaps. Uncommitted diff in the worktree and at evidence/test-fix-flag-file-pause.diff.
  • 🚨 live validation verdict: no-go (7 of 8 scenarios were driven live against the product); failed: Lab 2, inherited CLAUDE_CODE_CHILD_SESSION=1: minutes-later wake rotates why=unresumable to a fresh agent (second spawn), wake delivered, never passed to main, never dropped, Adversarial: the production gap actually elapses (stand-in paused, no wake flows for >75 s)
  • Live validation: ❌ no-go - 7 of 8 scenarios driven live against the product
Scenario Result Live Evidence
Module loads on pinned Claude Code 2.1.278 and main takes the session lock ✅ pass live live-e2e-run2.log ok line 1
First routine wake spawns the branch agent which reports routine ✅ pass live live-e2e-run2.log ok line 2
Captain-class wake passed to main with covering row; next routine wake reaches same agent via SendMessage ✅ pass live live-e2e-run2.log ok line 3
Lab 1, persistence on: after a real ~100 s gap the SAME agent resumes, send succeeds, no rotation, no new spawn ✅ pass live live-e2e-run2.log ok lines 4–5; run2-lab1-persistence-on-events.jsonl (send at 13:19:18 success=true after 102 s gap, one agent.spawn, zero agent.rotated)
Lab 2, inherited CLAUDE_CODE_CHILD_SESSION=1: minutes-later wake rotates why=unresumable to a fresh agent (second spawn), wake delivered, never passed to main, never dropped ❌ fail live live-e2e-run2.log not ok - Claude Code 2.1.278 never reached the unresumable rotation; run2-lab2-child-session-events.jsonl shows post-gap agent.send success=true resuming the same agent, no agent.r…
Adversarial: the production gap actually elapses (stand-in paused, no wake flows for >75 s) ❌ fail live run1-lab2-dummy.status: continuous 5 s appends, no gap >10 s under the committed pkill -STOP pause; probe shows tmux 3.4 SIGCONTs the pane. Fixed in worktree (flag file); run2 dummy.status shows 92–…
Adversarial: labs are isolated (fresh tmux socket and scratch home per case, no shared counters) ✅ pass live live-e2e-run2.log lists two lab roots (K2jnZ5, bKrEZ6); lab 2 events start at agent.spawn with spawnCount 1 / sendCount 0 and a new session id
Docs mention in docs/claude-supervision-branch.md Verification ⏸️ untested no Docs-only line; no runtime surface to drive. Note it claims the child-session lab proves rotation, which the live run does not confirm.
  • FM_BRANCH_MOD_LIVE=1 FM_BRANCH_MOD_LIVE_KEEP=1 bash tests/fm-branch-claude-mod-live-e2e.test.sh (run 1, committed code): 5 ok, 1 not ok, 618 s
  • probe: kill -STOP on a tmux new-window pane process, ps -o stat 0.3 s and 6 s later (stays Ss+, appends continue) — tmux 3.4 SIGCONTs the pane
  • edited pause_dummy/resume_dummy to a state/dummy.pause flag file read by the dummy loop
  • FM_BRANCH_MOD_LIVE=1 FM_BRANCH_MOD_LIVE_KEEP=1 bash tests/fm-branch-claude-mod-live-e2e.test.sh (run 2, flag-file pause): 5 ok, 1 not ok, 693 s
  • event-timeline extraction from both labs' branch-mod-events.jsonl and dummy.status gap analysis (102 s lab 1, 92 s lab 2 in run 2)
  • probe of the scrubbed launch env: CLAUDE_CODE_CHILD_SESSION=1 present in the pane environment
  • inspected ~/.claude/projects/-tmp-fm-branch-claude-live-bKrEZ6-home/*/subagents for lab 2 transcript files (present)

🔧 Fix applied.
✅ Re-checked - no issues remain.

  • Live validation: ✅ go - 7 of 8 scenarios driven live against the product
Scenario Result Live Evidence
Lab 1 (scrubbed launch, persistence on): module loads on the pinned 2.1.278, main takes lock, first routine wake spawns the branch, captain wake passes to main with cover row, next routine wake reache… ✅ pass live live-e2e-run.log ok lines 1-3; lab1-persistence-on/branch-mod-events.jsonl
Lab 1: minutes-later wake after a real pause resumes the SAME agent: send success:true, agent.rotated=0, agent.spawn=1 ✅ pass live live-e2e-run.log ok line 4; lab1 events: 2 agent.send both success:true resumedAgentId a9d3ae4abc23edf8c, 0 agent.rotated, 1 agent.spawn; dummy.status shows a 100 s gap
Lab 1 whole run: one spawn, every send successful, no dropped hand-back, no backstop delivery ✅ pass live live-e2e-run.log ok line 5; lab1 events handback.dropped=0 backstop.delivered=0
Lab 2 (inherited CLAUDE_CODE_CHILD_SESSION=1): minutes-later wake rotates why=unresumable ok:true to a fresh agent (second agent.spawn), wake delivered via spawn, never passed to main, never dropped ✅ pass live live-e2e-run.log ok line 6; lab2 events: agent.rotated x2 why=unresumable ok:true sendDetail 'No transcript found for agent ID', agent.spawn=3, wake.delivered via spawn=3, wake.passed=0, handback.drop…
Adversarial: test run from a shell that itself carries CLAUDE_CODE_CHILD_SESSION=1; lab tmux servers must not inherit the marker into their global env (the round-1 false negative), while the lab 2 Cla… ✅ pass live tmux-env-scrub-check.log: both sockets server-global-env none; lab 2 pane child CLAUDE_CODE_CHILD_SESSION=1, lab 1 pane child none
Adversarial: the production gap actually elapses (stand-in paused, no status appends for >75 s) in both labs ✅ pass live lab1 dummy.status gap 100 s before step 23; lab2 dummy.status gap 95 s before step 7
Labs are fully separate: fresh tmux socket and scratch home per case, lab 1 torn down before lab 2, no lab directories left behind ✅ pass live live-e2e-run.log names two distinct lab roots /tmp/fm-branch-claude-live.eN4Mg0 and .yB8PJd; ls /tmp | grep fm-branch-claude-live empty after the run
Docs mention in docs/claude-supervision-branch.md Verification describes the two labs ⏸️ untested no Docs-only line; no runtime surface to drive. Read the diff only.
  • FM_BRANCH_MOD_LIVE=1 FM_BRANCH_MOD_LIVE_KEEP=1 tests/fm-branch-claude-mod-live-e2e.test.sh on Claude Code 2.1.278 (exit 0, 474 s, 6/6 ok)
  • claude --version = 2.1.278 = CLAUDE_CODE_PIN in .claude/mods/fm-branch-mod/hooks/branch.ts
  • Concurrent monitor: tmux -L &lt;lab socket&gt; show-environment -g | grep CLAUDE_CODE_CHILD_SESSION and /proc/&lt;claude pid&gt;/environ for both labs
  • Post-run inspection of kept branch-mod-events.jsonl per lab: counts of agent.spawn, agent.send, agent.rotated, wake.delivered, wake.passed, handback.dropped, backstop.delivered
  • Post-run gap check over dummy.status timestamps (>10 s gaps) for both labs
🔧 **Document** - 1 issue found → auto-fixed ✅
  • ⚠️ tests/fm-branch-claude-mod-live-e2e.test.sh:224 - bin/fm-lint.sh exits 1 on the target commit: ShellCheck SC2046 on env $(unset_inherited) &#34;$REAL_TMUX&#34; ... (word splitting of the unset_inherited expansion is intentional). Not a documentation change; needs an inline # shellcheck disable=SC2046 with the reason, or an array, in the test itself.

🔧 Fix applied.
✅ Re-checked - no issues remain.

✅ **Lint** - passed

✅ No issues found.

✅ **Push** - passed

✅ No issues found.

The live test gains a second lab and two RCA cases: a minutes-later wake
resumes the same persisted agent when transcript saving is on (send succeeds,
no rotation), while an inherited CLAUDE_CODE_CHILD_SESSION makes every resume
unresumable, so the wake rotates to a fresh agent instead of being passed to
main or dropped. Count assertions settle across append lag and the rotation
chain is asserted by invariant rather than a frozen rotation count.
@andrewesweet
andrewesweet merged commit 616f2c0 into main Sep 19, 2026
19 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