Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
42 changes: 33 additions & 9 deletions bin/fm-watch.sh
Original file line number Diff line number Diff line change
Expand Up @@ -411,7 +411,7 @@ window_label() {

# The ONE derivation of a window's per-window marker key: `:`, `/` and `.` become
# `_` so a window name is usable as a filename suffix. Every per-window file the
# watcher keeps is named by it (.hash-, .count-, .stale-, .stale-since-,
# watcher keeps is named by it (.hash-, .count-, .stale-, .stale-since-, .stale-settled-,
# .wedge-escalations-, .paused-*, .writing-*), and live homes hold those markers on
# disk under the current format, so the format lives here alone: a second copy is
# how a future change to it silently orphans a window's markers instead of clearing
Expand Down Expand Up @@ -948,11 +948,25 @@ clear_write_tracking() { # <window-key>
# The worktree write probe runs ONLY here, inside the at-threshold branch that is
# about to escalate: at most one bounded walk per window per STALE_ESCALATE_SECS,
# never per poll.
wedge_timer_check() { # <window> <since-file> <triage-label> <escalation-count-file> <task>
local win=$1 since_file=$2 label=$3 escalation_file=$4 task=$5 since age n reason
wedge_timer_check() { # <window> <since-file> <triage-label> <escalation-count-file> <task> [reverify]
local win=$1 since_file=$2 label=$3 escalation_file=$4 task=$5 reverify=${6:-} since age n reason key settled
key=$(window_key "$win")
settled="$STATE/.stale-settled-$key"
# A stale hash already found no longer provably working stays quiet: no timer,
# no crew-state read per poll (see wedge_timer_gone_quiet).
if [ -n "$reverify" ] && [ -e "$settled" ] && [ "$(cat "$settled" 2>/dev/null || true)" = "$(cat "$STATE/.stale-$key" 2>/dev/null || true)" ]; then
return 0
fi
since=$(cat "$since_file" 2>/dev/null || true)
case "$since" in
''|*[!0-9]*)
if [ -n "$reverify" ] && ! crew_is_provably_working "$task"; then
# No timer to repair: the run that justified one is gone, so starting a
# fresh one would wedge-escalate a finished crew forever.
cp "$STATE/.stale-$key" "$settled" 2>/dev/null || : > "$settled"
triage_log "absorbed $label (crew no longer provably working, no wedge timer started): $win"
return 0
fi
# Publish the repaired timer only after its old write-deferral chain is
# gone, so observers cannot mistake a new idle window for the old chain.
clear_write_tracking "$(window_key "$win")"
Expand All @@ -962,6 +976,16 @@ wedge_timer_check() { # <window> <since-file> <triage-label> <escalation-count-
*)
age=$(( $(date +%s) - since ))
if [ "$age" -ge "$STALE_ESCALATE_SECS" ]; then
if [ -n "$reverify" ] && ! crew_is_provably_working "$task"; then
# The evidence that started this timer (a live run) is gone, so the
# pane is no longer a wedge suspect. Drop the timer and the hash
# suppressor: the next poll classifies the hash afresh, surfacing a
# finished crew once through the ordinary path instead of escalating.
rm -f "$since_file" "$escalation_file" "$STATE/.stale-$key"
clear_write_tracking "$key"
triage_log "absorbed $label timer (crew no longer provably working, reclassifying): $win"
return 0
fi
if crew_worktree_written_since "$task" "$STATE" "$since_file"; then
wedge_defer_writing "$win" "$since_file" "$label" "$age"
return 0
Expand Down Expand Up @@ -1016,7 +1040,7 @@ handle_paused_stale() { # <window> <task> <hash>
key=$(window_key "$win")
printf '%s' "$h" > "$STATE/.stale-$key"
: > "$STATE/.paused-$key"
rm -f "$STATE/.stale-since-$key" "$STATE/.wedge-escalations-$key"
rm -f "$STATE/.stale-since-$key" "$STATE/.wedge-escalations-$key" "$STATE/.stale-settled-$key"
clear_write_tracking "$key"
statusf="$STATE/$task.status"
mtime=$(stat_mtime "$statusf")
Expand Down Expand Up @@ -1148,7 +1172,7 @@ clear_pause_state() { # <window-key>
clear_stale_hash_tracking() { # <window-key>
local key=$1
clear_write_tracking "$key"
rm -f "$STATE/.stale-$key" "$STATE/.stale-since-$key" "$STATE/.wedge-escalations-$key"
rm -f "$STATE/.stale-$key" "$STATE/.stale-since-$key" "$STATE/.wedge-escalations-$key" "$STATE/.stale-settled-$key"
}

clear_pause_tracking() { # <window-key>
Expand Down Expand Up @@ -2455,7 +2479,7 @@ EOF
# wedge timer is running for it) - keep treating it that way
# without re-reading the crew state every poll, and without
# letting the still-captain-relevant log line re-surface it.
wedge_timer_check "$w" "$ssf" "stale (overridden terminal status)" "$ewf" "$task"
wedge_timer_check "$w" "$ssf" "stale (overridden terminal status)" "$ewf" "$task" reverify
fi
# else: already surfaced as genuinely terminal on a prior poll of
# this same hash - nothing left to do (matches the original,
Expand Down Expand Up @@ -2507,7 +2531,7 @@ EOF
*) handle_paused_stale "$w" "$task" "$h" ;;
esac
else
wedge_timer_check "$w" "$ssf" "non-terminal stale" "$ewf" "$task"
wedge_timer_check "$w" "$ssf" "non-terminal stale" "$ewf" "$task" reverify
fi
fi
fi
Expand All @@ -2520,7 +2544,7 @@ EOF
if [ "$busy_now" -eq 0 ] && busy_turn_over_age "$task"; then
busy_turn_bound_check "$w" "$task" "$h" "$ssf" "$ewf" && paused_bound=0
else
rm -f "$ssf" "$ewf"
rm -f "$ssf" "$ewf" "$STATE/.stale-settled-$key"
clear_write_tracking "$key"
fi
# A busy pane normally means real work resumed, so stale pause bookkeeping
Expand All @@ -2538,7 +2562,7 @@ EOF
if [ "$busy_now" -eq 0 ] && busy_turn_over_age "$task"; then
busy_turn_bound_check "$w" "$task" "$h" "$ssf" "$ewf" && paused_bound=0
else
rm -f "$ssf" "$ewf"
rm -f "$ssf" "$ewf" "$STATE/.stale-settled-$key"
clear_write_tracking "$key"
fi
task=$(window_to_task "$w" "$STATE")
Expand Down
1 change: 1 addition & 0 deletions docs/architecture.md
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,7 @@ A secondmate's endpoint liveness is still never read at all; a mate is admitted
A `paused:` line specifically claiming a no-mistakes run is the one declared wait not taken on faith for that whole cadence: both the watcher and the away-mode daemon revalidate it against crew state, and an unconfirmed claim (no run, failed, or parked at a gate) is escalated on the stale cadence instead of re-absorbed (`status_pause_claims_nm_run` in [`bin/fm-classify-lib.sh`](../bin/fm-classify-lib.sh); [configuration.md](configuration.md) "Pipeline-state watch" owns the mechanics).
Its initial normal-mode status signal still surfaces through the no-verb path, while a daemon-backed away posture self-handles that routine signal and owns later external-wait rechecks.
Fresh stale panes use the same current-state read before trusting the status log, so an active run or a proven busy worker outranks an old captain-relevant status-log line left behind before validation.
The same read gates the wedge timer of a stale pane: when the run that justified the timer is gone, the timer is dropped rather than escalated, and a finished crew (latest status `done:`, crew state unknown) surfaces at most once through the ordinary stale path and then stays quiet, while a crew that is still provably working and frozen escalates as before (`wedge_timer_check` in [`bin/fm-watch.sh`](../bin/fm-watch.sh); pinned in `tests/fm-watch-triage.test.sh`).
No-change heartbeats are also benign.
Separately from heartbeat backoff and wedge handling, the watcher poll runs `bin/fm-inactive-reconcile.sh` on its own bounded cadence, while locked session start sends the same bounded local scan through `bin/fm-startup-network.sh`'s deferred worker so current-state reads never block the digest.
In each home the scan considers only that home's long-inactive direct ordinary crewmates, excludes captain-held work, and accepts only `done` or `failed` from `bin/fm-crew-state.sh`.
Expand Down
87 changes: 85 additions & 2 deletions tests/fm-watch-triage.test.sh
Original file line number Diff line number Diff line change
Expand Up @@ -2067,6 +2067,75 @@ test_nonterminal_stale_provably_working_absorbed_then_escalated() {
pass "provably-working non-terminal stale is absorbed on first sight, then wedge-escalated past the threshold"
}

# --- a finished crew whose run is gone: the wedge timer stops, never repeats ---
# The live 2026-09 case: a crew reported done and only waits on an outside merge.
# While its run monitored CI the pane was provably working, which started the
# wedge timer; once the run vanished (fm-crew-state reads unknown) that timer kept
# escalating "possible wedge" every STALE_ESCALATE_SECS forever. Both status shapes
# reach the timer through a different branch, so each is driven through the same
# three phases: working absorb (timer starts), run gone at the threshold (no wedge
# wake, at most the ordinary surface), then the same hash stays quiet.
run_working_then_gone_case() { # <case-name> <task> <status-line>
local name=$1 task=$2 status_line=$3 dir state fakebin out capture_file window key pane_hash sig pid
dir=$(make_case "$name"); state="$dir/state"; fakebin="$dir/fakebin"
out="$dir/watch.out"; capture_file="$dir/pane.txt"
window="test:fm-$task"
printf 'idle after monitoring ci' > "$capture_file"
printf 'window=%s\nkind=ship\n' "$window" > "$state/$task.meta"
printf '%s\n' "$status_line" > "$state/$task.status"
sig=$(seen_sig "$state/$task.status"); printf '%s' "$sig" > "$state/.seen-${task}_status"
key=$(printf '%s' "$window" | tr ':/.' '___')
pane_hash=$(hash_text "idle after monitoring ci")
printf '%s' "$pane_hash" > "$state/.hash-$key"
printf '1\n' > "$state/.count-$key"

# Phase A: the run is monitoring CI, so the static pane is absorbed and timed.
export FM_FAKE_CREW_STATE='state: working · source: run-step · ci running'
watch_bg "$state" "$fakebin" "$out" FM_FAKE_TMUX_WINDOW="$window" FM_FAKE_TMUX_CAPTURE="$capture_file" FM_STALE_ESCALATE_SECS=240
pid=$!
wait_poll_cycle "$state" "$pid" || { reap "$pid"; fail "$name: watcher exited while absorbing a working run: $(cat "$out")"; }
[ -s "$state/.stale-since-$key" ] || { reap "$pid"; fail "$name: the working absorb did not start the wedge timer"; }
reap "$pid"
ack_stopped_cycle "$state" || fail "$name: could not acknowledge the phase-A stop"

# Phase B: the run is gone (unknown) and the timer is past the threshold. The
# old code escalated "possible wedge" here.
export FM_FAKE_CREW_STATE='state: unknown · source: none'
echo $(( $(date +%s) - 500 )) > "$state/.stale-since-$key"
: > "$out"
watch_bg "$state" "$fakebin" "$out" FM_FAKE_TMUX_WINDOW="$window" FM_FAKE_TMUX_CAPTURE="$capture_file" FM_STALE_ESCALATE_SECS=240
pid=$!
# The ordinary one-time surface ends this watcher; a wedge wake would too.
wait_for_exit "$pid" 100 || { reap "$pid"; fail "$name: a crew whose run is gone was never surfaced through the ordinary path"; }
grep -F "stale: $window" "$out" >/dev/null || fail "$name: the ordinary surface did not print a stale wake: $(cat "$out")"
grep -F "possible wedge" "$out" "$state/.wake-queue" >/dev/null 2>&1 \
&& fail "$name: a crew whose run is gone was wedge-escalated: $(cat "$out" "$state/.wake-queue" 2>/dev/null)"
[ ! -e "$state/.stale-since-$key" ] || fail "$name: the wedge timer survived the run going away"
[ ! -e "$state/.wedge-escalations-$key" ] || fail "$name: a wedge-escalation count was recorded for a finished crew"
ack_stopped_cycle "$state" || fail "$name: could not acknowledge the phase-B surface"

# Phase C: the same hash later stays quiet - no timer, no wake, however long.
: > "$out"; rm -f "$state/.wake-queue"
watch_bg "$state" "$fakebin" "$out" FM_FAKE_TMUX_WINDOW="$window" FM_FAKE_TMUX_CAPTURE="$capture_file" FM_STALE_ESCALATE_SECS=1
pid=$!
sleep 4
kill -0 "$pid" 2>/dev/null || { wait "$pid" 2>/dev/null || true; fail "$name: the finished crew woke firstmate again: $(cat "$out" "$state/.wake-queue" 2>/dev/null)"; }
[ ! -e "$state/.stale-since-$key" ] || { reap "$pid"; fail "$name: a finished crew restarted the wedge timer"; }
[ ! -s "$state/.wake-queue" ] || { reap "$pid"; fail "$name: a finished crew re-enqueued a wake: $(cat "$state/.wake-queue")"; }
reap "$pid"
unset FM_FAKE_CREW_STATE
}

test_terminal_done_crew_whose_run_is_gone_stops_wedge_escalating() {
run_working_then_gone_case done-run-gone donegone 'done: PR https://example.invalid/pr/1 checks green'
pass "a done: crew whose run is gone stops wedge-escalating after the ordinary surface"
}

test_nonterminal_crew_whose_run_is_gone_stops_wedge_escalating() {
run_working_then_gone_case quiet-run-gone quietgone 'working: waiting on the outside merge'
pass "a quiet crew whose run is gone stops wedge-escalating and never restarts the timer"
}

# --- non-terminal stale, crew NOT provably working: surfaced immediately ------
# The key requirement: a crew with no running pipeline that has gone quiet (and is
# not busy) has stopped - it may be done via interactive menus, waiting, or wedged.
Expand Down Expand Up @@ -3876,9 +3945,11 @@ test_nonterminal_stale_repairs_missing_or_corrupt_timer() {
printf '%s' "$pane_hash" > "$state/.hash-$key"
printf '1\n' > "$state/.count-$key"
printf '%s' "$pane_hash" > "$state/.stale-$key"
# The timer is only repaired for a crew that is still provably working.
export FM_FAKE_CREW_STATE='state: working · source: run-step · ci running'

PATH="$fakebin:$PATH" FM_FAKE_TMUX_WINDOW="$window" FM_FAKE_TMUX_CAPTURE="$capture_file" \
FM_STATE_OVERRIDE="$state" FM_STALE_ESCALATE_SECS=999 FM_POLL=1 FM_SIGNAL_GRACE=1 \
FM_STATE_OVERRIDE="$state" FM_CREW_STATE_BIN="$fakebin/fm-crew-state.sh" FM_STALE_ESCALATE_SECS=999 FM_POLL=1 FM_SIGNAL_GRACE=1 \
FM_CHECK_INTERVAL=999999 FM_HEARTBEAT=999999 "$WATCH" > "$out" &
pid=$!
wait_numeric_file "$state/.stale-since-$key" 30 || { reap "$pid"; fail "matching stale suppressor with missing timer did not initialize stale-since"; }
Expand All @@ -3893,14 +3964,15 @@ test_nonterminal_stale_repairs_missing_or_corrupt_timer() {
printf 'corrupt\n' > "$state/.stale-since-$key"
: > "$out"
PATH="$fakebin:$PATH" FM_FAKE_TMUX_WINDOW="$window" FM_FAKE_TMUX_CAPTURE="$capture_file" \
FM_STATE_OVERRIDE="$state" FM_STALE_ESCALATE_SECS=999 FM_POLL=1 FM_SIGNAL_GRACE=1 \
FM_STATE_OVERRIDE="$state" FM_CREW_STATE_BIN="$fakebin/fm-crew-state.sh" FM_STALE_ESCALATE_SECS=999 FM_POLL=1 FM_SIGNAL_GRACE=1 \
FM_CHECK_INTERVAL=999999 FM_HEARTBEAT=999999 "$WATCH" > "$out" &
pid=$!
wait_numeric_file "$state/.stale-since-$key" 30 || { reap "$pid"; fail "matching stale suppressor with corrupt timer did not repair stale-since"; }
since=$(cat "$state/.stale-since-$key" 2>/dev/null || true)
[ "$since" != "corrupt" ] || { reap "$pid"; fail "corrupt stale-since value was left in place"; }
[ ! -s "$state/.wake-queue" ] || { reap "$pid"; fail "corrupt stale-since repair enqueued a wake"; }
reap "$pid"
unset FM_FAKE_CREW_STATE
pass "matching non-terminal stale suppressors repair missing or corrupt stale-since timers"
}

Expand All @@ -3920,6 +3992,8 @@ test_nonterminal_stale_repairs_missing_or_corrupt_timer() {
test_wedge_escalation_deferred_while_worktree_is_written() {
local dir state fakebin out drain_out capture_file window key pane_hash sig pid wt back
dir=$(make_case wedge-worktree-writes); state="$dir/state"; fakebin="$dir/fakebin"
# The at-threshold wedge branch re-confirms the crew is still provably working.
export FM_FAKE_CREW_STATE='state: working · source: run-step · ci running'
out="$dir/watch.out"; drain_out="$dir/drain.out"; capture_file="$dir/pane.txt"
window="test:fm-writing"; wt="$dir/wt"
mkdir -p "$wt/src"
Expand Down Expand Up @@ -3978,6 +4052,7 @@ test_wedge_escalation_deferred_while_worktree_is_written() {
[ ! -e "$state/.writing-since-$key" ] || fail "the write-deferral chain outlived a real escalation"
FM_STATE_OVERRIDE="$state" "$DRAIN" > "$drain_out" 2>/dev/null || fail "drain after the stalled-crew escalation failed"
grep "$(printf '\tstale\t')" "$drain_out" | grep -F "$window" >/dev/null || fail "the stalled-crew escalation was not queued"
unset FM_FAKE_CREW_STATE
pass "a quiet pane writing its own worktree is deferred, while one writing nothing still wedge-escalates on the unchanged schedule"
}

Expand All @@ -3988,6 +4063,8 @@ test_wedge_escalation_deferred_while_worktree_is_written() {
test_write_deferral_resurfaces_on_the_bounded_cadence() {
local dir state fakebin out drain_out capture_file window key pane_hash sig pid wt back
dir=$(make_case wedge-worktree-resurface); state="$dir/state"; fakebin="$dir/fakebin"
# The at-threshold wedge branch re-confirms the crew is still provably working.
export FM_FAKE_CREW_STATE='state: working · source: run-step · ci running'
out="$dir/watch.out"; drain_out="$dir/drain.out"; capture_file="$dir/pane.txt"
window="test:fm-churn"; wt="$dir/wt"
mkdir -p "$wt/src"
Expand Down Expand Up @@ -4021,6 +4098,7 @@ test_write_deferral_resurfaces_on_the_bounded_cadence() {
[ ! -e "$state/.wedge-escalations-$key" ] || fail "a write-deferral recheck advanced the wedge escalation counter"
FM_STATE_OVERRIDE="$state" "$DRAIN" > "$drain_out" 2>/dev/null || fail "drain after the write-deferral recheck failed"
grep "$(printf '\tstale\t')" "$drain_out" | grep -F "$window" >/dev/null || fail "the write-deferral recheck was not queued"
unset FM_FAKE_CREW_STATE
pass "a write deferral re-surfaces once on the bounded pause cadence, so a churning worktree cannot stay invisible"
}

Expand Down Expand Up @@ -4083,6 +4161,8 @@ test_secondmate_home_supervision_churn_is_not_write_evidence() {
test_timer_repair_drops_a_finished_write_deferral_chain() {
local dir state fakebin out capture_file window key pane_hash sig pid wt back
dir=$(make_case wedge-write-chain-timer-repair); state="$dir/state"; fakebin="$dir/fakebin"
# The at-threshold wedge branch re-confirms the crew is still provably working.
export FM_FAKE_CREW_STATE='state: working · source: run-step · ci running'
out="$dir/watch.out"; capture_file="$dir/pane.txt"
window="test:fm-chain-repair"; wt="$dir/wt"
mkdir -p "$wt/src"
Expand Down Expand Up @@ -4143,6 +4223,7 @@ test_timer_repair_drops_a_finished_write_deferral_chain() {
[ ! -e "$state/.writing-resurfaced-$key" ] \
|| { reap "$pid"; fail "a fresh write deferral spent its bounded re-surface on the first poll"; }
reap "$pid"
unset FM_FAKE_CREW_STATE
pass "an idle-window timer repair drops a finished write-deferral chain, so the next deferral gets a fresh re-surface window"
}

Expand Down Expand Up @@ -5170,6 +5251,8 @@ test_permission_recovery_surfaces_preserved_status
test_terminal_stale_surfaced
test_stale_terminal_status_overridden_by_active_run
test_nonterminal_stale_provably_working_absorbed_then_escalated
test_terminal_done_crew_whose_run_is_gone_stops_wedge_escalating
test_nonterminal_crew_whose_run_is_gone_stops_wedge_escalating
test_wedge_escalation_marks_demand_deep_inspection_after_threshold
test_wedge_escalation_resets_when_pane_becomes_active
test_busy_pane_below_turn_age_bound_is_absorbed
Expand Down
Loading