Warn when an outbound frame push fails - #128
Open
douglaseel wants to merge 8 commits into
Open
Conversation
ggoldens
approved these changes
Aug 7, 2026
douglaseel
changed the title
douglaseel
changed the title
A push that raises takes the model's output off the wire while the device keeps filling the gap with repeats, so the session looks alive and only the content is missing. Reporting that at debug meant the log said nothing at all: media kept flowing, frames kept arriving, and what the model actually produced never left the runtime. Reproducing it took instrumenting the whole outbound path, because nothing in normal operation pointed at the push. It is a warning now. The first failure carries the traceback and the rest are counted, reported every three hundred frames, so a persistent fault is visible without one line per frame at frame rate. The pacer a layer above already reports its own sink failures this way. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
douglaseel
force-pushed
the
douglas/metadata-round-trip-every-session
branch
from
August 7, 2026 23:23
f03d0be to
0c60acf
Compare
douglaseel
changed the title
The job has been sitting in `pytest -q tests/integration` on the runner with nothing after that line, while the same command finishes locally in under a second. Quiet output and a suite that waits rather than aborts leave nothing to read: the run is reclaimed and the evidence goes with it. So the session names each test as it starts, keeps output unbuffered, streams the runtime's own logging, and arms pytest's faulthandler with a two-minute ceiling and exit-on-timeout — a stall now prints every thread's stack and ends the job instead of holding the runner. This is diagnostic scaffolding on a throwaway branch, not a change to keep. The flags belong on the command rather than in the ini file so that removing them is a single revert. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
The loopback stalls in create_peer_connection on the runner, and the thread dump puts it on the second one: the client's peer connection is created and produces an offer, then the runtime's own call never returns. Everything the loopback does with tracks, negotiation, media and metadata sits after that point, so none of it can be the cause. This creates two peer connections on the shared factory and nothing else, with a log either side of each call so a stall names which one it was. A second test drops the first before creating the second, because "two live at once" and "a second one at all" point at different places. No ICE servers are involved: WebRtcConfig leaves them empty, which the loopback already relied on, so candidate gathering has nothing external to reach and the earlier guess about STUN was wrong. Diagnostic scaffolding on a throwaway branch. Locally both tests finish in 0.14 seconds, so anything they say will be said by the runner. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
The isolation tests never reported: the loopback collects first, stalls, and faulthandler aborts the process, taking everything after it. So they run in their own pytest call ahead of the suite, with a shorter ceiling of their own, and a non-zero exit from them does not stop the loopback from being attempted after. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
Bare peer connections coexist fine on the runner — two of them, and a third after dropping one, all in under a second. So what stalls the loopback is the state the first one carries by the time the second is created, not the count. This adds that state one piece at a time: transceivers, a track on a sender, a data channel, the offer, the offer applied locally. Each step logs before and after, so a stall names the piece that caused it rather than the call it surfaced in — the mistake I made reading the first dump, which pointed at create_peer_connection when that call is fine on its own. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
Every variant that passes hands create_peer_connection an empty observer. The runtime hands it five bound Python callables, and that is the one difference left between the isolation that passes on the runner in under a second and the loopback that stalls in the same call. With callbacks registered the native side can call into Python while the creating thread still holds the GIL. That is the shape of a deadlock, and it fits a stall whose other thread carries no Python frame at all. Same eight steps as the passing variant; step 8 is the only line that differs, so a stall names the observer and nothing else. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
Six rebuilt scenarios pass on the runner in about a second each — two bare peer connections, create-drop-create, a first connection carrying transceivers, a track, a data channel and an applied offer, and a second one whose observer holds the same five callbacks the runtime registers. All four pass in the very invocation where the loopback stalls, so the cause is not the environment, the runner, or the network. Rebuilding it from the outside keeps leaving something out. So the real path is traced instead: a line either side of every call in _negotiate, from creating the connection through applying the answer. The last line printed names the call that never returned, which the thread dump can only point at — it put the stall on create_peer_connection, and that call finishes on its own on the same runner. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
The trace put the stall on the call itself: the last line logged is the one immediately before create_peer_connection, and the only other thread in the dump has a Python thread state with no Python frame — a native thread waiting to enter Python. That is the installed binding holding the GIL across a proxy call. Creating a peer connection is posted to libwebrtc's signalling thread and the caller blocks until it finishes; the stand-in client is gathering candidates at that moment, and each candidate is delivered by that same thread into a Python callback. The creating thread waits for the signalling thread, the signalling thread waits for the GIL, and the creating thread is in native code, so it never yields. The probe drives that collision with nothing else present — a candidate callback parked in Python, then one call — in a subprocess, since a watchdog inside the stuck process would need the GIL the caller holds. It fails against the published wheel and passes against a build that releases the GIL, which is where the fix belongs; the six rebuilt scenarios it replaces all passed, because none of them left a callback in flight. Signed-off-by: Douglas Amorim Ferreira <douglaseel@gmail.com>
Dere-Wah
requested changes
Aug 13, 2026
Comment on lines
65
to
+68
| _install_locked(session) | ||
| session.run("pytest", "-q", "tests/integration", *session.posargs) | ||
| # Diagnostic settings while an integration hang is being chased in CI: -v names | ||
| # each test as it starts, -s keeps output unbuffered so the last line before a | ||
| # stall is real, --log-cli-level streams the runtime's own logging, and the |
Contributor
There was a problem hiding this comment.
This shoudl be removed, it looks temporary
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
3 participants
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.
Why
The outbound drain loop reported a push that raised at
debug, which meant a failing push said nothing at all. The device keeps filling the gap with repeats, so media keeps flowing and frames keep arriving — and what the model produced simply never leaves the runtime. The session looks alive and only the content is missing.That shape is not hypothetical: confirming it took instrumenting the entire path from
emitto the wire, because nothing in normal operation pointed at the push. A failure that removes the model's output while leaving every other signal healthy is not a debug-level event.What Changed
The drain loop warns. The first failure carries its traceback and the rest are counted, reported every three hundred frames, so a persistent fault is visible without emitting a line per frame at frame rate. The pacer a layer above already reports its own sink failures this way, so this brings the two seams in line.
The unit test drives the real loop rather than re-implementing the branch: a track object with no
push_video_frame, one bundle on the queue, and an assertion that the warning arrives withexc_infoattached.What came out of this PR and is not in it
This started as a repeated-session integration test — negotiate a fresh peer and client several times over, round-trip a tagged frame each time — meant to guard the frame-metadata wiring against a regression that only shows up after the first connection.
That test is removed, because it hangs CI. Locally twelve sessions run in 2.4 seconds; in CI the Integration job went from twelve seconds to over two hours with no result. Bounding each session and wrapping the whole test in
asyncio.timeoutdid not help: the run still sat for seven minutes past a ninety-second ceiling, which places the hang somewhere the event loop cannot interrupt — a blocking native call on a thread, or teardown between sessions.The hang is worth more attention than the test was. Repeated negotiate-and-close cycles in one process stalling is runtime behaviour, not test behaviour, and it may well be related to the intermittent metadata failure that prompted all of this — roughly one connection in fifteen returning every frame bare. Both stay open, and I would rather chase the hang with a reproduction than land a test that can burn a runner for two hours.