ops(nvb-watch): no per-bridge liveness check — 3 bridges dead for 3 days while daily digests read healthy #131

Closed
opened 2026-08-14 01:23:16 +00:00 by robocub · 2 comments
Collaborator

Summary

nvb-watch detected the 2026-08-11 bridge outage once, then reported the instance healthy for three days while three bridges were dead. Detection is event-based; there is no bridge-level liveness state check.

Timeline (NVB Ops room)

08-11 01:17-01:26  five bridges die (see the classifier bug issue)
08-11 01:30  🚨 nvb-watch: ❌ 5 ERROR line(s) in the bridge journal: …
08-12 00:00  📊 daily digest — journal(15m): err=0 warn=0 svc=active
08-13 00:00  📊 daily digest — … svc=active
08-14 00:00  📊 daily digest — … svc=active
08-14 01:08  operator restarts the service after noticing a room wasn't bridging

The single alert fired correctly, at 01:30 on a Monday night, and was missed. Nothing repeated it.

Why the monitor went quiet

  1. The ERROR check is event-based, not state-based. nvb-watch.sh scans a 15-minute journal cursor window (journalctl --after-cursor). Once the five ERROR lines scrolled past, every later run saw err=0. A dead bridge is silent, so silence reads as health.
  2. 💀 only checks systemctl is-active. The process was alive; only 3 of its 9 bridges weren't. Same masking already documented for the reboot boot-race — this is the second time it has hidden a real outage.
  3. The daily digest reports the 15-min sample, so err=0 warn=0 svc=active looked reassuring every single day of the outage.

Fix

Interim (no release needed): latch on channel unregistered from puppet pool — the exact death signature — into state/bridges.down; alert once, then re-alert daily while the latch is non-empty; clear with a when that bridge registers again. nvb-ops.conf already carries NVB_CONFIG, so the configured roster is available for comparison.

Robust: have the supervisor write a machine-readable roster to <data_dir>/bridges.json (sibling of the existing audit.jsonl) on every state transition plus a periodic refresh:

{"updated": 1755..., "pid": 570490,
 "bridges": [{"name":"Light Voice","origin":"static","state":"alive","since":...,"consecutive_failures":0}]}

