dark/nether-voicebridge

Watch

Fork 1

fix(matrix): transient /sync errors misclassified as fatal auth — substring match hits the `since=` token (killed 5 bridges, 3 dead for 3 days) #130

New issue

Closed

opened 2026-08-14 01:23:16 +00:00 by robocub · 1 comment

robocub commented

2026-08-14 01:23:16 +00:00

Collaborator

Summary

A transient network error on /sync is classified as a fatal auth error, because the classifier substring-matches the stringified error — and the string contains the sync URL, whose ?since=<token> can itself contain 401 or 403. The supervisor treats a fatal auth verdict as unrecoverable and kills the bridge with no retry.

On 2026-08-11 01:17–01:26 UTC this killed five bridges on the public instance. Three stayed dead for three days until a manual systemctl restart.

Evidence

The bug, crates/matrix-rtc/src/matrix.rs:1150-1153:

let msg = e.to_string();
// 401/403 are auth failures — propagate immediately.
if msg.contains("401") || msg.contains("403") || msg.contains("M_UNKNOWN_TOKEN") {
    return Err(anyhow::anyhow!("Matrix sync fatal auth error: {e}"));
}

What the bridges actually logged:

ERROR bridge{name=Light Voice}: nether_voicebridge::supervisor: bridge failed
  error=Matrix sync fatal auth error: error sending request for url
        (https://nether.im/_matrix/client/v3/sync?since=54015213&timeout=30000&use_state_after=true)

error sending request for url is a reqwest transport error — there is no HTTP response, so there is no 401. The match fired on the sync token. Every bridge that died had a token in the 5401xxxx range:

Bridge	`since=`	contains `401`
Voice	54013070	yes
Light Gaming	54013070	yes
fbi	54014591	yes
Light Voice	54015213	yes
Dark Voice	54015517	yes

Proof by contrast — the same underlying transport error two days later, with tokens that do not contain 401/403, correctly retried and logged only a WARN:

WARN bridge{name=fbi}: Matrix sync error — retrying in 5 s
  error=error sending request for url (…/sync?since=54945882&…)
WARN nvb_matrix_rtc::mgmt: management bot sync error — retrying in 5 s
  error=error sending request for url (…/sync?since=54953739&…)

So the failure is not "a bad night for the network" — it is a bad range of sync tokens. The landmine re-arms every time the homeserver's sync stream crosses a position containing 401 or 403.

Second defect: a fatal verdict is permanent

crates/bridge/src/supervisor.rs:262 logs bridge failed and the bridge is gone for the process lifetime. There is no restart path.

The three static config.toml bridges (Light Voice, Light Gaming, Dark Voice) therefore stayed dead for three days. The three tenant bridges (Voice, fbi, bridge) came back only by accident: a self-serve link approval on 08-12 triggered supervisor: reconciling tenants against tenants.toml → tenant added — starting bridge. Static bridges have no equivalent path.

This subsumes a previously-unfiled recurring gotcha: after a host reboot the bridge starts before Tuwunel is serving, every bridge's m.login.application_service gets 502, and all bridges die permanently the same way. Both need the same defence.

Fix

Typed classification. Replace the substring match with a decision on the actual HTTP status / errcode. Fatal: status 401, or errcode M_UNKNOWN_TOKEN/M_MISSING_TOKEN; 403 only with errcode M_FORBIDDEN. Never fatal: no HTTP response at all (transport error), 5xx, 429, timeouts. Keep the decision a pure function over (Option<u16>, Option<&str>) so it is unit-testable without a live SDK, with a thin adapter from matrix_sdk::Error.
Same twin at crates/matrix-rtc/src/mgmt.rs:1242 (management bot sync loop) — identical code, identical bug.
Supervisor auto-restart with exponential backoff (base * 2^n capped, mirroring the puppet join-timeout quarantine in crates/discord/src/puppet.rs:351), so that even a genuinely fatal error, a panic, or a startup 502 cannot leave a bridge permanently dead. Operator-initiated stops and shutdown must not auto-restart.
Lower priority, same class: crates/matrix-rtc/src/matrix.rs:583 chooses a log message via msg.contains("403"). Cosmetic today (both branches return Err), but it will mislead on any room_id or URL containing 403.

Regression test

The incident itself: an error with no HTTP status whose message contains since=54015213 must classify as transient. Plus 401/M_UNKNOWN_TOKEN → fatal, and 502/timeout → transient.

Monitoring did not surface the 3-day outage — filed separately.
General lesson: match on structure, never on substrings of a stringified error.

## Summary A **transient network error** on `/sync` is classified as a **fatal auth error**, because the classifier substring-matches the *stringified* error — and the string contains the sync URL, whose `?since=<token>` can itself contain `401` or `403`. The supervisor treats a fatal auth verdict as unrecoverable and kills the bridge with no retry. On **2026-08-11 01:17–01:26 UTC** this killed **five bridges** on the public instance. Three stayed dead for **three days** until a manual `systemctl restart`. ## Evidence The bug, `crates/matrix-rtc/src/matrix.rs:1150-1153`: ```rust let msg = e.to_string(); // 401/403 are auth failures — propagate immediately. if msg.contains("401") || msg.contains("403") || msg.contains("M_UNKNOWN_TOKEN") { return Err(anyhow::anyhow!("Matrix sync fatal auth error: {e}")); } ``` What the bridges actually logged: ``` ERROR bridge{name=Light Voice}: nether_voicebridge::supervisor: bridge failed error=Matrix sync fatal auth error: error sending request for url (https://nether.im/_matrix/client/v3/sync?since=54015213&timeout=30000&use_state_after=true) ``` `error sending request for url` is a reqwest **transport** error — there is no HTTP response, so there is no 401. The match fired on the sync token. Every bridge that died had a token in the `5401xxxx` range: | Bridge | `since=` | contains `401` | |---|---|---| | Voice | 54**013**070 | yes | | Light Gaming | 54**013**070 | yes | | fbi | 54**014**591 | yes | | Light Voice | 54**015**213 | yes | | Dark Voice | 54**015**517 | yes | Proof by contrast — the same underlying transport error two days later, with tokens that do **not** contain `401`/`403`, correctly retried and logged only a WARN: ``` WARN bridge{name=fbi}: Matrix sync error — retrying in 5 s error=error sending request for url (…/sync?since=54945882&…) WARN nvb_matrix_rtc::mgmt: management bot sync error — retrying in 5 s error=error sending request for url (…/sync?since=54953739&…) ``` So the failure is not "a bad night for the network" — it is a **bad range of sync tokens**. The landmine re-arms every time the homeserver's sync stream crosses a position containing `401` or `403`. ## Second defect: a fatal verdict is permanent `crates/bridge/src/supervisor.rs:262` logs `bridge failed` and the bridge is gone for the process lifetime. There is no restart path. The three **static `config.toml`** bridges (Light Voice, Light Gaming, Dark Voice) therefore stayed dead for three days. The three **tenant** bridges (Voice, fbi, bridge) came back only by accident: a self-serve link approval on 08-12 triggered `supervisor: reconciling tenants against tenants.toml` → `tenant added — starting bridge`. Static bridges have no equivalent path. This subsumes a previously-unfiled recurring gotcha: **after a host reboot** the bridge starts before Tuwunel is serving, every bridge's `m.login.application_service` gets `502`, and all bridges die permanently the same way. Both need the same defence. ## Fix 1. **Typed classification.** Replace the substring match with a decision on the actual HTTP status / errcode. Fatal: status `401`, or errcode `M_UNKNOWN_TOKEN`/`M_MISSING_TOKEN`; `403` only with errcode `M_FORBIDDEN`. Never fatal: no HTTP response at all (transport error), 5xx, 429, timeouts. Keep the decision a pure function over `(Option<u16>, Option<&str>)` so it is unit-testable without a live SDK, with a thin adapter from `matrix_sdk::Error`. 2. **Same twin at `crates/matrix-rtc/src/mgmt.rs:1242`** (management bot sync loop) — identical code, identical bug. 3. **Supervisor auto-restart with exponential backoff** (`base * 2^n` capped, mirroring the puppet join-timeout quarantine in `crates/discord/src/puppet.rs:351`), so that even a genuinely fatal error, a panic, or a startup 502 cannot leave a bridge permanently dead. Operator-initiated stops and shutdown must not auto-restart. 4. **Lower priority, same class:** `crates/matrix-rtc/src/matrix.rs:583` chooses a log message via `msg.contains("403")`. Cosmetic today (both branches return `Err`), but it will mislead on any room_id or URL containing `403`. ## Regression test The incident itself: an error with **no HTTP status** whose message contains `since=54015213` must classify as **transient**. Plus `401`/`M_UNKNOWN_TOKEN` → fatal, and 502/timeout → transient. ## Related - Monitoring did not surface the 3-day outage — filed separately. - General lesson: match on structure, never on substrings of a stringified error.

robocub referenced this issue from a commit

2026-08-14 01:49:58 +00:00

fix(matrix,bridge): classify sync errors structurally + auto-restart failed bridges (#130, #131)

robocub referenced this issue from a pull request that will close it,

2026-08-14 02:06:14 +00:00

fix: classify sync errors structurally + auto-restart failed bridges (#130, #131) #132

robocub referenced this issue from a commit

2026-08-14 02:08:39 +00:00

release: 0.3.2 — sync-error misclassification fix + bridge liveness (#130, #131)

robocub closed this issue

2026-08-14 17:41:37 +00:00

robocub referenced this issue from a commit

2026-08-14 17:41:38 +00:00

Merge pull request 'fix: classify sync errors structurally + auto-restart failed bridges (#130, #131)' (#132) from fix/130-sync-auth-misclassification into master

robocub commented

2026-08-14 18:21:10 +00:00

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`.

robocub referenced this issue from a commit

2026-08-14 19:23:40 +00:00

ops(nvb-watch): watch ci.yml on master, with a daily re-alert while red (#131)

robocub referenced this issue from a commit

2026-08-19 23:30:25 +00:00

fix(mgmt): retry appservice login + initial sync at startup with capped backoff (#126)

robocub referenced this issue

2026-08-19 23:47:35 +00:00

fix(supervisor): retry appservice login at startup — a homeserver-unreachable boot race permanently kills every bridge until manual restart #126

robocub referenced this issue

2026-08-20 00:06:32 +00:00

fix(supervisor): retry appservice login at startup — a homeserver-unreachable boot race permanently kills every bridge until manual restart #126