From 581ecd4728192b7cd2afda616d7124dc161b80b7 Mon Sep 17 00:00:00 2001 From: Tomer Weller Date: Sun, 23 Aug 2026 05:19:37 +0000 Subject: [PATCH 1/2] =?UTF-8?q?Regression=20test=20for=20#3780=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-watchdog-postcondition.sh: a TAP harness pinning the watchdog post-condition fix. Asserts watchdog_classify_outcome distinguishes a real tick (new tick-history.jsonl row above a duration floor) from a spend-limit refusal no-op, an empty no-op, and a suspect-fast write; and that both crontab watchdogs write the refire-cooldown MARKER only on a real success and log a distinct outcome= line. Fails on main (shared lib and canonical scripts/monitor-watchdog.sh absent; project-loop-watchdog.sh logs bare exit=$rc with a pre-tick MARKER write). Refs #3780 Co-authored-by: Claude Code --- scripts/test-watchdog-postcondition.sh | 234 +++++++++++++++++++++++++ 1 file changed, 234 insertions(+) create mode 100755 scripts/test-watchdog-postcondition.sh diff --git a/scripts/test-watchdog-postcondition.sh b/scripts/test-watchdog-postcondition.sh new file mode 100755 index 00000000..11d0ed92 --- /dev/null +++ b/scripts/test-watchdog-postcondition.sh @@ -0,0 +1,234 @@ +#!/usr/bin/env bash +# +# Regression harness for the crontab watchdog post-condition detection (#3780). +# +# Incident: on 2026-07-28/29 the mainnet monitor ran ~24h with zero coverage +# while `monitor-watchdog.sh` logged 49 consecutive "successful" ticks. The org +# monthly spend limit made `claude -p` refuse to run and **exit 0**; the +# watchdog recorded `exit=$?` (the CLI's status, not the tick's) and could not +# tell a 1-second refusal from a completed tick. Worse, the refire-cooldown +# MARKER was written *before* the launch, so each no-op burned the full 30-min +# cooldown, and nothing escalated. +# +# This harness pins the fix: +# 1. `watchdog_classify_outcome` distinguishes a real tick (a NEW +# tick-history.jsonl row, above a duration floor) from a refusal no-op, +# an unexplained empty no-op, and a suspiciously-fast row write. +# 2. Both watchdogs write the cooldown MARKER **only** on a real `success`, +# so a refusal no-op does not burn the cooldown. +# 3. Both watchdogs log a distinct `outcome=` line instead of a bare +# `exit=0`. +# +# COUPLING: assertions key on the stable outcome tokens (`success`, +# `noop-refusal`, `noop-empty`, `suspect-fast`) and the MARKER-write behavior, +# not on log wording. If you reword a log line keep the `outcome=` +# token, or update this test in the same commit. +# +# Usage: bash scripts/test-watchdog-postcondition.sh +# Output: TAP on stdout, diagnostics on stderr. +# Exit: 0 = all pass, 1 = any fail. +# Portability: GNU/Linux (Bash 4+, coreutils, git). +# +set -uo pipefail + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +REPO_ROOT="$(cd "$SCRIPT_DIR/.." && pwd)" +LIB="$SCRIPT_DIR/lib/watchdog-postcondition.sh" +MONITOR_WD="$SCRIPT_DIR/monitor-watchdog.sh" +LOOP_WD="$SCRIPT_DIR/project-loop-watchdog.sh" + +# ── TAP state ──────────────────────────────────────────────────────────────── +TAP_PLAN=15 +TAP_CURRENT=0 +TAP_FAILURES=0 + +tap_plan() { echo "1..$TAP_PLAN"; } +tap_ok() { TAP_CURRENT=$((TAP_CURRENT + 1)); echo "ok $TAP_CURRENT - $1"; } +tap_not_ok() { + TAP_CURRENT=$((TAP_CURRENT + 1)) + TAP_FAILURES=$((TAP_FAILURES + 1)) + echo "not ok $TAP_CURRENT - $1" + [ -n "${2:-}" ] && echo "# $2" >&2 + return 0 +} + +# assert_eq DESC EXPECTED ACTUAL +assert_eq() { + local desc="$1" expected="$2" actual="$3" + if [ "$expected" = "$actual" ]; then + tap_ok "$desc" + else + tap_not_ok "$desc" "expected [$expected], got [$actual]" + fi +} + +# assert_no_file DESC PATH +assert_no_file() { + if [ ! -e "$2" ]; then tap_ok "$1"; else tap_not_ok "$1" "file exists: $2"; fi +} + +# assert_file DESC PATH +assert_file() { + if [ -e "$2" ]; then tap_ok "$1"; else tap_not_ok "$1" "file missing: $2"; fi +} + +# assert_grep DESC PATTERN FILE +assert_grep() { + if [ -f "$3" ] && grep -Eq -- "$2" "$3"; then + tap_ok "$1" + else + tap_not_ok "$1" "pattern /$2/ not found in $3" + fi +} + +TMPROOT="$(mktemp -d)" +cleanup() { rm -rf "$TMPROOT"; } +trap cleanup EXIT + +tap_plan + +# ── Preconditions / lib load ───────────────────────────────────────────────── +if [ ! -f "$LIB" ]; then + echo "# lib not found at $LIB — classifier assertions will fail" >&2 +else + # shellcheck source=scripts/lib/watchdog-postcondition.sh + . "$LIB" +fi + +# Wrapper that tolerates the lib being absent (so the harness reports clean TAP +# failures pre-fix instead of a hard bail). +classify() { + if command -v watchdog_classify_outcome >/dev/null 2>&1; then + watchdog_classify_outcome "$@" + else + echo "MISSING-LIB" + fi +} +histcount() { + if command -v watchdog_hist_count >/dev/null 2>&1; then + watchdog_hist_count "$@" + else + echo "MISSING-LIB" + fi +} + +# ── Unit: watchdog_hist_count ──────────────────────────────────────────────── +assert_eq "hist_count of a missing file is 0" "0" "$(histcount "$TMPROOT/nope.jsonl")" + +hf="$TMPROOT/hist.jsonl" +printf '{"ts":"a"}\n{"ts":"b"}\n{"ts":"c"}\n' > "$hf" +assert_eq "hist_count counts rows in an existing file" "3" "$(histcount "$hf")" + +# ── Unit: watchdog_classify_outcome branches ───────────────────────────────── +spend="$TMPROOT/spend.out" +printf "You've hit your org's monthly spend limit · run /usage-credits to ask your admin\n" > "$spend" +assert_eq "spend-limit no-op (no new row, refusal text) classifies noop-refusal" \ + "noop-refusal" "$(classify 100 100 2 "$spend")" + +normal="$TMPROOT/normal.out" +printf 'monitor-tick 2851 complete: node Validating, wrote history row\n' > "$normal" +assert_eq "real tick (new row, above floor) classifies success" \ + "success" "$(classify 100 101 372 "$normal")" + +empty="$TMPROOT/empty.out" +: > "$empty" +assert_eq "no new row with no recognized reason classifies noop-empty" \ + "noop-empty" "$(classify 100 100 40 "$empty")" + +assert_eq "new row under the duration floor classifies suspect-fast" \ + "suspect-fast" "$(classify 100 101 3 "$normal")" + +# ── E2E: monitor-watchdog.sh does NOT burn cooldown on a spend-limit no-op ──── +run_monitor_e2e() { + local kind="$1" fx="$TMPROOT/mon-$kind" + local data="$fx/data" sess="$fx/data/sess" repo="$fx/repo" bin="$fx/claude" + mkdir -p "$sess" "$repo" + local hist="$sess/tick-history.jsonl" + : > "$hist" # empty history => stale => the watchdog fires + # Stub CLI. + cat > "$bin" <> "$hist" + exit 0 +fi +EOF + chmod +x "$bin" + DATA="$data" SESS="$sess" HIST="$hist" REPO="$repo" CLAUDE_BIN="$bin" \ + WATCHDOG_DUR_FLOOR=1 ESCALATE_AFTER=3 \ + bash "$MONITOR_WD" >/dev/null 2>&1 + # Export the fixture paths for the caller's assertions. + E2E_MARKER="$data/monitor-watchdog.lastfire" + E2E_LOG="$data/monitor-watchdog.log" + E2E_FAILSTREAK="$data/monitor-watchdog.failstreak" +} + +if [ -f "$MONITOR_WD" ]; then + run_monitor_e2e spend + assert_no_file "monitor-watchdog: spend-limit no-op does NOT write the cooldown MARKER" "$E2E_MARKER" + assert_grep "monitor-watchdog: spend-limit no-op logs outcome=noop-refusal" 'outcome=noop-refusal' "$E2E_LOG" + assert_grep "monitor-watchdog: spend-limit no-op increments the failstreak" '^1$' "$E2E_FAILSTREAK" + + run_monitor_e2e real + assert_file "monitor-watchdog: real tick writes the cooldown MARKER" "$E2E_MARKER" + assert_grep "monitor-watchdog: real tick logs outcome=success" 'outcome=success' "$E2E_LOG" +else + echo "# $MONITOR_WD absent — 5 monitor e2e assertions will fail" >&2 + tap_not_ok "monitor-watchdog: spend-limit no-op does NOT write the cooldown MARKER" "script absent" + tap_not_ok "monitor-watchdog: spend-limit no-op logs outcome=noop-refusal" "script absent" + tap_not_ok "monitor-watchdog: spend-limit no-op increments the failstreak" "script absent" + tap_not_ok "monitor-watchdog: real tick writes the cooldown MARKER" "script absent" + tap_not_ok "monitor-watchdog: real tick logs outcome=success" "script absent" +fi + +# ── E2E: project-loop-watchdog.sh (clone path via a local bare remote) ──────── +if [ -f "$LOOP_WD" ]; then + fx="$TMPROOT/loop"; data="$fx/data"; sess="$fx/data/project-loop" + mkdir -p "$sess" + hist="$sess/tick-history.jsonl"; : > "$hist" + # Seed a local bare remote so the watchdog's `git clone --depth 1` works offline. + seed="$fx/seed"; bare="$fx/remote.git" + git init -q "$seed" + git -C "$seed" -c user.email=t@e -c user.name=t commit -q --allow-empty -m init + git clone -q --bare "$seed" "$bare" >/dev/null 2>&1 + bin="$fx/claude" + cat > "$bin" <<'EOF' +#!/usr/bin/env bash +echo "You've hit your org's monthly spend limit · run /usage-credits to ask your admin" +exit 0 +EOF + chmod +x "$bin" + DATA="$data" SESS="$sess" HIST="$hist" REMOTE="$bare" CLAUDE_BIN="$bin" \ + WATCHDOG_DUR_FLOOR=1 ESCALATE_AFTER=3 \ + bash "$LOOP_WD" >/dev/null 2>&1 + assert_no_file "project-loop-watchdog: spend-limit no-op does NOT write the cooldown MARKER" "$data/project-loop-watchdog.lastfire" + assert_grep "project-loop-watchdog: spend-limit no-op logs outcome=noop-refusal" 'outcome=noop-refusal' "$data/project-loop-watchdog.log" +else + echo "# $LOOP_WD absent — 2 loop e2e assertions will fail" >&2 + tap_not_ok "project-loop-watchdog: spend-limit no-op does NOT write the cooldown MARKER" "script absent" + tap_not_ok "project-loop-watchdog: spend-limit no-op logs outcome=noop-refusal" "script absent" +fi + +# ── Static: both watchdog scripts parse clean ──────────────────────────────── +if [ -f "$MONITOR_WD" ] && bash -n "$MONITOR_WD" 2>/dev/null; then + tap_ok "monitor-watchdog.sh parses clean (bash -n)" +else + tap_not_ok "monitor-watchdog.sh parses clean (bash -n)" "absent or syntax error" +fi +if bash -n "$LOOP_WD" 2>/dev/null; then + tap_ok "project-loop-watchdog.sh parses clean (bash -n)" +else + tap_not_ok "project-loop-watchdog.sh parses clean (bash -n)" "syntax error" +fi + +# ── Summary ────────────────────────────────────────────────────────────────── +if [ "$TAP_FAILURES" -gt 0 ]; then + echo "# $TAP_FAILURES of $TAP_PLAN assertions failed" >&2 + exit 1 +fi +echo "# all $TAP_PLAN assertions passed" >&2 +exit 0 From 6c33e2ff4ffaca6100987fba335dff3c545de205 Mon Sep 17 00:00:00 2001 From: Tomer Weller Date: Sun, 23 Aug 2026 05:22:32 +0000 Subject: [PATCH 2/2] Give crontab watchdogs a real tick post-condition MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `claude -p`'s exit status is the CLI's, not the tick's: a refusal to run (org monthly spend limit, auth failure) exits 0 and was logged as a successful tick. On 2026-07-28/29 this produced ~24h of dark mainnet monitoring recorded as 49 "successful" ticks, and because the refire-cooldown MARKER was written before the launch, each 1-second no-op burned the full 30-min cooldown. Add scripts/lib/watchdog-postcondition.sh — a source-safe classifier keyed on the only true success signal, a NEW tick-history.jsonl row: success (row advanced, duration >= floor), suspect-fast (row advanced but under the floor), noop-refusal (no row, output matches a known refusal regex), noop-empty (no row, no recognized reason). Both watchdogs now capture the row count and duration around the launch, log a distinct outcome= line, write the cooldown MARKER only on success (so a no-op retries at the next */15 slot), and emit a greppable ESCALATION line after N consecutive failed launches. Track the canonical scripts/monitor-watchdog.sh (previously only a live crontab copy) and apply the identical fix to the in-repo project-loop-watchdog.sh. Wire the TAP harness into CI. Refs #3780 Co-authored-by: Claude Code --- .github/workflows/ci.yml | 9 ++ scripts/lib/watchdog-postcondition.sh | 70 ++++++++++++++ scripts/monitor-watchdog.sh | 124 +++++++++++++++++++++++++ scripts/project-loop-watchdog.sh | 51 ++++++++-- scripts/test-watchdog-postcondition.sh | 3 +- 5 files changed, 248 insertions(+), 9 deletions(-) create mode 100755 scripts/lib/watchdog-postcondition.sh create mode 100755 scripts/monitor-watchdog.sh diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 727852a0..5196c7b7 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 + watchdog-postcondition: + name: Watchdog Post-Condition + runs-on: ubuntu-latest + timeout-minutes: 5 + steps: + - uses: actions/checkout@v4 + - name: Run watchdog post-condition harness + run: bash scripts/test-watchdog-postcondition.sh + ssc-henyey-mixed-mission-scripts: name: Henyey Mixed-Image SSC Scripts runs-on: ubuntu-latest diff --git a/scripts/lib/watchdog-postcondition.sh b/scripts/lib/watchdog-postcondition.sh new file mode 100755 index 00000000..a5500815 --- /dev/null +++ b/scripts/lib/watchdog-postcondition.sh @@ -0,0 +1,70 @@ +#!/usr/bin/env bash +# Shared post-condition detection for the crontab watchdogs (#3780). +# +# Both monitor-watchdog.sh and project-loop-watchdog.sh launch a headless +# `claude -p` tick when their in-session loop looks dead. The defect this lib +# fixes: `exit=$?` is the CLI's exit status, not the tick's. A refusal to run +# (org spend limit, auth failure, "not logged in") exits 0 and is +# indistinguishable from a completed tick — on 2026-07-28/29 this produced 24h +# of dark monitoring logged as 49 "successful" ticks. The only true success +# signal is a NEW row in tick-history.jsonl. +# +# This file is SOURCE-SAFE: it defines functions and sets a few overridable +# defaults, with no other top-level side effects (no `set -e`, no output), so +# it can be sourced into scripts that manage their own shell options. +# +# Canonical copy: scripts/lib/watchdog-postcondition.sh in the henyey repo. +# The live crontab copies of the watchdogs must be re-synced from the fixed +# canonical scripts (and this lib copied alongside) after merge. + +# Any invocation completing faster than this floor is treated as not-a-real-tick +# even if a row appears to have advanced (the incident's spend-limit no-ops ran +# 1–3 s; real ticks ran p50 372 s). Overridable so tests can lower it. +: "${WATCHDOG_DUR_FLOOR:=30}" + +# Signatures that make `claude -p` exit 0 without running a tick. Case-insensitive +# ERE. Overridable so operators can extend it without editing this file. +: "${WATCHDOG_REFUSAL_RE:=spend limit|usage-credits|Invalid API key|authentication|not logged in|please run .*login|rate limit|quota}" + +# watchdog_hist_count HIST_FILE +# Echo the number of rows (lines) in HIST_FILE, or 0 if it is missing/empty. +watchdog_hist_count() { + local f="${1:-}" + if [ -n "$f" ] && [ -f "$f" ]; then + # `wc -l < file` avoids printing the filename; trim any padding. + wc -l < "$f" 2>/dev/null | tr -d '[:space:]' + else + echo 0 + fi +} + +# watchdog_classify_outcome PRE POST DURATION_SECS [OUTPUT_FILE] +# Pure classifier. Echoes exactly one of: +# success — a new tick-history row appeared AND duration >= floor +# suspect-fast — a new row appeared but under the duration floor (do NOT +# treat as success; the STALE/ALIVE gates prevent +# double-dispatch, so leaving the cooldown unburned is safe) +# noop-refusal — no new row AND the captured output matches a known refusal +# noop-empty — no new row and no recognized reason +watchdog_classify_outcome() { + local pre="${1:-0}" post="${2:-0}" dur="${3:-0}" out="${4:-}" + local floor="${WATCHDOG_DUR_FLOOR:-30}" + + # Guard against non-numeric input so the comparisons below never error. + case "$pre$post$dur$floor" in *[!0-9]*) ;; esac + + if [ "${post:-0}" -gt "${pre:-0}" ] 2>/dev/null; then + if [ "${dur:-0}" -ge "${floor:-30}" ] 2>/dev/null; then + echo success + else + echo suspect-fast + fi + return 0 + fi + + if [ -n "$out" ] && [ -f "$out" ] && grep -Eiq -- "$WATCHDOG_REFUSAL_RE" "$out" 2>/dev/null; then + echo noop-refusal + else + echo noop-empty + fi +} diff --git a/scripts/monitor-watchdog.sh b/scripts/monitor-watchdog.sh new file mode 100755 index 00000000..4eb1d444 --- /dev/null +++ b/scripts/monitor-watchdog.sh @@ -0,0 +1,124 @@ +#!/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. +# +# Post-condition (#3780): `claude -p` exit status is the CLI's, not the tick's. +# A refusal to run (org monthly spend limit, auth failure) exits 0 and used to +# be logged as a successful tick — on 2026-07-28/29 this produced 24h of dark +# monitoring logged as 49 "successful" ticks. The only true success signal is a +# NEW tick-history.jsonl row. We now capture the row count and duration around +# the launch, classify the outcome via scripts/lib/watchdog-postcondition.sh, +# write the refire-cooldown MARKER ONLY on a real success (so a no-op does not +# burn the cooldown), and emit a greppable ESCALATION line after N consecutive +# failed launches. +# +# Canonical copy: scripts/monitor-watchdog.sh in the henyey repo. +# Live copy: /home/tomer/data/monitor-watchdog.sh (what crontab executes, +# decoupled from repo checkout state). After changing this script, re-sync the +# live copy AND scripts/lib/watchdog-postcondition.sh alongside it. +# +# Install: */15 * * * * /home/tomer/data/monitor-watchdog.sh +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" + +# Paths/binaries are env-overridable (with the production values as defaults) so +# tests can point them at a ~/data fixture; production behavior is unchanged. +: "${CLAUDE_BIN:=/home/tomer/.local/bin/claude}" +: "${SESSION_ID:=74535976}" +: "${DATA:=/home/tomer/data}" +: "${SESS:=$DATA/$SESSION_ID}" +: "${HIST:=$SESS/tick-history.jsonl}" +: "${REPO:=/home/tomer/henyey-1}" +ALIVE="$SESS/.alive" +LOCK="$DATA/monitor-watchdog.lock" +MARKER="$DATA/monitor-watchdog.lastfire" +LOG="$DATA/monitor-watchdog.log" +FAILSTREAK="$DATA/monitor-watchdog.failstreak" +CAP="$DATA/monitor-watchdog.lastcapture" + +STALE_SECS=1800 # fire when last completed tick is older than 30 min +ALIVE_FRESH_SECS=600 # skip if a tick STARTED within the last 10 min (in-flight) +REFIRE_COOLDOWN=1800 # never fire more than once per 30 min +TICK_TIMEOUT=1500 # cap a headless tick at 25 min +: "${ESCALATE_AFTER:=3}" # greppable escalation after N consecutive failed launches + +# Shared post-condition detection (row-count + duration + refusal classifier). +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +# shellcheck source=scripts/lib/watchdog-postcondition.sh +. "${WATCHDOG_LIB:-$SCRIPT_DIR/lib/watchdog-postcondition.sh}" + +# Serialize watchdog instances. +exec 9>"$LOCK" +flock -n 9 || exit 0 + +now=$(date -u +%s) + +# 1) Last COMPLETED tick (history line ts). Missing/unparseable => epoch 0 (fire). +last_epoch=0 +if [ -f "$HIST" ]; then + last_ts=$(tail -1 "$HIST" | python3 -c 'import sys,json +try: print(json.load(sys.stdin).get("ts","")) +except Exception: print("")' 2>/dev/null) + [ -n "$last_ts" ] && last_epoch=$(date -u -d "$last_ts" +%s 2>/dev/null || echo 0) +fi +[ $(( now - last_epoch )) -le "$STALE_SECS" ] && exit 0 + +# 2) A tick touches .alive at START — if fresh, one is in flight; don't collide. +if [ -f "$ALIVE" ]; then + alive_age=$(( now - $(stat -c %Y "$ALIVE") )) + [ "$alive_age" -le "$ALIVE_FRESH_SECS" ] && exit 0 +fi + +# 3) Refire cooldown. +if [ -f "$MARKER" ]; then + last_fire=$(cat "$MARKER" 2>/dev/null || echo 0) + [ $(( now - last_fire )) -lt "$REFIRE_COOLDOWN" ] && exit 0 +fi +# NOTE: the cooldown MARKER is intentionally NOT written here (#3780). It used +# to be written pre-tick, so a 1-second no-op burned the full 30-min cooldown. +# It is now written only after the post-condition confirms a real tick ran, so +# a failed launch can be retried at the next */15 slot. + +# Keep the log bounded (~5 MB). +if [ -f "$LOG" ] && [ "$(stat -c %s "$LOG")" -gt 5242880 ]; then + tail -c 1048576 "$LOG" > "$LOG.tmp" && mv "$LOG.tmp" "$LOG" +fi + +echo "$(date -u +%FT%TZ) watchdog: loop stale ($((now - last_epoch))s since last tick) — launching headless tick" >> "$LOG" +cd "$REPO" || exit 1 + +# Capture the pre-tick row count and the invocation output, then classify. +pre=$(watchdog_hist_count "$HIST") +start=$(date -u +%s) +timeout "$TICK_TIMEOUT" "$CLAUDE_BIN" --model claude-opus-4-8 --dangerously-skip-permissions \ + -p '/monitor-tick' > "$CAP" 2>&1 +rc=$? +dur=$(( $(date -u +%s) - start )) +post=$(watchdog_hist_count "$HIST") +cat "$CAP" >> "$LOG" # preserve full diagnosability in the watchdog log +outcome=$(watchdog_classify_outcome "$pre" "$post" "$dur" "$CAP") +rm -f "$CAP" +echo "$(date -u +%FT%TZ) watchdog: headless tick outcome=$outcome dur=${dur}s rows=$((post - pre)) exit=$rc" >> "$LOG" + +if [ "$outcome" = "success" ]; then + printf '%s\n' "$now" > "$MARKER" # burn the cooldown only on a real tick + printf '0\n' > "$FAILSTREAK" +else + fs=$(cat "$FAILSTREAK" 2>/dev/null || echo 0) + case "$fs" in ''|*[!0-9]*) fs=0 ;; esac + fs=$((fs + 1)) + printf '%s\n' "$fs" > "$FAILSTREAK" + if [ "$fs" -ge "$ESCALATE_AFTER" ]; then + echo "$(date -u +%FT%TZ) watchdog: ESCALATION $fs consecutive failed launches (last outcome=$outcome) — monitor loop is dark and headless recovery is not working" >> "$LOG" + fi +fi diff --git a/scripts/project-loop-watchdog.sh b/scripts/project-loop-watchdog.sh index af8b0158..3d907d1d 100755 --- a/scripts/project-loop-watchdog.sh +++ b/scripts/project-loop-watchdog.sh @@ -34,17 +34,21 @@ set -u # cron runs with a minimal PATH (/usr/bin:/bin) that omits ~/.local/bin, where # the `claude` launcher lives (see monitor-watchdog.sh's 2026-07-22 incident). export PATH="/home/tomer/.local/bin:$PATH" -CLAUDE_BIN="/home/tomer/.local/bin/claude" -DATA=/home/tomer/data -SESS="$DATA/project-loop" -HIST="$SESS/tick-history.jsonl" +# Paths/binaries are env-overridable (with the production values as defaults) so +# tests can point them at a ~/data fixture; production behavior is unchanged. +: "${CLAUDE_BIN:=/home/tomer/.local/bin/claude}" +: "${DATA:=/home/tomer/data}" +: "${SESS:=$DATA/project-loop}" +: "${HIST:=$SESS/tick-history.jsonl}" +: "${REMOTE:=https://github.com/stellar-experimental/henyey.git}" ALIVE="$SESS/.alive" LOCK="$DATA/project-loop-watchdog.lock" MARKER="$DATA/project-loop-watchdog.lastfire" LOG="$DATA/project-loop-watchdog.log" +FAILSTREAK="$DATA/project-loop-watchdog.failstreak" +CAP="$DATA/project-loop-watchdog.lastcapture" SCRATCH="$DATA/project-loop-watchdog-scratch" -REMOTE="https://github.com/stellar-experimental/henyey.git" STALE_SECS=2700 # fire when last completed tick is older than 45 min # (loop's own idle cadence widens to ~30 min; 1.5x that) @@ -53,6 +57,12 @@ ALIVE_FRESH_SECS=1800 # skip if a tick STARTED within the last 30 min (in-flig # generous to avoid double-dispatching a live session) REFIRE_COOLDOWN=1800 # never fire more than once per 30 min TICK_TIMEOUT=1800 # cap a headless tick at 30 min +: "${ESCALATE_AFTER:=3}" # greppable escalation after N consecutive failed launches + +# Shared post-condition detection (#3780) — same classifier as monitor-watchdog. +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +# shellcheck source=scripts/lib/watchdog-postcondition.sh +. "${WATCHDOG_LIB:-$SCRIPT_DIR/lib/watchdog-postcondition.sh}" # Serialize watchdog instances. exec 9>"$LOCK" @@ -81,7 +91,10 @@ if [ -f "$MARKER" ]; then last_fire=$(cat "$MARKER" 2>/dev/null || echo 0) [ $(( now - last_fire )) -lt "$REFIRE_COOLDOWN" ] && exit 0 fi -printf '%s\n' "$now" > "$MARKER" +# NOTE: the cooldown MARKER is intentionally NOT written here (#3780). It used +# to be written pre-tick, so a launch that never ran a real tick (spend limit, +# auth failure — both make `claude -p` exit 0) burned the full 30-min cooldown. +# It is now written only after the post-condition confirms a real tick ran. # Keep the log bounded (~5 MB). if [ -f "$LOG" ] && [ "$(stat -c %s "$LOG")" -gt 5242880 ]; then @@ -99,11 +112,33 @@ if ! git clone --quiet --depth 1 "$REMOTE" "$SCRATCH" >> "$LOG" 2>&1; then exit 1 fi +# Capture the pre-tick row count and the invocation output, then classify the +# outcome (#3780) — a new tick-history.jsonl row is the only true success signal. +pre=$(watchdog_hist_count "$HIST") +start=$(date -u +%s) cd "$SCRATCH" || exit 1 timeout "$TICK_TIMEOUT" "$CLAUDE_BIN" --model claude-opus-4-8 --dangerously-skip-permissions \ - -p '/project-tick' >> "$LOG" 2>&1 + -p '/project-tick' > "$CAP" 2>&1 rc=$? -echo "$(date -u +%FT%TZ) watchdog: headless tick exit=$rc" >> "$LOG" +dur=$(( $(date -u +%s) - start )) +post=$(watchdog_hist_count "$HIST") +cat "$CAP" >> "$LOG" # preserve full diagnosability in the watchdog log +outcome=$(watchdog_classify_outcome "$pre" "$post" "$dur" "$CAP") +rm -f "$CAP" +echo "$(date -u +%FT%TZ) watchdog: headless tick outcome=$outcome dur=${dur}s rows=$((post - pre)) exit=$rc" >> "$LOG" + +if [ "$outcome" = "success" ]; then + printf '%s\n' "$now" > "$MARKER" # burn the cooldown only on a real tick + printf '0\n' > "$FAILSTREAK" +else + fs=$(cat "$FAILSTREAK" 2>/dev/null || echo 0) + case "$fs" in ''|*[!0-9]*) fs=0 ;; esac + fs=$((fs + 1)) + printf '%s\n' "$fs" > "$FAILSTREAK" + if [ "$fs" -ge "$ESCALATE_AFTER" ]; then + echo "$(date -u +%FT%TZ) watchdog: ESCALATION $fs consecutive failed launches (last outcome=$outcome) — project loop is dark and headless recovery is not working" >> "$LOG" + fi +fi cd "$DATA" || true rm -rf "$SCRATCH" diff --git a/scripts/test-watchdog-postcondition.sh b/scripts/test-watchdog-postcondition.sh index 11d0ed92..746d237a 100755 --- a/scripts/test-watchdog-postcondition.sh +++ b/scripts/test-watchdog-postcondition.sh @@ -140,7 +140,8 @@ assert_eq "new row under the duration floor classifies suspect-fast" \ # ── E2E: monitor-watchdog.sh does NOT burn cooldown on a spend-limit no-op ──── run_monitor_e2e() { - local kind="$1" fx="$TMPROOT/mon-$kind" + local kind="$1" + local fx="$TMPROOT/mon-$kind" local data="$fx/data" sess="$fx/data/sess" repo="$fx/repo" bin="$fx/claude" mkdir -p "$sess" "$repo" local hist="$sess/tick-history.jsonl"