nvb-watch then alerts when any bridge is not alive, or when updated goes stale (>5 min — dead-man's switch for the writer), and adds bridges=N/M to the daily digest so that a healthy digest actually proves the bridges are alive — precisely what failed here.

Also: nvb-watch.sh, nvb-backup.sh and a sanitised nvb-ops.conf.example currently exist only on the prod host, unreviewed and unbackuped. Bring them into the repo under ops/ and point docs/operations-runbook.md at them.

## Summary `nvb-watch` detected the 2026-08-11 bridge outage **once**, then reported the instance healthy for three days while three bridges were dead. Detection is event-based; there is no bridge-level liveness **state** check. ## Timeline (NVB Ops room) ``` 08-11 01:17-01:26 five bridges die (see the classifier bug issue) 08-11 01:30 🚨 nvb-watch: ❌ 5 ERROR line(s) in the bridge journal: … 08-12 00:00 📊 daily digest — journal(15m): err=0 warn=0 svc=active 08-13 00:00 📊 daily digest — … svc=active 08-14 00:00 📊 daily digest — … svc=active 08-14 01:08 operator restarts the service after noticing a room wasn't bridging ``` The single alert fired correctly, at 01:30 on a Monday night, and was missed. Nothing repeated it. ## Why the monitor went quiet 1. **The ERROR check is event-based, not state-based.** `nvb-watch.sh` scans a 15-minute journal cursor window (`journalctl --after-cursor`). Once the five ERROR lines scrolled past, every later run saw `err=0`. A dead bridge is *silent*, so silence reads as health. 2. **`💀` only checks `systemctl is-active`.** The process was alive; only 3 of its 9 bridges weren't. Same masking already documented for the reboot boot-race — this is the second time it has hidden a real outage. 3. **The daily digest reports the 15-min sample**, so `err=0 warn=0 svc=active` looked reassuring every single day of the outage. ## Fix **Interim (no release needed):** latch on `channel unregistered from puppet pool` — the exact death signature — into `state/bridges.down`; alert once, then **re-alert daily** while the latch is non-empty; clear with a ✅ when that bridge registers again. `nvb-ops.conf` already carries `NVB_CONFIG`, so the configured roster is available for comparison. **Robust:** have the supervisor write a machine-readable roster to `<data_dir>/bridges.json` (sibling of the existing `audit.jsonl`) on every state transition plus a periodic refresh: ```json {"updated": 1755..., "pid": 570490, "bridges": [{"name":"Light Voice","origin":"static","state":"alive","since":...,"consecutive_failures":0}]} ``` `nvb-watch` then alerts when any bridge is not `alive`, or when `updated` goes stale (>5 min — dead-man's switch for the writer), and adds `bridges=N/M` to the daily digest **so that a healthy digest actually proves the bridges are alive** — precisely what failed here. **Also:** `nvb-watch.sh`, `nvb-backup.sh` and a sanitised `nvb-ops.conf.example` currently exist only on the prod host, unreviewed and unbackuped. Bring them into the repo under `ops/` and point `docs/operations-runbook.md` at them.
Author
Collaborator

Related gap found while fixing this: nothing watches ci.yml either.

The hermetic CI gate has been red on master since the 0.3.1 release commit ad53ccd on 2026-07-26 (run #289) — 19 days — because that commit orphaned generate_config_with_pool_size and clippy --all-targets -D warnings fails on dead code. Nobody noticed, for the same structural reason as the bridge outage: the nvb-watch Actions guardrail (section 3b) polls only e2e.yml scheduled runs.

Fixed the dead code in #132, but the monitoring hole stands. Worth extending the guardrail to alert when the newest ci.yml run on master is failing — cheap, same API call, same state-latch pattern.

Related gap found while fixing this: **nothing watches `ci.yml`** either. The hermetic CI gate has been **red on master since the 0.3.1 release commit `ad53ccd` on 2026-07-26** (run #289) — 19 days — because that commit orphaned `generate_config_with_pool_size` and `clippy --all-targets -D warnings` fails on dead code. Nobody noticed, for the same structural reason as the bridge outage: the nvb-watch Actions guardrail (section 3b) polls **only** `e2e.yml` scheduled runs. Fixed the dead code in #132, but the monitoring hole stands. Worth extending the guardrail to alert when the newest `ci.yml` run **on master** is failing — cheap, same API call, same state-latch pattern.
Author
Collaborator

Shipped in v0.3.2 (https://nether.codes/dark/nether-voicebridge/releases/tag/v0.3.2), deployed to prod 2026-08-14 18:16 UTC.

Prod verification: all 9 bridges report joined Matrix room after the restart, /var/lib/nether-voicebridge/bridges.json lists 9/9 alive with its updated stamp advancing every 60 s, and the ops digest now carries bridges=9/9. The only journal ERROR since the restart is a pre-existing stale federated invite from qwertyad.one, unrelated to this work.

Live fault-injection results (run on the build host against the test fixture, prod untouched):

  • homeserver blocked mid-run → Matrix sync error — retrying in 5 s, zero bridge failed, bridge recovered on its own;
  • corrupted appservice token → real 401 Unauthorized still classified fatal → automatic restarts at 5 / 10 / 20 / 40 / 80 s, roster showing restarting, consecutive_failures=5.
Shipped in **v0.3.2** (https://nether.codes/dark/nether-voicebridge/releases/tag/v0.3.2), deployed to prod 2026-08-14 18:16 UTC. Prod verification: all **9 bridges** report `joined Matrix room` after the restart, `/var/lib/nether-voicebridge/bridges.json` lists **9/9 alive** with its `updated` stamp advancing every 60 s, and the ops digest now carries `bridges=9/9`. The only journal ERROR since the restart is a pre-existing stale federated invite from `qwertyad.one`, unrelated to this work. Live fault-injection results (run on the build host against the test fixture, prod untouched): - homeserver blocked mid-run → `Matrix sync error — retrying in 5 s`, **zero** `bridge failed`, bridge recovered on its own; - corrupted appservice token → real `401 Unauthorized` still classified fatal → automatic restarts at **5 / 10 / 20 / 40 / 80 s**, roster showing `restarting`, `consecutive_failures=5`.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
dark/nether-voicebridge#131
No description provided.