diff --git a/bin/fm-herdr-lab-viewer.py b/bin/fm-herdr-lab-viewer.py index ce40e0b4a9e..509c3a10340 100755 --- a/bin/fm-herdr-lab-viewer.py +++ b/bin/fm-herdr-lab-viewer.py @@ -79,6 +79,21 @@ def _child(slave, master, session): def _process_start(pid): + # Must match bin/fm-herdr-lab.sh's fm_herdr_lab_process_start: /proc start + # ticks count from boot, so a host clock step cannot change them the way it + # re-renders ps lstart. + try: + with open("/proc/%d/stat" % pid, encoding="utf-8") as handle: + stat = handle.read() + except OSError: + return _process_lstart(pid) + fields = stat.rpartition(")")[2].split() + if len(fields) < 20 or not fields[19].isdigit(): + raise RuntimeError("process start ticks unavailable") + return "proc-starttime=%s" % fields[19] + + +def _process_lstart(pid): result = subprocess.run( ["ps", "-p", str(pid), "-o", "lstart="], check=True, diff --git a/bin/fm-herdr-lab.sh b/bin/fm-herdr-lab.sh index 12a041f2acc..b289e936640 100755 --- a/bin/fm-herdr-lab.sh +++ b/bin/fm-herdr-lab.sh @@ -32,6 +32,8 @@ # bin/fm-herdr-lab-viewer.py owns the pty mechanics. # Start succeeds only when that session reports a foreground client and the # recorded viewer process still matches its launch identity. +# When /proc stat is readable, the viewer records start ticks for both processes; +# existing ps lstart records remain readable for a running viewer. # Stop signals only identity-matched recorded processes and retains its # ownership record until detach is confirmed or the session is stopped or # absent; teardown refuses when that stop cannot be confirmed. @@ -207,10 +209,41 @@ fm_herdr_lab_viewer_reason() { # printf '%s' "$out" | jq -r '.result.reason // empty' 2>/dev/null } +# Prints the process start identity the viewer launcher records. /proc stat +# field 22 counts clock ticks since boot, so a host clock step cannot change it; +# ps lstart re-renders those ticks against the wall-clock boot time (WSL2 steps +# it about every 30 seconds) and would disown a running viewer. fm_herdr_lab_process_start() { # + local stat_line starttime + local -a stat_fields + if [ -r "/proc/$1/stat" ]; then + stat_line=$(cat "/proc/$1/stat" 2>/dev/null) || return 1 + # After the final comm delimiter, array index 19 is proc stat field 22. + read -r -a stat_fields <<< "${stat_line##*)}" + [ "${#stat_fields[@]}" -ge 20 ] || return 1 + starttime=${stat_fields[19]} + case "$starttime" in ''|*[!0-9]*) return 1 ;; esac + printf 'proc-starttime=%s' "$starttime" + return 0 + fi + fm_herdr_lab_process_lstart "$1" +} + +fm_herdr_lab_process_lstart() { # LC_ALL=C ps -p "$1" -o lstart= 2>/dev/null | sed 's/^[[:space:]]*//;s/[[:space:]]*$//' } +fm_herdr_lab_process_start_matches() { # + local current + case "$2" in + proc-starttime=*) current=$(fm_herdr_lab_process_start "$1") || return 1 ;; + # A record written before start-tick identity holds ps lstart text; keep + # honoring it so an upgrade does not strand a running viewer. + *) current=$(fm_herdr_lab_process_lstart "$1") || return 1 ;; + esac + [ -n "$current" ] && [ "$current" = "$2" ] +} + fm_herdr_lab_process_parent() { # LC_ALL=C ps -p "$1" -o ppid= 2>/dev/null | sed 's/^[[:space:]]*//;s/[[:space:]]*$//' } @@ -225,7 +258,7 @@ fm_herdr_lab_viewer_recorded_value() { # } fm_herdr_lab_viewer_owned_pair() { # - local launcher_pid viewer_pid launcher_start viewer_start current_start parent_pid + local launcher_pid viewer_pid launcher_start viewer_start parent_pid launcher_pid=$(fm_herdr_lab_viewer_recorded_value "$1" launcher_pid) || return 1 viewer_pid=$(fm_herdr_lab_viewer_recorded_value "$1" viewer_pid) || return 1 case "$launcher_pid:$viewer_pid" in @@ -233,10 +266,8 @@ fm_herdr_lab_viewer_owned_pair() { # esac launcher_start=$(fm_herdr_lab_viewer_recorded_value "$1" launcher_start) || return 1 viewer_start=$(fm_herdr_lab_viewer_recorded_value "$1" viewer_start) || return 1 - current_start=$(fm_herdr_lab_process_start "$launcher_pid") || return 1 - [ -n "$current_start" ] && [ "$current_start" = "$launcher_start" ] || return 1 - current_start=$(fm_herdr_lab_process_start "$viewer_pid") || return 1 - [ -n "$current_start" ] && [ "$current_start" = "$viewer_start" ] || return 1 + fm_herdr_lab_process_start_matches "$launcher_pid" "$launcher_start" || return 1 + fm_herdr_lab_process_start_matches "$viewer_pid" "$viewer_start" || return 1 parent_pid=$(fm_herdr_lab_process_parent "$viewer_pid") || return 1 [ "$parent_pid" = "$launcher_pid" ] || return 1 printf '%s %s' "$launcher_pid" "$viewer_pid" diff --git a/bin/fm-pending-reply-lib.sh b/bin/fm-pending-reply-lib.sh index e53b5a8c17c..22a0ee5100d 100755 --- a/bin/fm-pending-reply-lib.sh +++ b/bin/fm-pending-reply-lib.sh @@ -48,7 +48,9 @@ # request_turn_completed_epoch= # recovery_attempted_epoch= # recovery_sender_pid= -# recovery_sender_identity= +# recovery_sender_identity= Linux /proc start ticks plus full cmdline hex; +# ps lstart plus command where /proc is unavailable. +# Existing ps-form records remain readable. # recovery_sent_epoch= # recovery_delivery_outcome= # recovery_turn_seen_busy= @@ -1014,6 +1016,31 @@ fm_pending_reply_send_recovery() { # } fm_pending_reply_pid_identity() { # + local pid=$1 proc_root stat_line starttime cmdline_hex + local -a stat_fields + case "$pid" in ''|*[!0-9]*) return 1 ;; esac + proc_root=${FM_PROC_ROOT_OVERRIDE:-/proc} + # /proc stat field 22 counts clock ticks since boot, so a host clock step + # cannot change it; ps lstart re-renders those ticks against the wall-clock + # boot time (WSL2 steps it about every 30 seconds) and would read a live + # sender as dead. Start ticks distinguish reused PIDs; the full cmdline + # preserves the sender command identity. + if [ -r "$proc_root/$pid/stat" ] && [ -r "$proc_root/$pid/cmdline" ]; then + stat_line=$(cat "$proc_root/$pid/stat" 2>/dev/null) || return 1 + # After the final comm delimiter, array index 19 is proc stat field 22. + read -r -a stat_fields <<< "${stat_line##*)}" + [ "${#stat_fields[@]}" -ge 20 ] || return 1 + starttime=${stat_fields[19]} + case "$starttime" in ''|*[!0-9]*) return 1 ;; esac + cmdline_hex=$(od -An -v -tx1 "$proc_root/$pid/cmdline" 2>/dev/null | tr -d '[:space:]') || return 1 + [ -n "$cmdline_hex" ] || return 1 + printf 'proc-starttime=%s cmdline-hex=%s' "$starttime" "$cmdline_hex" + return 0 + fi + fm_pending_reply_ps_identity "$pid" +} + +fm_pending_reply_ps_identity() { # local pid=$1 identity case "$pid" in ''|*[!0-9]*) return 1 ;; esac identity=$(COLUMNS=10000 LC_ALL=C ps -p "$pid" -o lstart= -o command= 2>/dev/null) || return 1 @@ -1026,7 +1053,12 @@ fm_pending_reply_sender_alive() { # pid=$(fm_pending_reply_get "$rec" recovery_sender_pid) expected=$(fm_pending_reply_get "$rec" recovery_sender_identity) [ -n "$expected" ] || return 1 - actual=$(fm_pending_reply_pid_identity "$pid") || return 1 + case "$expected" in + proc-starttime=*) actual=$(fm_pending_reply_pid_identity "$pid") || return 1 ;; + # A record written before start-tick identity holds the ps form; keep + # honoring it so an upgrade does not strand an in-flight recovery. + *) actual=$(fm_pending_reply_ps_identity "$pid") || return 1 ;; + esac [ "$actual" = "$expected" ] } diff --git a/bin/fm-remote-job-lib.sh b/bin/fm-remote-job-lib.sh index 68d3b62c064..cb94d4d8916 100755 --- a/bin/fm-remote-job-lib.sh +++ b/bin/fm-remote-job-lib.sh @@ -82,6 +82,17 @@ # it to stop itself once its root is pruned, and # bin/fm-remote-job-reap-orphans.sh uses it to reap workers that were already # orphaned that way. +# +# fm_remote_job_process_start is the one process-identity reader behind the +# worker lock, staging, and claim start records. Where /proc//stat is +# readable (Linux) it records starttime=, which no wall-clock step moves; ps lstart is rendered from the current +# boot time there, so every NTP, VM or WSL2 time-sync, or resume step would +# make a live worker stop matching its own records. Elsewhere (Darwin) it +# records ps lstart, which a clock step does not move. A Linux record still in +# lstart form was written before this contract: fm_remote_job_process_start_for_record +# compares it as lstart, and a lock owner in that form is identified by pid and +# exact command so ensure replaces it in place. FM_REMOTE_JOB_LABEL=dev.firstmate.remote-job FM_REMOTE_JOB_MAX_BYTES=${FM_REMOTE_JOB_MAX_BYTES:-1048576} @@ -767,7 +778,7 @@ fm_remote_job_stage_owner_alive() { # case "$pid" in ''|*[!0-9]*) return 1 ;; esac [ "$pid" -gt 1 ] || return 1 recorded_start=$(fm_remote_job_read_single_line "$stage/.owner-start" 256 2>/dev/null) || return 1 - actual_start=$(fm_remote_job_process_start "$pid" 2>/dev/null) || return 1 + actual_start=$(fm_remote_job_process_start_for_record "$pid" "$recorded_start" 2>/dev/null) || return 1 [ "$recorded_start" = "$actual_start" ] } @@ -902,7 +913,24 @@ fm_remote_job_worker_ready_path() { printf '%s\n' "$FM_REMOTE_JOB_STATE/worker.r fm_remote_job_worker_identity_path() { printf '%s\n' "$FM_REMOTE_JOB_STATE/worker.identity"; } fm_remote_job_worker_lock_path() { printf '%s\n' "$FM_REMOTE_JOB_STATE/worker.lock"; } -fm_remote_job_process_start() { +fm_remote_job_process_start() { # + local pid=$1 proc_root stat_line + local -a stat_fields + case "$pid" in ''|*[!0-9]*) return 1 ;; esac + proc_root=${FM_PROC_ROOT_OVERRIDE:-/proc} + if [ -r "$proc_root/$pid/stat" ]; then + stat_line=$(cat "$proc_root/$pid/stat" 2>/dev/null) || return 1 + # After the final comm delimiter, array index 19 is proc stat field 22. + read -r -a stat_fields <<< "${stat_line##*)}" + [ "${#stat_fields[@]}" -ge 20 ] || return 1 + case "${stat_fields[19]}" in ''|*[!0-9]*) return 1 ;; esac + printf 'starttime=%s\n' "${stat_fields[19]}" + return 0 + fi + fm_remote_job_process_lstart "$pid" +} + +fm_remote_job_process_lstart() { # local pid=$1 ps_bin value if [ -x /bin/ps ]; then ps_bin=/bin/ps; elif [ -x /usr/bin/ps ]; then ps_bin=/usr/bin/ps; else return 1; fi value=$("$ps_bin" -p "$pid" -o lstart= 2>/dev/null) || return 1 @@ -911,6 +939,19 @@ fm_remote_job_process_start() { printf '%s\n' "$value" } +# The current start of in the form was written in, so a record +# a pre-upgrade worker wrote as ps lstart text is still compared as lstart +# rather than never matching the starttime= form. +fm_remote_job_process_start_for_record() { # + local current + current=$(fm_remote_job_process_start "$1") || return 1 + case "$current:$2" in + starttime=*:starttime=*) ;; + starttime=*:*) current=$(fm_remote_job_process_lstart "$1") || return 1 ;; + esac + printf '%s\n' "$current" +} + fm_remote_job_process_command() { local pid=$1 ps_bin value if [ -x /bin/ps ]; then ps_bin=/bin/ps; elif [ -x /usr/bin/ps ]; then ps_bin=/usr/bin/ps; else return 1; fi @@ -1012,7 +1053,15 @@ fm_remote_job_lock_owner_matches_process() { [ "$pid" -gt 1 ] || return 1 recorded_start=$(fm_remote_job_read_single_line "$lock/start" 256) || return 1 actual_start=$(fm_remote_job_process_start "$pid") || return 1 - [ "$recorded_start" = "$actual_start" ] || return 1 + # A Linux owner recorded as ps lstart text is a worker from before start ticks + # were recorded. Any clock step since has re-rendered its lstart, so its pid + # and exact command identify it, which lets ensure replace it in place + # instead of starting a second supervisor beside it. + case "$actual_start:$recorded_start" in + starttime=*:starttime=*) [ "$recorded_start" = "$actual_start" ] || return 1 ;; + starttime=*:*) ;; + *) [ "$recorded_start" = "$actual_start" ] || return 1 ;; + esac recorded_command=$(fm_remote_job_read_single_line "$lock/command" 8192) || return 1 actual_command=$(fm_remote_job_process_command "$pid") || return 1 [ "$recorded_command" = "$actual_command" ] || return 1 diff --git a/bin/fm-remote-job-worker.sh b/bin/fm-remote-job-worker.sh index 8973f5d6dae..93efb752633 100755 --- a/bin/fm-remote-job-worker.sh +++ b/bin/fm-remote-job-worker.sh @@ -333,7 +333,7 @@ worker_signal_process_or_group() { # process|group worker_supervisor_identity_status() { # local job=$1 pid=$2 recorded_start actual_start recorded_start=$(fm_remote_job_read_single_line "$job/.claim/supervisor_start" 256 2>/dev/null) || return 2 - actual_start=$(fm_remote_job_process_start "$pid" 2>/dev/null) || { + actual_start=$(fm_remote_job_process_start_for_record "$pid" "$recorded_start" 2>/dev/null) || { worker_process_or_group_alive process "$pid" && return 2 return 1 } @@ -350,7 +350,7 @@ worker_group_identity_status() { # local job=$1 pid=$2 recorded_start actual_start file="$1/.claim/group_start" [ -e "$file" ] || [ -L "$file" ] || return 3 recorded_start=$(fm_remote_job_read_single_line "$file" 256 2>/dev/null) || return 2 - actual_start=$(fm_remote_job_process_start "$pid" 2>/dev/null) || { + actual_start=$(fm_remote_job_process_start_for_record "$pid" "$recorded_start" 2>/dev/null) || { kill -0 "$pid" 2>/dev/null && return 2 worker_process_or_group_alive group "$pid" && return 0 return 1 @@ -446,7 +446,7 @@ worker_stop_recorded_execution() { # worker_lane_identity_matches() { # local pid=$1 start=$2 actual_start [ -n "$start" ] || return 1 - actual_start=$(fm_remote_job_process_start "$pid" 2>/dev/null) || return 1 + actual_start=$(fm_remote_job_process_start_for_record "$pid" "$start" 2>/dev/null) || return 1 [ "$actual_start" = "$start" ] } @@ -571,7 +571,7 @@ worker_claim_owner_alive() { # case "$pid" in ''|*[!0-9]*) return 1 ;; esac if [ -e "$claim/owner_start" ] || [ -L "$claim/owner_start" ]; then recorded_start=$(fm_remote_job_read_single_line "$claim/owner_start" 256 2>/dev/null) || return 1 - actual_start=$(fm_remote_job_process_start "$pid" 2>/dev/null) || return 1 + actual_start=$(fm_remote_job_process_start_for_record "$pid" "$recorded_start" 2>/dev/null) || return 1 [ "$recorded_start" = "$actual_start" ] return fi diff --git a/docs/remote-secondmates.md b/docs/remote-secondmates.md index 42d496acb39..b5c3721d9cd 100644 --- a/docs/remote-secondmates.md +++ b/docs/remote-secondmates.md @@ -82,6 +82,8 @@ On macOS the worker is `dev.firstmate.remote-job`, an Aqua-scoped LaunchAgent at After that bootstrap, every non-doctor `fm-on.sh` target runs through that worker in the remote account's GUI session. It never runs in the SSH process or a Herdr pane. Linux uses the same queue and worker protocol without the Aqua-session requirement. +On Linux, where `/proc//stat` is readable, the worker uses kernel start ticks for process identity so host clock steps do not make a healthy worker appear stale. +During an upgrade, a worker with an older `ps lstart` lock record is recognized by its PID and exact command and replaced when its code changes; [`bin/fm-remote-job-lib.sh`](../bin/fm-remote-job-lib.sh) owns that identity contract. When idle, the worker checks for newly staged work about once per second; after a lane starts or finishes it checks more frequently for a short period. ### Job lanes and preemption diff --git a/tests/fm-herdr-lab.test.sh b/tests/fm-herdr-lab.test.sh index 24a630b0db4..2c9a994bffd 100755 --- a/tests/fm-herdr-lab.test.sh +++ b/tests/fm-herdr-lab.test.sh @@ -451,6 +451,60 @@ test_viewer_stop_requires_the_recorded_parent() { pass "fm-herdr-lab: viewer ownership requires the recorded parent" } +# Drives the real launcher against a sleeping viewer, then emulates a host +# clock step with a ps whose lstart text changes afterwards, as procps output +# does when the wall-clock boot time moves. +test_viewer_ownership_survives_host_clock_step() { + local name="fm-lab-viewer-clock-$$" record viewer_bin="$TMP_ROOT/clock-viewer-bin" + local step="$TMP_ROOT/clock-stepped" launcher_pid pair viewer_pid launcher_lstart viewer_lstart + if [ ! -r "/proc/$$/stat" ]; then + echo "skip: fm-herdr-lab: no /proc start ticks on this host; ps lstart is its identity" + return 0 + fi + mkdir -p "$viewer_bin" "$TRIPWIRES" + cat > "$viewer_bin/herdr" < "$viewer_bin/ps" </dev/null 2>&1 & + launcher_pid=$! + while [ ! -f "$record" ]; do + kill -0 "$launcher_pid" 2>/dev/null || fail "the viewer launcher exited before recording its pair" + "$REAL_SLEEP" 0.01 + done + viewer_pid=$(sed -n 's/^viewer_pid=//p' "$record") + + : > "$step" + pair=$(FM_FAKE_CLOCK_STEP="$step" PATH="$viewer_bin:$PATH" run_with_fake fm_herdr_lab_viewer_owned_pair "$name") \ + || fail "a host clock step disowned the running lab viewer" + assert_equals "$launcher_pid $viewer_pid" "$pair" "the stepped ownership check named the wrong pair" + + rm -f "$step" + launcher_lstart=$(fm_herdr_lab_process_lstart "$launcher_pid") + viewer_lstart=$(fm_herdr_lab_process_lstart "$viewer_pid") + printf 'launcher_pid=%s\nlauncher_start=%s\nviewer_pid=%s\nviewer_start=%s\n' \ + "$launcher_pid" "$launcher_lstart" "$viewer_pid" "$viewer_lstart" > "$record" + run_with_fake fm_herdr_lab_viewer_owned_alive "$name" \ + || fail "a viewer recorded in the legacy lstart form was stranded by the upgrade" + + kill -TERM "$launcher_pid" 2>/dev/null || true + wait "$launcher_pid" 2>/dev/null || true + kill -0 "$viewer_pid" 2>/dev/null && fail "the launcher left its viewer running" + rm -f "$record" + pass "fm-herdr-lab: viewer ownership survives a host clock step and keeps legacy records" +} + test_interrupted_viewer_start_cancels_launcher() { local name="fm-lab-viewer-interrupt-$$" command_pid launcher_pid status=0 local started="$TMP_ROOT/viewer-interrupt-started" attached="$TMP_ROOT/viewer-interrupt-attached" @@ -548,6 +602,7 @@ test_viewer_timeout_allows_launcher_escalation test_viewer_start_requires_its_owned_process test_viewer_stop_only_signals_owned_processes test_viewer_stop_requires_the_recorded_parent +test_viewer_ownership_survives_host_clock_step test_interrupted_viewer_start_cancels_launcher test_teardown_refuses_while_viewer_attached test_viewer_stop_retains_record_when_detach_is_unreadable diff --git a/tests/fm-pending-reply.test.sh b/tests/fm-pending-reply.test.sh index 350741fca2a..204dc076f6c 100755 --- a/tests/fm-pending-reply.test.sh +++ b/tests/fm-pending-reply.test.sh @@ -32,6 +32,8 @@ # 17. Recovery and escalation grace are measured from the relevant turn's # completion, never from delivery or send time, and each takes one fresh, # uncached status read - accepting any verb - immediately before firing +# 18. A live recovery sender survives a host clock step, a reused pid does +# not, and a sender recorded in the legacy ps form is still recognized set -u # shellcheck source=tests/lib.sh @@ -1923,6 +1925,72 @@ test_escalated_undelivered_correlation_stays_retryable() { pass "an escalated correlation stays retryable only while undelivered" } +# A fake /proc plus a ps that renders lstart the way procps does: boot time +# (btime, which a host clock step moves) plus the process's start ticks. +make_clock_step_proc() { # -> fakebin + local dir=$1 pid=$2 starttime=$3 fb="$1/clock-fakebin" + mkdir -p "$dir/proc/$pid" "$fb" + printf 'btime 1784094040\n' > "$dir/proc/stat" + printf '%s (sender) S 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 %s 20 21\n' \ + "$pid" "$starttime" > "$dir/proc/$pid/stat" + printf 'bash\0-c\0recovery sender\0' > "$dir/proc/$pid/cmdline" + cat > "$fb/ps" <<'SH' +#!/usr/bin/env bash +pid=$2 +btime=$(sed -n 's/^btime //p' "$FM_PROC_ROOT_OVERRIDE/stat") +stat=$(cat "$FM_PROC_ROOT_OVERRIDE/$pid/stat") || exit 1 +read -r -a fields <<< "${stat##*)}" +printf 'started-at-%s bash -c recovery sender\n' "$((btime + fields[19] / 100))" +SH + chmod +x "$fb/ps" + printf '%s\n' "$fb" +} + +test_recovery_sender_survives_host_clock_step() { + local home state corr rec fb proc pid=4242 identity legacy + home=$(setup_parent clock-step) + state="$home/state" + proc="$home/proc" + fb=$(make_clock_step_proc "$home" "$pid" 987654) + corr=$(fm_pending_reply_create "$home" "$state" hibit "clock step recovery") + fm_pending_reply_mark_delivered "$state" "$corr" + fm_pending_reply_mark_turn_completed "$state" "$corr" request + rec=$(fm_pending_reply_path "$state" "$corr") + identity=$(PATH="$fb:$PATH" FM_PROC_ROOT_OVERRIDE="$proc" fm_pending_reply_pid_identity "$pid") \ + || fail "fake sender identity should be observable" + fm_pending_reply_set "$rec" recovery_attempted_epoch 2500 || fail "attempt precommit failed" + fm_pending_reply_set "$rec" recovery_sender_pid "$pid" || fail "sender pid commit failed" + fm_pending_reply_set "$rec" recovery_sender_identity "$identity" || fail "sender identity commit failed" + fm_pending_reply_set "$rec" phase recovery_sending || fail "sending phase failed" + + printf 'btime 1784094016\n' > "$proc/stat" + PATH="$fb:$PATH" FM_PROC_ROOT_OVERRIDE="$proc" fm_pending_reply_tick_one "$state" "$corr" unknown \ + || fail "clock-step recovery tick failed" + [ "$(phase_of "$state" "$corr")" = recovery_sending ] \ + || fail "a host clock step made the live recovery sender read as dead" + + printf '%s (sender) S 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 987655 20 21\n' "$pid" > "$proc/$pid/stat" + PATH="$fb:$PATH" FM_PROC_ROOT_OVERRIDE="$proc" fm_pending_reply_tick_one "$state" "$corr" unknown \ + || fail "reused-pid recovery tick failed" + [ "$(fm_pending_reply_get "$rec" recovery_delivery_outcome)" = unknown ] \ + || fail "a reused sender pid must still read as a dead sender" + + corr=$(fm_pending_reply_create "$home" "$state" hibit "legacy identity recovery") + fm_pending_reply_mark_delivered "$state" "$corr" + fm_pending_reply_mark_turn_completed "$state" "$corr" request + rec=$(fm_pending_reply_path "$state" "$corr") + legacy=$(PATH="$fb:$PATH" FM_PROC_ROOT_OVERRIDE="$proc" ps -p "$pid" -o lstart= -o command=) + fm_pending_reply_set "$rec" recovery_attempted_epoch 2500 || fail "legacy attempt precommit failed" + fm_pending_reply_set "$rec" recovery_sender_pid "$pid" || fail "legacy sender pid commit failed" + fm_pending_reply_set "$rec" recovery_sender_identity "$legacy" || fail "legacy sender identity commit failed" + fm_pending_reply_set "$rec" phase recovery_sending || fail "legacy sending phase failed" + PATH="$fb:$PATH" FM_PROC_ROOT_OVERRIDE="$proc" fm_pending_reply_tick_one "$state" "$corr" unknown \ + || fail "legacy recovery tick failed" + [ "$(phase_of "$state" "$corr")" = recovery_sending ] \ + || fail "a sender recorded in the legacy ps form was stranded by the upgrade" + pass "a recovery sender's identity survives a host clock step and keeps legacy records" +} + # --- run -------------------------------------------------------------------- test_normal_correlated_reply_resolves_once @@ -1969,5 +2037,6 @@ test_mechanical_helper_writes_parent_channel test_remote_parent_replies_is_not_wrong_home test_local_parent_replies_is_wrong_home_evidence test_escalated_undelivered_correlation_stays_retryable +test_recovery_sender_survives_host_clock_step printf 'ok - all pending-reply tests passed\n' diff --git a/tests/fm-remote-job.test.sh b/tests/fm-remote-job.test.sh index b7e9061bc5b..1740751f87f 100755 --- a/tests/fm-remote-job.test.sh +++ b/tests/fm-remote-job.test.sh @@ -26,6 +26,7 @@ STALL_WORKER_PID= STALL_REPLACEMENT_PID= STALL_JOB_GROUP= QUIET_WORKER_PID= +DRIFT_ROOT="$TMP_ROOT/drift-root" mkdir -p "$REMOTE_ROOT/bin" "$REMOTE_HOME" "$ACCOUNT_HOME" "$RUNTIME_BIN" # worker.pid records the serving child, not its restart supervisor, so stopping # that pid alone leaves the supervisor to respawn - the leak @@ -45,6 +46,7 @@ cleanup_remote_job_fixture() { wait "$stall_pid" 2>/dev/null || true done [ -z "$STALL_JOB_GROUP" ] || kill -KILL -- "-$STALL_JOB_GROUP" 2>/dev/null || true + pkill -KILL -f "$DRIFT_ROOT/bin/fm-remote-job-worker.sh" 2>/dev/null || true if [ -f "$STATE_ROOT/worker.pid" ]; then fm_remote_job_stop_worker_tree "$(cat "$STATE_ROOT/worker.pid")" || true fi @@ -1224,4 +1226,105 @@ assert_grep "remote job worker exited 3 times; stopping the supervisor" "$TMP_RO "the restart guard did not explain why it stopped" pass "barely healthy worker failures remain bounded by the restart guard" +# On Linux, ps lstart is rendered from the current boot time, which every NTP, +# VM or WSL2 time-sync, or resume step moves, so a live worker used to stop +# matching its own records and every ensure started another supervisor. The +# fake /proc root below changes btime the way such a step does, then reuses +# the pid with a different start. +PROC_FIXTURE="$TMP_ROOT/fake-proc" +mkdir -p "$PROC_FIXTURE/4242" +printf 'btime 1784094040\n' > "$PROC_FIXTURE/stat" +printf '4242 (fm-remote-job) w) S 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 987654 20 21 22\n' \ + > "$PROC_FIXTURE/4242/stat" +PROC_BEFORE=$(FM_PROC_ROOT_OVERRIDE="$PROC_FIXTURE" fm_remote_job_process_start 4242) \ + || fail "the process identity could not read a /proc start" +[ "$PROC_BEFORE" = starttime=987654 ] \ + || fail "the process identity did not record stat field 22 ('$PROC_BEFORE')" +printf 'btime 1784094016\n' > "$PROC_FIXTURE/stat" +PROC_AFTER_STEP=$(FM_PROC_ROOT_OVERRIDE="$PROC_FIXTURE" fm_remote_job_process_start 4242) \ + || fail "the process identity could not re-read a /proc start after a clock step" +[ "$PROC_AFTER_STEP" = "$PROC_BEFORE" ] \ + || fail "the process identity changed with btime ('$PROC_BEFORE' then '$PROC_AFTER_STEP')" +printf '4242 (fm-remote-job) w) S 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 987655 20 21 22\n' \ + > "$PROC_FIXTURE/4242/stat" +PROC_REUSED=$(FM_PROC_ROOT_OVERRIDE="$PROC_FIXTURE" fm_remote_job_process_start 4242) \ + || fail "the process identity could not read a reused pid" +[ "$PROC_REUSED" != "$PROC_BEFORE" ] || fail "the process identity missed a reused pid" +pass "process identity ignores wall-clock steps and detects pid reuse" + +# A Linux worker started before start ticks were recorded holds an lstart +# owner record that any clock step since has moved. Ensure must still +# recognize it rather than start a supervisor beside it, drain supervisors +# already piled up beside it, and replace it in place once its code changes. +if [ -r "/proc/$$/stat" ]; then + DRIFT_HOME="$TMP_ROOT/drift-account" + DRIFT_STATE="$TMP_ROOT/drift-jobs" + cp -R "$REMOTE_ROOT" "$DRIFT_ROOT" + mkdir -p "$DRIFT_HOME" + chmod 700 "$DRIFT_HOME" + drift_supervisors() { + pgrep -f -x "/bin/bash $DRIFT_ROOT/bin/fm-remote-job-worker.sh" | wc -l | tr -d ' ' + } + FM_REMOTE_JOB_STATE_ROOT=$DRIFT_STATE + fm_remote_job_ensure_worker "$DRIFT_ROOT" "$DRIFT_HOME" || fail "$FM_REMOTE_JOB_ERROR" + case "$(cat "$DRIFT_STATE/worker.lock/start")" in + starttime=*) ;; + *) fail "a Linux worker did not record its start ticks" ;; + esac + DRIFT_WORKER_PID=$(cat "$DRIFT_STATE/worker.pid") + printf 'Mon Jan 5 03:04:05 2026\n' > "$DRIFT_STATE/worker.lock/start" + for _ in 1 2 3 4 5; do + fm_remote_job_ensure_worker "$DRIFT_ROOT" "$DRIFT_HOME" || fail "$FM_REMOTE_JOB_ERROR" + [ "$(drift_supervisors)" -le 1 ] \ + || fail "ensure started another supervisor beside a live worker whose lstart record drifted" + done + [ "$(cat "$DRIFT_STATE/worker.pid")" = "$DRIFT_WORKER_PID" ] \ + || fail "ensure replaced a current worker whose lstart record drifted" + pass "ensure keeps one supervisor for a live worker whose lstart record drifted" + + for _ in 1 2 3; do + HOME="$DRIFT_HOME" FM_ROOT_OVERRIDE="$DRIFT_ROOT" FM_REMOTE_JOB_STATE_ROOT="$DRIFT_STATE" \ + FM_REMOTE_JOB_PLATFORM_OVERRIDE=Linux "$DRIFT_ROOT/bin/fm-remote-job-worker.sh" \ + >> "$TMP_ROOT/drift-pile.out" 2>> "$TMP_ROOT/drift-pile.err" & + done + for _ in $(seq 1 200); do + [ "$(drift_supervisors)" -eq 1 ] && break + sleep 0.1 + done + [ "$(drift_supervisors)" -eq 1 ] \ + || fail "supervisors piled beside a live worker whose lstart record drifted did not drain" + [ "$(cat "$DRIFT_STATE/worker.pid")" = "$DRIFT_WORKER_PID" ] \ + || fail "draining the piled supervisors replaced the owning worker" + pass "supervisors piled beside a drifted legacy owner drain" + + DRIFT_OLD_PGID=$(fm_remote_job_process_pgid "$DRIFT_WORKER_PID") \ + || fail "the drifted worker's process group could not be resolved" + printf '\n' >> "$DRIFT_ROOT/bin/fm-remote-job-worker.sh" + fm_remote_job_ensure_worker "$DRIFT_ROOT" "$DRIFT_HOME" || fail "$FM_REMOTE_JOB_ERROR" + [ "$(cat "$DRIFT_STATE/worker.pid")" != "$DRIFT_WORKER_PID" ] \ + || fail "ensure retained a legacy-record worker running stale code" + ! kill -0 -- "-$DRIFT_OLD_PGID" 2>/dev/null \ + || fail "ensure left the replaced legacy-record worker group alive" + for _ in $(seq 1 100); do + [ "$(drift_supervisors)" -eq 1 ] && break + sleep 0.1 + done + [ "$(drift_supervisors)" -eq 1 ] || fail "upgrading a legacy-record worker left more than one supervisor" + case "$(cat "$DRIFT_STATE/worker.lock/start")" in + starttime=*) ;; + *) fail "the replacement worker did not record its start ticks" ;; + esac + fm_remote_job_stage "$DRIFT_HOME" "$DRIFT_ROOT" "$REMOTE_HOME" fm-probe-job.sh < /dev/null > /dev/null + JOB_ID=$FM_REMOTE_JOB_ID + fm_remote_job_wait "$DRIFT_HOME" "$JOB_ID" || fail "$FM_REMOTE_JOB_ERROR" + [ "$FM_REMOTE_JOB_EXIT" -eq 0 ] || fail "the upgraded worker did not run a job" + fm_remote_job_reap "$DRIFT_HOME" "$JOB_ID" || fail "the upgraded worker's job could not be reaped" + fm_remote_job_stop_worker_tree "$(cat "$DRIFT_STATE/worker.pid")" \ + || fail "the upgraded worker tree did not stop" + FM_REMOTE_JOB_STATE_ROOT=$STATE_ROOT + pass "ensure replaces a legacy-record worker in place after its code changes" +else + pass "lstart-record drift and upgrade checks skipped where /proc is absent" +fi + echo "ALL TESTS PASSED"