fix(session): recover stalled video subscriptions with a keyframe-forcing watchdog
Build / macOS (macos-latest) (push) Successful in 1m7s
Build / Linux (ubuntu-24.04) (push) Successful in 1m14s
Build / macOS (macos-latest) (pull_request) Successful in 53s
Build / Linux (ubuntu-24.04) (pull_request) Successful in 1m19s
Build / Windows (windows-latest) (push) Failing after 3m25s
Build / Windows (windows-latest) (pull_request) Failing after 3m0s
Build / macOS (macos-latest) (push) Successful in 1m7s
Build / Linux (ubuntu-24.04) (push) Successful in 1m14s
Build / macOS (macos-latest) (pull_request) Successful in 53s
Build / Linux (ubuntu-24.04) (pull_request) Successful in 1m19s
Build / Windows (windows-latest) (push) Failing after 3m25s
Build / Windows (windows-latest) (pull_request) Failing after 3m0s
Camera sources in the OBS plugin were dropping out at random and never recovering, while the same players stayed healthy in browser talkback. Measured on the live server: every OBS plugin subscriber racked up 862-1099 nackMisses (retransmit requests for packets the SFU had already aged out of its send buffer -- unrecoverable loss) and sat at plis == 2 for a multi-hour session, versus 0/adaptive-PLI for a browser subscriber in the same room. The pinned client-sdk-cpp (1.10.1) exposes no PLI/keyframe-request API at all, so a decoder that lost a frame that way had no way to resync for the rest of the show. Add a stall-recovery watchdog: StallWatchdog (session_types.h/.cpp) is a pure, fake-clock-testable class that decides when a video subscription has gone too long (2000ms, kStallRecoveryTimeout) without a decoded frame reaching OBS. LiveKitSession::Impl polls it from a dedicated thread and, through the existing command queue (never touching the SDK off the worker thread), toggles the publication's setEnabled(false)/ setEnabled(true) -- the one lever this SDK exposes that makes the SFU restart delivery, and a restart always begins with a keyframe. Repeated attempts against the same stall back off exponentially (2s/4s/8s/16s/30s-capped, mirroring the shape of the adapter's own reconnect backoff) so a genuinely gone publisher is retried on a bounded cadence instead of hammered every 2 seconds. A muted, disabled or unsubscribed track, an audio-only source, or a disconnected session never arms the watchdog: new onTrackMuted/onTrackUnmuted handlers suspend and resume its clock, always re-baselining from "now" rather than a stale timestamp, so un-muting after a long legitimate camera-off period cannot read as a multi-minute stall. Each attempt, and eventual recovery, is logged through a new DiagnosticHandler that the OBS adapter maps onto obs_log at the same severities the file already uses for other notable events. Also investigated (not changed): the setVideoQuality(HIGH) pin added for an earlier simulcast-resize bug. The SDK's own docs and the FFI binary's wire-protocol strings show setVideoQuality only bounds spatial/simulcast layer selection (UpdateTrackSettings.quality), never temporal layers or frame rate, which the SFU's own congestion control governs independently -- so this pin is unlikely to be the cause of the packet-loss symptom, and is probably an inert no-op now that publishing is pinned server-side to a single spatial layer (L1T3). Left in place since that is not fully unambiguous from the SDK alone. Full writeup in .stall-recovery-report.md (untracked, not part of this commit). Adds 3 new headless StallWatchdog tests (fires-after-threshold, does- not-fire-when-muted/disabled, backs-off-rather-than-loops) to test_session.cpp; caught a real bug during development where onFrameDelivered() reset the backoff duration but not the next-attempt-allowed timestamp, throttling a just-recovered stream against its own stale backoff. Built and all 6 CTest suites pass (124/124 checks in test_session); also verified clean under ThreadSanitizer with warning counts unchanged from the pre-change baseline. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
+136
-2
@@ -14,8 +14,10 @@ You may obtain a copy of the License at
|
||||
// COVERED headlessly -- the session's own decision-making: the state
|
||||
// machine's transitions (including the publisher-swap and reconnect paths
|
||||
// that motivated this plugin), track selection, frame geometry validation,
|
||||
// and the real connect() failure paths against the real SDK (bad URL,
|
||||
// unreachable host, garbage token).
|
||||
// the stall-recovery watchdog's timing/backoff decisions (StallWatchdog,
|
||||
// driven with a fake clock -- see its own section below), and the real
|
||||
// connect() failure paths against the real SDK (bad URL, unreachable
|
||||
// host, garbage token).
|
||||
//
|
||||
// NOT COVERED here -- anything that needs a LiveKit server to answer:
|
||||
// a successful connect, actual subscription, and actual decoded frames
|
||||
@@ -209,6 +211,134 @@ void testFailureAndRecovery()
|
||||
ST_ASSERT(idle.state() == SessionState::Idle);
|
||||
}
|
||||
|
||||
// ---------------------------------------------------------------------------
|
||||
// StallWatchdog -- the stall-recovery watchdog's pure timing/decision logic.
|
||||
//
|
||||
// This is deliberately driven with an explicit, fake clock (arbitrary
|
||||
// steady_clock::time_points built by hand, never std::chrono::...::now())
|
||||
// rather than real sleeps: every case below needs to be exact about
|
||||
// "1999ms in" vs "2001ms in" and about backoff boundaries, and a test that
|
||||
// actually slept for 30+ seconds to exercise the backoff ceiling would be
|
||||
// exactly the kind of slow, flaky test this project's whole headless-test
|
||||
// philosophy exists to avoid. See StallWatchdog's own comment
|
||||
// (session_types.h) for the measured server evidence this exists to fix.
|
||||
// ---------------------------------------------------------------------------
|
||||
|
||||
void testStallWatchdogFiresAfterThreshold()
|
||||
{
|
||||
const auto t0 = std::chrono::steady_clock::now();
|
||||
StallWatchdog w(std::chrono::milliseconds(2000), std::chrono::milliseconds(30000));
|
||||
|
||||
// Nothing subscribed yet: polling is a no-op, no matter how much time
|
||||
// has "passed" -- an audio-only source or a disconnected session must
|
||||
// never fire.
|
||||
ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(10000)));
|
||||
|
||||
// A track becomes subscribed. Still well under the threshold: quiet.
|
||||
w.setExpectingFrames(true, t0);
|
||||
ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(500)));
|
||||
ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(1999)));
|
||||
|
||||
// No frame ever arrived, and the threshold has now elapsed: fires
|
||||
// exactly once when asked right at/after the boundary.
|
||||
ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(2000)));
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 1);
|
||||
|
||||
// A frame arriving resets the clock -- the far more common case in a
|
||||
// healthy stream, where onFrameDelivered() is called every ~33ms and
|
||||
// poll() (every kWatchdogPollInterval) never sees 2000ms of silence.
|
||||
StallWatchdog healthy(std::chrono::milliseconds(2000), std::chrono::milliseconds(30000));
|
||||
healthy.setExpectingFrames(true, t0);
|
||||
for (int ms = 0; ms <= 5000; ms += 33)
|
||||
healthy.onFrameDelivered(t0 + std::chrono::milliseconds(ms));
|
||||
ST_ASSERT(!healthy.poll(t0 + std::chrono::milliseconds(5010)));
|
||||
ST_ASSERT_EQ(healthy.attemptsThisStall(), 0);
|
||||
}
|
||||
|
||||
void testStallWatchdogDoesNotFireWhenNotExpectingFrames()
|
||||
{
|
||||
const auto t0 = std::chrono::steady_clock::now();
|
||||
StallWatchdog w(std::chrono::milliseconds(2000), std::chrono::milliseconds(30000));
|
||||
|
||||
// A muted (or disabled/unsubscribed) track is expected silence, not a
|
||||
// stall -- setExpectingFrames(false, ...) is exactly what
|
||||
// LiveKitSession::Impl::handleMuteChange (and detachVideo()) call in
|
||||
// that case. It must not fire no matter how long it stays that way.
|
||||
w.setExpectingFrames(false, t0);
|
||||
ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(2000)));
|
||||
ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(60000)));
|
||||
ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(600000)));
|
||||
|
||||
// Un-muting (setExpectingFrames(true, ...)) starts a BRAND NEW grace
|
||||
// period from that moment -- it must not read "was silent for ten
|
||||
// minutes" as "stalled for ten minutes" and fire immediately.
|
||||
const auto unmuted_at = t0 + std::chrono::milliseconds(600000);
|
||||
w.setExpectingFrames(true, unmuted_at);
|
||||
ST_ASSERT(!w.poll(unmuted_at + std::chrono::milliseconds(1999)));
|
||||
ST_ASSERT(w.poll(unmuted_at + std::chrono::milliseconds(2000)));
|
||||
}
|
||||
|
||||
void testStallWatchdogBacksOffRatherThanLooping()
|
||||
{
|
||||
const auto t0 = std::chrono::steady_clock::now();
|
||||
StallWatchdog w(std::chrono::milliseconds(2000), std::chrono::milliseconds(30000));
|
||||
w.setExpectingFrames(true, t0);
|
||||
|
||||
// First attempt at the threshold.
|
||||
auto now = t0 + std::chrono::milliseconds(2000);
|
||||
ST_ASSERT(w.poll(now));
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 1);
|
||||
|
||||
// A genuinely gone publisher: no frame ever comes back. Immediately
|
||||
// asking again (the naive "retry every poll interval forever" a
|
||||
// watchdog without backoff would do) must NOT fire -- that is precisely
|
||||
// the "hammered every 2 seconds forever" this backoff exists to avoid.
|
||||
ST_ASSERT(!w.poll(now + std::chrono::milliseconds(250)));
|
||||
ST_ASSERT(!w.poll(now + std::chrono::milliseconds(1999)));
|
||||
|
||||
// The backoff after attempt 1 is the base timeout (2000ms): the second
|
||||
// attempt is allowed at +2000ms from the first, not before.
|
||||
now += std::chrono::milliseconds(2000);
|
||||
ST_ASSERT(w.poll(now));
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 2);
|
||||
|
||||
// Backoff doubles: the third attempt needs a 4000ms gap, not 2000ms.
|
||||
ST_ASSERT(!w.poll(now + std::chrono::milliseconds(3999)));
|
||||
now += std::chrono::milliseconds(4000);
|
||||
ST_ASSERT(w.poll(now));
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 3);
|
||||
|
||||
// ... and again to 8000ms, and again to 16000ms.
|
||||
ST_ASSERT(!w.poll(now + std::chrono::milliseconds(7999)));
|
||||
now += std::chrono::milliseconds(8000);
|
||||
ST_ASSERT(w.poll(now));
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 4);
|
||||
|
||||
ST_ASSERT(!w.poll(now + std::chrono::milliseconds(15999)));
|
||||
now += std::chrono::milliseconds(16000);
|
||||
ST_ASSERT(w.poll(now));
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 5);
|
||||
|
||||
// The backoff is capped: doubling 16000ms would be 32000ms, but it
|
||||
// never exceeds max_backoff (30000ms) no matter how many attempts have
|
||||
// failed, so a publisher that comes back after an hour is still
|
||||
// retried at a bounded cadence, not abandoned.
|
||||
for (int i = 0; i < 6; ++i) {
|
||||
ST_ASSERT(!w.poll(now + std::chrono::milliseconds(29999)));
|
||||
now += std::chrono::milliseconds(30000);
|
||||
ST_ASSERT(w.poll(now));
|
||||
}
|
||||
|
||||
// A frame finally arrives: the stall is over, and the NEXT one (a fresh
|
||||
// stall, not a continuation) starts back at the base cadence rather
|
||||
// than staying parked at the 30s ceiling forever.
|
||||
w.onFrameDelivered(now);
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 0);
|
||||
ST_ASSERT(!w.poll(now + std::chrono::milliseconds(1999)));
|
||||
ST_ASSERT(w.poll(now + std::chrono::milliseconds(2000)));
|
||||
ST_ASSERT_EQ(w.attemptsThisStall(), 1);
|
||||
}
|
||||
|
||||
// ---------------------------------------------------------------------------
|
||||
// Real SDK, failure paths only (no LiveKit server available headlessly)
|
||||
// ---------------------------------------------------------------------------
|
||||
@@ -335,6 +465,10 @@ int main()
|
||||
testReconnect();
|
||||
testFailureAndRecovery();
|
||||
|
||||
testStallWatchdogFiresAfterThreshold();
|
||||
testStallWatchdogDoesNotFireWhenNotExpectingFrames();
|
||||
testStallWatchdogBacksOffRatherThanLooping();
|
||||
|
||||
LiveKitSession::globalInitialize();
|
||||
testConnectRejectsIncompleteConfig();
|
||||
testConnectToUnreachableServerFailsCleanly();
|
||||
|
||||
Reference in New Issue
Block a user