e2e nightly RED 8 days — real multi-channel/encrypted/recovery audio failure cluster (NOT contention); env-vs-code TBD #124

Open
opened 2026-07-19 22:12:58 +00:00 by robocub · 2 comments
Collaborator

The nightly e2e suite has been RED every night since ~2026-07-11 (8+ days). Triaged 2026-07-19. It is NOT host contention (my two earlier theories — apt-daily timing, then shared-host load — are both disproven below). It is a real, deterministic failure cluster the nightly has been correctly catching while nobody was watching (hence #123's guardrail need).

Reproduction (staging, 0.3.0 bins, standing env)

Full --all --profile compressed on staging: 21 pass, 5 fail (+ #104 known-fail, 1 unexpected-pass). The 5 fails, re-run in isolation on a quiet host (load ~2), still all fail — several worse, so contention is ruled out:

scenario signature
multi_bridge_isolation mean_ncc=0.000, and voicetick health speaking=0 silent=0 for the WHOLE run on BOTH anchors — the anchors are in voice (ticks climb) but demux zero speaker audio
external_disconnect_recovery ncc=0.011, dropouts=8 — no audio after recovery
recovery_no_spare ncc=0.008, dropouts=6
audio_d2m_enc ncc=0.51, dropouts — encrypted D→M garbled
steal_release_repromotion logic, not audio: channel C got bot …409515, expected the stolen …565730 — wrong puppet promoted

The pattern

Single-channel, steady-state scenarios PASSaudio_d2m_unenc, audio_m2d_unenc, audio_m2d_enc, audio_m2d_enc_freshjoin all green. Failures cluster in multi-channel / multi-bot / encrypted-D→M / post-recovery paths. multi_bridge_isolation's speaking=0 on both channels (while single-channel d2m works minutes earlier with the same harness) points at the anchor/demux or puppet-pool when two channels are active at once; steal_release's wrong-bot points at pool composition/allocation.

Onset

Nightly flipped between the 07-11 04:15 pass and 06:03 (scheduled) fail. No audio/puppet-core commit lands in that window (07-11 02:00–07:00 = mgmt #77/#78, e2e harness, docs only). So either (a) the FULL --all nightly first exercised these scenarios then, or (b) standing-test-environment drift around that time. steal_release_repromotion demonstrably PASSED when added (#24, 07-12, "LIVE-PASS 26.5s") and fails now → a genuine regression for at least that one.

Two live hypotheses (needs a focused session — do NOT rush)

  1. Standing-test-environment drift (prod-safe): a harness puppet bot left the automated-testing guild / pool composition changed / test-speaker issue → multi-bot scenarios pick wrong/absent bots. The speaking=0 + wrong-bot signatures fit this. Check first — cheapest: verify all NVB_E2E_PUPPET_TOKENS bots are present in guild 1523348036040790087.
  2. Real code gap (prod-relevant): a genuine bug in encrypted-D→M / multi-channel / puppet-recovery — which would overlap open review issues #69 (E2EE media-key delivery correctness) and #70 (puppet rejoin/reconnect gaps), and could even relate to @qwertyad's unexplained choppy audio. Cannot be ruled out without the env check + a per-scenario debug.

Prod impact — honestly uncertain

If (2), real users in encrypted rooms / multi-channel guilds / after a puppet reconnect could get degraded or missing Discord→Matrix audio. If (1), prod is fine. Current prod usage is light (1 active tenant) so we have little field signal either way. Treat potential prod impact as open until the env-vs-code question is settled.

Immediate follow-ups

  • #123: correct the record (08:30 cron move did not fix this; contention was never the cause).
  • The red-nightly ops-room alert (#123 Step 4) is now clearly worth building — the suite caught real issues for 8 days silently.
The nightly e2e suite has been RED every night since ~2026-07-11 (8+ days). Triaged 2026-07-19. **It is NOT host contention** (my two earlier theories — apt-daily timing, then shared-host load — are both disproven below). It is a **real, deterministic failure cluster** the nightly has been correctly catching while nobody was watching (hence #123's guardrail need). ## Reproduction (staging, 0.3.0 bins, standing env) Full `--all --profile compressed` on staging: **21 pass, 5 fail** (+ #104 known-fail, 1 unexpected-pass). The 5 fails, **re-run in isolation on a quiet host (load ~2), still all fail — several worse**, so contention is ruled out: | scenario | signature | |---|---| | `multi_bridge_isolation` | `mean_ncc=0.000`, and `voicetick health speaking=0 silent=0` for the WHOLE run on BOTH anchors — the anchors are in voice (ticks climb) but demux **zero** speaker audio | | `external_disconnect_recovery` | `ncc=0.011`, dropouts=8 — no audio after recovery | | `recovery_no_spare` | `ncc=0.008`, dropouts=6 | | `audio_d2m_enc` | `ncc=0.51`, dropouts — encrypted D→M garbled | | `steal_release_repromotion` | logic, not audio: `channel C got bot …409515, expected the stolen …565730` — wrong puppet promoted | ## The pattern **Single-channel, steady-state scenarios PASS** — `audio_d2m_unenc`, `audio_m2d_unenc`, `audio_m2d_enc`, `audio_m2d_enc_freshjoin` all green. **Failures cluster in multi-channel / multi-bot / encrypted-D→M / post-recovery** paths. `multi_bridge_isolation`'s `speaking=0` on both channels (while single-channel d2m works minutes earlier with the same harness) points at the anchor/demux or puppet-pool when **two channels are active at once**; `steal_release`'s wrong-bot points at pool composition/allocation. ## Onset Nightly flipped between the 07-11 04:15 pass and 06:03 (scheduled) fail. **No audio/puppet-core commit lands in that window** (07-11 02:00–07:00 = mgmt #77/#78, e2e harness, docs only). So either (a) the FULL `--all` nightly first exercised these scenarios then, or (b) standing-test-environment drift around that time. `steal_release_repromotion` demonstrably PASSED when added (#24, 07-12, "LIVE-PASS 26.5s") and fails now → a genuine regression for at least that one. ## Two live hypotheses (needs a focused session — do NOT rush) 1. **Standing-test-environment drift** (prod-safe): a harness puppet bot left the automated-testing guild / pool composition changed / test-speaker issue → multi-bot scenarios pick wrong/absent bots. The `speaking=0` + wrong-bot signatures fit this. **Check first — cheapest:** verify all `NVB_E2E_PUPPET_TOKENS` bots are present in guild `1523348036040790087`. 2. **Real code gap** (prod-relevant): a genuine bug in encrypted-D→M / multi-channel / puppet-recovery — which would overlap open review issues **#69** (E2EE media-key delivery correctness) and **#70** (puppet rejoin/reconnect gaps), and could even relate to @qwertyad's unexplained choppy audio. Cannot be ruled out without the env check + a per-scenario debug. ## Prod impact — honestly uncertain If (2), real users in **encrypted rooms / multi-channel guilds / after a puppet reconnect** could get degraded or missing Discord→Matrix audio. If (1), prod is fine. Current prod usage is light (1 active tenant) so we have little field signal either way. **Treat potential prod impact as open until the env-vs-code question is settled.** ## Immediate follow-ups - #123: correct the record (08:30 cron move did not fix this; contention was never the cause). - The red-nightly ops-room alert (#123 Step 4) is now clearly worth building — the suite caught real issues for 8 days silently.
Author
Collaborator

Env hypothesis #1 — partial check: all 3 harness puppet bots (nvb-test-harness-1/2/3, the NVB_E2E_PUPPET_TOKENS pool) are present in the test guild 1523348036040790087. So it is NOT a bot that left the guild (simplest drift ruled out). Remaining env angles: whether a 3-bot pool is still sufficient for the multi-channel multi_bridge_isolation/steal scenarios and whether the pool composition/ordering drifted (the steal failure expected bot …565730, got …409515). Next session should: (a) run one failing multi-bridge scenario with per-bot allocation tracing, (b) compare the expected-vs-actual bot IDs against the current pool, (c) if the pool checks out, treat it as a real code gap and bisect against the last known-green nightly commit.

**Env hypothesis #1 — partial check:** all 3 harness puppet bots (`nvb-test-harness-1/2/3`, the `NVB_E2E_PUPPET_TOKENS` pool) are present in the test guild `1523348036040790087`. So it is NOT a bot that left the guild (simplest drift ruled out). Remaining env angles: whether a 3-bot pool is still sufficient for the multi-channel `multi_bridge_isolation`/`steal` scenarios and whether the pool *composition/ordering* drifted (the `steal` failure expected bot `…565730`, got `…409515`). Next session should: (a) run one failing multi-bridge scenario with per-bot allocation tracing, (b) compare the expected-vs-actual bot IDs against the current pool, (c) if the pool checks out, treat it as a real code gap and bisect against the last known-green nightly commit.
Author
Collaborator

Root-caused: infra-induced flakiness in the live suite, not a bridge regression

Investigated with clean-tree builds (git archive, per the #123 rule) on a quiet forgejo-runner. Evidence:

1. The code under test is unchanged since the last green nightly. The only post-green puppet.rs commits are two recovery fixes (6a3ac86, cf82850) that predate the scenarios exercising them, plus an additive read-only guild_footprint() for #94 — none touch allocation/audio logic. steal_repromotion.rs and multi_bridge_isolation.rs and their observers/actors (ConnCountProbe, DiscordListener, MatrixSpeaker) are byte-identical to when they passed. 48/48 hermetic puppet-allocation tests pass on master.

2. The "green" runs in the API history were workflow_dispatch → default smoke_open_close only. The last green scheduled full run predates the cluster's scenarios; the full multi-channel/recovery/enc set has essentially never passed a scheduled nightly since it was added ~07-11. The early 06:00 reds were apt-daily contention (already addressed by the 08:30 move).

3. Every cluster scenario passes standalone on a clean quiet host. Individually: steal_release_repromotion , multi_bridge_isolation (audio crossed both channels ncc 0.94/0.99, cross-talk absent — the opposite of the reported speaking=0 / zero demux), and in a full --all: external_disconnect_recovery , recovery_no_spare , force_move_recovery .

4. A full --all scored 23 pass / 3 fail / 2 known-fail — and the 3 fails are all infra:

  • steal_release_repromotion + audio_d2m_enc: the bridge logs show a phantom's Matrix membership dropping ~3 s after join (Carol/Alice m.call.member vanishing), collapsing the multi-actor choreography. nether.im was returning intermittent 502s throughout (same 502s produced both #104 known-fails). audio_d2m_enc re-ran with a different ncc (0.253 → 0.500) → non-deterministic.
  • multi_bridge_isolation: the bridge released its puppet and left Discord voice on time (23:04:24, well inside the 60 s deadline) — the harness listener just never observed the leave, i.e. Discord voice-state propagation lag at the tail of a 30-scenario suite churning only 3 shared bots.

The earlier "reproduces on a quiet host" note was almost certainly from an accumulated/frankenbuild tree (the #123 pitfall); a clean-tree build does not reproduce it.

Fixes

  • #125 (fix/124-e2e-flaky-retry): retry a Pass-expected scenario once on transient failure (a real regression fails both attempts; each retry re-sweeps memberships). Unit-tested; live --all validation attached to the PR.
  • Ops guardrail (the actual "red went unnoticed 8 days" gap) deployed to nvb-watch: polls the Actions API and alerts the ops room on a new failing / stale (>30 h) scheduled e2e.yml run, plus e2e:#N status in the daily digest.
  • mgmt_dm_pending_reap: keep KnownFail — it known-failed on a 502 this run, so it is not reliably unexpected-passing (closes the residual question from #100).

Not prod-relevant

The encrypted-D→M / multi-channel / recovery paths are healthy on stable infra; the failures require the homeserver to be flapping 502s or the shared harness bots to be voice-state-rate-limited at the suite tail. No prod change indicated.

## Root-caused: infra-induced flakiness in the live suite, **not** a bridge regression Investigated with clean-tree builds (`git archive`, per the #123 rule) on a **quiet** forgejo-runner. Evidence: **1. The code under test is unchanged since the last green nightly.** The only post-green `puppet.rs` commits are two recovery fixes (`6a3ac86`, `cf82850`) that *predate* the scenarios exercising them, plus an additive read-only `guild_footprint()` for #94 — none touch allocation/audio logic. `steal_repromotion.rs` and `multi_bridge_isolation.rs` and their observers/actors (`ConnCountProbe`, `DiscordListener`, `MatrixSpeaker`) are byte-identical to when they passed. **48/48 hermetic puppet-allocation tests pass on master.** **2. The "green" runs in the API history were `workflow_dispatch` → default `smoke_open_close` only.** The last green scheduled full run predates the cluster's scenarios; the full multi-channel/recovery/enc set has essentially never passed a scheduled nightly since it was added ~07-11. The early 06:00 reds were apt-daily contention (already addressed by the 08:30 move). **3. Every cluster scenario passes standalone on a clean quiet host.** Individually: `steal_release_repromotion` ✅, `multi_bridge_isolation` ✅ (audio crossed both channels ncc 0.94/0.99, cross-talk absent — the opposite of the reported `speaking=0 / zero demux`), and in a full `--all`: `external_disconnect_recovery` ✅, `recovery_no_spare` ✅, `force_move_recovery` ✅. **4. A full `--all` scored 23 pass / 3 fail / 2 known-fail — and the 3 fails are all infra:** - `steal_release_repromotion` + `audio_d2m_enc`: the bridge logs show a phantom's Matrix **membership dropping ~3 s after join** (Carol/Alice `m.call.member` vanishing), collapsing the multi-actor choreography. nether.im was returning intermittent **502s** throughout (same 502s produced both `#104` known-fails). `audio_d2m_enc` re-ran with a *different* ncc (0.253 → 0.500) → non-deterministic. - `multi_bridge_isolation`: the bridge released its puppet and left Discord voice **on time** (23:04:24, well inside the 60 s deadline) — the harness listener just never observed the leave, i.e. **Discord voice-state propagation lag** at the tail of a 30-scenario suite churning only 3 shared bots. The earlier "reproduces on a quiet host" note was almost certainly from an accumulated/frankenbuild tree (the #123 pitfall); a clean-tree build does not reproduce it. ## Fixes - **#125** (`fix/124-e2e-flaky-retry`): retry a Pass-expected scenario once on transient failure (a real regression fails both attempts; each retry re-sweeps memberships). Unit-tested; live `--all` validation attached to the PR. - **Ops guardrail (the actual "red went unnoticed 8 days" gap)** deployed to `nvb-watch`: polls the Actions API and alerts the ops room on a new failing / stale (>30 h) scheduled `e2e.yml` run, plus `e2e:#N status` in the daily digest. - `mgmt_dm_pending_reap`: **keep** `KnownFail` — it known-failed on a 502 this run, so it is *not* reliably unexpected-passing (closes the residual question from #100). ## Not prod-relevant The encrypted-D→M / multi-channel / recovery paths are healthy on stable infra; the failures require the homeserver to be flapping 502s or the shared harness bots to be voice-state-rate-limited at the suite tail. No prod change indicated.
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#124
No description provided.