From 924cc0d8347c85f54dfa5ba0141fc70f7b74d906 Mon Sep 17 00:00:00 2001 From: MLA82 <212341412+MLA82@users.noreply.github.com> Date: Fri, 4 Sep 2026 14:04:50 +0200 Subject: [PATCH 1/4] fix: watcher and backlog-handoff correctness fixes Three independent fixes to watcher and handoff behavior: - fm-watch-arm.sh / fm-watch.sh: a watched process that exits cleanly after absorbing a benign condition (nothing left to do) was reported as a false FAILED. Recognize a benign-absorb exit and report it as clean instead. - fm-backlog-handoff.sh: the backlog handoff's receiver-side wake did not name which items it actually routed, making the wake ambiguous when more than one item moved in the same handoff. The wake now names its own routed items directly, and covers every resume path uniformly instead of threading an extra parameter through each one. - fm-config-inherit-lib.sh / fm-remote-inherit-push.sh: shared captain header validation could not tolerate a mid-phrase reflow (a wrapped line whose whitespace differs only in reflow position), causing a spurious validation failure on an otherwise-identical header. --- bin/fm-backlog-handoff.sh | 95 ++++++- bin/fm-config-inherit-lib.sh | 1 + bin/fm-remote-inherit-push.sh | 9 - bin/fm-watch-arm.sh | 6 + bin/fm-watch.sh | 2 + tests/fm-backlog-handoff.test.sh | 73 ++++++ tests/fm-shared-captain-inheritance.test.sh | 63 +++++ tests/fm-watch-benign-absorb.test.sh | 258 ++++++++++++++++++++ 8 files changed, 487 insertions(+), 20 deletions(-) create mode 100644 tests/fm-watch-benign-absorb.test.sh diff --git a/bin/fm-backlog-handoff.sh b/bin/fm-backlog-handoff.sh index 882be0b367f..c4da0ad3406 100755 --- a/bin/fm-backlog-handoff.sh +++ b/bin/fm-backlog-handoff.sh @@ -97,6 +97,60 @@ MAIN_BACKLOG="$DATA/backlog.md" RECEIVER_WAKE_MESSAGE='New routed work is in your backlog. Run bin/fm-session-start.sh now, then act on the routed task.' +# Two consecutive handoffs to the same receiver used to send this exact same +# fixed line with no indication which task either one named, so a receiver +# reading them close together had no way to tell a second genuine handoff +# apart from a duplicate of the first - a real 2026-08-25 incident (see +# backlog item handoff-nachricht-nennt-auftrag-nicht) where the receiver read +# an unlabeled second handoff as an unproven repeat of the first and blocked +# on it. Appended, never inserted, so the fixed sentence itself stays a +# stable substring for every existing caller and test that greps for it. +receiver_wake_message() { # ... + local ids + [ "$#" -gt 0 ] || { printf '%s' "$RECEIVER_WAKE_MESSAGE"; return; } + ids=$(printf '%s, ' "$@") + ids=${ids%, } + printf '%s Routed: %s.' "$RECEIVER_WAKE_MESSAGE" "$ids" +} + +# Extracts every item key from a "- [ ] - " backlog/outbox line, +# in file order, one per line - the same line shape outbox_item_count counts. +receiver_wake_item_keys_from_file() { # <path> + grep -E '^- \[[ x]\] ' "$1" 2>/dev/null | sed -E 's/^- \[[ x]\] ([^ ]+) .*/\1/' +} + +receiver_wake_message_path() { # <secondmate-id> + printf '%s\n' "$STATE/.backlog-handoff-$1.wake-message" +} + +receiver_wake_message_write() { # <secondmate-id> <message> + local id=$1 message=$2 path tmp + path=$(receiver_wake_message_path "$id") + tmp=$(umask 077; mktemp "$STATE/.backlog-handoff-wake-message.XXXXXX") || return 1 + if ! printf '%s' "$message" > "$tmp" || ! chmod 600 "$tmp" || ! mv -f -- "$tmp" "$path"; then + rm -f -- "$tmp" + return 1 + fi +} + +# Falls back to the fixed generic line when no per-batch message was ever +# recorded (a legacy marker predating this, or the bare-`pending` transition +# in wake_pending_secondmate_receiver, which has no fresh key list to work +# from) so a receiver is never left without an actionable instruction. +receiver_wake_message_read() { # <secondmate-id> + local path + path=$(receiver_wake_message_path "$1") + if [ -f "$path" ] && [ ! -L "$path" ]; then + cat "$path" + else + printf '%s' "$RECEIVER_WAKE_MESSAGE" + fi +} + +receiver_wake_message_clear() { # <secondmate-id> + rm -f -- "$(receiver_wake_message_path "$1")" +} + ACTIVE_HANDOFF_LOCK= ACTIVE_REGISTRY_LOCK= RECEIVER_WAKE_IGNORE_ID= @@ -384,8 +438,9 @@ receiver_wake_state_write() { # <secondmate-id> <state> fi } -receiver_wake_mark() { # <secondmate-id> <prepared|pending> [batch-id] - local id=$1 wake_phase=$2 batch=${3:-} marker="$STATE/.backlog-handoff-$1.wake-pending" value corr rec +receiver_wake_mark() { # <secondmate-id> <prepared|pending> [batch-id] [message] + local id=$1 wake_phase=$2 batch=${3:-} message=${4:-$RECEIVER_WAKE_MESSAGE} + local marker="$STATE/.backlog-handoff-$1.wake-pending" value corr rec local wake_state case "$wake_phase" in prepared | pending) ;; *) return 1 ;; esac if [ -e "$marker" ] || [ -L "$marker" ]; then @@ -408,7 +463,11 @@ receiver_wake_mark() { # <secondmate-id> <prepared|pending> [batch-id] *) return 1 ;; esac fi - corr=$(fm_pending_reply_create "$FM_HOME" "$STATE" "$id" "$RECEIVER_WAKE_MESSAGE") || return 1 + corr=$(fm_pending_reply_create "$FM_HOME" "$STATE" "$id" "$message") || return 1 + if ! receiver_wake_message_write "$id" "$message"; then + fm_pending_reply_discard_undelivered "$STATE" "$corr" || true + return 1 + fi wake_state="$wake_phase:$corr" if [ "$wake_phase" = prepared ]; then printf '%s' "$batch" | grep -Eq '^[a-f0-9]{16}$' || return 1 @@ -416,16 +475,17 @@ receiver_wake_mark() { # <secondmate-id> <prepared|pending> [batch-id] fi if ! receiver_wake_state_write "$id" "$wake_state"; then fm_pending_reply_discard_undelivered "$STATE" "$corr" || true + receiver_wake_message_clear "$id" return 1 fi } -receiver_wake_mark_pending() { # <secondmate-id> - receiver_wake_mark "$1" pending +receiver_wake_mark_pending() { # <secondmate-id> [message] + receiver_wake_mark "$1" pending "" "${2:-$RECEIVER_WAKE_MESSAGE}" } -receiver_wake_mark_prepared() { # <secondmate-id> <batch-id> - receiver_wake_mark "$1" prepared "$2" +receiver_wake_mark_prepared() { # <secondmate-id> <batch-id> [message] + receiver_wake_mark "$1" prepared "$2" "${3:-$RECEIVER_WAKE_MESSAGE}" } receiver_wake_discard_prepared() { # <secondmate-id> @@ -440,6 +500,7 @@ receiver_wake_discard_prepared() { # <secondmate-id> *) return 1 ;; esac fm_pending_reply_discard_undelivered "$STATE" "$corr" || return 1 + receiver_wake_message_clear "$id" rm -f -- "$marker" } @@ -470,6 +531,7 @@ receiver_wake_discard_pending() { # <secondmate-id> pending) ;; *) return 1 ;; esac + receiver_wake_message_clear "$id" rm -f -- "$marker" } @@ -535,6 +597,7 @@ receiver_wake_clear_confirmed() { # <secondmate-id> return 0 fi if receiver_wake_pending_delivered_valid "$id" || receiver_wake_confirmed_valid "$id"; then + receiver_wake_message_clear "$id" if ! rm -f -- "$marker"; then RECEIVER_WAKE_IGNORE_ID=$id printf 'warning: confirmed receiver wake left a stale marker at %s; later handoffs will ignore it\n' "$marker" >&2 @@ -548,7 +611,7 @@ receiver_wake_clear_confirmed() { # <secondmate-id> } wake_secondmate_receiver() { # <secondmate-id> <correlation-id> - local id=$1 corr=$2 meta="$STATE/$1.meta" out rc=0 + local id=$1 corr=$2 meta="$STATE/$1.meta" out rc=0 message if [ ! -f "$meta" ] || [ -L "$meta" ]; then printf 'error: handed off work to secondmate %s, but no live receiver endpoint is recorded; the destination backlog is durable and the receiver was not woken\n' "$id" >&2 return 1 @@ -557,9 +620,10 @@ wake_secondmate_receiver() { # <secondmate-id> <correlation-id> printf 'error: secondmate %s has non-secondmate endpoint metadata; backlog is durable but the receiver was not woken\n' "$id" >&2 return 1 } + message=$(receiver_wake_message_read "$id") out=$(FM_HOME="$FM_HOME" FM_STATE_OVERRIDE="$STATE" FM_ROOT_OVERRIDE="$FM_ROOT" \ FM_PENDING_REPLY_EXISTING_CORR="$corr" \ - "$SCRIPT_DIR/fm-send.sh" "$id" "$RECEIVER_WAKE_MESSAGE" 2>&1) || rc=$? + "$SCRIPT_DIR/fm-send.sh" "$id" "$message" 2>&1) || rc=$? if [ "$rc" -ne 0 ]; then [ -z "$out" ] || printf '%s\n' "$out" >&2 printf 'error: backlog delivery to secondmate %s succeeded, but its receiver wake failed; retry a tracked remote wake with --resume-pending or a later new handoff, and retry a local wake by rerunning its handoff\n' "$id" >&2 @@ -614,6 +678,7 @@ wake_pending_secondmate_receiver() { # <secondmate-id> [retain-confirmed] printf 'error: receiver wake for secondmate %s was confirmed, but pending state could not be cleared\n' "$id" >&2 return 1 } + receiver_wake_message_clear "$id" fi } @@ -623,6 +688,7 @@ outbox_item_count() { # <path> remote_deliver_outbox() { # <secondmate-id> <outbox-path> local id=$1 outbox=$2 remote_rel receive_out snapshot bytes hash generation counter counter_tmp current marker wake_rc=0 wake_state=pending + local -a wake_keys=() [ -f "$outbox" ] && [ ! -L "$outbox" ] || { echo "error: pending outbox is unavailable or unsafe: $outbox" >&2 return 1 @@ -704,7 +770,13 @@ remote_deliver_outbox() { # <secondmate-id> <outbox-path> wake_state=dropped wake_rc=1 elif ! receiver_wake_pending_valid "$id" && ! receiver_wake_confirmed_valid "$id"; then - receiver_wake_mark_pending "$id" || { + # The outbox's own item lines are the batch's ground truth here, valid + # for the fresh-stage call and every later resume alike since resuming + # only ever re-reads this same durable file. + while IFS= read -r key; do + [ -n "$key" ] && wake_keys+=("$key") + done < <(receiver_wake_item_keys_from_file "$outbox") + receiver_wake_mark_pending "$id" "$(receiver_wake_message "${wake_keys[@]}")" || { wake_state=dropped wake_rc=1 } @@ -717,6 +789,7 @@ remote_deliver_outbox() { # <secondmate-id> <outbox-path> return 1 } if [ "$wake_rc" -eq 0 ]; then + receiver_wake_message_clear "$id" if ! rm -f -- "$marker"; then RECEIVER_WAKE_IGNORE_ID=$id echo "warning: remote outbox and receiver wake completed, but a stale confirmed wake marker remains at $marker; later handoffs will ignore it" >&2 @@ -1048,7 +1121,7 @@ if [ -e "$WAKE_PENDING_MARKER" ] || [ -L "$WAKE_PENDING_MARKER" ]; then ;; esac fi -receiver_wake_mark_prepared "$ID" "$REQUESTED_BATCH" || { +receiver_wake_mark_prepared "$ID" "$REQUESTED_BATCH" "$(receiver_wake_message "${TO_MOVE[@]}")" || { echo "error: receiver wake state for secondmate $ID could not be recorded; nothing was moved" >&2 exit 1 } diff --git a/bin/fm-config-inherit-lib.sh b/bin/fm-config-inherit-lib.sh index 79ff10605c2..4fe87dbe0aa 100644 --- a/bin/fm-config-inherit-lib.sh +++ b/bin/fm-config-inherit-lib.sh @@ -221,6 +221,7 @@ warn_inheritable_config_error() { shared_captain_header_valid() { local src=$1 head head=$(sed -n '1,12p' "$src" 2>/dev/null) || return 1 + head=$(printf '%s' "$head" | tr '\n' ' ' | tr -s '[:space:]' ' ') case "$head" in *main-authoritative*) ;; *) return 1 ;; esac case "$head" in *"read-only in secondmate homes"*) ;; *) return 1 ;; esac case "$head" in *"must not be edited there"*) ;; *) return 1 ;; esac diff --git a/bin/fm-remote-inherit-push.sh b/bin/fm-remote-inherit-push.sh index 518e849b762..aacbcf5ba8d 100755 --- a/bin/fm-remote-inherit-push.sh +++ b/bin/fm-remote-inherit-push.sh @@ -29,15 +29,6 @@ sha256_file() { file_link_count() { if [ "$(uname)" = Darwin ]; then /usr/bin/stat -f %l "$1" 2>/dev/null; else stat -c %h "$1" 2>/dev/null; fi } -shared_captain_header_valid() { - local head - head=$(sed -n '1,12p' "$1" 2>/dev/null) || return 1 - case "$head" in *main-authoritative*) ;; *) return 1 ;; esac - case "$head" in *"read-only in secondmate homes"*) ;; *) return 1 ;; esac - case "$head" in *"must not be edited there"*) ;; *) return 1 ;; esac - case "$head" in *"main firstmate"*) ;; *) return 1 ;; esac - case "$head" in *"marked status"*|*"document pointer"*) ;; *) return 1 ;; esac -} [ "$#" -eq 2 ] || { echo "usage: fm-remote-inherit-push.sh <secondmate-id> <generation>" >&2; exit 2; } ID=$1 GENERATION=$2 diff --git a/bin/fm-watch-arm.sh b/bin/fm-watch-arm.sh index d134f519402..0e594923a7d 100755 --- a/bin/fm-watch-arm.sh +++ b/bin/fm-watch-arm.sh @@ -298,6 +298,12 @@ close_unobserved_cycle() { fi fm_lock_release "$WATCH_DELIVERY_LOCK" if [ -n "$reason" ]; then + # A delivery record whose reason starts with "absorbed" means the watcher + # ended after only absorbing benign events - perfectly healthy, just no + # actionable wake was ever published. Treat it as a clean close. + case "$reason" in + "absorbed "*) printf '%s\n' "$reason"; return 0 ;; + esac printf '%s\n' "$reason" return 0 fi diff --git a/bin/fm-watch.sh b/bin/fm-watch.sh index 31cf64aa43f..f28e915da47 100755 --- a/bin/fm-watch.sh +++ b/bin/fm-watch.sh @@ -2605,6 +2605,7 @@ EOF wake "$reason" fi triage_log "absorbed benign $reason" + watch_delivery_publish "absorbed benign $reason" || true fi fi @@ -2866,6 +2867,7 @@ EOF touch "$STATE/.last-heartbeat" echo $(( $(cat "$STATE/.heartbeat-streak" 2>/dev/null || echo 0) + 1 )) > "$STATE/.heartbeat-streak" triage_log "absorbed heartbeat (no captain-relevant change)" + watch_delivery_publish "absorbed heartbeat (no captain-relevant change)" || true fi fi diff --git a/tests/fm-backlog-handoff.test.sh b/tests/fm-backlog-handoff.test.sh index ef935ef187e..a4d6667025e 100755 --- a/tests/fm-backlog-handoff.test.sh +++ b/tests/fm-backlog-handoff.test.sh @@ -48,6 +48,19 @@ inbox_body_stream() { # <state-dir> <task-id> done } +# One line per durable inbox record's own body (fm_task_inbox_body prints no +# trailing newline of its own, so inbox_body_stream's concatenation is not +# usable when a caller needs to tell one record's body apart from another's). +inbox_bodies_by_record() { # <state-dir> <task-id> + local rec + for rec in "$1/$2.inbox"/*.msg; do + [ -f "$rec" ] || continue + bash -c '. "$1"; fm_task_inbox_body "$2"' _ \ + "$ROOT/bin/fm-task-inbox-lib.sh" "$rec" + printf '\n' + done +} + inbox_record_count() { # <state-dir> <task-id> find "$1/$2.inbox" -maxdepth 1 -type f -name '*.msg' 2>/dev/null | wc -l | tr -d '[:space:]' } @@ -1344,7 +1357,67 @@ EOF pass "registry entry without (home: ...) fails cleanly with has no home" } +# Regression for a real 2026-08-25 incident (backlog item +# handoff-nachricht-nennt-auftrag-nicht): the receiver's wake instruction used +# to be one fixed line with no indication which task it named, so two +# handoffs delivered close together were textually identical - the receiver +# read the second as an unproven repeat of the first and blocked on it. +test_two_consecutive_handoffs_name_their_own_items() { + local home="$TMP_ROOT/two-handoffs-main" sub="$TMP_ROOT/two-handoffs-sub" fakebin + local out1 out2 bodies first_line second_line + setup_homes "$home" "$sub" + mkdir -p "$sub/state" "$sub/data" + cat > "$home/data/backlog.md" <<'EOF' +## Queued +- [ ] postfach-uebergang-abschliessen - first routed item (repo: alpha) +- [ ] vault-regelfragen-umsetzung - second routed item (repo: alpha) + +## Done +EOF + printf '## Queued\n\n## Done\n' > "$sub/data/backlog.md" + fakebin=$(make_fake_tmux "$TMP_ROOT/two-handoffs-fake") + out1="$TMP_ROOT/two-handoffs-1.out" + out2="$TMP_ROOT/two-handoffs-2.out" + FM_HOME="$home" FM_ROOT_OVERRIDE="$ROOT" PATH="$fakebin:$PATH" \ + FM_FAKE_TMUX_WINDOW='firstmate:fm-design' \ + FM_FAKE_TMUX_LOG="$TMP_ROOT/two-handoffs-tmux.log" \ + FM_FAKE_TMUX_CAPTURE="$TMP_ROOT/two-handoffs-fake/pane.txt" \ + FM_SEND_SETTLE=0 FM_SEND_SLEEP=0 FM_SEND_RETRIES=1 \ + "$ROOT/bin/fm-backlog-handoff.sh" design postfach-uebergang-abschliessen \ + > "$out1" 2>&1 \ + || fail "first handoff failed: $(cat "$out1")" + FM_HOME="$home" FM_ROOT_OVERRIDE="$ROOT" PATH="$fakebin:$PATH" \ + FM_FAKE_TMUX_WINDOW='firstmate:fm-design' \ + FM_FAKE_TMUX_LOG="$TMP_ROOT/two-handoffs-tmux.log" \ + FM_FAKE_TMUX_CAPTURE="$TMP_ROOT/two-handoffs-fake/pane.txt" \ + FM_SEND_SETTLE=0 FM_SEND_SLEEP=0 FM_SEND_RETRIES=1 \ + "$ROOT/bin/fm-backlog-handoff.sh" design vault-regelfragen-umsetzung \ + > "$out2" 2>&1 \ + || fail "second handoff failed: $(cat "$out2")" + + bodies=$(inbox_body_stream "$home/state" design) + assert_contains "$bodies" 'New routed work is in your backlog.' \ + "receiver inbox lost the fixed routed-work instruction" + assert_contains "$bodies" 'postfach-uebergang-abschliessen' \ + "first handoff's message did not name its own item" + assert_contains "$bodies" 'vault-regelfragen-umsetzung' \ + "second handoff's message did not name its own item" + + bodies=$(inbox_bodies_by_record "$home/state" design) + first_line=$(printf '%s\n' "$bodies" | grep -F 'postfach-uebergang-abschliessen') + second_line=$(printf '%s\n' "$bodies" | grep -F 'vault-regelfragen-umsetzung') + [ "$first_line" != "$second_line" ] \ + || fail "two handoffs for different items produced the same message text: $first_line" + printf '%s\n' "$first_line" | grep -qF 'vault-regelfragen-umsetzung' \ + && fail "the first handoff's message also named the second item: $first_line" + printf '%s\n' "$second_line" | grep -qF 'postfach-uebergang-abschliessen' \ + && fail "the second handoff's message also named the first item: $second_line" + + pass "two consecutive handoffs each name their own item, so they are never textually identical" +} + test_handoff_wakes_live_local_receiver +test_two_consecutive_handoffs_name_their_own_items test_failed_wake_retries_when_the_item_is_already_present test_known_receiver_failure_remains_retryable_after_grace test_known_failure_restores_retry_after_reconciliation_race diff --git a/tests/fm-shared-captain-inheritance.test.sh b/tests/fm-shared-captain-inheritance.test.sh index efd61dd804f..d5656d96933 100755 --- a/tests/fm-shared-captain-inheritance.test.sh +++ b/tests/fm-shared-captain-inheritance.test.sh @@ -204,6 +204,68 @@ test_unsafe_artifacts_and_failure_restore_readonly_mode() { pass "unsafe shared captain artifacts are rejected and failure restores read-only mode" } +test_header_validation_tolerates_reflow_but_rejects_missing_phrase() { + local rec primary second reflowed err rc + + reflowed=$(mktemp "$TMP_ROOT/reflowed-header.XXXXXX") + cat > "$reflowed" <<'EOF' +# Shared captain preferences + +This file is main-authoritative in the main +firstmate home. +In secondmate homes it is read-only in secondmate +homes and must not be edited there. +Route new captain-preference discoveries to the main firstmate through marked status or a document pointer. +EOF + shared_captain_header_valid "$reflowed" \ + || fail "a header reflowed mid-phrase should still validate when every phrase's words are intact" + + rec=$(new_home_pair header-reflow) + primary=${rec%%|*} + second=${rec#*|} + write_shared "$primary/data/captain-shared.md" "reflow-carrying shared body" + sed -i.bak 's/^This file is main-authoritative in the main firstmate home\.$/This file is main-authoritative in the main\nfirstmate home./' \ + "$primary/data/captain-shared.md" + rm -f "$primary/data/captain-shared.md.bak" + + propagate_secondmate_inheritance "$primary" "$second" >/dev/null 2>"$TMP_ROOT/header-reflow.err" \ + || fail "reflowed but semantically intact header should still propagate" + cmp -s "$primary/data/captain-shared.md" "$second/data/captain-shared.md" \ + || fail "reflowed header propagation did not converge secondmate shared preferences" + + rm -f "$reflowed" + reflowed=$(mktemp "$TMP_ROOT/missing-phrase-header.XXXXXX") + cat > "$reflowed" <<'EOF' +# Shared captain preferences + +This file is main-authoritative in the main firstmate home. +Route new captain-preference discoveries to the main firstmate through marked status or a document pointer. +EOF + if shared_captain_header_valid "$reflowed"; then + fail "a header genuinely missing a required phrase must still be rejected" + fi + + rec=$(new_home_pair header-missing) + primary=${rec%%|*} + second=${rec#*|} + cat > "$primary/data/captain-shared.md" <<'EOF' +# Shared captain preferences + +This file is main-authoritative in the main firstmate home. +Route new captain-preference discoveries to the main firstmate through marked status or a document pointer. + +missing-phrase shared body +EOF + err="$TMP_ROOT/header-missing.err" + propagate_secondmate_inheritance "$primary" "$second" >/dev/null 2>"$err"; rc=$? + [ "$rc" -ne 0 ] || fail "header genuinely missing a required phrase should be rejected" + assert_grep "primary source header missing required main-authoritative warning" "$err" \ + "missing-phrase rejection error should be explicit" + assert_absent "$second/data/captain-shared.md" "rejected header should not propagate to the secondmate" + + pass "shared captain header validation tolerates mid-phrase reflow but still rejects a genuinely missing phrase" +} + make_fake_spawn_toolchain() { local dir=$1 fakebin fakebin="$dir/fakebin" @@ -396,6 +458,7 @@ test_first_copy_readonly_and_local_files_preserved test_drift_quarantine_collision_and_repeated_convergence test_missing_source_mirrors_absence_without_losing_local_bytes test_unsafe_artifacts_and_failure_restore_readonly_mode +test_header_validation_tolerates_reflow_but_rejects_missing_phrase test_spawn_convergence_point_copies_shared_file test_bootstrap_convergence_point_copies_shared_file test_config_push_convergence_point_updates_changed_source diff --git a/tests/fm-watch-benign-absorb.test.sh b/tests/fm-watch-benign-absorb.test.sh new file mode 100644 index 00000000000..032b8b52997 --- /dev/null +++ b/tests/fm-watch-benign-absorb.test.sh @@ -0,0 +1,258 @@ +#!/usr/bin/env bash +# tests/fm-watch-benign-absorb.test.sh - regression tests for the benign-absorb +# delivery-record fix. +# +# Before this fix, a watcher cycle that ended after only absorbing benign events +# (no wake() call) was reported as +# "watcher: FAILED - cycle ended without an actionable reason" +# by an attached arm, even though the watcher ran perfectly healthy - it simply +# had nothing actionable to report. The watcher publishes a delivery-ledger record +# inside watch_delivery_publish() only from wake(), so benign-absorb paths never +# wrote one. close_unobserved_cycle() in the arm found no record and failed. +# +# The fix: absorb paths now also call watch_delivery_publish with a reason starting +# "absorbed", and close_unobserved_cycle() treats "absorbed" delivery records as +# a clean close instead of FAILED. +# +# These are real-process tests: a real bin/fm-watch.sh holds the singleton, a real +# bin/fm-watch-arm.sh attaches to it, and we verify both the fixed false-positive +# and the preserved genuine-failure alarm. + +set -u + +# shellcheck source=tests/wake-helpers.sh +. "$(dirname "${BASH_SOURCE[0]}")/wake-helpers.sh" + +WATCH="$ROOT/bin/fm-watch.sh" +WATCH_ARM="$ROOT/bin/fm-watch-arm.sh" +DRAIN="$ROOT/bin/fm-wake-drain.sh" + +TMP_ROOT=$(fm_test_tmproot fm-watch-benign-absorb-tests) + +SEED_PID= +ARM_PID= + +# Start the real watcher as the singleton holder. +# Sets FM_HOME to the case's home dir so all state is isolated. +start_seed_watcher() { # <home> <state> <fakebin> <watch-out> + local home=$1 state=$2 fakebin=$3 out=$4 i + PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" FM_POLL=1 \ + FM_SIGNAL_GRACE=1 FM_CHECK_INTERVAL=999999 FM_HEARTBEAT=999999 "$WATCH" > "$out" & + SEED_PID=$! + i=0 + while [ "$i" -lt 60 ]; do + [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ + && [ -e "$state/.last-watcher-beat" ] && break + sleep 0.1 + i=$((i + 1)) + done + [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ + || fail "seed watcher did not take the lock" +} + +# Attach a real arm to the live cycle. +start_attached_arm() { # <home> <state> <fakebin> <arm-out> <confirm-timeout> + local home=$1 state=$2 fakebin=$3 armout=$4 confirm=$5 i + PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" \ + FM_ARM_ATTACH_POLL=0.1 FM_ARM_CONFIRM_TIMEOUT="$confirm" "$WATCH_ARM" > "$armout" & + ARM_PID=$! + i=0 + while [ "$i" -lt 80 ]; do + grep -qF "watcher: attached pid=$SEED_PID" "$armout" 2>/dev/null && break + sleep 0.1 + i=$((i + 1)) + done + grep -qF "watcher: attached pid=$SEED_PID" "$armout" \ + || fail "arm did not attach to the live watcher: $(cat "$armout")" +} + +# --- regression: benign absorb (signal) then clean exit --- + +test_attached_arm_clean_close_after_benign_signal_absorb() { + local dir home state fakebin out armout status + dir=$(make_case benign-signal-absorb-clean-close) + home="$dir/home" + state="$dir/state" + fakebin="$dir/fakebin" + out="$dir/watch.out" + armout="$dir/arm.out" + mkdir -p "$home/data" + + # Create a benign status file: "working: step 1" is a no-verb status + # whose crew will be classed as NOT provably working by default (unknown). + # To make it benign, we need to set the fake verdict to provably working + # via FM_FAKE_CREW_STATE in the watcher's environment. + printf 'working: step 1\n' > "$state/task.status" + + # Start the watcher with a fake crew-state that classifies this task as + # provably working, so the signal is benign and gets absorbed. + PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" \ + FM_CREW_STATE_BIN="$fakebin/fm-crew-state.sh" \ + FM_FAKE_CREW_STATE='state: working · source: run-step · validating (running)' \ + FM_POLL=1 FM_SIGNAL_GRACE=1 FM_CHECK_INTERVAL=999999 FM_HEARTBEAT=999999 \ + "$WATCH" > "$out" & + SEED_PID=$! + i=0 + while [ "$i" -lt 60 ]; do + [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ + && [ -e "$state/.last-watcher-beat" ] && break + sleep 0.1 + i=$((i + 1)) + done + [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ + || fail "seed watcher did not take the lock" + + start_attached_arm "$home" "$state" "$fakebin" "$armout" 1 + + # The watcher sees task.status as "working: step 1" with provably-working crew. + # It should absorb (benign) and log "absorbed benign". Let it absorb at least + # one full poll cycle. + sleep 3 + + # Now kill the watcher. The attached arm should find the "absorbed benign" + # delivery record and report clean exit, not FAILED. + kill -TERM "$SEED_PID" 2>/dev/null || true + wait "$SEED_PID" 2>/dev/null || true + + wait_for_exit "$ARM_PID" 120 || { + kill -KILL "$ARM_PID" 2>/dev/null || true + fail "attached arm did not close after benign-signal-absorb watcher exit" + } + status=$? + + # Verify: no FAILED line, and a clean close reason starting with "absorbed" + grep -qF 'watcher: FAILED' "$armout" \ + && fail "attached arm reported a benign-absorb close as FAILED: $(cat "$armout")" + + # The arm should report the absorbed reason from the delivery record + grep -qE '^absorbed ' "$armout" \ + || fail "attached arm did not report the absorbed close reason: $(cat "$armout")" + + expect_code 0 "$status" "a benign-signal-absorb close must exit cleanly" + pass "watch-arm: attached arm reports clean close after watcher that absorbed benign signals" +} + +# --- regression: benign absorb (heartbeat) then clean exit --- + +test_attached_arm_clean_close_after_benign_heartbeat_absorb() { + local dir home state fakebin out armout status + dir=$(make_case benign-heartbeat-absorb-clean-close) + home="$dir/home" + state="$dir/state" + fakebin="$dir/fakebin" + out="$dir/watch.out" + armout="$dir/arm.out" + mkdir -p "$home/data" + + # Create a benign status file so the heartbeat scan has something to scan. + printf 'working: step 1\n' > "$state/task.status" + # Prime the .seen-* suppressor so the heartbeat scan sees nothing new. + prime_status_seen "$state" "$state/task.status" + + # Use a short HEARTBEAT so the heartbeat scan runs every poll cycle. + PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" FM_POLL=1 \ + FM_HEARTBEAT=1 FM_SIGNAL_GRACE=1 FM_CHECK_INTERVAL=999999 \ + "$WATCH" > "$out" & + SEED_PID=$! + i=0 + while [ "$i" -lt 60 ]; do + [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ + && [ -e "$state/.last-watcher-beat" ] && break + sleep 0.1 + i=$((i + 1)) + done + [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ + || fail "seed watcher did not take the lock" + + start_attached_arm "$home" "$state" "$fakebin" "$armout" 1 + + # Heartbeat scan will find task.status but the .seen-* suppressor means + # nothing actionable. The watcher absorbs and logs "absorbed heartbeat". + # FM_HEARTBEAT=1 means the first heartbeat runs after ~1s, then doubles. + # Wait 2s to ensure at least one heartbeat cycle completes. + sleep 3 + + # Kill the watcher. The attached arm should find the "absorbed heartbeat" + # delivery record and report clean exit. + kill -TERM "$SEED_PID" 2>/dev/null || true + wait "$SEED_PID" 2>/dev/null || true + + wait_for_exit "$ARM_PID" 120 || { + kill -KILL "$ARM_PID" 2>/dev/null || true + fail "attached arm did not close after benign-heartbeat-absorb watcher exit" + } + status=$? + + # Verify: no FAILED line + grep -qF 'watcher: FAILED' "$armout" \ + && fail "attached arm reported a benign-heartbeat-absorb close as FAILED: $(cat "$armout")" + + # The arm should report the absorbed heartbeat reason + grep -qE '^absorbed heartbeat' "$armout" \ + || fail "attached arm did not report the absorbed heartbeat reason: $(cat "$armout")" + + expect_code 0 "$status" "a benign-heartbeat-absorb close must exit cleanly" + pass "watch-arm: attached arm reports clean close after watcher that absorbed benign heartbeat" +} + +# --- regression: genuine failure still fails --- + +test_attached_arm_still_fails_when_no_delivery_record_at_all() { + local dir home state fakebin out armout + dir=$(make_case benign-absorb-no-record-genuine-failure) + home="$dir/home" + state="$dir/state" + fakebin="$dir/fakebin" + out="$dir/watch.out" + armout="$dir/arm.out" + mkdir -p "$home/data" + + # Start a real watcher. No status files at all - the watcher will silently + # loop (no pending, no stale, no heartbeat actionable). No delivery record + # will ever be published. + start_seed_watcher "$home" "$state" "$fakebin" "$out" + start_attached_arm "$home" "$state" "$fakebin" "$armout" 1 + + # Give the arm time to fully attach and settle before we kill the watcher. + # This ensures the arm's cycle_watcher_pid/identity are correctly set. + sleep 1 + + # Kill the watcher abruptly before any poll cycle completes. This simulates a + # genuinely unexplained gap: the watcher process was destroyed before it could + # publish any delivery record (no wake, no absorb, nothing). + kill -KILL "$SEED_PID" 2>/dev/null || true + wait "$SEED_PID" 2>/dev/null || true + + # The arm must still detect this as FAILED because there is no delivery record + # at all - not a wake record and not an absorbed record. This is the real safety + # property that must not be weakened. + # Wait for the arm to exit (it will exit with code 1 because it reports FAILED). + # We poll kill -0 and then call wait ourselves to capture the exit code. + i=0 + arm_exit=124 + while [ "$i" -lt 300 ]; do + if ! kill -0 "$ARM_PID" 2>/dev/null; then + wait "$ARM_PID" 2>/dev/null + arm_exit=$? + break + fi + sleep 0.1 + i=$((i + 1)) + done + if [ "$i" -ge 300 ]; then + kill -KILL "$ARM_PID" 2>/dev/null || true + fail "arm did not close after abrupt watcher kill" + fi + + # The genuine failure case: no delivery record at all -> FAILED + # The arm should have exited nonzero (code 1 = fail_unexplained_cycle) + [ "$arm_exit" -ne 0 ] || fail "arm exited 0 when it should have failed: $(cat "$armout")" + grep -qF 'watcher: FAILED - cycle ended without an actionable reason' "$armout" \ + || fail "genuine failure (no delivery record) was not reported as FAILED: $(cat "$armout")" + + pass "watch-arm: a cycle with no delivery record at all still fails loudly" +} + +test_attached_arm_clean_close_after_benign_signal_absorb +test_attached_arm_clean_close_after_benign_heartbeat_absorb +test_attached_arm_still_fails_when_no_delivery_record_at_all From 61cc53ede19fae9d1308edb75f76fea45ecd778d Mon Sep 17 00:00:00 2001 From: MLA82 <212341412+MLA82@users.noreply.github.com> Date: Fri, 11 Sep 2026 00:52:14 +0200 Subject: [PATCH 2/4] docs(watcher-continuity): Document absorbed-only cycle recording and resolution --- docs/watcher-continuity.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/docs/watcher-continuity.md b/docs/watcher-continuity.md index 9f79edf94cd..78229ce4f07 100644 --- a/docs/watcher-continuity.md +++ b/docs/watcher-continuity.md @@ -101,7 +101,9 @@ An actionable child output returns that reason normally. A zero/empty child return rechecks the home lock and beacon, attaches to a verified healthy successor when one exists, or resolves the close against the watcher's bounded terminal-delivery ledger. An attached arm follows verified identity-matched successors and resolves the same way when that chain ends without one, because it holds no handle on the watcher's stdout and cannot read the reason line itself. Before releasing its singleton lock after printing an actionable reason, the watcher records that reason with its PID and process identity in `state/.watch-deliveries.log`. +It publishes the same kind of record, without exiting, for a benign absorbed-only cycle (an absorbed signal or an absorbed heartbeat), so a later unexplained close still has a record to attach to even when the watcher never had an actionable reason to print. A matching PID and identity lets an attached arm report the delivered reason and exit zero even after its durable wake was handled and acknowledged, while an unrelated queue producer or a recycled PID cannot satisfy the match. +A matching record whose reason starts with `absorbed` resolves as a clean close rather than a failure, since it proves the watcher ended after only absorbing benign wakes. Only a cycle with no matching delivery record emits `watcher: FAILED - cycle ended without an actionable reason` and exits nonzero. The arm layer appends one tab-separated record per observed cycle to `state/.watch-cycle-exits.log`. From 1a094bcfbc4414fa94701b1070601e4a5ca6abdb Mon Sep 17 00:00:00 2001 From: MLA82 <212341412+MLA82@users.noreply.github.com> Date: Fri, 11 Sep 2026 04:58:40 +0200 Subject: [PATCH 3/4] no-mistakes(review): Drop benign-absorb change; name reused remote wake items --- bin/fm-backlog-handoff.sh | 44 +++- bin/fm-watch-arm.sh | 6 - bin/fm-watch.sh | 2 - docs/watcher-continuity.md | 2 - tests/fm-remote-backlog-handoff.test.sh | 7 + tests/fm-watch-benign-absorb.test.sh | 258 ------------------------ 6 files changed, 42 insertions(+), 277 deletions(-) delete mode 100644 tests/fm-watch-benign-absorb.test.sh diff --git a/bin/fm-backlog-handoff.sh b/bin/fm-backlog-handoff.sh index c4da0ad3406..de9d9a1b75c 100755 --- a/bin/fm-backlog-handoff.sh +++ b/bin/fm-backlog-handoff.sh @@ -151,6 +151,27 @@ receiver_wake_message_clear() { # <secondmate-id> rm -f -- "$(receiver_wake_message_path "$1")" } +# A still-pending wake that a later batch reuses must name every item routed +# since it was recorded, so the new keys are merged into the stored list. A +# stored generic line names no items and is left as it is. +receiver_wake_message_add_keys() { # <secondmate-id> <item-key>... + local id=$1 prefix="$RECEIVER_WAKE_MESSAGE Routed: " message key + local -a keys=() + shift + message=$(receiver_wake_message_read "$id") + case "$message" in "$prefix"*.) ;; *) return 0 ;; esac + message=${message#"$prefix"} + message=${message%.} + while [ -n "$message" ]; do + keys+=("${message%%, *}") + case "$message" in *", "*) message=${message#*, } ;; *) message= ;; esac + done + for key in "$@"; do + case " ${keys[*]} " in *" $key "*) ;; *) keys+=("$key") ;; esac + done + receiver_wake_message_write "$id" "$(receiver_wake_message "${keys[@]}")" +} + ACTIVE_HANDOFF_LOCK= ACTIVE_REGISTRY_LOCK= RECEIVER_WAKE_IGNORE_ID= @@ -687,7 +708,7 @@ outbox_item_count() { # <path> } remote_deliver_outbox() { # <secondmate-id> <outbox-path> - local id=$1 outbox=$2 remote_rel receive_out snapshot bytes hash generation counter counter_tmp current marker wake_rc=0 wake_state=pending + local id=$1 outbox=$2 remote_rel receive_out snapshot bytes hash generation counter counter_tmp current marker wake_rc=0 wake_state=pending key local -a wake_keys=() [ -f "$outbox" ] && [ ! -L "$outbox" ] || { echo "error: pending outbox is unavailable or unsafe: $outbox" >&2 @@ -766,17 +787,22 @@ remote_deliver_outbox() { # <secondmate-id> <outbox-path> return 1 fi marker="$STATE/.backlog-handoff-$id.wake-pending" + # The outbox's own item lines are the batch's ground truth here, valid + # for the fresh-stage call and every later resume alike since resuming + # only ever re-reads this same durable file. + while IFS= read -r key; do + [ -n "$key" ] && wake_keys+=("$key") + done < <(receiver_wake_item_keys_from_file "$outbox") if [ "$RECEIVER_WAKE_IGNORE_ID" = "$id" ]; then wake_state=dropped wake_rc=1 - elif ! receiver_wake_pending_valid "$id" && ! receiver_wake_confirmed_valid "$id"; then - # The outbox's own item lines are the batch's ground truth here, valid - # for the fresh-stage call and every later resume alike since resuming - # only ever re-reads this same durable file. - while IFS= read -r key; do - [ -n "$key" ] && wake_keys+=("$key") - done < <(receiver_wake_item_keys_from_file "$outbox") - receiver_wake_mark_pending "$id" "$(receiver_wake_message "${wake_keys[@]}")" || { + elif receiver_wake_pending_valid "$id"; then + receiver_wake_message_add_keys "$id" ${wake_keys[@]+"${wake_keys[@]}"} || { + wake_state=dropped + wake_rc=1 + } + elif ! receiver_wake_confirmed_valid "$id"; then + receiver_wake_mark_pending "$id" "$(receiver_wake_message ${wake_keys[@]+"${wake_keys[@]}"})" || { wake_state=dropped wake_rc=1 } diff --git a/bin/fm-watch-arm.sh b/bin/fm-watch-arm.sh index 0e594923a7d..d134f519402 100755 --- a/bin/fm-watch-arm.sh +++ b/bin/fm-watch-arm.sh @@ -298,12 +298,6 @@ close_unobserved_cycle() { fi fm_lock_release "$WATCH_DELIVERY_LOCK" if [ -n "$reason" ]; then - # A delivery record whose reason starts with "absorbed" means the watcher - # ended after only absorbing benign events - perfectly healthy, just no - # actionable wake was ever published. Treat it as a clean close. - case "$reason" in - "absorbed "*) printf '%s\n' "$reason"; return 0 ;; - esac printf '%s\n' "$reason" return 0 fi diff --git a/bin/fm-watch.sh b/bin/fm-watch.sh index f28e915da47..31cf64aa43f 100755 --- a/bin/fm-watch.sh +++ b/bin/fm-watch.sh @@ -2605,7 +2605,6 @@ EOF wake "$reason" fi triage_log "absorbed benign $reason" - watch_delivery_publish "absorbed benign $reason" || true fi fi @@ -2867,7 +2866,6 @@ EOF touch "$STATE/.last-heartbeat" echo $(( $(cat "$STATE/.heartbeat-streak" 2>/dev/null || echo 0) + 1 )) > "$STATE/.heartbeat-streak" triage_log "absorbed heartbeat (no captain-relevant change)" - watch_delivery_publish "absorbed heartbeat (no captain-relevant change)" || true fi fi diff --git a/docs/watcher-continuity.md b/docs/watcher-continuity.md index 78229ce4f07..9f79edf94cd 100644 --- a/docs/watcher-continuity.md +++ b/docs/watcher-continuity.md @@ -101,9 +101,7 @@ An actionable child output returns that reason normally. A zero/empty child return rechecks the home lock and beacon, attaches to a verified healthy successor when one exists, or resolves the close against the watcher's bounded terminal-delivery ledger. An attached arm follows verified identity-matched successors and resolves the same way when that chain ends without one, because it holds no handle on the watcher's stdout and cannot read the reason line itself. Before releasing its singleton lock after printing an actionable reason, the watcher records that reason with its PID and process identity in `state/.watch-deliveries.log`. -It publishes the same kind of record, without exiting, for a benign absorbed-only cycle (an absorbed signal or an absorbed heartbeat), so a later unexplained close still has a record to attach to even when the watcher never had an actionable reason to print. A matching PID and identity lets an attached arm report the delivered reason and exit zero even after its durable wake was handled and acknowledged, while an unrelated queue producer or a recycled PID cannot satisfy the match. -A matching record whose reason starts with `absorbed` resolves as a clean close rather than a failure, since it proves the watcher ended after only absorbing benign wakes. Only a cycle with no matching delivery record emits `watcher: FAILED - cycle ended without an actionable reason` and exits nonzero. The arm layer appends one tab-separated record per observed cycle to `state/.watch-cycle-exits.log`. diff --git a/tests/fm-remote-backlog-handoff.test.sh b/tests/fm-remote-backlog-handoff.test.sh index f05c1ad14fe..4e5af744c50 100755 --- a/tests/fm-remote-backlog-handoff.test.sh +++ b/tests/fm-remote-backlog-handoff.test.sh @@ -102,6 +102,8 @@ command_name=$(perl -MMIME::Base64=decode_base64 -e '$d=decode_base64($ARGV[0]); case "${FM_FAKE_SSH_MODE:-normal}:$command_name" in *:fm-remote-secondmate-control.sh) printf '%s\n' "$command_name" >> "$FM_FAKE_REMOTE_WAKE_LOG" + perl -MMIME::Base64=decode_base64 -e '$d=decode_base64($ARGV[0]); $d=~tr/\0\n/ /; print "$d\n"' "$argv_b64" \ + >> "$FM_FAKE_REMOTE_WAKE_LOG.argv" [ "${FM_FAKE_REMOTE_WAKE_RC:-0}" -eq 0 ] || printf 'remote receiver wake failed\n' >&2 exit "${FM_FAKE_REMOTE_WAKE_RC:-0}" ;; @@ -446,6 +448,11 @@ assert_absent "$PARENT/data/handoff/ios.outbox.md" "permanently lost wake retain || fail "later handoff did not retain the same pending wake correlation" [ "$(grep -cF fm-remote-secondmate-control.sh "$WAKE_LOG")" -gt "$wakes_after_resume" ] \ || fail "later handoff did not retry the separately pending wake" +reused_wake=$(tail -n 1 "$WAKE_LOG.argv") +assert_contains "$reused_wake" 'wake-permanent-a' \ + "reused pending wake dropped the earlier batch's item" +assert_contains "$reused_wake" 'wake-permanent-b' \ + "reused pending wake did not name the later batch's item" pass "a permanently unconfirmable wake never jams later durable handoffs" RM_FAKEBIN="$TMP_ROOT/rm-fakebin" diff --git a/tests/fm-watch-benign-absorb.test.sh b/tests/fm-watch-benign-absorb.test.sh deleted file mode 100644 index 032b8b52997..00000000000 --- a/tests/fm-watch-benign-absorb.test.sh +++ /dev/null @@ -1,258 +0,0 @@ -#!/usr/bin/env bash -# tests/fm-watch-benign-absorb.test.sh - regression tests for the benign-absorb -# delivery-record fix. -# -# Before this fix, a watcher cycle that ended after only absorbing benign events -# (no wake() call) was reported as -# "watcher: FAILED - cycle ended without an actionable reason" -# by an attached arm, even though the watcher ran perfectly healthy - it simply -# had nothing actionable to report. The watcher publishes a delivery-ledger record -# inside watch_delivery_publish() only from wake(), so benign-absorb paths never -# wrote one. close_unobserved_cycle() in the arm found no record and failed. -# -# The fix: absorb paths now also call watch_delivery_publish with a reason starting -# "absorbed", and close_unobserved_cycle() treats "absorbed" delivery records as -# a clean close instead of FAILED. -# -# These are real-process tests: a real bin/fm-watch.sh holds the singleton, a real -# bin/fm-watch-arm.sh attaches to it, and we verify both the fixed false-positive -# and the preserved genuine-failure alarm. - -set -u - -# shellcheck source=tests/wake-helpers.sh -. "$(dirname "${BASH_SOURCE[0]}")/wake-helpers.sh" - -WATCH="$ROOT/bin/fm-watch.sh" -WATCH_ARM="$ROOT/bin/fm-watch-arm.sh" -DRAIN="$ROOT/bin/fm-wake-drain.sh" - -TMP_ROOT=$(fm_test_tmproot fm-watch-benign-absorb-tests) - -SEED_PID= -ARM_PID= - -# Start the real watcher as the singleton holder. -# Sets FM_HOME to the case's home dir so all state is isolated. -start_seed_watcher() { # <home> <state> <fakebin> <watch-out> - local home=$1 state=$2 fakebin=$3 out=$4 i - PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" FM_POLL=1 \ - FM_SIGNAL_GRACE=1 FM_CHECK_INTERVAL=999999 FM_HEARTBEAT=999999 "$WATCH" > "$out" & - SEED_PID=$! - i=0 - while [ "$i" -lt 60 ]; do - [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ - && [ -e "$state/.last-watcher-beat" ] && break - sleep 0.1 - i=$((i + 1)) - done - [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ - || fail "seed watcher did not take the lock" -} - -# Attach a real arm to the live cycle. -start_attached_arm() { # <home> <state> <fakebin> <arm-out> <confirm-timeout> - local home=$1 state=$2 fakebin=$3 armout=$4 confirm=$5 i - PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" \ - FM_ARM_ATTACH_POLL=0.1 FM_ARM_CONFIRM_TIMEOUT="$confirm" "$WATCH_ARM" > "$armout" & - ARM_PID=$! - i=0 - while [ "$i" -lt 80 ]; do - grep -qF "watcher: attached pid=$SEED_PID" "$armout" 2>/dev/null && break - sleep 0.1 - i=$((i + 1)) - done - grep -qF "watcher: attached pid=$SEED_PID" "$armout" \ - || fail "arm did not attach to the live watcher: $(cat "$armout")" -} - -# --- regression: benign absorb (signal) then clean exit --- - -test_attached_arm_clean_close_after_benign_signal_absorb() { - local dir home state fakebin out armout status - dir=$(make_case benign-signal-absorb-clean-close) - home="$dir/home" - state="$dir/state" - fakebin="$dir/fakebin" - out="$dir/watch.out" - armout="$dir/arm.out" - mkdir -p "$home/data" - - # Create a benign status file: "working: step 1" is a no-verb status - # whose crew will be classed as NOT provably working by default (unknown). - # To make it benign, we need to set the fake verdict to provably working - # via FM_FAKE_CREW_STATE in the watcher's environment. - printf 'working: step 1\n' > "$state/task.status" - - # Start the watcher with a fake crew-state that classifies this task as - # provably working, so the signal is benign and gets absorbed. - PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" \ - FM_CREW_STATE_BIN="$fakebin/fm-crew-state.sh" \ - FM_FAKE_CREW_STATE='state: working · source: run-step · validating (running)' \ - FM_POLL=1 FM_SIGNAL_GRACE=1 FM_CHECK_INTERVAL=999999 FM_HEARTBEAT=999999 \ - "$WATCH" > "$out" & - SEED_PID=$! - i=0 - while [ "$i" -lt 60 ]; do - [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ - && [ -e "$state/.last-watcher-beat" ] && break - sleep 0.1 - i=$((i + 1)) - done - [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ - || fail "seed watcher did not take the lock" - - start_attached_arm "$home" "$state" "$fakebin" "$armout" 1 - - # The watcher sees task.status as "working: step 1" with provably-working crew. - # It should absorb (benign) and log "absorbed benign". Let it absorb at least - # one full poll cycle. - sleep 3 - - # Now kill the watcher. The attached arm should find the "absorbed benign" - # delivery record and report clean exit, not FAILED. - kill -TERM "$SEED_PID" 2>/dev/null || true - wait "$SEED_PID" 2>/dev/null || true - - wait_for_exit "$ARM_PID" 120 || { - kill -KILL "$ARM_PID" 2>/dev/null || true - fail "attached arm did not close after benign-signal-absorb watcher exit" - } - status=$? - - # Verify: no FAILED line, and a clean close reason starting with "absorbed" - grep -qF 'watcher: FAILED' "$armout" \ - && fail "attached arm reported a benign-absorb close as FAILED: $(cat "$armout")" - - # The arm should report the absorbed reason from the delivery record - grep -qE '^absorbed ' "$armout" \ - || fail "attached arm did not report the absorbed close reason: $(cat "$armout")" - - expect_code 0 "$status" "a benign-signal-absorb close must exit cleanly" - pass "watch-arm: attached arm reports clean close after watcher that absorbed benign signals" -} - -# --- regression: benign absorb (heartbeat) then clean exit --- - -test_attached_arm_clean_close_after_benign_heartbeat_absorb() { - local dir home state fakebin out armout status - dir=$(make_case benign-heartbeat-absorb-clean-close) - home="$dir/home" - state="$dir/state" - fakebin="$dir/fakebin" - out="$dir/watch.out" - armout="$dir/arm.out" - mkdir -p "$home/data" - - # Create a benign status file so the heartbeat scan has something to scan. - printf 'working: step 1\n' > "$state/task.status" - # Prime the .seen-* suppressor so the heartbeat scan sees nothing new. - prime_status_seen "$state" "$state/task.status" - - # Use a short HEARTBEAT so the heartbeat scan runs every poll cycle. - PATH="$fakebin:$PATH" FM_HOME="$home" FM_STATE_OVERRIDE="$state" FM_POLL=1 \ - FM_HEARTBEAT=1 FM_SIGNAL_GRACE=1 FM_CHECK_INTERVAL=999999 \ - "$WATCH" > "$out" & - SEED_PID=$! - i=0 - while [ "$i" -lt 60 ]; do - [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ - && [ -e "$state/.last-watcher-beat" ] && break - sleep 0.1 - i=$((i + 1)) - done - [ "$(cat "$state/.watch.lock/pid" 2>/dev/null || true)" = "$SEED_PID" ] \ - || fail "seed watcher did not take the lock" - - start_attached_arm "$home" "$state" "$fakebin" "$armout" 1 - - # Heartbeat scan will find task.status but the .seen-* suppressor means - # nothing actionable. The watcher absorbs and logs "absorbed heartbeat". - # FM_HEARTBEAT=1 means the first heartbeat runs after ~1s, then doubles. - # Wait 2s to ensure at least one heartbeat cycle completes. - sleep 3 - - # Kill the watcher. The attached arm should find the "absorbed heartbeat" - # delivery record and report clean exit. - kill -TERM "$SEED_PID" 2>/dev/null || true - wait "$SEED_PID" 2>/dev/null || true - - wait_for_exit "$ARM_PID" 120 || { - kill -KILL "$ARM_PID" 2>/dev/null || true - fail "attached arm did not close after benign-heartbeat-absorb watcher exit" - } - status=$? - - # Verify: no FAILED line - grep -qF 'watcher: FAILED' "$armout" \ - && fail "attached arm reported a benign-heartbeat-absorb close as FAILED: $(cat "$armout")" - - # The arm should report the absorbed heartbeat reason - grep -qE '^absorbed heartbeat' "$armout" \ - || fail "attached arm did not report the absorbed heartbeat reason: $(cat "$armout")" - - expect_code 0 "$status" "a benign-heartbeat-absorb close must exit cleanly" - pass "watch-arm: attached arm reports clean close after watcher that absorbed benign heartbeat" -} - -# --- regression: genuine failure still fails --- - -test_attached_arm_still_fails_when_no_delivery_record_at_all() { - local dir home state fakebin out armout - dir=$(make_case benign-absorb-no-record-genuine-failure) - home="$dir/home" - state="$dir/state" - fakebin="$dir/fakebin" - out="$dir/watch.out" - armout="$dir/arm.out" - mkdir -p "$home/data" - - # Start a real watcher. No status files at all - the watcher will silently - # loop (no pending, no stale, no heartbeat actionable). No delivery record - # will ever be published. - start_seed_watcher "$home" "$state" "$fakebin" "$out" - start_attached_arm "$home" "$state" "$fakebin" "$armout" 1 - - # Give the arm time to fully attach and settle before we kill the watcher. - # This ensures the arm's cycle_watcher_pid/identity are correctly set. - sleep 1 - - # Kill the watcher abruptly before any poll cycle completes. This simulates a - # genuinely unexplained gap: the watcher process was destroyed before it could - # publish any delivery record (no wake, no absorb, nothing). - kill -KILL "$SEED_PID" 2>/dev/null || true - wait "$SEED_PID" 2>/dev/null || true - - # The arm must still detect this as FAILED because there is no delivery record - # at all - not a wake record and not an absorbed record. This is the real safety - # property that must not be weakened. - # Wait for the arm to exit (it will exit with code 1 because it reports FAILED). - # We poll kill -0 and then call wait ourselves to capture the exit code. - i=0 - arm_exit=124 - while [ "$i" -lt 300 ]; do - if ! kill -0 "$ARM_PID" 2>/dev/null; then - wait "$ARM_PID" 2>/dev/null - arm_exit=$? - break - fi - sleep 0.1 - i=$((i + 1)) - done - if [ "$i" -ge 300 ]; then - kill -KILL "$ARM_PID" 2>/dev/null || true - fail "arm did not close after abrupt watcher kill" - fi - - # The genuine failure case: no delivery record at all -> FAILED - # The arm should have exited nonzero (code 1 = fail_unexplained_cycle) - [ "$arm_exit" -ne 0 ] || fail "arm exited 0 when it should have failed: $(cat "$armout")" - grep -qF 'watcher: FAILED - cycle ended without an actionable reason' "$armout" \ - || fail "genuine failure (no delivery record) was not reported as FAILED: $(cat "$armout")" - - pass "watch-arm: a cycle with no delivery record at all still fails loudly" -} - -test_attached_arm_clean_close_after_benign_signal_absorb -test_attached_arm_clean_close_after_benign_heartbeat_absorb -test_attached_arm_still_fails_when_no_delivery_record_at_all From 16b12faa85405f68fcf163b81fb91152c8dfac76 Mon Sep 17 00:00:00 2001 From: MLA82 <212341412+MLA82@users.noreply.github.com> Date: Fri, 11 Sep 2026 05:20:11 +0200 Subject: [PATCH 4/4] no-mistakes(document): Document routed-item keys in backlog-handoff wake comments --- bin/fm-backlog-handoff.sh | 21 +++++++++++---------- 1 file changed, 11 insertions(+), 10 deletions(-) diff --git a/bin/fm-backlog-handoff.sh b/bin/fm-backlog-handoff.sh index de9d9a1b75c..6e345589387 100755 --- a/bin/fm-backlog-handoff.sh +++ b/bin/fm-backlog-handoff.sh @@ -61,8 +61,10 @@ # original batch is retried, so it cannot discard wake intent for work that # already moved. No two-phase journal exists. # Every newly durable backlog delivery attempts one marked wake to the receiving -# endpoint. A local route moves directly into the destination backlog, and a -# missing or rejected local wake makes that command fail with the move intact so +# endpoint, naming the routed item keys; a remote batch that reuses a +# still-pending wake adds its keys to that wake's list. A local route moves +# directly into the destination backlog, and a missing or rejected local wake +# makes that command fail with the move intact so # rerunning the same handoff retries its prepared wake intent. After a durable # remote receipt, the outbox is released and the handoff succeeds regardless of # the best-effort wake outcome; an undelivered remote wake remains separately @@ -97,14 +99,13 @@ MAIN_BACKLOG="$DATA/backlog.md" RECEIVER_WAKE_MESSAGE='New routed work is in your backlog. Run bin/fm-session-start.sh now, then act on the routed task.' -# Two consecutive handoffs to the same receiver used to send this exact same -# fixed line with no indication which task either one named, so a receiver -# reading them close together had no way to tell a second genuine handoff -# apart from a duplicate of the first - a real 2026-08-25 incident (see -# backlog item handoff-nachricht-nennt-auftrag-nicht) where the receiver read -# an unlabeled second handoff as an unproven repeat of the first and blocked -# on it. Appended, never inserted, so the fixed sentence itself stays a -# stable substring for every existing caller and test that greps for it. +# Names the routed item keys so a receiver can tell a second genuine handoff +# apart from a duplicate of the first; an unlabeled fixed line once made a +# receiver block on a real second handoff as an unproven repeat (regression: +# test_two_consecutive_handoffs_name_their_own_items in +# tests/fm-backlog-handoff.test.sh). Appended, never inserted, so the fixed +# sentence itself stays a stable substring for every existing caller and test +# that greps for it. receiver_wake_message() { # <item-key>... local ids [ "$#" -gt 0 ] || { printf '%s' "$RECEIVER_WAKE_MESSAGE"; return; }