From 3a348a550c067c341ba5a4ab81a1ef348300e1a6 Mon Sep 17 00:00:00 2001 From: Krzysztof kuhy Rudnicki Date: Mon, 31 Aug 2026 14:27:03 +0200 Subject: [PATCH] fix: the watchdog stops burying the desktop in popups nobody asked for Three defects, and the loudest one was self-inflicted. test_watchdog.sh stubbed only curl and docker, so notify-send resolved to the real binary and the suite fired a dozen genuine critical popups every run -- from a pre-commit hook. On 2026-08-31 the timer emitted zero messages and the desktop still collected 297, all of them from committing. The stubs now live in the harness, and the suite asserts the counts. give_up() had no once-only flag, so a six-hour window announced itself every two minutes -- up to 180 times -- while its own text said "no further restarts". A stamp in the state dir now gates the popup, and only the popup: journald still gets every line, which is why the existing stdout assertions are untouched. alarm() hardcoded --urgency=critical, which xfce4-notifyd never expires, and passed no replace id, so they stacked instead of superseding. notify-send --print-id now feeds --replace-id from one slot. WATCHDOG_NOTIFY picks how much reaches the desktop at all; it defaults to escalation, so the routine restart/recovery pair is journald-only from here. test_watchdog.sh crossed the 250-line cap, so the sandbox and the assertions moved to test_watchdog_harness.sh, and the hook that runs the suite now watches all three files. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01416TegJ3sa8xL5qGGgrygP --- .env.sample | 33 ++++++++++ .pre-commit-config.yaml | 5 +- DOCS-liveness-and-trust.md | 27 ++++++++ scripts/signal_api_watchdog.sh | 70 ++++++++++++++++++-- scripts/test_watchdog.sh | 94 +++++++++------------------ scripts/test_watchdog_harness.sh | 106 +++++++++++++++++++++++++++++++ 6 files changed, 265 insertions(+), 70 deletions(-) create mode 100644 scripts/test_watchdog_harness.sh diff --git a/.env.sample b/.env.sample index 9088c97..3729ca7 100644 --- a/.env.sample +++ b/.env.sample @@ -87,3 +87,36 @@ PHOTO_PACK_DIR= # servers grab, and below the ephemeral range so the kernel cannot take it. BIND_HOST= BIND_PORT= + +# --------------------------------------------------------------------------- +# scripts/signal_api_watchdog.sh -- the two-minute timer that restarts the +# container when signal-cli can no longer reach Signal. Every value here is +# optional; the defaults are what the timer has always used. +# --------------------------------------------------------------------------- + +# What reaches the DESKTOP. journald gets every message either way, twice -- +# `journalctl --user -t signal-api-watchdog` and `-u signal-api-watchdog`. +# escalation only the give-up message pops, and only once per window +# always every transition pops, reusing one replaceable slot +# never nothing pops +# Default: escalation. The routine restart/recovery pair is the noise this +# exists to stop -- it used to pop on every firing, with critical urgency and +# no replace id, so one outage left a screen of boxes to dismiss by hand. +WATCHDOG_NOTIFY= + +# How long a popup stays up, in milliseconds. Default: 20000. +WATCHDOG_NOTIFY_EXPIRE_MS= + +# Consecutive failed probes before the container is restarted. Default: 2. +FAILURES_BEFORE_RESTART= + +# Restarts allowed inside RESTART_WINDOW before it gives up and escalates +# instead. A deregistered account is not fixable by restarting, and a +# forever-loop would hide that. Defaults: 3 restarts, 21600 seconds (6h). +MAX_RESTARTS= +RESTART_WINDOW= + +# Seconds to wait after a restart before deciding whether it helped, and the +# per-probe curl timeout. Defaults: 45 and 15. +SETTLE_SECONDS= +PROBE_TIMEOUT= diff --git a/.pre-commit-config.yaml b/.pre-commit-config.yaml index 54fd9fb..9eea3b5 100644 --- a/.pre-commit-config.yaml +++ b/.pre-commit-config.yaml @@ -130,13 +130,14 @@ repos: types: [shell] # The watchdog is bash, so pytest cannot reach it. Its own suite stubs - # curl and docker and drives every branch, including the give-up cap. + # curl, docker, notify-send and logger, and drives every branch -- + # including the give-up cap and how many popups a whole window produces. - id: watchdog-tests name: watchdog behaviour (bash) entry: scripts/test_watchdog.sh language: system pass_filenames: false - files: ^scripts/(signal_api_watchdog|test_watchdog)\.sh$ + files: ^scripts/(signal_api_watchdog|test_watchdog|test_watchdog_harness)\.sh$ # 100% branch coverage, no omits. Runs on every commit: coverage is the # whole point of the suite, and a partial run cannot prove it. diff --git a/DOCS-liveness-and-trust.md b/DOCS-liveness-and-trust.md index 5e2b025..afd9533 100644 --- a/DOCS-liveness-and-trust.md +++ b/DOCS-liveness-and-trust.md @@ -29,6 +29,33 @@ Two things now make that impossible to miss: and a forever-restart loop would hide it. `scripts/install_service.sh` installs and arms it beside the bot's own unit. +## What reaches the desktop + +Every watchdog message goes to journald twice — once via +`logger --tag signal-api-watchdog`, once as the unit's own stdout — and the +desktop popup is a *summary* of that, never the record. `WATCHDOG_NOTIFY` +decides how much of it pops: `escalation` (the default, give-up only), +`always`, or `never`. + +It is a summary because it was once a flood. Three things made it one: + +- The popups fired per **check**, not per state change, and `give_up()` had no + once-only flag — so a six-hour give-up window announced itself every two + minutes, up to 180 times, while its own text said "no further restarts". +- `alarm()` hardcoded `--urgency=critical`, which `xfce4-notifyd` never + expires, and passed no replace id, so they stacked instead of superseding. + `notify-send --print-id` now feeds `--replace-id` from + `${STATE_DIR}/notify_id`: one slot, reused. +- Worst of all, none of it needed an outage. `scripts/test_watchdog.sh` stubbed + only `curl` and `docker`, so `notify-send` was the real binary and the suite + fired a dozen genuine critical popups per run — from a pre-commit hook. On + 2026-08-31 the timer emitted **zero** messages and the desktop still + collected 297, every one of them self-inflicted by committing. + +The stubs now live in the harness, and the suite asserts the counts rather than +the absence: a healthy check pops nothing, a routine restart-and-recovery pops +nothing, and a sustained give-up window pops exactly once. + ```bash systemctl --user list-timers signal-api-watchdog.timer journalctl --user -u signal-api-watchdog.service -n 20 diff --git a/scripts/signal_api_watchdog.sh b/scripts/signal_api_watchdog.sh index b302cb8..0775e8d 100755 --- a/scripts/signal_api_watchdog.sh +++ b/scripts/signal_api_watchdog.sh @@ -28,9 +28,16 @@ readonly FAILURES_BEFORE_RESTART="${FAILURES_BEFORE_RESTART:-2}" readonly MAX_RESTARTS="${MAX_RESTARTS:-3}" readonly RESTART_WINDOW="${RESTART_WINDOW:-21600}" # 6 hours readonly SETTLE_SECONDS="${SETTLE_SECONDS:-45}" +# always: every transition pops. escalation: only the give-up does. never: none. +# Default escalation, because the routine restart/recovery pair is exactly the +# noise this knob exists to stop; journald still gets all of it either way. +readonly NOTIFY_MODE="${WATCHDOG_NOTIFY:-escalation}" +readonly NOTIFY_EXPIRE_MS="${WATCHDOG_NOTIFY_EXPIRE_MS:-20000}" readonly FAILURE_FILE="${STATE_DIR}/consecutive_failures" readonly RESTART_FILE="${STATE_DIR}/restarts" +readonly NOTIFY_ID_FILE="${STATE_DIR}/notify_id" +readonly ESCALATED_FILE="${STATE_DIR}/escalated_at" usage() { echo "Usage: $SCRIPT_NAME" @@ -45,12 +52,59 @@ die() { exit 1 } -# journald and the desktop, always both: the broken path IS Signal, so the -# bot cannot tell anybody about this itself. +# The escalation repeats on every firing for as long as the window lasts. The +# journal wants all of it; the desktop wants one box. So the stamp gates the +# POPUP only -- never the log lines, which is why the give-up text still +# appears on stdout for every check that reaches it. +escalation_is_new() { + local now stamp=0 + now="$(date +%s)" + if [[ -f "$ESCALATED_FILE" ]]; then + read -r stamp <"$ESCALATED_FILE" || true + [[ "$stamp" =~ ^[0-9]+$ ]] || stamp=0 + fi + if ((now - stamp < RESTART_WINDOW)); then + return 1 + fi + printf '%s\n' "$now" >"$ESCALATED_FILE" +} + +# One desktop slot, reused. Without --replace-id every firing stacked another +# popup that xfce4-notifyd never expires, so a single outage left a screenful +# of identical boxes to dismiss by hand -- 297 of them in one day. +notify() { + local urgency="$1" message="$2" previous=0 id + case "$NOTIFY_MODE" in + never) return 0 ;; + escalation) + if [[ "$urgency" != critical ]]; then + return 0 + fi + ;; + *) ;; + esac + if [[ "$urgency" == critical ]] && ! escalation_is_new; then + return 0 + fi + if [[ -f "$NOTIFY_ID_FILE" ]]; then + read -r previous <"$NOTIFY_ID_FILE" || true + [[ "$previous" =~ ^[0-9]+$ ]] || previous=0 + fi + id="$(notify-send --print-id --replace-id="$previous" --urgency="$urgency" \ + --expire-time="$NOTIFY_EXPIRE_MS" --app-name=signal-bot \ + "signal-bot" "$message" 2>/dev/null)" || return 0 + if [[ "$id" =~ ^[0-9]+$ ]]; then + printf '%s\n' "$id" >"$NOTIFY_ID_FILE" + fi +} + +# journald and stdout always; the desktop only when notify() agrees. The broken +# path IS Signal, so the bot cannot tell anybody about this itself -- but it +# only needs to say it once. alarm() { logger --priority user.warning --tag signal-api-watchdog -- "$1" || true echo "== $1" - notify-send --urgency=critical --app-name=signal-bot "signal-bot" "$1" 2>/dev/null || true + notify "${2:-normal}" "$1" } validate_requirements() { @@ -89,10 +143,17 @@ connection_is_alive() { return 1 } +# Recovery re-arms the escalation: the next outage is a new event and deserves +# its own box, rather than being silenced by a stamp from the previous one. +clear_alarms() { + rm -f "$ESCALATED_FILE" +} + record_success() { local previous previous="$(read_count)" printf '0\n' >"$FAILURE_FILE" + clear_alarms if ((previous >= FAILURES_BEFORE_RESTART)); then alarm "signal-api is reachable again after ${previous} failed probe(s)." fi @@ -125,7 +186,7 @@ give_up() { This is probably not transient: the account may be deregistered, or the host \ firewall may be blocking the container. Check 'docker exec ${CONTAINER} head -5 \ /var/log/signal-cli-json-rpc-1/out.log' and 'docker exec ${CONTAINER} getent hosts \ -chat.signal.org'. No further restarts until the window passes." +chat.signal.org'. No further restarts until the window passes." critical } restart_container() { @@ -135,6 +196,7 @@ restart_container() { sleep "$SETTLE_SECONDS" if connection_is_alive; then printf '0\n' >"$FAILURE_FILE" + clear_alarms alarm "signal-api is back: the connection to Signal is alive again." return 0 fi diff --git a/scripts/test_watchdog.sh b/scripts/test_watchdog.sh index afca9f3..122e6b1 100755 --- a/scripts/test_watchdog.sh +++ b/scripts/test_watchdog.sh @@ -33,70 +33,8 @@ ok() { echo " ok: $1" } -# Rebuild a pristine sandbox: stub binaries, stub answers, empty state. -setup() { - rm -rf "$WORK" - mkdir -p "$WORK/bin" "$WORK/state" - printf '200' >"$WORK/bot_code" - printf '200' >"$WORK/api_code" - printf '0' >"$WORK/fix_on_restart" - - cat >"$WORK/bin/curl" <"$WORK/bin/docker" <> "$WORK/docker.log" -if [[ "\$(cat "$WORK/fix_on_restart")" == "1" ]]; then - printf '200' > "$WORK/bot_code" - printf '200' > "$WORK/api_code" -fi -EOF - chmod +x "$WORK/bin/curl" "$WORK/bin/docker" -} - -run_watchdog() { - PATH="$WORK/bin:$PATH" \ - PHONE_NUMBER="+15550000000" \ - STATE_DIRECTORY="$WORK/state" \ - SETTLE_SECONDS=0 \ - FAILURES_BEFORE_RESTART=2 \ - MAX_RESTARTS=2 \ - RESTART_WINDOW=3600 \ - "$WATCHDOG" 2>&1 -} - -expect_contains() { - if [[ "$1" == *"$2"* ]]; then - ok "$3" - else - fail "$3 -- got: $1" - fi -} - -expect_missing() { - if [[ "$1" != *"$2"* ]]; then - ok "$3" - else - fail "$3 -- unexpectedly found $2" - fi -} - -expect_file() { - local actual - actual="$(cat "$1" 2>/dev/null || echo MISSING)" - if [[ "$actual" == "$2" ]]; then - ok "$3" - else - fail "$3 -- $1 is '$actual', expected '$2'" - fi -} +# shellcheck source=scripts/test_watchdog_harness.sh +source "${REPO_ROOT}/scripts/test_watchdog_harness.sh" test_healthy_is_free() { echo "== a healthy bot needs no restart and no authenticated probe" @@ -108,6 +46,7 @@ test_healthy_is_free() { else ok "docker was never called" fi + expect_notifications 0 "a healthy check pops nothing" } test_one_failure_waits() { @@ -138,6 +77,7 @@ test_confirmed_failure_restarts_and_recovers() { expect_contains "$(cat "$WORK/docker.log")" "restart signal-api" "the container was restarted" expect_contains "$out" "is back" "the recovery is announced" expect_file "$WORK/state/consecutive_failures" "0" "the counter was cleared" + expect_notifications 0 "the routine restart/recovery pair stays out of the desktop" } test_restart_that_does_not_help() { @@ -170,6 +110,31 @@ test_gives_up_instead_of_looping() { fi expect_contains "$out" "still deaf" "the give-up message explains what to check" expect_contains "$out" "out.log" "the give-up message names the log to read" + # Three firings reach give_up here; the journal got all three (asserted + # above, on the LAST run's stdout) and the desktop got one. + expect_notifications 1 "a sustained give-up window pops exactly once" +} + +test_notify_modes() { + echo "== WATCHDOG_NOTIFY decides what reaches the desktop" + setup + printf '400' >"$WORK/bot_code" + printf '400' >"$WORK/api_code" + WATCHDOG_NOTIFY=never run_watchdog >/dev/null + WATCHDOG_NOTIFY=never run_watchdog >/dev/null + expect_notifications 0 "never pops nothing at all" + + setup + printf '400' >"$WORK/bot_code" + printf '400' >"$WORK/api_code" + WATCHDOG_NOTIFY=always run_watchdog >/dev/null + WATCHDOG_NOTIFY=always run_watchdog >/dev/null + # Two sends -- "restarting" then "still deaf" -- collapsed by --replace-id + # into one box on screen. Counting sends is what makes the reuse visible. + expect_notifications 2 "always pops the routine pair the default suppresses" + expect_contains "$(cat "$WORK/notify.log")" "--replace-id" \ + "the popup reuses one desktop slot instead of stacking" + expect_file "$WORK/state/notify_id" "4242" "the slot id is persisted for the next firing" } test_requires_a_number() { @@ -216,6 +181,7 @@ main() { test_confirmed_failure_restarts_and_recovers test_restart_that_does_not_help test_gives_up_instead_of_looping + test_notify_modes test_requires_a_number echo "============================================================" diff --git a/scripts/test_watchdog_harness.sh b/scripts/test_watchdog_harness.sh new file mode 100644 index 0000000..555c88a --- /dev/null +++ b/scripts/test_watchdog_harness.sh @@ -0,0 +1,106 @@ +# shellcheck shell=bash +# ============================================================================ +# The sandbox and the assertions for test_watchdog.sh. +# +# Split out when the two together crossed the shared 250-line cap. Sourced, +# never executed: it defines the stub PATH the suite runs against and the +# expect_* helpers, and it owns WORK/FAILURES set by its caller. +# ============================================================================ + +# Rebuild a pristine sandbox: stub binaries, stub answers, empty state. +setup() { + rm -rf "$WORK" + mkdir -p "$WORK/bin" "$WORK/state" + printf '200' >"$WORK/bot_code" + printf '200' >"$WORK/api_code" + printf '0' >"$WORK/fix_on_restart" + + cat >"$WORK/bin/curl" <"$WORK/bin/docker" <> "$WORK/docker.log" +if [[ "\$(cat "$WORK/fix_on_restart")" == "1" ]]; then + printf '200' > "$WORK/bot_code" + printf '200' > "$WORK/api_code" +fi +EOF + + # Stubbed because they are NOT stubbed by default: notify-send and logger + # resolve to the real binaries, so this suite used to fire a dozen genuine + # critical popups per run -- and it runs from pre-commit, which made every + # commit spam the desktop. notify.log is now also what proves the dedup. + cat >"$WORK/bin/notify-send" <> "$WORK/notify.log" +echo 4242 +EOF + + cat >"$WORK/bin/logger" <> "$WORK/logger.log" +EOF + chmod +x "$WORK/bin/curl" "$WORK/bin/docker" "$WORK/bin/notify-send" "$WORK/bin/logger" +} + +notify_count() { + [[ -f "$WORK/notify.log" ]] || { + printf '0' + return 0 + } + grep -c '' "$WORK/notify.log" +} + +expect_notifications() { + local actual + actual="$(notify_count)" + if [[ "$actual" == "$1" ]]; then + ok "$2" + else + fail "$2 -- got $actual popup(s), expected $1" + fi +} + +run_watchdog() { + PATH="$WORK/bin:$PATH" \ + PHONE_NUMBER="+15550000000" \ + STATE_DIRECTORY="$WORK/state" \ + SETTLE_SECONDS=0 \ + FAILURES_BEFORE_RESTART=2 \ + MAX_RESTARTS=2 \ + RESTART_WINDOW=3600 \ + "$WATCHDOG" 2>&1 +} + +expect_contains() { + if [[ "$1" == *"$2"* ]]; then + ok "$3" + else + fail "$3 -- got: $1" + fi +} + +expect_missing() { + if [[ "$1" != *"$2"* ]]; then + ok "$3" + else + fail "$3 -- unexpectedly found $2" + fi +} + +expect_file() { + local actual + actual="$(cat "$1" 2>/dev/null || echo MISSING)" + if [[ "$actual" == "$2" ]]; then + ok "$3" + else + fail "$3 -- $1 is '$actual', expected '$2'" + fi +}