fix(voice): decode Opus ourselves so one bad frame cannot end a recording - #37
Merged
Conversation
In production a single Opus frame that failed to decode ended an entire recording. `PacketDecoder._decode_packet` let `OpusError: corrupted stream` escape into `PacketRouter.run()`, which logged it, set `reader.error` and called `stop_listening()` in its `finally`. Capture stopped for every speaker at once; the session stayed open, the bot stayed in the channel, and it closed with no audio and no transcription job. A `sessions` row with zero participants was the first anyone knew. Everyone in that channel had been told they were being recorded. The fix is structural rather than defensive: `RecordingSink.wants_opus()` returns `True`, so the library constructs no `discord.opus.Decoder` and never reaches `_decode_packet`. The crash site becomes unreachable through the library's documented public API -- no monkey-patching, no internals, and nothing a version bump can break quietly. Sturnus now decodes, and owns what a failure means: - `domain/stream_health.py` decides what an accumulating run of failures means. Pure stdlib, so the escalation rule can be exercised exhaustively without a voice connection. Escalation is edge-triggered: a stream failing at 50 fps produces one WARNING, not 3000 log lines a minute. - `infrastructure/discord/decoding.py` holds one native decoder per SSRC, mirroring `PacketRouter.decoders`. Opus is stateful, so sharing a decoder between speakers would corrupt both streams. A frame that will not decode costs that frame; the decoder is kept, not reset (measured: it decodes the very next good frame). One rebuild per stream at UNUSABLE, then reporting only. Never a reconnect. - `infrastructure/discord/sink.py` runs the per-frame pipeline on the router thread behind a `write()` that cannot raise -- the invariant that keeps the router thread alive. A discarded frame is lossless with respect to time: `SpeakerWriter` places audio by RTP-derived absolute time, so the gap becomes real silence in exactly the right place and nothing after it shifts. The consent gate keeps its strictness and gains ordering: the synchronous role check runs on every frame, now *before* the decoder, so audio nobody consented to is never turned into PCM and no decoder is created for that speaker. The consent-record check stays on the loop, per frame, behind the same cache. Per-speaker degradation never ends a session. The one exception is total failure: if no stream decodes anything, the session closes with the new `EndReason.DECODE_FAILURE` rather than producing empty files while telling everyone they are recorded -- the original incident in a new costume. Also here, because the incident's real lesson was invisibility: - Frames cross to the event loop as immutable messages through one bounded queue drained by a single task, replacing one `run_coroutine_threadsafe` future per packet. Per-speaker ordering is preserved and a stalled loop drops counted frames instead of accumulating futures. - `listen(sink, after=...)` finally observes capture dying on its own: it is logged, counted, announced in the channel, and resumed once as a guarded last resort. - `OpusNotLoaded` is probed once in `join()` before connecting, so a missing libopus refuses the channel instead of recording hours of silence. - Audio that cannot be attributed to a member is never decoded or written -- no consent record can be checked for an unknown identity -- but it is counted, logged and reported once, with the pause-and-speak-again hint that is what makes Discord send the SSRC mapping. - `/metrics` serves real counters, which is also what turns the deferred FEC decision into a measurement rather than an argument. - CI installs libopus0: owning decoding makes it a test-time dependency, and constructing an `OpusError` at all requires the library loaded. Docs record what production answered, including the spike's open question about whether `source` is populated on a speaker's first packet: it is not, for someone already talking when the bot connects. Refs: docs/verification/voice-receive-spike.md, spec 6.1
Review of the decode work found defects around it, and the ones that matter share the original incident's shape: a failure that happens and nobody hears about it. Closing the decode path while leaving those would have fixed the symptom and kept the disease. **The alarm no longer shares fate with the audio.** `CaptureStopped`, `DecodeTotalFailure` and `StreamStateChanged` travelled through the same bounded queue as frames, so a loop far enough behind to be dropping audio dropped the messages reporting that capture had died -- the alarm discarded by exactly the load that raised it. `CaptureChannel` gives the crossing two lanes: audio is bounded and dropped, control messages are neither bounded nor queued behind it. They need no bound of their own because they are rate-limited at the source, and a flood of them would be a bug in one of those limits rather than a load condition. The audio bound now counts frames submitted and not yet drained, rather than frames sitting in a queue. `call_soon_threadsafe` hands the message to the loop's callback queue, so while the loop is actually stalled -- the only situation the bound exists for -- a bound read off the destination stays at zero while callbacks pile up without limit. **Capture dying is now an end reason of its own.** Nothing armed a close when capture could not be resumed: the session stayed open with nothing arriving and eventually closed as `idle_timeout`, indistinguishable in the database from a meeting where nobody spoke. That row is precisely what let the production incident go unnoticed. `EndReason.CAPTURE_FAILURE` says which one it was, and the guild then waits out `REJOIN_COOLDOWN` before another session may start -- leaving the channel is itself a voice-state update, so rejoining immediately reproduced the fault once per empty session, each one announcing to everyone present that they were being recorded. **A dead stream can no longer report itself healthy.** Only `OpusError` reached `StreamHealth`, so anything else the decoder raised left through the outer guard untouched: the stream stayed HEALTHY with `frames_seen == 0` while every frame of it was thrown away. Whatever the failure, the frame is now counted against that stream, escalates, and counts towards the total-failure verdict. **One failing speaker is no longer read as total failure.** The verdict excluded any stream with fewer than `never_decoded_after` frames, so a single failing speaker while everyone else was briefly quiet ended the recording for the whole channel. Every live stream counts now, including the ones too young to judge: those are evidence something might still work. Declaring total failure by mistake ends a real recording; declining to costs empty files the per-stream errors already shout about. **Nothing on the frame drain awaits the network or the database.** The drain is a single consumer and everything behind it is somebody's audio, so a rate-limited `channel.send` or a slow consent lookup stalled capture for every speaker at once. Notices are posted from tasks of their own. `ConsentCache.verdict` never awaits: a cached entry answers immediately and refreshes beside the drain, and a frame arriving before that speaker's verdict is known is counted and dropped -- audio we cannot vouch for is not recorded, the same rule unattributed audio follows. Serving a stale verdict is bounded by `stale_after` rather than by whether the database happens to be up, because an hour-old verdict authorising a recording is not something to be relaxed about. Also here: - `sturnus_voice_frames_decoded_total` was incremented in the sink and again in the adapter's drain and read about double. All three frame counters now live in the decoder, which is the one place that knows why a frame did not make it -- so `frames_discarded_total` finally carries the `code` label its documentation always claimed, and `code="-4"` is the production corrupted-stream case. - `join()` connects before it builds anything that has to be torn down; a failed `connect` no longer leaves an orphaned drain task behind it. Each fix has a test that fails without it, asserting the outcome rather than the path: that the notification arrives while frames are being dropped, that the session row says `capture_failure` and not `idle_timeout`, that a stream failing on a `MemoryError` stops claiming to be healthy. Refs: spec 5.1, 6.1
The fix stays: the sink returns wants_opus() = True, so the library builds no discord.opus.Decoder and never reaches _decode_packet -- the line whose uncaught OpusError: corrupted stream killed the packet-router thread and stopped capture for every speaker. Sturnus decodes per SSRC, discards a frame that will not decode whatever the decoder raised, and carries on; write() is total; capture that dies ends the session with a reason that says "we could not hear" rather than "nobody spoke", and a join() that fails now does the same instead of leaving a session open with nothing behind it. Everything the branch had grown around that comes out. The ConsentCache rewrite is reverted to main's: it was unrelated to Opus decoding and it turned a database outage into a silent stop -- every frame got a None verdict, nothing recorded, no ERROR, and the session closed as idle_timeout, which is strictly worse than the behaviour it replaced. The two-lane CaptureChannel goes back to a plain asyncio.Queue: the control lane let a message overtake the audio ahead of it, reordering SpeakerStreamEnded in front of the frames it should follow. The rejoin cooldown, the metrics registry and its labels, and StreamHealth's four-state machine with its thresholds, transitions and decoder recycling are gone; what the escalation actually needs is one counter per stream and one threshold, which is what is left. Each removed concern was real, so each is written down in docs/verification/voice-receive-spike.md under Known limitations, with what was observed and why the implementation was not yet worth its surface: the blocking consent lookup on the frame drain, the unbounded audio backlog, the rejoin loop, the absence of any notice to the people in the channel, and the absence of voice metrics. Every failure path that remains is visible -- a WARNING or ERROR someone will read, and a distinguishable end reason on the session row. Tests that only covered the removed machinery are deleted; the rest assert on outcomes, including the incident itself replayed through real libopus.
The two new end reasons close a session and make the bot leave the channel -- and leaving is itself a voice-state update. The handler sees members still present, opens a fresh session row, rejoins with fresh decoders, meets the same fault and closes again: new row, new decoders, same failure, repeat, each cycle announcing to everyone in the channel that they are being recorded. The reduction dropped the cooldown as extra machinery around the decode fix; it was not extra, it was what made those reasons safe to introduce. A session that ends with `capture_failure` or `decode_failure` now holds its guild out of that channel for `REJOIN_COOLDOWN`. While it is in force `on_voice_state_update` returns without counting anyone, which is the specific event the loop fed on. The earlier version of this guard could only lapse inside `on_voice_state_update`, so a guild whose membership did not change again stayed blocked indefinitely -- a transient fault turned into an outage, waiting on the very people the fault was not caused by. Here the tick loop lifts it and then recounts the channel itself through `_sync_participants`, the same path a voice-state update takes. Nobody has to leave and come back for recording to resume, and no operator has to clear anything. `_GuildRecording` carries its `discord.Guild` for that: the tick has no event to read the channel off, and resolving it per tick through the client's cache would silently do nothing whenever the lookup missed. Three log lines separate "waiting out a capture failure" from "nothing is happening": an ERROR naming the reason and the deadline when the guard is armed, an INFO for each voice-state update it suppresses, and an INFO when it lifts. `docs/operations.md` gains the troubleshooting entry that ties them to the `session` rows they explain, and the loop comes out of the spike's *Known limitations*. Both tests assert the outcome on `sessions.opened` rather than the mechanism, and each fails without its half: without the handler guard a second session row opens on the update the bot's own `leave()` produced; without the tick-driven lapse none ever opens again, in a test that dispatches no voice-state update at all after the failure.
Two restructurings of `SturnusClient` met here: main's reconfiguration engine (#35) and this branch's capture pipeline. Main's structure is the trunk; this branch's behaviour is re-expressed inside it. The one decision worth naming: the rejoin guard moved out of `on_voice_state_update` and into `_sync_participants`. On this branch the event handler was the only way a session could start, so the guard was correct there. Under main's engine it no longer is -- `_build`, `_retarget` and `_apply_pending` reach `_sync_participants` too, so a deferred channel change landing on the same tick as a capture failure would have smuggled a session past a guard sitting in the handler. One check at the funnel covers every path. The cooldown is armed between `_return_to_idle` and `_apply_pending`, not after, for the same reason. It lapses in `_tick_guild` after `_reconcile`, so the recount uses the configuration the reconcile just settled on. Also merged: `RecordingService.retarget()` now takes the channel name alongside the id (#34 + #35), and the capture-pipeline fakes follow the `open_session` signature that gained `channel_name`.
Contributor
Author
|
Merged Two restructurings of The rejoin guard moved out of Ordering follows from the same reasoning: the cooldown is armed between Also merged: 575 tests pass, mypy and ruff clean. Verified independently of the test count that no test function from either side was dropped in the merge. Both halves of the guard were mutation-checked: removing the guard fails Two gaps this merge makes visible, neither a regression
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
What was broken
Recording produced zero participants, for two independent reasons:
discord-ext-voice-recvcatches decoder errors inPacketRouter.run(), setsreader.error, callsstop_listening()in itsfinally— and the thread exits. Not that speaker, not that packet: everything.What this branch does
Rather than working around the library or papering over failures with reconnects, it uses the seam the library provides:
wants_opus() = True. The library then never constructs a decoder at all (self._decoder = None if self.sink.wants_opus() else Decoder()) and never reaches_decode_packet. Decoding becomes ours, ininfrastructure/discord/decoding.py, with one decoder per SSRC — so a failure costs exactly the frame it occurred in.The processing is built as its own extension, not as patchwork inside the adapter:
decoding.py— per-SSRC decoder registry; errors stay local to a framesink.py— the sink itself, with no knowledge of sessions or the databasevoice.py— the wiring, unchanged in its role as an adapterAlongside that, late mapping: a stream whose SSRC is not yet known is buffered until the speaking event arrives, instead of being dropped.
Rejoin guard
The bot's own
leave()triggers a voice-state update that makes it rejoin immediately. The guard against that now lapses through the existing tick loop (_tick_all) rather than through channel events — otherwise it stays stuck whenever nothing else happens after the bot leaves.Reproduced rather than merely unit-tested: 16 simulated minutes with no events at all, after which recording resumed; and three simulated hours of persistently failing receive produced twelve attempts, not a hot loop.
Deliberately left alone
on_readyrebuilds every guild's pipeline, and Discord fires it on every gateway reconnect, not just the first start. A reconnect mid-session therefore discards theRecordingServiceholding the open session row, its data key and its writers. Nothing closes it, so the row staysopen, and its audio is only collected by recovery on the next restart.This is already the behaviour on
mainand is not a regression from this branch. What a reconnect should do with a live recording — resume it, close it cleanly, start a new one — is its own decision and belongs in its own PR.