diff --git a/scripts/hetzner/install-disk-gc.sh b/scripts/hetzner/install-disk-gc.sh index 9cdcb3f8..e75a3a59 100644 --- a/scripts/hetzner/install-disk-gc.sh +++ b/scripts/hetzner/install-disk-gc.sh @@ -31,7 +31,8 @@ # β€” ~/.cache/ms-playwright is the prod-dogfood browser set, and silently # deleting it would break the smoke suite with no signal. Reclaim it by hand. # -# Reports what it freed through the watchdog's Telegram channel (lib-alert.sh), +# Journals what it freed and pages only when the outcome is NOT routine +# (still above the warn mark, or nothing left to reclaim) β€” lib-alert.sh, # and only when it actually did something β€” no "ran and did nothing" noise. # # Idempotent: re-run any time. Logic is covered by @@ -238,7 +239,19 @@ fi end_pct=$(pct); end_used=$(usedk) total=$(( (start_used - end_used) / 1024 )) if [ "$total" -gt 0 ]; then - alert "🧹" "DISK GC: freed ${total}MB (${start_pct}% β†’ ${end_pct}%) β€” ${FREED_LOG:-n/a}" + # Routine maintenance SUCCEEDING is not news. This fired at 00:02 on + # 2026-08-29 β€” "freed 2296MB (81% β†’ 78%)" β€” a correct report of the box + # looking after itself, requiring nothing from anyone. The disk check already + # pages above 85%, so a GC that lands back under the mark has, by definition, + # removed the reason to say anything. It goes to the journal. + # + # It still PAGES when the outcome is not routine: space was reclaimed and the + # disk is STILL above the warn mark, which is the trend that ends in a full + # volume and is genuinely worth a human's attention. + logger -t disk-gc "DISK GC: freed ${total}MB (${start_pct}% β†’ ${end_pct}%) β€” ${FREED_LOG:-n/a}" + if [ "${end_pct:-0}" -gt 85 ]; then + alert "🧹" "DISK GC: freed ${total}MB but / is still ${end_pct}% β€” reclaiming is no longer keeping up. ${FREED_LOG:-n/a}" + fi else # Above the mark but nothing safe left to reclaim: that is a real capacity # problem and the operator needs to know it, not a silent no-op. diff --git a/scripts/hetzner/install-host-alerts.sh b/scripts/hetzner/install-host-alerts.sh index 787be951..7ba65db7 100755 --- a/scripts/hetzner/install-host-alerts.sh +++ b/scripts/hetzner/install-host-alerts.sh @@ -293,24 +293,52 @@ fi # UNIT: ●") β€” which is how this shipped once already. The sed is belt and # braces for systemd builds that ignore --plain. The old aggregate code got # away with the bullet because it only tested the string for emptiness. +# +# ONE INCIDENT IS ONE MESSAGE ACROSS DETECTORS, not just within one. +# +# This sweep and the OnFailure notifier are two independent detectors of the +# same fact, and on 2026-08-29 they both reported it: `βš™οΈ FAILED UNIT: +# orangecat-cat-outcomes.service` at 06:45 from here, `πŸ”΄ UNIT DOWN: +# orangecat-cat-outcomes.service` at 06:46 from notify-failure once its grace +# window expired. Each was individually correct and correctly deduplicated +# against itself β€” which is exactly why the duplicate survived a fix aimed at +# per-detector storms. Keying per detector still lets N detectors send N +# messages. +# +# So the cooldown key is the SUBJECT (the unit), shared with notify-failure: +# whichever detector notices first speaks, the other finds the claim already +# taken and goes to the journal. Neither has to know the other exists. +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=() for u in ${failed_units[@]+"${failed_units[@]}"}; do - k="unit_$(printf '%s' "$u" | tr -c 'a-zA-Z0-9' '_')" + k="failed_$(printf '%s' "$u" | tr -c 'a-zA-Z0-9' '_')" unit_now[$k]=1 - alert_transition "$k" bad "βš™οΈ" "FAILED UNIT: $u" + # 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. + printf '%s' "$u" > "$MON/state/host_$k" + alert_once "$u" "$UNIT_COOLDOWN" "βš™οΈ" "FAILED UNIT: $u" done # Anything that was failing and is not in the current set has recovered. Without -# this the key would stay `bad` and its next genuine failure would be silent β€” -# the same latch, one level down. -for sf in "$MON"/state/host_unit_*; do +# 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. +for sf in "$MON"/state/host_failed_*; do [ -e "$sf" ] || continue k=$(basename "$sf"); k=${k#host_} - [ -n "${unit_now[$k]:-}" ] || alert_transition "$k" ok "" "" + [ -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" + fi + [ -n "$u" ] && alert_clear "$u" + rm -f "$sf" done -# Retire the old aggregate latch so it cannot linger at `bad` forever. -rm -f "$MON/state/host_units" +# 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_* # App .env readability β€” repair it, don't report it. # diff --git a/scripts/hetzner/test-disk-gc.sh b/scripts/hetzner/test-disk-gc.sh index 611c95fd..8c245856 100755 --- a/scripts/hetzner/test-disk-gc.sh +++ b/scripts/hetzner/test-disk-gc.sh @@ -58,6 +58,19 @@ done chmod +x "$TMP/bin"/* export PATH="$TMP/bin:$PATH" export MON="$TMP" +# logger records the JOURNAL; curl records what reaches the PHONE. Without the +# second stub, moving a message from alert() to logger() looks identical to +# leaving it alone β€” which is how a routine nightly report could go on being +# "tested" while still ringing a phone every midnight. +cat > "$TMP/bin/curl" <<'STUB' +#!/usr/bin/env bash +for a in "$@"; do case "$a" in text=*) printf '%s\n' "${a#text=}" >> "$SEND_LOG";; esac; done +exit 0 +STUB +chmod +x "$TMP/bin/curl" +printf 'TELEGRAM_BOT_TOKEN=test-token\nTELEGRAM_CHAT_ID=test-chat\n' > "$TMP/telegram.env" +export SEND_LOG="$TMP/sent.log" +: > "$SEND_LOG" export ALERT_LOG="$TMP/alerts.log" pass=0 fail=0 @@ -67,7 +80,7 @@ check() { if [ "$2" -eq 0 ]; then pass=$((pass+1)); printf ' βœ“ %s\n' "$1" # Build a fresh fake filesystem for each scenario. seed() { rm -rf "$FAKE_FS"; mkdir -p "$FAKE_FS/dev" "$FAKE_FS/opt" - : > "$ALERT_LOG"; rm -f "$TMP/state/host_diskgc" + : > "$ALERT_LOG"; : > "$SEND_LOG"; rm -f "$TMP/state/host_diskgc" local old_ts="202601010000" # long past β†’ cold # Two cold repos and one worked-on-today repo, each with a 20MB node_modules. for r in coldrepo olderrepo; do @@ -123,8 +136,13 @@ check "releases beyond keep-count removed" \ "$([ ! -d "$FAKE_FS/opt/someapp/releases/rel-1" ] && echo 0 || echo 1)" check "newest 2 releases kept" \ "$([ -d "$FAKE_FS/opt/someapp/releases/rel-4" ] && [ -d "$FAKE_FS/opt/someapp/releases/rel-3" ] && echo 0 || echo 1)" -check "reports what it freed" \ +check "reports what it freed β€” to the journal" \ "$(grep -q 'DISK GC: freed' "$ALERT_LOG" && echo 0 || echo 1)" +# A successful nightly GC that leaves the disk healthy asks nothing of anyone. +# It fired at 00:02 on 2026-08-29 ("freed 2296MB, 81% β†’ 78%") purely to say the +# box had looked after itself. Journal yes, phone no. +check "a routine successful GC does not reach the phone" \ + "$([ ! -s "$SEND_LOG" ] && echo 0 || echo 1)" # ── 3. Stops at the cheapest tier that suffices (does not over-delete) ────── # Usage is 50%, target 45%. Dropping two 10MB releases gets there, so the GC @@ -144,10 +162,15 @@ check "cheap tier actually ran: releases trimmed to 2 (got $rels)" \ # No dev root, no releases β†’ every tier is a no-op, but the disk is still full. rm -rf "$FAKE_FS"; mkdir -p "$FAKE_FS/dev" "$FAKE_FS/opt" truncate -s 180M "$FAKE_FS/ballast" -: > "$ALERT_LOG"; rm -f "$TMP/state/host_diskgc" +: > "$ALERT_LOG"; : > "$SEND_LOG"; rm -f "$TMP/state/host_diskgc" gc DISK_GC_HIGH_PCT=75 DISK_GC_TARGET_PCT=65 check "exhausted tiers while still full: escalates, not silent" \ "$(grep -q 'could not free space' "$ALERT_LOG" && echo 0 || echo 1)" +# The half that must survive quietening the routine case: an outcome the +# operator has to act on still reaches them. Silencing everything would be the +# worse bug of the two. +check "…and that one DOES reach the phone" \ + "$(grep -q 'could not free space' "$SEND_LOG" && echo 0 || echo 1)" # ── 5. safe_rm refuses to delete outside the root it was given ─────────────── mkdir -p "$TMP/outside/precious" diff --git a/scripts/hetzner/test-host-alerts.sh b/scripts/hetzner/test-host-alerts.sh index 80889ab4..34d7705d 100755 --- a/scripts/hetzner/test-host-alerts.sh +++ b/scripts/hetzner/test-host-alerts.sh @@ -186,8 +186,8 @@ 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: unit_' "$ALERT_LOG" 2>/dev/null | tr -d "[:space:]" || true; } -rm -f "$TMP"/state/host_unit_* "$TMP/state/host_units" +unit_alerts() { grep -c 'FAILED UNIT\|RECOVERED: ' "$ALERT_LOG" 2>/dev/null | tr -d "[:space:]" || true; } +rm -f "$TMP"/state/host_failed_* "$TMP/state/host_units" "$TMP"/state/paged_* run_units "a.service b.service" check "units: first failures alert once per unit (got $(unit_alerts))" \ @@ -203,8 +203,8 @@ check "units: a NEW failure alerts while old ones are still failing (got $(unit_ "$([ "$(unit_alerts)" -eq 1 ] && grep -q 'c.service' "$ALERT_LOG" && echo 0 || echo 1)" run_units "b.service c.service" -check "units: only the recovered unit reports RECOVERED" \ - "$(grep -q 'RECOVERED: unit_a_service' "$ALERT_LOG" && [ "$(unit_alerts)" -eq 1 ] && echo 0 || echo 1)" +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)" run_units "" check "units: the rest recover when the set empties (got $(unit_alerts))" \ @@ -275,11 +275,12 @@ check "tight memory: no 'integer expected' from field-count drift" \ # ── the bullet: systemd prefixes a failed unit with "●" without --plain ------- # Shipped once as `FAILED UNIT: ●`, one shared key for every failure. The stub # 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" 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)" check "units: the state key is derived from the name, not the bullet" \ - "$([ -e "$TMP/state/host_unit_z_service" ] && echo 0 || echo 1)" + "$([ -e "$TMP/state/host_failed_z_service" ] && echo 0 || echo 1)" # ── 6. OnFailure notifier: one incident is ONE page, not one per restart ────── # On 2026-08-28 vitareba-app could not read its .env (root-owned after a @@ -465,7 +466,7 @@ env_run() { # run host-check with only the env check able to say anything printf '%s' ok > "$TMP/state/host_mem"; printf '%s' ok > "$TMP/state/host_disk" # Likewise the failed-unit keys: section 1b leaves z.service at `bad`, and an # empty FAILED_UNITS here would emit its RECOVERED into this section's count. - rm -f "$TMP"/state/host_unit_* + rm -f "$TMP"/state/host_failed_* APPROOT="$TMP/opt" APP_UNITS="demo-app.service" UNIT_USER="$(id -un)" \ DISK_PCT=82 bash "$TMP/host-check.sh" >/dev/null 2>&1 || true } @@ -496,7 +497,7 @@ check "env: a fresh recurrence is reported again, not muted by the last repair" chmod 000 "$TMP/opt/demo/shared/.env" : > "$ALERT_LOG"; : > "$SEND_LOG"; : > "$CHOWN_LOG" printf '%s' ok > "$TMP/state/host_mem"; printf '%s' ok > "$TMP/state/host_disk" -rm -f "$TMP"/state/host_unit_* +rm -f "$TMP"/state/host_failed_* rm -f "$TMP"/state/paged_envfix_demo "$TMP"/state/paged_envbad_demo CHOWN_FAIL=1 APPROOT="$TMP/opt" APP_UNITS="demo-app.service" UNIT_USER="$(id -un)" \ DISK_PCT=82 bash "$TMP/host-check.sh" >/dev/null 2>&1 || true @@ -504,5 +505,62 @@ check "env: an unrepairable .env asks, and carries the exact fix command" \ "$([ "$(sent)" -eq 1 ] && grep -q 'chown .* && systemctl restart demo-app.service' "$SEND_LOG" && echo 0 || echo 1)" chmod 600 "$TMP/opt/demo/shared/.env" +# ── 12. Two detectors, one incident, ONE message ───────────────────────────── +# 2026-08-29 06:45 `βš™οΈ FAILED UNIT: orangecat-cat-outcomes.service` from the +# sweep; 06:46 `πŸ”΄ UNIT DOWN: orangecat-cat-outcomes.service` from the OnFailure +# notifier once its grace expired. Both were correct, and both were correctly +# deduplicated *against themselves* β€” which is precisely why this duplicate +# survived a fix aimed at per-detector storms. Keying per detector lets N +# detectors send N messages for one fact. The key is the SUBJECT. +rm -f "$TMP"/state/paged_* "$TMP"/state/host_failed_* "$TMP"/state/dedupe_* +: > "$ALERT_LOG"; : > "$SEND_LOG" + +# The notifier speaks first (this is the real order: OnFailure fires at once, +# the sweep runs on its 5-minute tick). +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))" \ + "$([ "$(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. +rm -f "$TMP"/state/paged_* "$TMP"/state/host_failed_* "$TMP"/state/dedupe_* +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 +check "cross-detector: the notifier then stays silent (got $(pages))" \ + "$([ "$(pages)" -eq 0 ] && echo 0 || echo 1)" + +# A different unit is still a different incident β€” sharing the key must not +# turn one outage into a fleet-wide gag. +: > "$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)" + +# ── 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" # 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)" + +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 +: > "$ALERT_LOG"; : > "$SEND_LOG" +run_units "" +check "recovery: an UNannounced failure gets no closure either (got $(unit_alerts))" \ + "$([ "$(unit_alerts)" -eq 0 ] && echo 0 || echo 1)" + printf '\n %d passed, %d failed\n' "$pass" "$fail" [ "$fail" -eq 0 ]