vh
02a6fc019d
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.
141 lines
6.3 KiB
Bash
Executable File
141 lines
6.3 KiB
Bash
Executable File
#!/usr/bin/env bash
|
|
# althing-notify-failure — report a systemd unit entering FAILED state to the
|
|
# althing infra-ops inbox.
|
|
#
|
|
# WHY THIS EXISTS. An uptime check cannot see the dangerous failure on this box.
|
|
# svos-dev measured it on 2026-09-22: a config change on 09-19 made svos.service
|
|
# refuse to boot, the RUNNING process predated the change and kept serving, and
|
|
# the service sat one restart away from dark for three days. Every uptime probe
|
|
# was green and correct the whole time -- the thing was up. The signal that
|
|
# would have fired is failed-START, not down.
|
|
#
|
|
# A count after that conversation: 13 running user units on nh3-dev, ZERO with
|
|
# an OnFailure hook. Including althing-po-herald, whose silent failure cuts
|
|
# infra-ops's own mail delivery -- a blind spot in the notification path that
|
|
# every other alarm on this fleet depends on.
|
|
#
|
|
# WHY OnFailure IS THE RIGHT TRIGGER AND NOT NOISE. It 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, not one per attempt.
|
|
set -uo pipefail
|
|
|
|
UNIT="${1:-unknown.service}"
|
|
HOST="$(hostname)"
|
|
SPOOL="${HOME}/.local/state/althing-notify-failure"
|
|
POSTBOX="${POSTBOX:-${HOME}/.local/bin/postbox}"
|
|
RECIPIENT="${ALERT_RECIPIENT:-infra-ops}"
|
|
|
|
# ⚠ NEVER report on ourselves. Without this, a notifier that fails while
|
|
# reporting a failure would be reported by another notifier, and so on. The
|
|
# template deliberately carries no OnFailure of its own either -- belt and
|
|
# braces, because a notification loop is the one bug that pages you forever.
|
|
case "$UNIT" in
|
|
althing-notify-failure@*) exit 0 ;;
|
|
esac
|
|
|
|
state=$(systemctl --user show "$UNIT" -p ActiveState --value 2>/dev/null)
|
|
sub=$(systemctl --user show "$UNIT" -p SubState --value 2>/dev/null)
|
|
result=$(systemctl --user show "$UNIT" -p Result --value 2>/dev/null)
|
|
code=$(systemctl --user show "$UNIT" -p ExecMainStatus --value 2>/dev/null)
|
|
desc=$(systemctl --user show "$UNIT" -p Description --value 2>/dev/null)
|
|
since=$(systemctl --user show "$UNIT" -p ExecMainExitTimestamp --value 2>/dev/null)
|
|
|
|
body=$(cat <<EOF
|
|
${desc:-$UNIT}
|
|
|
|
host ${HOST}
|
|
unit ${UNIT}
|
|
state ${state:-?} (${sub:-?})
|
|
result ${result:-?}
|
|
exit status ${code:-?}
|
|
failed at ${since:-?}
|
|
|
|
This is a FAILED-START alarm, not an uptime check. It does not fire on a clean
|
|
restart or a deliberate stop, so a message here means the unit could not come
|
|
back -- the state an uptime probe reports as healthy right up until the moment
|
|
the old process goes away.
|
|
|
|
Last journal lines:
|
|
|
|
$(journalctl --user -u "$UNIT" -n 25 --no-pager -o short-iso 2>/dev/null | sed 's/^/ /')
|
|
|
|
Triage:
|
|
systemctl --user status ${UNIT}
|
|
journalctl --user -u ${UNIT} -n 100 --no-pager
|
|
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.
|
|
mkdir -p "$SPOOL"
|
|
stamp=$(date -u +%Y%m%dT%H%M%SZ)
|
|
printf '%s\n' "$body" > "${SPOOL}/${stamp}-${UNIT}.txt"
|
|
|
|
if [ -x "$POSTBOX" ]; then
|
|
if printf '%s\n' "$body" | ALTHING_HANDLE="${ALTHING_HANDLE:-infra-ops}" \
|
|
"$POSTBOX" send --to "$RECIPIENT" \
|
|
--subject "[systemd] ${UNIT} FAILED on ${HOST}" >/dev/null 2>&1; then
|
|
printf 'delivered %s to %s\n' "$UNIT" "$RECIPIENT"
|
|
else
|
|
# ⚠ If althing-po-herald is the unit that failed, the message still
|
|
# REACHES the post office (postbox talks to it directly; the herald only
|
|
# delivers inbound pokes) -- it just will not be pushed into a live
|
|
# session. It is stored and the next `postbox read` finds it. A memo to
|
|
# the successor, which is the whole point.
|
|
printf 'POSTBOX DELIVERY FAILED for %s; spooled at %s\n' "$UNIT" "$SPOOL" >&2
|
|
fi
|
|
else
|
|
printf 'postbox not executable at %s; spooled only\n' "$POSTBOX" >&2
|
|
fi
|
|
|
|
# Always succeed. A notifier that exits non-zero is itself a failed unit, and
|
|
# this one must never become the thing that needs reporting.
|
|
exit 0
|