diff --git a/core/src/session_types.cpp b/core/src/session_types.cpp index 3db4387..95bfd73 100644 --- a/core/src/session_types.cpp +++ b/core/src/session_types.cpp @@ -234,10 +234,18 @@ bool StallWatchdog::poll(std::chrono::steady_clock::time_point now) // between two recovery attempts, so it is enforced on the gap itself; // that way the promise holds for whatever backoff_ happens to contain, // rather than depending on every earlier growth step having clamped - // correctly. A capped release build on Windows got that one step wrong - // (the ceiling engaged one attempt late, so a single 32s gap slipped - // past the 30s ceiling), which is exactly the kind of drift this - // clamp-at-use makes unrepresentable. + // correctly. + // + // CORRECTION: an earlier version of this comment blamed a Windows + // release build for letting the ceiling engage one attempt late. That + // was wrong, and it is worth recording why rather than quietly + // deleting it. Windows CI was failing, two successive diagnoses blamed + // this arithmetic, and neither fixed anything -- the second produced a + // byte-identical failure. Instrumenting the actual test on the Windows + // runner showed the watchdog was innocent on all three platforms: the + // TEST's loop was miscompiled (see core/tests/test_session.cpp). This + // clamp-at-use is kept on its own merit as defence in depth, not + // because any platform ever got the ceiling wrong. const std::chrono::milliseconds wait = backoff_ < max_backoff_ ? backoff_ : max_backoff_; next_attempt_allowed_ = now + wait; // Double-and-clamp as plain value arithmetic on a single type. This was diff --git a/core/tests/test_session.cpp b/core/tests/test_session.cpp index e2bf809..97481c2 100644 --- a/core/tests/test_session.cpp +++ b/core/tests/test_session.cpp @@ -278,45 +278,81 @@ void testStallWatchdogDoesNotFireWhenNotExpectingFrames() ST_ASSERT(w.poll(unmuted_at + std::chrono::milliseconds(2000))); } +// Every time point below is derived ABSOLUTELY from t0 -- `t0 + +// milliseconds(at_ms)`, with the cursor kept as a plain integer -- rather +// than by accumulating into a steady_clock::time_point local +// (`now += milliseconds(30000)`). That is not a style preference; it is +// load-bearing on Windows. +// +// The MSVC 19.44 (VS 2022 BuildTools 14.44.35207) x64 Release build +// miscompiles the accumulate-then-pass shape inside a fixed-stride loop: +// +// for (int i = 0; i < 6; ++i) { +// ST_ASSERT(!w.poll(now + milliseconds(29999))); +// now += milliseconds(30000); +// ST_ASSERT(w.poll(now)); // <-- gets a STALE `now` +// } +// +// Measured in CI, with the value captured on the callee side of a +// __declspec(noinline) wrapper so it is what actually crossed the call +// boundary: all six iterations passed t0+32000ms -- the value `now` held +// BEFORE the first `+=` -- while the caller's own `now` was correct +// (a checksum of the arguments in the same loop summed to exactly +// 62000+92000+...+212000). The argument was hoisted out of the loop as if +// it were loop-invariant. Linux and macOS pass 62000, 92000, ... 212000 for +// the same source. +// +// The watchdog itself is not implicated: in the same Windows binary, the +// same StallWatchdog, in the same loop, fed the same instants written as +// `t0 + milliseconds(at_ms)` (or even just via a named copy of `now`) +// answers correctly on every iteration. Production is not exposed either -- +// LiveKitSession::Impl::watchdogLoop() calls +// stall_watchdog.poll(std::chrono::steady_clock::now()) with a fresh clock +// read per tick, not a loop-carried local advanced by a constant. +// +// No assertion below is weaker than before: every gap is still checked one +// millisecond on either side of its boundary. void testStallWatchdogBacksOffRatherThanLooping() { const auto t0 = std::chrono::steady_clock::now(); StallWatchdog w(std::chrono::milliseconds(2000), std::chrono::milliseconds(30000)); w.setExpectingFrames(true, t0); + // Milliseconds since t0. A plain integer cursor, advanced explicitly. + long long at_ms = 2000; + // First attempt at the threshold. - auto now = t0 + std::chrono::milliseconds(2000); - ST_ASSERT(w.poll(now)); + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); 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))); + ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(at_ms + 250))); + ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(at_ms + 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)); + at_ms += 2000; + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); 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(!w.poll(t0 + std::chrono::milliseconds(at_ms + 3999))); + at_ms += 4000; + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); 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(!w.poll(t0 + std::chrono::milliseconds(at_ms + 7999))); + at_ms += 8000; + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); 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(!w.poll(t0 + std::chrono::milliseconds(at_ms + 15999))); + at_ms += 16000; + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); ST_ASSERT_EQ(w.attemptsThisStall(), 5); // The backoff is capped: doubling 16000ms would be 32000ms, but it @@ -324,18 +360,18 @@ void testStallWatchdogBacksOffRatherThanLooping() // 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)); + ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(at_ms + 29999))); + at_ms += 30000; + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); } // 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); + w.onFrameDelivered(t0 + std::chrono::milliseconds(at_ms)); 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(!w.poll(t0 + std::chrono::milliseconds(at_ms + 1999))); + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms + 2000))); ST_ASSERT_EQ(w.attemptsThisStall(), 1); } @@ -352,8 +388,10 @@ void testStallWatchdogNeverWaitsLongerThanTheCeiling() StallWatchdog w(std::chrono::milliseconds(1000), std::chrono::milliseconds(5000)); w.setExpectingFrames(true, t0); - auto now = t0 + std::chrono::milliseconds(1000); - ST_ASSERT(w.poll(now)); + // Absolute instants off t0, for the reason spelled out above + // testStallWatchdogBacksOffRatherThanLooping(). + long long at_ms = 1000; + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); // Expected gaps between consecutive attempts: 1000, 2000, 4000, then the // ceiling for good. Each gap is checked on both sides of its boundary, so @@ -361,9 +399,9 @@ void testStallWatchdogNeverWaitsLongerThanTheCeiling() const int expected_gaps[] = {1000, 2000, 4000, 5000, 5000, 5000, 5000}; int attempt = 1; for (int gap : expected_gaps) { - ST_ASSERT(!w.poll(now + std::chrono::milliseconds(gap - 1))); - now += std::chrono::milliseconds(gap); - ST_ASSERT(w.poll(now)); + ST_ASSERT(!w.poll(t0 + std::chrono::milliseconds(at_ms + gap - 1))); + at_ms += gap; + ST_ASSERT(w.poll(t0 + std::chrono::milliseconds(at_ms))); ST_ASSERT_EQ(w.attemptsThisStall(), ++attempt); } }