diff --git a/.github/workflows/fleet-uptime.yml b/.github/workflows/fleet-uptime.yml index 65cd5297..82f80d9d 100644 --- a/.github/workflows/fleet-uptime.yml +++ b/.github/workflows/fleet-uptime.yml @@ -113,7 +113,9 @@ jobs: `how botsmann stayed broken unnoticed.`, ].join('\n'), }); - await tg(`🔴 ${d.app} is DOWN (${detail}) as of ${now}`); + // Same voice as the on-box watchdog ("🔴 DOWN: app (…)"), and + // no ISO timestamp — Telegram already stamps every message. + await tg(`🔴 DOWN: ${d.app} (${detail})`); } } @@ -128,7 +130,7 @@ jobs: await github.rest.issues.update({ owner, repo, issue_number: issue.number, state: 'closed', }); - await tg(`✅ ${app} RECOVERED at ${now}`); + await tg(`✅ RECOVERED: ${app}`); } const c = result.counts || {}; diff --git a/scripts/hetzner/install-host-alerts.sh b/scripts/hetzner/install-host-alerts.sh index 4c5b989d..2a8316c2 100755 --- a/scripts/hetzner/install-host-alerts.sh +++ b/scripts/hetzner/install-host-alerts.sh @@ -118,36 +118,76 @@ alert() { return 0 } -# One incident is one message. The caller names the subject; repeated detections -# of the SAME subject inside go to the journal only, and a re-page -# after the cooldown is a deliberate still-broken reminder. alert_clear on -# recovery is the other half and is load-bearing: without it the next genuine -# outage of that subject inherits the last one's silence. -alert_once() { # key cooldown emoji text - local key="$1" cd="$2" emoji="$3" text="$4" +# One incident is one message, and reminders BACK OFF. The stamp holds +# "ts count": each successful claim quadruples the next reminder's wait +# (30m → 2h → 8h → daily, capped at a day). On 2026-08-29 George's phone got +# the same four failing crons every 30 minutes all morning — a thing that has +# been broken for six hours is not new information twice an hour, and the fix +# agent (incident-dispatch) already has the journal. alert_clear on recovery +# resets the ladder, so the next genuine outage pages immediately again. +# +# claim_once is the decision without the delivery: callers that want to speak +# about SEVERAL claimed subjects in one message (the host-check digest) claim +# each and deliver once. alert_once stays as claim+deliver for the one-subject +# callers (the OnFailure notifier, the env repair). +claim_once() { # key base-cooldown → 0 = claimed (caller may speak), 1 = held + local key="$1" cd="$2" local sf="$MON/state/paged_$(_alert_key "$key")" - local now last - now=$(date +%s); last=$(cat "$sf" 2>/dev/null | tr -dc '0-9') - if [ -n "$last" ] && [ "$((now - last))" -lt "$cd" ]; then - logger -t watchdog "ALERT held for ${key}: paged $((now - last))s ago, cooldown ${cd}s" - return 0 + local now last count exp wait + now=$(date +%s); last=""; count=0 + if [ -f "$sf" ]; then + read -r last count < "$sf" 2>/dev/null || true + last=$(printf '%s' "$last" | tr -dc '0-9') + count=$(printf '%s' "${count:-}" | tr -dc '0-9'); count=${count:-0} + fi + if [ -n "$last" ]; then + exp=0; [ "$count" -gt 0 ] && exp=$((count - 1)); [ "$exp" -gt 3 ] && exp=3 + wait=$(( cd * 4 ** exp )); [ "$wait" -gt 86400 ] && wait=86400 + if [ "$((now - last))" -lt "$wait" ]; then + logger -t watchdog "ALERT held for ${key}: claimed $((now - last))s ago, next reminder after ${wait}s" + return 1 + fi fi mkdir -p "$MON/state" - printf '%s' "$now" > "$sf" - _alert_deliver "$emoji $text" + printf '%s %s' "$now" "$((count + 1))" > "$sf" + return 0 +} +alert_once() { # key cooldown emoji text + claim_once "$1" "$2" || return 0 + _alert_deliver "$3 $4" return 0 } alert_clear() { rm -f "$MON/state/paged_$(_alert_key "$1")"; return 0; } -alert_transition() { # key state emoji text - local key="$1" state="$2" emoji="$3" text="$4" - local sf="$MON/state/host_$(printf '%s' "$key" | tr -c 'a-zA-Z0-9' '_')" +alert_transition() { # key state emoji text [subject] + local key="$1" state="$2" emoji="$3" text="$4" subject="${5:-}" + local kk; kk=$(printf '%s' "$key" | tr -c 'a-zA-Z0-9' '_') + local sf="$MON/state/host_$kk" subf="$MON/state/subject_$kk" local prev="ok"; [ -f "$sf" ] && prev=$(cat "$sf") [ "$state" = "$prev" ] && return 0 printf '%s' "$state" > "$sf" # A transition IS the deliberate decision, so deliver it directly rather than # through alert()'s floor: a unit that fails, recovers and fails again inside # five minutes is genuinely three events, and the floor would eat the third. - if [ "$state" = "bad" ]; then _alert_deliver "$emoji $text"; else _alert_deliver "✅ RECOVERED: $key"; fi + # + # Recovery names the SUBJECT, never the key. `✅ RECOVERED: + # rtc_revampit_configured_host_does_not_resolve__typing_static_nvi` and + # `✅ RECOVERED: agentwork_reparaturbonus-zh` both reached George's phone on + # 2026-08-29 — closure messages nobody can parse, because this function used + # to print its own state-file key. The subject is remembered at bad-time + # (explicit 5th arg, else the text up to its first colon, else the key) so + # the recovery can say the same human name the failure did. + if [ "$state" = "bad" ]; then + if [ -z "$subject" ]; then + subject="${text%%:*}" + { [ -z "$subject" ] || [ "$subject" = "$text" ]; } && subject="$key" + fi + printf '%s' "$subject" | cut -c1-60 > "$subf" + _alert_deliver "$emoji $text" + else + local named=""; [ -f "$subf" ] && named=$(cat "$subf" 2>/dev/null) + rm -f "$subf" + _alert_deliver "✅ RECOVERED: ${named:-$key}" + fi # MUST return 0 unconditionally. A trailing `[ "$state" = "ok" ] && alert ...` # here returned 1 on the bad path, so a caller written as # check && alert_transition k bad ... || alert_transition k ok ... @@ -216,14 +256,21 @@ else fi fi -tail=$(journalctl -u "$unit" -n 4 --no-pager -o cat 2>/dev/null | tr '\n' ' ' | cut -c1-300) +# The page shows the APP's error, not systemd's liturgy. The old message +# repeated the unit name four times ("appcron-kivvi-dunning.service: Main +# process exited … Failed with result … Failed to start appcron-kivvi-dunning +# … Triggering OnFailure") and buried the one line that mattered — the app's +# own `curl: (22) … HTTP 500`. Filter the boilerplate, keep the evidence. +tail=$(journalctl -u "$unit" -n 12 --no-pager -o cat 2>/dev/null \ + | grep -vE 'Main process exited|Failed with result|Failed to start|Triggering OnFailure|Scheduled restart|Start request repeated|Deactivated successfully|Consumed .* CPU time|^(Starting|Started|Stopping|Stopped) ' \ + | tail -n 4 | tr '\n' ' ' | cut -c1-300) # A page-worthy failure is also dispatch-worthy: queue the remediation agent # BEFORE composing the page, so the page can say the fix is already in motion — # that one clause is the difference between "act now" and "read the outcome # when it arrives". incident-dispatch has its own per-unit stamp, so the # reminder re-page after COOLDOWN does not queue a second agent. disp=$("$MON/incident-dispatch.sh" "$unit" 2>/dev/null || true) -alert_once "$unit" "$COOLDOWN" "🔴" "UNIT DOWN: ${unit} — ${tail:-}${disp:+ → 🤖 fix agent dispatched (${disp}); outcome follows}" +alert_once "$unit" "$COOLDOWN" "🔴" "DOWN: ${unit%.service} — ${tail:-}${disp:+ → 🤖 fix agent dispatched (${disp}); outcome follows}" NF chmod +x "$MON/notify-failure.sh" @@ -440,30 +487,53 @@ UNIT_COOLDOWN=${NOTIFY_COOLDOWN_SEC:-1800} mapfile -t failed_units < <(systemctl list-units --type=service --state=failed --no-legend --plain 2>/dev/null \ | sed 's/^[^A-Za-z0-9]*//' | awk '{print $1}' | grep -E '\.service$' | grep -v '^notify-failure@') declare -A unit_now=() +announce=() for u in ${failed_units[@]+"${failed_units[@]}"}; do k="failed_$(printf '%s' "$u" | tr -c 'a-zA-Z0-9' '_')" unit_now[$k]=1 - # The state file records WHICH units are known-failed (its content is the unit - # name, so recovery can name it); alert_once decides whether anyone is told. + # ONE-TICK GRACE. A unit first seen failed is recorded and watched, not + # paged: the OnFailure notifier already pages real failures within seconds + # (with its own recovery guard), so the sweep's job is the PERSISTENT + # failure, and a unit that is gone by the next tick was a deploy blip. On + # 2026-08-29 11:19 an orangecat deploy failed three units for under five + # minutes and George got six messages (3 FAILED + 3 RECOVERED) about a + # non-event the notifier had already correctly declined to page. + if [ ! -e "$MON/state/host_$k" ]; then + printf '%s' "$u" > "$MON/state/host_$k" + logger -t watchdog "sweep: ${u} failed, first sighting — watching, not paging" + continue + fi + # The state file records WHICH units are known-failed (its content is the + # unit name, so recovery can name it); claim_once decides whether anyone is + # told — the same subject stamp the notifier uses, so whichever detector + # speaks first claims the incident, and reminders back off together. printf '%s' "$u" > "$MON/state/host_$k" - # Same dispatch as the OnFailure notifier, same shared `dispatch:` stamp — - # whichever detector notices first queues the ONE agent, the other finds the - # claim taken. See incident-dispatch.sh for why a page queues its own fix. - disp=$("$MON/incident-dispatch.sh" "$u" 2>/dev/null || true) - alert_once "$u" "$UNIT_COOLDOWN" "⚙️" "FAILED UNIT: $u${disp:+ → 🤖 fix agent dispatched (${disp}); outcome follows}" + if claim_once "$u" "$UNIT_COOLDOWN"; then + # Same dispatch as the OnFailure notifier, same shared `dispatch:` stamp — + # whichever detector notices first queues the ONE agent. + disp=$("$MON/incident-dispatch.sh" "$u" 2>/dev/null || true) + announce+=("${u%.service}${disp:+ (🤖 ${disp})}") + fi done +# N failures in one tick are ONE message, not N. The morning of 2026-08-29 +# reads as triples — 09:32, 10:02, 10:33, each three separate messages naming +# one unit apiece. A digest carries the same facts in a single glance. +if [ "${#announce[@]}" -gt 0 ]; then + _alert_deliver "⚙️ STILL FAILING: $(printf '%s; ' "${announce[@]}" | sed 's/; $//')" +fi # Anything that was failing and is not in the current set has recovered. Without # this the key would stay set and its next genuine failure would be silent — # the same latch, one level down. Report the recovery only if the failure was # actually announced: closure on a message nobody received is just noise, and # `✅ RECOVERED: unit____` is how that reads when the key is not a real name. +recovered=() for sf in "$MON"/state/host_failed_*; do [ -e "$sf" ] || continue k=$(basename "$sf"); k=${k#host_} [ -n "${unit_now[$k]:-}" ] && continue u=$(cat "$sf" 2>/dev/null) if [ -n "$u" ] && [ -e "$MON/state/paged_$(printf '%s' "$u" | tr -c 'a-zA-Z0-9' '_')" ]; then - _alert_deliver "✅ RECOVERED: $u" + recovered+=("${u%.service}") fi # Clear the dispatch stamp with the page stamp: a unit that recovers and # breaks again is a NEW incident and deserves a fresh agent, not the last @@ -471,6 +541,11 @@ for sf in "$MON"/state/host_failed_*; do [ -n "$u" ] && alert_clear "$u" && alert_clear "dispatch:$u" rm -f "$sf" done +# Same digest rule as the failures: closures that land on one tick are one +# message (10:58 on 2026-08-29 was three separate RECOVERED lines for one fix). +if [ "${#recovered[@]}" -gt 0 ]; then + _alert_deliver "✅ RECOVERED: $(printf '%s; ' "${recovered[@]}" | sed 's/; $//')" +fi # Retire the old aggregate latch, and the previous per-unit keys whose content # was a bare ok/bad and whose name could not be turned back into a unit. rm -f "$MON/state/host_units" "$MON"/state/host_unit_* diff --git a/scripts/hetzner/test-host-alerts.sh b/scripts/hetzner/test-host-alerts.sh index bbcb7012..e09af987 100755 --- a/scripts/hetzner/test-host-alerts.sh +++ b/scripts/hetzner/test-host-alerts.sh @@ -142,7 +142,9 @@ exec "$@" STUB cat > "$TMP/bin/journalctl" <<'STUB' #!/usr/bin/env bash -echo "stub journal line" +# %b expands \n escapes, so a test can stage a multi-line journal via +# JOURNAL_LINES and exercise the boilerplate filter on realistic output. +printf '%b\n' "${JOURNAL_LINES:-stub journal line}" STUB # The notifier waits 8s before deciding a unit is really down. Tests assert the # decision, not the wall clock — stub it out so the suite stays instant. @@ -213,29 +215,42 @@ check "86% third tick: still silent (got $n3)" "$([ "$n3" -eq 0 ] && echo 0 || e # alert to these counts — an earlier version of this test counted a disk # RECOVERED as a unit alert and "failed" on correct behaviour. run_units() { : > "$ALERT_LOG"; DISK_PCT=82 FAILED_UNITS="$1" bash "$TMP/host-check.sh" >/dev/null 2>&1 || true; } -unit_alerts() { grep -c 'FAILED UNIT\|RECOVERED: ' "$ALERT_LOG" 2>/dev/null | tr -d "[:space:]" || true; } +unit_alerts() { grep -c 'STILL FAILING\|RECOVERED: ' "$ALERT_LOG" 2>/dev/null | tr -d "[:space:]" || true; } rm -f "$TMP"/state/host_failed_* "$TMP/state/host_units" "$TMP"/state/paged_* +# One-tick grace: the sweep's first sighting watches, never pages — the +# OnFailure notifier owns the instant page, and a unit gone by the next tick +# was a deploy blip (the 2026-08-29 11:19 orangecat six-pack). run_units "a.service b.service" -check "units: first failures alert once per unit (got $(unit_alerts))" \ - "$([ "$(unit_alerts)" -eq 2 ] && echo 0 || echo 1)" +check "units: first sighting is silent — the sweep watches, not pages (got $(unit_alerts))" \ + "$([ "$(unit_alerts)" -eq 0 ] && grep -q 'first sighting' "$ALERT_LOG" && echo 0 || echo 1)" +# Persistent on the second tick: page — and BOTH units in ONE digest message, +# not one message per unit (09:32/10:02/10:33 each arrived as triples). run_units "a.service b.service" -check "units: identical set is silent — no storm (got $(unit_alerts))" \ +check "units: persistent failures page on the second tick (got $(unit_alerts))" \ + "$([ "$(unit_alerts)" -eq 1 ] && echo 0 || echo 1)" +check "units: N units in one tick are ONE digest naming both" \ + "$(grep -q 'STILL FAILING: .*a.*b' "$ALERT_LOG" && echo 0 || echo 1)" + +run_units "a.service b.service" +check "units: identical set inside the cooldown is silent — no storm (got $(unit_alerts))" \ "$([ "$(unit_alerts)" -eq 0 ] && echo 0 || echo 1)" -# THE regression. A stuck unit must not mask a new one. +# THE regression. A stuck unit must not mask a new one — c pages on ITS second +# sighting even though a and b are still failing and still muted. run_units "a.service b.service c.service" -check "units: a NEW failure alerts while old ones are still failing (got $(unit_alerts))" \ - "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'c.service' "$ALERT_LOG" && echo 0 || echo 1)" +run_units "a.service b.service c.service" +check "units: a NEW failure pages while old ones are still failing (got $(unit_alerts))" \ + "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'STILL FAILING: c' "$ALERT_LOG" && echo 0 || echo 1)" run_units "b.service c.service" -check "units: only the recovered unit reports RECOVERED, by NAME" \ - "$(grep -q 'RECOVERED: a.service' "$ALERT_LOG" && [ "$(unit_alerts)" -eq 1 ] && echo 0 || echo 1)" +check "units: only the recovered unit reports RECOVERED, by NAME (no .service)" \ + "$(grep -q 'RECOVERED: a$' "$ALERT_LOG" && [ "$(unit_alerts)" -eq 1 ] && echo 0 || echo 1)" run_units "" -check "units: the rest recover when the set empties (got $(unit_alerts))" \ - "$([ "$(unit_alerts)" -eq 2 ] && echo 0 || echo 1)" +check "units: the rest recover in ONE digest when the set empties (got $(unit_alerts))" \ + "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'RECOVERED: b; c' "$ALERT_LOG" && echo 0 || echo 1)" check "units: the old aggregate latch file is not recreated" \ "$([ ! -e "$TMP/state/host_units" ] && echo 0 || echo 1)" @@ -304,8 +319,9 @@ check "tight memory: no 'integer expected' from field-count drift" \ # above now emits the bullet, so this is a real regression test. rm -f "$TMP"/state/paged_z_service "$TMP"/state/host_failed_z_service run_units "z.service" +run_units "z.service" check "units: the unit NAME is alerted, not systemd's bullet" \ - "$(grep -q 'FAILED UNIT: z.service' "$ALERT_LOG" && ! grep -q 'FAILED UNIT: ●' "$ALERT_LOG" && echo 0 || echo 1)" + "$(grep -q 'STILL FAILING: z' "$ALERT_LOG" && ! grep -q 'STILL FAILING: ●' "$ALERT_LOG" && echo 0 || echo 1)" check "units: the state key is derived from the name, not the bullet" \ "$([ -e "$TMP/state/host_failed_z_service" ] && echo 0 || echo 1)" @@ -317,7 +333,7 @@ check "units: the state key is derived from the name, not the bullet" \ # help: it only silences a unit that comes back, and this one never did. These # cases pin the per-unit cooldown that fixes it. notify() { : > "$ALERT_LOG"; bash "$TMP/notify-failure.sh" "$1" >/dev/null 2>&1 || true; } -pages() { grep -c 'UNIT DOWN' "$ALERT_LOG" 2>/dev/null | tr -d "[:space:]" || true; } +pages() { grep -c '🔴 DOWN:' "$ALERT_LOG" 2>/dev/null | tr -d "[:space:]" || true; } stamp_of() { echo "$TMP/state/paged_$(printf '%s' "$1" | tr -c 'a-zA-Z0-9' '_')"; } rm -f "$TMP"/state/paged_* @@ -548,15 +564,18 @@ UNIT_TYPE=oneshot notify orangecat-cat-outcomes.service check "cross-detector: the notifier pages the failure (got $(pages))" \ "$([ "$(pages)" -eq 1 ] && echo 0 || echo 1)" run_units "orangecat-cat-outcomes.service" -check "cross-detector: the sweep then stays silent about the SAME unit (got $(unit_alerts))" \ +run_units "orangecat-cat-outcomes.service" +check "cross-detector: the sweep (past its grace) stays silent about the SAME unit (got $(unit_alerts))" \ "$([ "$(unit_alerts)" -eq 0 ] && echo 0 || echo 1)" check "cross-detector: the sweep's suppression is still journalled" \ "$(grep -q 'ALERT held for orangecat-cat-outcomes.service' "$ALERT_LOG" && echo 0 || echo 1)" # And the reverse order — whichever detector gets there first is the one that -# speaks; neither needs to know the other exists. +# speaks; neither needs to know the other exists. (First the sweep's grace +# tick, then its page.) rm -f "$TMP"/state/paged_* "$TMP"/state/host_failed_* "$TMP"/state/dedupe_* run_units "some-cron.service" +run_units "some-cron.service" check "cross-detector: the sweep pages when it is first (got $(unit_alerts))" \ "$([ "$(unit_alerts)" -eq 1 ] && echo 0 || echo 1)" UNIT_TYPE=oneshot notify some-cron.service @@ -565,28 +584,32 @@ check "cross-detector: the notifier then stays silent (got $(pages))" \ # A different unit is still a different incident — sharing the key must not # turn one outage into a fleet-wide gag. +run_units "some-cron.service another-cron.service" : > "$ALERT_LOG"; : > "$SEND_LOG" run_units "some-cron.service another-cron.service" check "cross-detector: a DIFFERENT unit still pages while the first is claimed" \ - "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'another-cron.service' "$ALERT_LOG" && echo 0 || echo 1)" + "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'STILL FAILING: another-cron' "$ALERT_LOG" && echo 0 || echo 1)" # ── 13. Closure only for failures that were actually announced ─────────────── # `✅ RECOVERED: unit____` reached George on 2026-08-28 — closure on a message # nobody ever received, naming a key instead of a unit. If nothing was said # about the failure, nothing needs saying about its recovery. rm -f "$TMP"/state/paged_* "$TMP"/state/host_failed_* "$TMP"/state/dedupe_* +run_units "quiet.service" # grace tick run_units "quiet.service" # pages, stamp claimed : > "$ALERT_LOG"; : > "$SEND_LOG" run_units "" # recovers check "recovery: an announced failure gets closure, named by unit (got $(unit_alerts))" \ - "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'RECOVERED: quiet.service' "$ALERT_LOG" && echo 0 || echo 1)" + "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'RECOVERED: quiet' "$ALERT_LOG" && echo 0 || echo 1)" +# A failure that never got past the grace tick was never announced — a deploy +# blip that recovers by the next tick produces ZERO messages, failure or +# closure. This is the whole point of the grace. rm -f "$TMP"/state/paged_* "$TMP"/state/host_failed_* "$TMP"/state/dedupe_* -run_units "silent.service" -rm -f "$TMP"/state/paged_silent_service # as if the page had been suppressed +run_units "silent.service" # first sighting only : > "$ALERT_LOG"; : > "$SEND_LOG" run_units "" -check "recovery: an UNannounced failure gets no closure either (got $(unit_alerts))" \ +check "recovery: a blip inside the grace gets no closure — zero messages total (got $(unit_alerts))" \ "$([ "$(unit_alerts)" -eq 0 ] && echo 0 || echo 1)" # ── 14. A page queues its own fix: incident dispatch ───────────────────────── @@ -674,5 +697,84 @@ FLEETCROWN_TOKEN_FILE="$TMP/does-not-exist.env" notify solon-app.service check "dispatch: a missing token file skips the queue but keeps the page (got $(pages))" \ "$([ "$(pages)" -eq 1 ] && [ "$(dispatches)" -eq 0 ] && echo 0 || echo 1)" +# ── 15. The page shows the APP's error, not systemd's liturgy ──────────────── +# The 2026-08-29 messages read "appcron-kivvi-dunning.service: Main process +# exited … Failed with result … Failed to start appcron-kivvi-dunning … +# Triggering OnFailure" — the unit name four times, the actual error (curl's +# HTTP 500) pushed out of the 300-char window or drowned. Filter the +# boilerplate; the evidence is the message. +reset_dispatch +JOURNAL_LINES='curl: (22) The requested URL returned error: 500\nappcron kivvi GET /api/cron/dunning: HTTP 500\nMain process exited, code=exited, status=22/n/a\nFailed with result exit-code.\nFailed to start appcron-kivvi-dunning.service.\nTriggering OnFailure= dependencies.' \ + UNIT_TYPE=oneshot notify appcron-kivvi-dunning.service +check "page: carries the app's own error line" \ + "$(grep -q 'curl: (22)' "$ALERT_LOG" && echo 0 || echo 1)" +check "page: systemd boilerplate is filtered out" \ + "$(! grep -q 'Triggering OnFailure' "$SEND_LOG" && ! grep -q 'Main process exited' "$SEND_LOG" && echo 0 || echo 1)" +check "page: says DOWN: with the unit named once, without .service" \ + "$(grep -q '🔴 DOWN: appcron-kivvi-dunning —' "$ALERT_LOG" && echo 0 || echo 1)" + +# ── 16. Recovery names the SUBJECT, never the state key ────────────────────── +# `✅ RECOVERED: rtc_revampit_configured_host_does_not_resolve__typing_static_nvi` +# and `✅ RECOVERED: agentwork_reparaturbonus-zh` both reached the phone on +# 2026-08-29 — closure messages nobody can parse. alert_transition remembers +# the human subject at bad-time and uses it at recovery. +reset_logs +lib alert_transition rtc_revampit_configured_host_does_not_resolve__typing_x bad "🧩" "revampit: configured host does not resolve: typing-static-nvidia-bra.trycloudflare.com" +lib alert_transition rtc_revampit_configured_host_does_not_resolve__typing_x ok "" "" +check "transition: recovery names the subject derived from the failure text" \ + "$(grep -q '✅ RECOVERED: revampit$' "$SEND_LOG" && echo 0 || echo 1)" +check "transition: the raw state key never reaches the phone" \ + "$(! grep -q 'rtc_revampit' "$SEND_LOG" && echo 0 || echo 1)" + +# An explicit subject wins over derivation. +reset_logs +lib alert_transition agentwork_repz bad "🚫" "uncommitted changes older than 48h in reparaturbonus-zh" "reparaturbonus-zh" +lib alert_transition agentwork_repz ok "" "" +check "transition: an explicit subject is used verbatim on recovery" \ + "$(grep -q '✅ RECOVERED: reparaturbonus-zh$' "$SEND_LOG" && echo 0 || echo 1)" + +# No colon, no subject → fall back to the key (never the whole failure text). +reset_logs +lib alert_transition disk bad "💾" "DISK 86% on / (>85%)" +lib alert_transition disk ok "" "" +check "transition: colon-less text falls back to the key on recovery" \ + "$(grep -q '✅ RECOVERED: disk$' "$SEND_LOG" && echo 0 || echo 1)" + +# ── 17. Reminders back off: 30m, 2h, 8h — never every half hour all day ────── +# The stamp holds "ts count"; each claim quadruples the next wait. The morning +# of 2026-08-29: identical FAILED messages at 08:01, 08:31, 09:01, 09:32, +# 10:02, 10:33 — six reminders in 2.5h about a fact the first one carried. +reset_logs +now=$(date +%s) +# Claimed once (count=1), base cooldown elapsed → the FIRST reminder goes out. +printf '%s %s' "$((now - 2000))" 1 > "$TMP/state/paged_bk" +lib alert_once bk 1800 "🔴" "backoff probe" +check "backoff: first reminder after the base cooldown (got $(sent))" \ + "$([ "$(sent)" -eq 1 ] && echo 0 || echo 1)" +# Claimed twice (count=2) → the next wait is 4× base; the same age is now held. +reset_logs +printf '%s %s' "$((now - 2000))" 2 > "$TMP/state/paged_bk" +lib alert_once bk 1800 "🔴" "backoff probe" +check "backoff: after two claims the same age is held — wait is 4x (got $(sent))" \ + "$([ "$(sent)" -eq 0 ] && grep -q 'ALERT held for bk' "$ALERT_LOG" && echo 0 || echo 1)" +# …but a 3h age clears the 2h bar. +reset_logs +printf '%s %s' "$((now - 10800))" 2 > "$TMP/state/paged_bk" +lib alert_once bk 1800 "🔴" "backoff probe" +check "backoff: the 4x reminder still arrives once its wait elapses (got $(sent))" \ + "$([ "$(sent)" -eq 1 ] && echo 0 || echo 1)" +# The ladder is capped: even a huge count waits at most a day. +reset_logs +printf '%s %s' "$((now - 90000))" 99 > "$TMP/state/paged_bk" +lib alert_once bk 1800 "🔴" "backoff probe" +check "backoff: the ladder caps at one day — a broken thing is never silent forever (got $(sent))" \ + "$([ "$(sent)" -eq 1 ] && echo 0 || echo 1)" +# alert_clear resets the ladder: after recovery the next outage pages at once. +reset_logs +lib alert_clear bk +lib alert_once bk 1800 "🔴" "fresh outage" +check "backoff: recovery resets the ladder — a fresh outage pages immediately (got $(sent))" \ + "$([ "$(sent)" -eq 1 ] && echo 0 || echo 1)" + printf '\n %d passed, %d failed\n' "$pass" "$fail" [ "$fail" -eq 0 ]