fix(alerts): suppress duplicate failure alarms, keyed on the cause
svos-dev challenged a claim this README made -- that a crash-loop yields one
message per episode -- with a measurement: one 2026-09-19 boot-gate refusal on
svos.service produced FIVE transitions into failed, and the operator got five
messages.
Measured here before accepting it, because a peer's number is still a number
someone else took: a unit with Restart=on-failure, burst 3, interval 30s
produced 7 journal failure lines and exactly ONE notifier invocation. So the
multiplier is not universal -- it needs retries spanning start-limit windows or
an external restarter. svos.service carries StartLimitIntervalSec=5min, which
is how it accumulated five.
Both conditions exist on this box, so the guard goes in as cheap insurance
rather than as a fix for something proven here. The README now states both
numbers and which restart policy each of the twelve units carries, since that
is what decides the exposure. Noted with it: hermes-gateway has start limiting
DISABLED, so it retries forever and may never reach failed at all -- worth
knowing before trusting this alarm to cover it.
Design, taken from svos-dev's shape:
- Keyed on a hash of the CAUSE (unit + result + exit status + the shape of
its last error lines), never the unit name alone. A genuinely different
failure inside the window is a new fact and must still page; suppressing by
unit would hide a second, worse failure behind the first.
- Suppression is LOGGED to suppressed.log, never silent. An alarm that
quietly declines to fire is indistinguishable from one that is broken.
⚠ The first test of this appeared to show the cooldown not working, and the
test was wrong rather than the code -- it invoked the script BEFORE failing the
unit, so the two calls legitimately saw different states and computed different
fingerprints. Re-run the way systemd actually invokes it: same cause 3x -> 1
sent, 2 suppressed and logged; a different cause inside the same window -> sent.
This commit is contained in:
@@ -29,8 +29,44 @@ delivery, a blind spot in the notification path every other alarm depends on.
|
||||
|
||||
`OnFailure` does not fire on a clean restart or a deliberate stop. svos-dev's
|
||||
four restarts and three deploys in one day would have produced **zero** alerts.
|
||||
With `Restart=on-failure`, a unit enters failed state only after exhausting its
|
||||
start-limit burst, so a crash-loop yields **one** message per episode.
|
||||
|
||||
### Duplicate suppression, and a claim I had to correct
|
||||
|
||||
This README originally asserted that a crash-loop "yields one message per
|
||||
episode". svos-dev challenged it with a measurement: one 2026-09-19 boot-gate
|
||||
refusal on `svos.service` produced **five** transitions into `failed`, and the
|
||||
operator got five messages.
|
||||
|
||||
Measured here before accepting or rejecting it: a unit with
|
||||
`Restart=on-failure`, burst 3, interval 30s produced **7 journal failure lines
|
||||
and exactly 1 notifier invocation**. So the multiplier is *not* universal — it
|
||||
needs retries spanning start-limit windows, or an external restarter. svos.service
|
||||
has `StartLimitIntervalSec=5min`, which is how it accumulated five.
|
||||
|
||||
Both conditions exist on this box, so there is now a **cooldown** (900s default,
|
||||
`NOTIFY_COOLDOWN_SECONDS`) — cheap insurance rather than a fix for something
|
||||
proven here. Two properties it must have, both tested:
|
||||
|
||||
- **Keyed on the CAUSE, not the unit.** A genuinely different failure inside the
|
||||
window is a new fact and still pages. Suppressing by unit name alone would
|
||||
hide a second, worse failure behind the first.
|
||||
- **Suppression is logged** (`suppressed.log`), never silent. An alarm that
|
||||
quietly declines to fire is indistinguishable from one that is broken, and
|
||||
this whole mechanism exists because something that looked fine was not.
|
||||
|
||||
Verified: same cause fired 3× → 1 sent, 2 suppressed and logged; a different
|
||||
cause inside the same window → sent.
|
||||
|
||||
### Restart policy decides the exposure
|
||||
|
||||
| policy | units |
|
||||
|---|---|
|
||||
| `Restart=always` | althing-po-herald, hermes-gateway, lrpg-demo, ttyd-caddy, ttyd-ro, ttyd-rw |
|
||||
| `Restart=on-failure` | althing-seat-page, booth, peedlar, svos, wherethef, zellij-web |
|
||||
|
||||
`hermes-gateway` has `StartLimitIntervalUSec=0` — start limiting disabled, so it
|
||||
retries forever and may never reach `failed` at all. Worth knowing before
|
||||
trusting this alarm to cover it.
|
||||
|
||||
## Two traps, both hit during the build
|
||||
|
||||
|
||||
@@ -67,6 +67,50 @@ Triage:
|
||||
EOF
|
||||
)
|
||||
|
||||
# ---- duplicate suppression ---------------------------------------------------
|
||||
#
|
||||
# OnFailure fires on every transition INTO failed, not once per incident.
|
||||
# svos-dev measured five such transitions for one 2026-09-19 boot-gate refusal
|
||||
# on svos.service (StartLimitBurst=3, StartLimitIntervalSec=5min), and the
|
||||
# operator saw five messages for one outage.
|
||||
#
|
||||
# MEASURED HERE, because the claim deserved checking rather than adopting: a
|
||||
# simple crash-loop inside ONE start-limit window fires the notifier exactly
|
||||
# ONCE -- a unit with Restart=on-failure, burst 3, interval 30s produced 7
|
||||
# journal failure lines and 1 notifier invocation. So the multiplier is not
|
||||
# universal; it needs retries that span windows, or an external restarter.
|
||||
# Both exist on this box, so the guard is cheap insurance rather than a fix for
|
||||
# something already proven here.
|
||||
#
|
||||
# KEYED ON THE CAUSE, NOT THE UNIT. A genuinely different failure inside the
|
||||
# window is a NEW FACT and must still page -- suppressing by unit name alone
|
||||
# would hide a second, worse failure behind the first. The fingerprint is the
|
||||
# unit plus its result, exit status, and the shape of its last error lines.
|
||||
#
|
||||
# SUPPRESSION IS LOGGED, NEVER SILENT. An alarm that quietly declines to fire is
|
||||
# indistinguishable from one that is broken, and this whole mechanism exists
|
||||
# because a thing that looked fine was not.
|
||||
COOLDOWN="${NOTIFY_COOLDOWN_SECONDS:-900}"
|
||||
mkdir -p "$SPOOL"
|
||||
fingerprint=$(printf '%s|%s|%s|%s' "$UNIT" "${result:-}" "${code:-}" \
|
||||
"$(journalctl --user -u "$UNIT" -n 10 --no-pager -o cat 2>/dev/null \
|
||||
| grep -iE 'error|fail|refus|cannot|denied' | head -5)" \
|
||||
| sha256sum | cut -c1-16)
|
||||
guard="${SPOOL}/.cooldown-${fingerprint}"
|
||||
now=$(date +%s)
|
||||
if [ -f "$guard" ]; then
|
||||
last=$(cat "$guard" 2>/dev/null || echo 0)
|
||||
age=$(( now - last ))
|
||||
if [ "$age" -lt "$COOLDOWN" ]; then
|
||||
printf 'SUPPRESSED duplicate for %s (same cause %s, %ss into a %ss cooldown); not sending\n' \
|
||||
"$UNIT" "$fingerprint" "$age" "$COOLDOWN"
|
||||
printf '%s suppressed %s age=%ss\n' "$(date -Is)" "$UNIT" "$age" \
|
||||
>> "${SPOOL}/suppressed.log"
|
||||
exit 0
|
||||
fi
|
||||
fi
|
||||
printf '%s' "$now" > "$guard"
|
||||
|
||||
# Durable local record FIRST, so the signal survives a post-office outage.
|
||||
# postbox has no outbox: a send that cannot reach the post office is dropped,
|
||||
# and this alarm exists precisely for the cases nobody is watching.
|
||||
|
||||
Reference in New Issue
Block a user