From ee15022cedfa61b4e2d0e7aeb3dce1541babc080 Mon Sep 17 00:00:00 2001 From: Tomer Weller Date: Sun, 23 Aug 2026 12:23:40 +0000 Subject: [PATCH 1/2] =?UTF-8?q?Regression=20test=20for=20#3789=20=E2=80=94?= =?UTF-8?q?=20fails=20on=20current=20main?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Adds scripts/test-monitor-watchdog.sh covering the three over-firing/harm mechanisms the watchdog fix must close: the STALE_SECS resize (a 32-min completion cadence fires at 1800s, skips at 4200s), fail-closed on an unparseable history tail (PARSE_ERROR => skip, no refire marker written), ts/timestamp key acceptance, the flock in-flight guard, and a python3-free tail parse. Fails on main: the decision lib and watchdog script do not exist yet, so the decision functions are undefined. Refs #3789 Co-authored-by: Claude Code --- scripts/test-monitor-watchdog.sh | 246 +++++++++++++++++++++++++++++++ 1 file changed, 246 insertions(+) create mode 100755 scripts/test-monitor-watchdog.sh diff --git a/scripts/test-monitor-watchdog.sh b/scripts/test-monitor-watchdog.sh new file mode 100755 index 00000000..fdf73261 --- /dev/null +++ b/scripts/test-monitor-watchdog.sh @@ -0,0 +1,246 @@ +#!/usr/bin/env bash +# +# Regression + unit harness for the monitor-loop crontab watchdog: +# scripts/lib/monitor-watchdog-decisions.sh (pure decision logic) +# scripts/monitor-watchdog.sh (I/O wrapper: locks, launch) +# +# Covers the three #3789 over-firing / harm mechanisms carried over from #3757: +# 1. STALE_SECS resize — a healthy-but-slow ~32-min completion cadence must +# FIRE at the old 1800s bar (the bug) and SKIP at the new 4200s bar (fix). +# 2. flock in-flight guard — a watchdog tick that cannot take the shared +# whole-tick lock logs "skipped: tick in flight" and launches nothing. +# 3. Fail CLOSED on an unparseable history tail — no fire, and the refire +# marker is NOT written (contrast the old epoch-0 => unconditional fire). +# +# Usage: bash scripts/test-monitor-watchdog.sh +# Output: Test Anything Protocol (TAP) on stdout. +# Exit: 0 if all pass, 1 otherwise. +# Portability: GNU/Linux only (GNU `date -d`, `stat -c`, flock, timeout). + +set -uo pipefail + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +REPO_ROOT="$(cd "$SCRIPT_DIR/.." && pwd)" +LIB="$SCRIPT_DIR/lib/monitor-watchdog-decisions.sh" +WATCHDOG="$SCRIPT_DIR/monitor-watchdog.sh" + +# Scratch honors the #2843 ~/data session contract when available, else a +# system mktemp (CI ephemeral runner). +if [[ -n "${CLAUDE_SESSION_ID:-}" && -d "${HOME}/data" ]]; then + SCRATCH="$(mktemp -d "${HOME}/data/${CLAUDE_SESSION_ID}/test-monitor-watchdog.XXXXXX")" +else + SCRATCH="$(mktemp -d)" +fi +trap 'rm -rf "$SCRATCH"' EXIT + +# ── TAP plumbing ───────────────────────────────────────────────────────────── +TEST_NUM=0 +FAIL=0 +ok() { TEST_NUM=$((TEST_NUM + 1)); printf 'ok %d - %s\n' "$TEST_NUM" "$1"; } +notok() { TEST_NUM=$((TEST_NUM + 1)); FAIL=$((FAIL + 1)); printf 'not ok %d - %s\n' "$TEST_NUM" "$1" + shift; for l in "$@"; do printf '# %s\n' "$l"; done; } +is() { # is DESC ACTUAL EXPECTED + if [ "$2" = "$3" ]; then ok "$1"; else notok "$1" "expected: [$3]" "actual: [$2]"; fi; } + +# Source the pure decision lib. +if [ ! -f "$LIB" ]; then + notok "decision lib present ($LIB)" "missing — cannot run decision tests" +else + # shellcheck source=/dev/null + source "$LIB" +fi + +# ───────────────────────────────────────────────────────────────────────────── +# test_over_fire_threshold — the STALE_SECS resize, demonstrated in BOTH +# directions: a healthy 32-min completion cadence FIRES at the old 1800s bar +# (the #3757/#3789 over-firing bug) and SKIPS at the new 4200s bar (the fix). +# ───────────────────────────────────────────────────────────────────────────── +test_over_fire_threshold() { + local now=1000000000 + local last=$(( now - 1920 )) # 32 min ago + local d_old d_new + d_old=$(watchdog_should_fire "$now" "$last" 1800 0 1800) + d_new=$(watchdog_should_fire "$now" "$last" 4200 0 1800) + is "over-fire: 32-min cadence FIRES at STALE_SECS=1800 (the bug)" "$d_old" "fire stale" + is "over-fire: 32-min cadence SKIPS at STALE_SECS=4200 (the fix)" "$d_new" "skip fresh" +} + +# ───────────────────────────────────────────────────────────────────────────── +# test_fail_closed_on_unparseable_tail — a present-but-unparseable tail yields +# PARSE_ERROR => skip, and (integration) does NOT write the refire marker. +# ───────────────────────────────────────────────────────────────────────────── +test_fail_closed_on_unparseable_tail() { + local h1="$SCRATCH/hist-notjson.jsonl" h2="$SCRATCH/hist-nots.jsonl" + printf '%s\n' '{not json' > "$h1" + printf '%s\n' '{"ledger":42,"ok":true}' > "$h2" + + is "fail-closed: non-JSON tail => PARSE_ERROR" "$(watchdog_last_epoch "$h1")" "PARSE_ERROR" + is "fail-closed: JSON w/o ts|timestamp => PARSE_ERROR" "$(watchdog_last_epoch "$h2")" "PARSE_ERROR" + is "fail-closed: PARSE_ERROR decision is skip" "$(watchdog_should_fire 1000000000 PARSE_ERROR 4200 0 1800)" "skip parse-error" + + # Integration: the wrapper must NOT write the marker on a PARSE_ERROR skip, + # and must NOT launch the mocked claude. Contrast the old epoch-0 => fire. + _mk_env + cp "$h1" "$WD_HIST" + ( eval "$WD_ENV"; bash "$WATCHDOG" ) >/dev/null 2>&1 + [ ! -f "$WD_MARKER" ] \ + && ok "fail-closed: refire marker NOT written on PARSE_ERROR skip" \ + || notok "fail-closed: refire marker NOT written on PARSE_ERROR skip" "marker exists: $WD_MARKER" + [ ! -f "$WD_CLAUDE_SENTINEL" ] \ + && ok "fail-closed: headless tick NOT launched on PARSE_ERROR skip" \ + || notok "fail-closed: headless tick NOT launched on PARSE_ERROR skip" "sentinel exists" +} + +# ───────────────────────────────────────────────────────────────────────────── +# test_accepts_ts_and_timestamp_keys — both key names parse to the same epoch. +# ───────────────────────────────────────────────────────────────────────────── +test_accepts_ts_and_timestamp_keys() { + local iso='2026-08-23T12:00:00Z' + local want; want=$(date -u -d "$iso" +%s) + local hts="$SCRATCH/hist-ts.jsonl" hto="$SCRATCH/hist-timestamp.jsonl" + printf '%s\n' "{\"ts\":\"$iso\",\"ledger\":9}" > "$hts" + printf '%s\n' "{\"ledger\":9,\"timestamp\":\"$iso\"}" > "$hto" + is "keys: \"ts\" parses" "$(watchdog_last_epoch "$hts")" "$want" + is "keys: \"timestamp\" parses" "$(watchdog_last_epoch "$hto")" "$want" +} + +# ───────────────────────────────────────────────────────────────────────────── +# test_fire_on_missing_history — a missing history file fires (fail open); the +# fail-closed guard must NOT over-correct into never firing on a dark loop. +# ───────────────────────────────────────────────────────────────────────────── +test_fire_on_missing_history() { + is "missing-history: last_epoch => MISSING" "$(watchdog_last_epoch "$SCRATCH/does-not-exist.jsonl")" "MISSING" + is "missing-history: decision => fire" "$(watchdog_should_fire 1000000000 MISSING 4200 0 1800)" "fire no-history" +} + +# ───────────────────────────────────────────────────────────────────────────── +# test_cooldown — stale but a firing happened within the cooldown => skip. +# ───────────────────────────────────────────────────────────────────────────── +test_cooldown() { + local now=1000000000 last=$(( 1000000000 - 6000 )) recent=$(( 1000000000 - 600 )) + is "cooldown: stale + recent fire => skip" "$(watchdog_should_fire "$now" "$last" 4200 "$recent" 1800)" "skip cooldown" + is "cooldown: stale + old fire => fire" "$(watchdog_should_fire "$now" "$last" 4200 $(( now - 3600 )) 1800)" "fire stale" +} + +# ───────────────────────────────────────────────────────────────────────────── +# test_parses_without_python3 — the tail parse must not depend on python3 (a +# missing interpreter on cron's PATH silently blinded the watchdog 2026-07-22). +# ───────────────────────────────────────────────────────────────────────────── +test_parses_without_python3() { + local iso='2026-08-23T12:00:00Z' + local want; want=$(date -u -d "$iso" +%s) + local h="$SCRATCH/hist-nopy.jsonl" + printf '%s\n' "{\"ts\":\"$iso\"}" > "$h" + # Minimal PATH that excludes any python3 shim, keeping only core coreutils. + local out + out=$(PATH=/usr/bin:/bin bash -c ' + source "'"$LIB"'" + watchdog_last_epoch "'"$h"'" + ') + is "no-python3: tail still parses" "$out" "$want" +} + +# ───────────────────────────────────────────────────────────────────────────── +# test_flock_skips_when_lock_held — a background holder owns the shared tick +# lock; a stale-history watchdog run must log "skipped: tick in flight" and +# launch nothing. +# ───────────────────────────────────────────────────────────────────────────── +test_flock_skips_when_lock_held() { + _mk_env + # Stale history so the decision alone would be "fire". + printf '%s\n' "{\"ts\":\"$(date -u -d '2 hours ago' +%FT%TZ)\"}" > "$WD_HIST" + + # Background holder takes TICK_LOCK for ~5s. + ( flock -x 8; sleep 5 ) 8>"$WD_TICK_LOCK" & + local holder=$! + # Give the holder time to acquire. + sleep 0.5 + + ( eval "$WD_ENV"; bash "$WATCHDOG" ) >/dev/null 2>&1 + + kill "$holder" 2>/dev/null; wait "$holder" 2>/dev/null + + grep -q 'skipped: tick in flight' "$WD_LOG" \ + && ok "flock: logs 'skipped: tick in flight' when lock held" \ + || notok "flock: logs 'skipped: tick in flight' when lock held" "log:" "$(cat "$WD_LOG" 2>/dev/null)" + [ ! -f "$WD_CLAUDE_SENTINEL" ] \ + && ok "flock: headless tick NOT launched when lock held" \ + || notok "flock: headless tick NOT launched when lock held" "sentinel exists" +} + +# ───────────────────────────────────────────────────────────────────────────── +# test_fires_and_launches_when_stale_and_free — stale history + free lock => +# the mocked claude IS launched and the refire marker IS written. +# ───────────────────────────────────────────────────────────────────────────── +test_fires_and_launches_when_stale_and_free() { + _mk_env + printf '%s\n' "{\"ts\":\"$(date -u -d '2 hours ago' +%FT%TZ)\"}" > "$WD_HIST" + + ( eval "$WD_ENV"; bash "$WATCHDOG" ) >/dev/null 2>&1 + + [ -f "$WD_CLAUDE_SENTINEL" ] \ + && ok "fire: headless tick launched when stale and lock free" \ + || notok "fire: headless tick launched when stale and lock free" "log:" "$(cat "$WD_LOG" 2>/dev/null)" + [ -f "$WD_MARKER" ] \ + && ok "fire: refire marker written" \ + || notok "fire: refire marker written" "marker missing" +} + +# _mk_env — create a fresh mock environment (temp DATA, mock claude, mock repo). +# Runs in the CURRENT shell (NOT command substitution) so it can set the WD_* +# globals used by post-run assertions. Also populates WD_ENV: the `export ...` +# block a subshell should `eval` to target this environment before invoking the +# watchdog under test. +_mk_env() { + local base; base="$(mktemp -d "$SCRATCH/env.XXXXXX")" + local data="$base/data" repo="$base/repo" bin="$base/bin" + mkdir -p "$data" "$repo" "$bin" + WD_HIST="$data/tick-history.jsonl" + WD_MARKER="$data/monitor-watchdog.lastfire" + WD_LOG="$data/monitor-watchdog.log" + WD_LOCK="$data/monitor-watchdog.lock" + WD_TICK_LOCK="$data/monitor-tick.lock" + WD_CLAUDE_SENTINEL="$data/claude-was-launched" + + # Mock `claude`: record that it ran, then exit 0. + cat > "$bin/claude" < "$WD_CLAUDE_SENTINEL" +exit 0 +MOCK + chmod +x "$bin/claude" + + WD_ENV="$(cat </dev/null 2>&1; then + test_over_fire_threshold + test_fail_closed_on_unparseable_tail + test_accepts_ts_and_timestamp_keys + test_fire_on_missing_history + test_cooldown + test_parses_without_python3 + test_flock_skips_when_lock_held + test_fires_and_launches_when_stale_and_free +else + notok "decision functions loaded" "watchdog_should_fire not defined — lib failed to source" +fi + +printf '1..%d\n' "$TEST_NUM" +[ "$FAIL" -eq 0 ] || { printf '# %d test(s) failed\n' "$FAIL"; exit 1; } +exit 0 From 3a74a019a0dcf04ac78a3ac4e64a3f606ae68219 Mon Sep 17 00:00:00 2001 From: Tomer Weller Date: Sun, 23 Aug 2026 12:28:17 +0000 Subject: [PATCH 2/2] Canonicalize monitor-watchdog.sh and fix over-firing (STALE_SECS/flock/fail-closed) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Ports the deployed-only /home/tomer/data/monitor-watchdog.sh into the repo as scripts/monitor-watchdog.sh with its decision arithmetic lifted into the pure, unit-tested lib scripts/lib/monitor-watchdog-decisions.sh (mirrors the monitor-decisions.sh testability pattern). Fixes the three #3757/#3789 over-firing/harm mechanisms: - STALE_SECS 1800 -> 4200 (70 min). The watchdog measures completion-to-now, so a healthy-but-slow ~30-min idle cadence plus multi-minute ticks tripped the old 30-min bar and fired a duplicate headless tick on nearly every cron cycle. The header records the corrected rule: wakeup <= STALE_SECS - tick_duration. - Replaced the .alive-mtime in-flight heuristic with a bilateral flock on a shared whole-tick lock ($DATA/monitor-tick.lock). The watchdog holds it (fd 8) across the headless launch; the in-session tick takes the same lock around its metrics scrape/archive critical section. This closes the interleaving race that corrupted archive metadata.env. A watchdog run that cannot take the lock logs "skipped: tick in flight" and exits 0. - Fail CLOSED on an unparseable history tail: PARSE_ERROR -> log loudly, exit 0, do NOT fire and do NOT write the refire marker (a missing file still fires for bootstrap/dark-loop). Tail parse is dependency-light (grep/sed/date, no python3/jq) and accepts both ts and timestamp keys. All tunables/paths are env-overridable with production defaults so the harness can retarget a temp dir. Wraps the check-12 archive step in both the .claude and .agents monitor-tick SKILL.md copies with an identical flock -w 30 on the shared lock (skips a single snapshot on timeout — a missed snapshot is harmless, a corrupt one is not). Wires scripts/test-monitor-watchdog.sh into CI and registers the new lib in the cross-shell harness manifest. Refs #3789 Co-authored-by: Claude Code --- .agents/skills/monitor-tick/SKILL.md | 15 +++ .claude/skills/monitor-tick/SKILL.md | 15 +++ .github/workflows/ci.yml | 9 ++ scripts/lib/monitor-watchdog-decisions.sh | 134 ++++++++++++++++++++++ scripts/monitor-watchdog.sh | 132 +++++++++++++++++++++ scripts/test-shell-lib-cross-shell.sh | 3 + 6 files changed, 308 insertions(+) create mode 100644 scripts/lib/monitor-watchdog-decisions.sh create mode 100755 scripts/monitor-watchdog.sh diff --git a/.agents/skills/monitor-tick/SKILL.md b/.agents/skills/monitor-tick/SKILL.md index 4db59a53..e252d7d3 100644 --- a/.agents/skills/monitor-tick/SKILL.md +++ b/.agents/skills/monitor-tick/SKILL.md @@ -1152,6 +1152,20 @@ against a node that is in real-time sync with age=2s). ```bash ARCHIVE_DIR="$HOME/data/$MONITOR_SESSION_ID/metrics/archive" mkdir -p "$ARCHIVE_DIR" + + # Serialize this archive critical section against a concurrent HEADLESS + # tick launched by the crontab watchdog (scripts/monitor-watchdog.sh) on + # the shared whole-tick lock. Without it, an in-session tick and a + # watchdog-launched tick interleave their scrape->rotate->archive sequences + # and cross-contaminate a snapshot's current.prom/prev.prom + metadata.env + # (#3757 comment 5100384841 / #3789). The watchdog holds this same lock for + # its whole run, so if it is mid-flight this flock -w 30 may time out; when + # it does we SKIP writing this one snapshot and continue the tick — a missed + # snapshot is harmless, a corrupt one is not. Wrap ONLY this archive step + # (do NOT extend the lock over the status-comment/publish path — #3789). + TICK_LOCK="$HOME/data/monitor-tick.lock" + ( + flock -w 30 8 || { echo "check-12 archive: tick lock busy after 30s — skipping this snapshot" >&2; exit 0; } TIMESTAMP=$(date -u +%Y-%m-%dT%H:%M:%S.%NZ) SNAP_TMP="$ARCHIVE_DIR/${TIMESTAMP}.tmp" SNAP_FINAL="$ARCHIVE_DIR/${TIMESTAMP}" @@ -1199,6 +1213,7 @@ against a node that is in real-time sync with age=2s). # Clean up orphaned .tmp dirs from crashed prior ticks find "$ARCHIVE_DIR" -maxdepth 1 -name '*.tmp' -type d -mmin +5 \ -exec rm -rf {} + 2>/dev/null || true + ) 8>"$TICK_LOCK" ``` 8. **Weekly alarm regression replay** — replay the archived metrics history diff --git a/.claude/skills/monitor-tick/SKILL.md b/.claude/skills/monitor-tick/SKILL.md index e855a482..d7ddd61c 100644 --- a/.claude/skills/monitor-tick/SKILL.md +++ b/.claude/skills/monitor-tick/SKILL.md @@ -1340,6 +1340,20 @@ tracks node health, and this signal is not one. ```bash ARCHIVE_DIR="$HOME/data/$MONITOR_SESSION_ID/metrics/archive" mkdir -p "$ARCHIVE_DIR" + + # Serialize this archive critical section against a concurrent HEADLESS + # tick launched by the crontab watchdog (scripts/monitor-watchdog.sh) on + # the shared whole-tick lock. Without it, an in-session tick and a + # watchdog-launched tick interleave their scrape->rotate->archive sequences + # and cross-contaminate a snapshot's current.prom/prev.prom + metadata.env + # (#3757 comment 5100384841 / #3789). The watchdog holds this same lock for + # its whole run, so if it is mid-flight this flock -w 30 may time out; when + # it does we SKIP writing this one snapshot and continue the tick — a missed + # snapshot is harmless, a corrupt one is not. Wrap ONLY this archive step + # (do NOT extend the lock over the status-comment/publish path — #3789). + TICK_LOCK="$HOME/data/monitor-tick.lock" + ( + flock -w 30 8 || { echo "check-12 archive: tick lock busy after 30s — skipping this snapshot" >&2; exit 0; } TIMESTAMP=$(date -u +%Y-%m-%dT%H:%M:%S.%NZ) SNAP_TMP="$ARCHIVE_DIR/${TIMESTAMP}.tmp" SNAP_FINAL="$ARCHIVE_DIR/${TIMESTAMP}" @@ -1383,6 +1397,7 @@ tracks node health, and this signal is not one. # Clean up orphaned .tmp dirs from crashed prior ticks find "$ARCHIVE_DIR" -maxdepth 1 -name '*.tmp' -type d -mmin +5 \ -exec rm -rf {} + 2>/dev/null || true + ) 8>"$TICK_LOCK" ``` 8. **Weekly alarm regression replay** — replay the archived metrics history diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 727852a0..d3e9f7ef 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -181,6 +181,15 @@ jobs: - name: Run project-loop skill snippet harness run: bash scripts/test-project-loop-skill-snippets.sh + monitor-watchdog: + name: Monitor Watchdog + runs-on: ubuntu-latest + timeout-minutes: 5 + steps: + - uses: actions/checkout@v4 + - name: Run monitor-watchdog decision + wrapper harness + run: bash scripts/test-monitor-watchdog.sh + ssc-henyey-mixed-mission-scripts: name: Henyey Mixed-Image SSC Scripts runs-on: ubuntu-latest diff --git a/scripts/lib/monitor-watchdog-decisions.sh b/scripts/lib/monitor-watchdog-decisions.sh new file mode 100644 index 00000000..b40b895f --- /dev/null +++ b/scripts/lib/monitor-watchdog-decisions.sh @@ -0,0 +1,134 @@ +#!/usr/bin/env bash +# +# Pure decision logic for the monitor-loop crontab watchdog +# (scripts/monitor-watchdog.sh). +# +# Mirrors the testability pattern of scripts/lib/monitor-decisions.sh: the +# watchdog wrapper owns all I/O (locks, launching the headless tick, writing +# the refire marker, logging); the two functions here are pure and fully unit- +# testable (scripts/test-monitor-watchdog.sh). +# +# Requires: Bash 3.2+, GNU/Linux (GNU `date -d`, `tail`, `grep -oE`, `sed -E`). +# Does NOT set shell options (set -e, -u) — callers control strictness. +# Idempotent: safe to source multiple times. +# + +[[ -n "${_MONITOR_WATCHDOG_DECISIONS_LOADED:-}" ]] && return 0 +_MONITOR_WATCHDOG_DECISIONS_LOADED=1 + +# ───────────────────────────────────────────────────────────────────────────── +# watchdog_last_epoch HIST_FILE +# +# Resolve the completion time of the last tick recorded in HIST_FILE (a JSONL +# tick history; the timestamp lives on the LAST line under key `ts` OR +# `timestamp`). +# +# Echoes EXACTLY one token on stdout: +# MISSING — HIST_FILE does not exist. A dark/bootstrapping loop; the +# caller SHOULD fire (this is the one fail-OPEN case). +# PARSE_ERROR — HIST_FILE exists but its last line has no parseable +# `ts`/`timestamp` value (not JSON, missing key, or a value +# GNU `date` cannot interpret). The caller MUST fail CLOSED: +# do NOT fire and do NOT write the refire marker (#3789). An +# unparseable tail is NOT evidence the loop is dead — treating +# it as epoch 0 (the old behavior) fired unconditionally and +# produced a 56,590-year "staleness" (#3757). +# — epoch seconds of the last completed tick. +# +# Dependency-light on purpose: uses only `tail`/`grep`/`sed`/`date` — never +# python3 or jq. A missing interpreter on cron's minimal PATH must not be able +# to silently blind the watchdog (dark-monitoring incident 2026-07-22). +# +# Accepts both `ts` (henyey monitor loop) and `timestamp` (alternate producers) +# keys; the first of either found on the last line wins. +# +# Returns: 0 always. +# ───────────────────────────────────────────────────────────────────────────── +watchdog_last_epoch() { + local hist="$1" + [ -f "$hist" ] || { printf 'MISSING\n'; return 0; } + + local line ts epoch + line=$(tail -n 1 "$hist" 2>/dev/null) + + # Isolate the first "ts":"..." or "timestamp":"..." pair, then strip the + # key/colon/quote scaffolding. Value may itself contain colons (ISO-8601 + # time), so peel the fixed prefix/suffix rather than splitting on ':'. + ts=$(printf '%s' "$line" \ + | grep -oE '"(ts|timestamp)"[[:space:]]*:[[:space:]]*"[^"]*"' \ + | head -n 1 \ + | sed -E 's/^"[^"]*"[[:space:]]*:[[:space:]]*"//; s/"$//') + + if [ -z "$ts" ]; then + printf 'PARSE_ERROR\n' + return 0 + fi + + epoch=$(date -u -d "$ts" +%s 2>/dev/null) + case "$epoch" in + ''|*[!0-9]*) printf 'PARSE_ERROR\n'; return 0 ;; + esac + + printf '%s\n' "$epoch" + return 0 +} + +# ───────────────────────────────────────────────────────────────────────────── +# watchdog_should_fire NOW LAST_TOKEN STALE_SECS LAST_FIRE REFIRE_COOLDOWN +# +# Pure staleness + cooldown decision. Reads and writes NO files; all times are +# passed in as epoch seconds so the whole matrix is deterministically testable. +# +# NOW — current epoch seconds. +# LAST_TOKEN — output of watchdog_last_epoch (an epoch, MISSING, or +# PARSE_ERROR). +# STALE_SECS — fire only if the last completed tick is older than this. +# LAST_FIRE — epoch of the last watchdog firing (0 if never / unknown). +# REFIRE_COOLDOWN — never fire twice within this many seconds. +# +# Echoes EXACTLY one line "VERDICT REASON" on stdout: +# fire no-history — no history file: dark loop / bootstrap (fail open). +# fire stale — last tick older than STALE_SECS and cooldown elapsed. +# skip fresh — last tick within STALE_SECS. +# skip cooldown — stale, but a firing happened within REFIRE_COOLDOWN. +# skip parse-error — history tail unparseable: FAIL CLOSED (do not fire, +# do not write the marker). +# +# Returns: 0 always. +# ───────────────────────────────────────────────────────────────────────────── +watchdog_should_fire() { + local now="$1" last_token="$2" stale_secs="$3" last_fire="$4" cooldown="$5" + + # Fail closed on an unparseable tail — highest precedence. + if [ "$last_token" = "PARSE_ERROR" ]; then + printf 'skip parse-error\n' + return 0 + fi + + # Staleness. + local stale=no + if [ "$last_token" = "MISSING" ]; then + stale=yes + elif [ $(( now - last_token )) -gt "$stale_secs" ]; then + stale=yes + fi + + if [ "$stale" = no ]; then + printf 'skip fresh\n' + return 0 + fi + + # Stale — apply the refire cooldown. + case "$last_fire" in ''|*[!0-9]*) last_fire=0 ;; esac + if [ "$last_fire" -gt 0 ] && [ $(( now - last_fire )) -lt "$cooldown" ]; then + printf 'skip cooldown\n' + return 0 + fi + + if [ "$last_token" = "MISSING" ]; then + printf 'fire no-history\n' + else + printf 'fire stale\n' + fi + return 0 +} diff --git a/scripts/monitor-watchdog.sh b/scripts/monitor-watchdog.sh new file mode 100755 index 00000000..e392f0f8 --- /dev/null +++ b/scripts/monitor-watchdog.sh @@ -0,0 +1,132 @@ +#!/usr/bin/env bash +# Monitor-loop watchdog — crontab backstop for the in-session /monitor-tick loop. +# +# The primary loop runs inside an interactive Claude Code session via +# ScheduleWakeup (~20 min cadence). That loop can silently die (session +# compaction, consumed wakeups, session exit). Audit 2026-07-16 found 571 +# dead-hours across 64 days (33 gaps >1h). This script runs from crontab +# every 15 min and launches a headless tick ONLY when the loop looks dead. +# +# Canonical copy: scripts/monitor-watchdog.sh in the henyey repo (this file). +# Live copy: /home/tomer/data/monitor-watchdog.sh (what crontab executes, +# decoupled from repo checkout state — deploy by copying this file there). +# +# Install: */15 * * * * /home/tomer/data/monitor-watchdog.sh +# +# Decision logic (staleness, cooldown, tail parsing) lives in the pure, +# unit-tested lib scripts/lib/monitor-watchdog-decisions.sh (mirrors the +# monitor-decisions.sh testability pattern). This wrapper owns all I/O: the +# self-serialization lock, the shared whole-tick lock, the refire marker, the +# log, and the headless launch. Covered by scripts/test-monitor-watchdog.sh. +# +# Staleness rule (corrected — #3789): the watchdog measures COMPLETION-to-now, +# so it fires whenever `wakeup + tick_duration > STALE_SECS`. STALE_SECS must +# therefore satisfy `expected_wakeup <= STALE_SECS - expected_tick_duration`, +# NOT merely "keep wakeups under STALE_SECS". With the loop's observed ~30-min +# idle cadence plus multi-minute ticks, the old 1800s bar fired on healthy but +# slow cycles (#3757: the watchdog fired a duplicate headless tick on nearly +# every cron cycle). STALE_SECS=4200 (70 min) gives ~40 min of headroom. +set -u + +# cron runs with a minimal PATH (/usr/bin:/bin) that omits ~/.local/bin, where +# the `claude` launcher lives. Without this the headless tick fails with +# "timeout: failed to run command 'claude': No such file or directory" and the +# watchdog silently no-ops every 15 min (dark-monitoring incident 2026-07-22). +export PATH="/home/tomer/.local/bin:$PATH" + +# Source the pure decision lib relative to this script (works regardless of the +# cwd cron invokes us from). +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +# shellcheck source=scripts/lib/monitor-watchdog-decisions.sh +source "$SCRIPT_DIR/lib/monitor-watchdog-decisions.sh" + +# ── Config — production defaults, all env-overridable (the test harness and any +# alternate deployment retarget these without editing the script). ──────────── +CLAUDE_BIN="${CLAUDE_BIN:-/home/tomer/.local/bin/claude}" +CLAUDE_MODEL="${WATCHDOG_CLAUDE_MODEL:-claude-opus-4-8}" +DATA="${WATCHDOG_DATA:-/home/tomer/data}" +ENV_FILE="${WATCHDOG_ENV_FILE:-$DATA/monitor-loop.env}" +REPO="${WATCHDOG_REPO:-/home/tomer/henyey-1}" + +# SESSION_ID: prefer an explicit MONITOR_SESSION_ID, else read it from +# monitor-loop.env, else the historical production default. Keeps the watchdog +# and the loop pointed at the same session dir even across loop restarts. +SESSION_ID="${MONITOR_SESSION_ID:-}" +if [ -z "$SESSION_ID" ] && [ -f "$ENV_FILE" ]; then + SESSION_ID=$(grep -E '^MONITOR_SESSION_ID=' "$ENV_FILE" 2>/dev/null | tail -n 1 | cut -d= -f2-) +fi +SESSION_ID="${SESSION_ID:-74535976}" + +SESS="$DATA/$SESSION_ID" +HIST="${WATCHDOG_HIST:-$SESS/tick-history.jsonl}" +LOCK="${WATCHDOG_LOCK:-$DATA/monitor-watchdog.lock}" # self-serialization +TICK_LOCK="${WATCHDOG_TICK_LOCK:-$DATA/monitor-tick.lock}" # shared whole-tick +MARKER="${WATCHDOG_MARKER:-$DATA/monitor-watchdog.lastfire}" +LOG="${WATCHDOG_LOG:-$DATA/monitor-watchdog.log}" + +STALE_SECS="${WATCHDOG_STALE_SECS:-4200}" # fire when last COMPLETED tick + # is older than 70 min +REFIRE_COOLDOWN="${WATCHDOG_REFIRE_COOLDOWN:-1800}" # >= 1 firing / 30 min +TICK_TIMEOUT="${WATCHDOG_TICK_TIMEOUT:-1500}" # cap a headless tick at 25 min + +mkdir -p "$DATA" 2>/dev/null || true + +log() { printf '%s %s\n' "$(date -u +%FT%TZ)" "$1" >> "$LOG"; } + +# ── Self-serialize watchdog instances (fd 9). ──────────────────────────────── +exec 9>"$LOCK" +flock -n 9 || exit 0 + +now=$(date -u +%s) + +# ── Decide (pure). ─────────────────────────────────────────────────────────── +last_token=$(watchdog_last_epoch "$HIST") + +last_fire=0 +if [ -f "$MARKER" ]; then + last_fire=$(cat "$MARKER" 2>/dev/null || echo 0) + case "$last_fire" in ''|*[!0-9]*) last_fire=0 ;; esac +fi + +decision=$(watchdog_should_fire "$now" "$last_token" "$STALE_SECS" "$last_fire" "$REFIRE_COOLDOWN") +verdict="${decision%% *}" +reason="${decision#* }" + +if [ "$verdict" != "fire" ]; then + # Fail CLOSED on an unparseable tail: log LOUDLY (an unparseable history is a + # real anomaly an operator should see) and exit WITHOUT writing the marker + # (#3789). fresh/cooldown skips are the quiet common case. + if [ "$reason" = "parse-error" ]; then + log "WARNING: history tail unparseable ($HIST) — failing CLOSED, NOT firing. Inspect the loop's liveness manually." + fi + exit 0 +fi + +# ── In-flight guard (fd 8): take the shared whole-tick lock. If an in-session +# tick (which takes the same lock around its metrics scrape/archive critical +# section) or a prior headless firing holds it, a tick is in flight — skip. +# Held across the headless launch below so the child inherits it and the +# in-session check-12 serializes behind us. This REPLACES the old .alive-mtime +# heuristic, closing the interleaving race that corrupted archive metadata.env +# (#3757 / #3789). ───────────────────────────────────────────────────────────── +exec 8>"$TICK_LOCK" +if ! flock -n 8; then + log "skipped: tick in flight" + exit 0 +fi + +# Committed to firing — record the marker (only reached past the fail-closed +# and in-flight guards, so a PARSE_ERROR skip never writes it). +printf '%s\n' "$now" > "$MARKER" + +# Keep the log bounded (~5 MB). +if [ -f "$LOG" ] && [ "$(stat -c %s "$LOG" 2>/dev/null || echo 0)" -gt 5242880 ]; then + tail -c 1048576 "$LOG" > "$LOG.tmp" && mv "$LOG.tmp" "$LOG" +fi + +log "watchdog: loop stale (reason=$reason, last=$last_token, now=$now) — launching headless tick" +cd "$REPO" || { log "watchdog: repo $REPO missing — aborting firing"; exit 1; } +timeout "$TICK_TIMEOUT" "$CLAUDE_BIN" --model "$CLAUDE_MODEL" --dangerously-skip-permissions \ + -p '/monitor-tick' >> "$LOG" 2>&1 +rc=$? +log "watchdog: headless tick exit=$rc" diff --git a/scripts/test-shell-lib-cross-shell.sh b/scripts/test-shell-lib-cross-shell.sh index 60dd8623..9bba4bcf 100755 --- a/scripts/test-shell-lib-cross-shell.sh +++ b/scripts/test-shell-lib-cross-shell.sh @@ -52,6 +52,7 @@ SOURCED_LIBS=( dedup-filing.sh deploy-quarantine.sh monitor-decisions.sh + monitor-watchdog-decisions.sh review-pr-merge.sh review-pr-verdicts.sh pipeline-anomaly-log.sh @@ -73,6 +74,8 @@ expected_funcs_for() { echo "parse_quarantine_file check_quarantine_active check_quarantine_ancestry quarantine_append quarantine_remove quarantine_resolve quarantine_autostamp quarantine_resolved_is_ve_green" ;; monitor-decisions.sh) echo "check_session_wiped check_long_stale_session detect_crash_state cleanup_guard prune_rotated_logs prune_metrics_archive" ;; + monitor-watchdog-decisions.sh) + echo "watchdog_last_epoch watchdog_should_fire" ;; review-pr-merge.sh) echo "attempt_merge classify_linked_pr_state is_auto_merge_armed has_armed_waiting_comment check_armed_pr_health" ;; review-pr-verdicts.sh)