diff --git a/breadcast-caststream-sys/src/facade.cc b/breadcast-caststream-sys/src/facade.cc index c4eed93..3ec4288 100644 --- a/breadcast-caststream-sys/src/facade.cc +++ b/breadcast-caststream-sys/src/facade.cc @@ -1,6 +1,7 @@ #include "facade.h" #include +#include #include #include #include @@ -101,6 +102,20 @@ struct CastStreamSender { // signal before frame_pump_loop ever observed it. std::atomic frame_chain_broken{false}; + // See BreadcastEnqueueStats in facade.h. Counters are reset by the reading + // call; gauges are overwritten at every enqueue attempt. All relaxed -- + // these are diagnostics, and a torn read across two of them costs nothing + // but a slightly inconsistent log line. + std::atomic enqueue_ok{0}; + std::atomic enqueue_payload_too_large{0}; + std::atomic enqueue_id_span_limit{0}; + std::atomic enqueue_max_duration_in_flight{0}; + std::atomic dropped_non_monotonic{0}; + std::atomic in_flight_frames{0}; + std::atomic in_flight_ms{0}; + std::atomic max_in_flight_ms{0}; + std::atomic round_trip_time_ms{0}; + // The caller's own user_data + callbacks, as passed to `_create`. Not // called directly -- session.h/message_port_bridge.h are instead given // trampolines below (with `this` as their user_data) so this struct can @@ -304,6 +319,7 @@ int32_t breadcast_caststream_sender_enqueue_frame(CastStreamSender* sender, if (sender->have_last_capture_time && capture_time_us <= sender->last_capture_time_us) { sender->frame_chain_broken.store(true, std::memory_order_relaxed); + sender->dropped_non_monotonic.fetch_add(1, std::memory_order_relaxed); return; } @@ -339,14 +355,68 @@ int32_t breadcast_caststream_sender_enqueue_frame(CastStreamSender* sender, // is flag the drop so the next frame comes in clean -- see // `frame_chain_broken`'s doc comment on why that matters here, not just // for the encoder's bitrate. - if (video_sender->EnqueueFrame(frame) != Sender::OK) { - sender->frame_chain_broken.store(true, std::memory_order_relaxed); + // Sampled *before* the enqueue attempt, so these describe the state the + // Sender used to make its accept/reject decision below rather than the + // state after it. See BreadcastEnqueueStats in facade.h. + const auto to_ms = [](Clock::duration d) { + return static_cast( + std::chrono::duration_cast(d).count()); + }; + sender->in_flight_frames.store( + static_cast(video_sender->GetInFlightFrameCount()), + std::memory_order_relaxed); + sender->in_flight_ms.store( + to_ms(video_sender->GetInFlightMediaDuration(rtp_timestamp)), + std::memory_order_relaxed); + sender->max_in_flight_ms.store( + to_ms(video_sender->GetMaxInFlightMediaDuration()), + std::memory_order_relaxed); + sender->round_trip_time_ms.store( + to_ms(video_sender->GetCurrentRoundTripTime()), + std::memory_order_relaxed); + + switch (video_sender->EnqueueFrame(frame)) { + case Sender::OK: + sender->enqueue_ok.fetch_add(1, std::memory_order_relaxed); + break; + case Sender::PAYLOAD_TOO_LARGE: + sender->enqueue_payload_too_large.fetch_add(1, std::memory_order_relaxed); + sender->frame_chain_broken.store(true, std::memory_order_relaxed); + break; + case Sender::REACHED_ID_SPAN_LIMIT: + sender->enqueue_id_span_limit.fetch_add(1, std::memory_order_relaxed); + sender->frame_chain_broken.store(true, std::memory_order_relaxed); + break; + case Sender::MAX_DURATION_IN_FLIGHT: + sender->enqueue_max_duration_in_flight.fetch_add(1, std::memory_order_relaxed); + sender->frame_chain_broken.store(true, std::memory_order_relaxed); + break; } }); return 0; } +void breadcast_caststream_sender_take_stats(CastStreamSender* sender, + BreadcastEnqueueStats* out) { + if (!sender || !out) { + return; + } + out->enqueue_ok = sender->enqueue_ok.exchange(0, std::memory_order_relaxed); + out->enqueue_payload_too_large = + sender->enqueue_payload_too_large.exchange(0, std::memory_order_relaxed); + out->enqueue_id_span_limit = + sender->enqueue_id_span_limit.exchange(0, std::memory_order_relaxed); + out->enqueue_max_duration_in_flight = + sender->enqueue_max_duration_in_flight.exchange(0, std::memory_order_relaxed); + out->dropped_non_monotonic = + sender->dropped_non_monotonic.exchange(0, std::memory_order_relaxed); + out->in_flight_frames = sender->in_flight_frames.load(std::memory_order_relaxed); + out->in_flight_ms = sender->in_flight_ms.load(std::memory_order_relaxed); + out->max_in_flight_ms = sender->max_in_flight_ms.load(std::memory_order_relaxed); + out->round_trip_time_ms = sender->round_trip_time_ms.load(std::memory_order_relaxed); +} + int32_t breadcast_caststream_sender_needs_key_frame(CastStreamSender* sender) { return sender->needs_key_frame.load(std::memory_order_relaxed) ? 1 : 0; } diff --git a/breadcast-caststream-sys/src/facade.h b/breadcast-caststream-sys/src/facade.h index f472d24..8411721 100644 --- a/breadcast-caststream-sys/src/facade.h +++ b/breadcast-caststream-sys/src/facade.h @@ -103,6 +103,59 @@ int32_t breadcast_caststream_sender_enqueue_frame(CastStreamSender* sender, int32_t is_key_frame, int64_t capture_time_us); +// A snapshot of why frames are (or aren't) making it into the Sender. +// +// The `enqueue_frame` entry point above cannot report this: it returns as +// soon as the frame is *posted* to openscreen's TaskRunner, long before +// Sender::EnqueueFrame actually runs and decides. So a caller watching only +// its return value sees a 100% success rate even while every frame is being +// rejected downstream -- which is exactly the blind spot that made a +// multi-second picture freeze look, from the sender's own counters, like a +// perfectly healthy 30fps stream. +// +// The four `enqueue_*` counters are cumulative-since-last-read: reading +// them resets them to zero, so a caller polling once a second gets per-second +// rates directly. The remaining fields are instantaneous gauges, sampled on +// the TaskRunner thread at the moment of the most recent enqueue attempt. +typedef struct BreadcastEnqueueStats { + // Sender::EnqueueFrame returned OK -- the frame is genuinely in flight. + int32_t enqueue_ok; + // Sender::PAYLOAD_TOO_LARGE -- the encoded access unit needs more RTP + // packets than the packetizer allows. + int32_t enqueue_payload_too_large; + // Sender::REACHED_ID_SPAN_LIMIT -- more than kMaxUnackedFrames (120) + // frames have gone unacknowledged. + int32_t enqueue_id_span_limit; + // Sender::MAX_DURATION_IN_FLIGHT -- the in-flight media window + // (see `in_flight_ms`/`max_in_flight_ms`) is full. The expected symptom + // of the receiver's acknowledgements stalling. + int32_t enqueue_max_duration_in_flight; + // Frames dropped by the facade before ever reaching EnqueueFrame, by the + // non-monotonic-capture-time guard in enqueue_frame. + int32_t dropped_non_monotonic; + + // Sender::GetInFlightFrameCount() at the last enqueue attempt. + int32_t in_flight_frames; + // Sender::GetInFlightMediaDuration() at the last enqueue attempt, in ms -- + // i.e. the media timespan between the oldest unacknowledged frame and the + // one being enqueued. Note this is a *timespan*, not a byte count: frame + // size has no bearing on it, so a large key frame is neither more nor less + // likely to be rejected than a small P-frame. + int32_t in_flight_ms; + // Sender::GetMaxInFlightMediaDuration() at the last enqueue attempt, in ms. + // A frame is rejected when `in_flight_ms` would exceed this. openscreen + // computes it as clamp(2*RTT, kMinSenderInFlight, playout_delay/3), so on + // a low-latency LAN it sits at the kMinSenderInFlight floor. + int32_t max_in_flight_ms; + // Sender::GetCurrentRoundTripTime() at the last enqueue attempt, in ms. + int32_t round_trip_time_ms; +} BreadcastEnqueueStats; + +// Fills `out` with the current stats and resets the counters. Safe to call +// from any thread; cheap, non-blocking, lock-free. +void breadcast_caststream_sender_take_stats(CastStreamSender* sender, + BreadcastEnqueueStats* out); + // True (nonzero) if the receiver wants a key frame as soon as possible. // Safe to poll frequently; cheap, non-blocking, lock-free. int32_t breadcast_caststream_sender_needs_key_frame(CastStreamSender* sender); diff --git a/breadcast-caststream-sys/src/lib.rs b/breadcast-caststream-sys/src/lib.rs index cefd9e3..5837002 100644 --- a/breadcast-caststream-sys/src/lib.rs +++ b/breadcast-caststream-sys/src/lib.rs @@ -45,6 +45,29 @@ pub type OnErrorFn = pub type OnPictureLostFn = extern "C" fn(user_data: *mut c_void); +/// Mirrors `BreadcastEnqueueStats` in `facade.h` -- see that struct's doc +/// comment for what each field means and why they exist at all (short +/// version: `sender_enqueue_frame`'s return value reports only that the +/// frame was *posted* to openscreen's TaskRunner, never whether +/// `Sender::EnqueueFrame` subsequently accepted it, so it reads 100% success +/// even while every frame is being rejected). +/// +/// The `enqueue_*`/`dropped_*` fields are counts since the previous +/// `sender_take_stats` call; the rest are instantaneous gauges. +#[repr(C)] +#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)] +pub struct EnqueueStats { + pub enqueue_ok: i32, + pub enqueue_payload_too_large: i32, + pub enqueue_id_span_limit: i32, + pub enqueue_max_duration_in_flight: i32, + pub dropped_non_monotonic: i32, + pub in_flight_frames: i32, + pub in_flight_ms: i32, + pub max_in_flight_ms: i32, + pub round_trip_time_ms: i32, +} + unsafe extern "C" { /// Returns null on failure (e.g. an unparseable `remote_ip`, or the /// local UDP socket failed to bind). @@ -113,6 +136,16 @@ unsafe extern "C" { capture_time_us: i64, ) -> i32; + /// Fills `out` with the current enqueue stats and resets the counters. + /// + /// # Safety + /// `sender` must be live and `out` must be a valid, writable pointer to + /// an `EnqueueStats` for the duration of this call. + pub fn breadcast_caststream_sender_take_stats( + sender: *mut CastStreamSender, + out: *mut EnqueueStats, + ); + /// # Safety /// `sender` must be live. pub fn breadcast_caststream_sender_needs_key_frame(sender: *mut CastStreamSender) -> i32; diff --git a/breadcast-caststream-sys/src/session.cc b/breadcast-caststream-sys/src/session.cc index bde4770..9550582 100644 --- a/breadcast-caststream-sys/src/session.cc +++ b/breadcast-caststream-sys/src/session.cc @@ -39,6 +39,33 @@ using openscreen::cast::VideoStream; // audio-then-video streams collapses to just "index 0 is the video stream." constexpr int kVideoStreamIndex = 0; +// The playout delay breadcast asks the receiver for -- the window between +// capture here and presentation there. Deliberately *not* +// openscreen::cast::kDefaultTargetPlayoutDelay (400ms), because that value +// turned out to be the binding constraint on throughput, not just on latency. +// +// SenderImpl::GetMaxInFlightMediaDuration() computes the sender's send window +// as clamp(2*RTT, kMinSenderInFlight, target_playout_delay/3). At a 400ms +// target that ceiling is 133ms -- about four frames at 30 FPS. Instrumented +// measurement against real hardware (see BreadcastEnqueueStats in facade.h) +// found the round-trip time to a Chromecast over Wi-Fi sitting at 57-145ms, +// i.e. 2*RTT of 114-290ms: consistently *above* that 133ms ceiling. The +// window was therefore pinned at the ceiling and 3-40% of frames were being +// rejected with MAX_DURATION_IN_FLIGHT every second, each one silently +// breaking the H.264 reference chain and freezing the picture until the next +// key frame. +// +// Raising this to 1200ms lifts the ceiling to 400ms, so 2*RTT lands inside +// the clamp and the window tracks measured network conditions the way +// openscreen intended, instead of being capped below one round trip. The cost +// is ~800ms of additional end-to-end latency, which is unnoticeable for +// screen mirroring to a TV and a straight trade against multi-second freezes. +// +// Note this is only the *sender's* half of the fix: it must stay paired with +// the kMinSenderInFlight patch in vendor/openscreen (see PATCHES.md), which +// raises the floor of that same clamp for the moments when RTT dips. +constexpr std::chrono::milliseconds kTargetPlayoutDelay(1200); + VideoStream BuildVideoStream(const VideoParams& params, bool use_android_rtp_hack) { Stream stream; @@ -47,7 +74,7 @@ VideoStream BuildVideoStream(const VideoParams& params, stream.channels = 1; stream.rtp_payload_type = GetPayloadType(VideoCodec::kH264, use_android_rtp_hack); stream.ssrc = GenerateSsrc(/*higher_priority=*/false); - stream.target_delay = openscreen::cast::kDefaultTargetPlayoutDelay; + stream.target_delay = kTargetPlayoutDelay; stream.aes_key = GenerateRandomBytes16(); stream.aes_iv_mask = GenerateRandomBytes16(); stream.receiver_rtcp_event_log = true; diff --git a/breadcast-caststream-sys/vendor/openscreen/PATCHES.md b/breadcast-caststream-sys/vendor/openscreen/PATCHES.md index c25ec95..9c0cf08 100644 --- a/breadcast-caststream-sys/vendor/openscreen/PATCHES.md +++ b/breadcast-caststream-sys/vendor/openscreen/PATCHES.md @@ -62,3 +62,25 @@ There are no release/API-stability guarantees upstream. To update: (pulled in separately via gclient/DEPS in a full Chromium checkout). Reimplemented on `EVP_EncodeBlock`/`EVP_DecodeBlock` from system OpenSSL instead, same public interface. +6. **`cast/streaming/impl/sender_impl.cc`** — raised `kMinSenderInFlight` + from upstream's 66ms to 200ms. This is a behaviour patch, not a + portability one, and is the only one here that changes what goes on the + wire — so unlike the others it should *not* be silently re-applied when + rolling the pin without re-measuring first. + + `GetMaxInFlightMediaDuration()` sizes the sender's send window as + `clamp(2*RTT, kMinSenderInFlight, target_playout_delay/3)`. Upstream's + 66ms floor assumes the RTT is negligible, which holds for Chrome's own + usage but not for breadcast's measured case: instrumenting real + `Sender::EnqueueFrame` result codes (see `BreadcastEnqueueStats` in + `../../src/facade.h`) against a Chromecast over Wi-Fi showed RTT of + 57-145ms and a steady 3-40% of frames per second rejected with + `MAX_DURATION_IN_FLIGHT`. Because breadcast enqueues already-encoded + frames, each such rejection silently breaks the H.264 reference chain + rather than merely dropping a frame, which is what the user-visible + multi-second picture freezes turned out to be. + + Pairs with `kTargetPlayoutDelay` in `../../src/session.cc`, which raises + the *ceiling* of that same clamp (the ceiling, not this floor, was the + binding constraint at 400ms playout delay). Both are needed: this floor + covers RTT dips, that ceiling covers the normal case. diff --git a/breadcast-caststream-sys/vendor/openscreen/cast/streaming/impl/sender_impl.cc b/breadcast-caststream-sys/vendor/openscreen/cast/streaming/impl/sender_impl.cc index 4b08012..f253921 100644 --- a/breadcast-caststream-sys/vendor/openscreen/cast/streaming/impl/sender_impl.cc +++ b/breadcast-caststream-sys/vendor/openscreen/cast/streaming/impl/sender_impl.cc @@ -24,10 +24,18 @@ namespace { // The minimum amount of media the Sender keeps in-flight, regardless of the // measured network round-trip time. This keeps the encoder pipeline flowing on -// low-latency networks (roughly two video frames at 30 FPS). See -// crbug.com/498035450. +// low-latency networks. See crbug.com/498035450. +// +// LOCAL PATCH (breadcast): upstream is 66ms, roughly two video frames at +// 30 FPS. That is only enough when the round-trip time is genuinely +// negligible. Instrumented measurement against real hardware (a Chromecast +// over Wi-Fi) showed RTT swinging between 57ms and 145ms, so a 66ms floor +// leaves the send window narrower than a single round trip -- frames are +// rejected with MAX_DURATION_IN_FLIGHT faster than acknowledgements can +// free the window back up. A 200ms floor is ~6 frames at 30 FPS, enough to +// cover one round trip at the worst observed RTT. See PATCHES.md. constexpr Clock::duration kMinSenderInFlight = - Clock::to_duration(milliseconds(66)); + Clock::to_duration(milliseconds(200)); } // namespace diff --git a/breadcast-core/src/caststream.rs b/breadcast-core/src/caststream.rs index a6c6017..4b778d8 100644 --- a/breadcast-core/src/caststream.rs +++ b/breadcast-core/src/caststream.rs @@ -24,7 +24,7 @@ use breadcast_caststream_sys::{ self as sys, breadcast_caststream_sender_create, breadcast_caststream_sender_destroy, breadcast_caststream_sender_enqueue_frame, breadcast_caststream_sender_estimated_bandwidth_bps, breadcast_caststream_sender_needs_key_frame, breadcast_caststream_sender_negotiate, - breadcast_caststream_sender_on_message, + breadcast_caststream_sender_on_message, breadcast_caststream_sender_take_stats, }; /// The Cast Streaming ("Mirroring") receiver app id, pre-installed on every @@ -236,6 +236,22 @@ impl CastStreamSender { Ok(()) } + /// A snapshot of how the *underlying* `Sender::EnqueueFrame` has been + /// answering, plus its in-flight window gauges. Reading resets the + /// counters, so polling once a second yields per-second rates. + /// + /// [`Self::enqueue_frame`] deliberately cannot report any of this: it + /// returns as soon as the frame is posted to openscreen's TaskRunner, + /// before the real accept/reject happens. Any "frames enqueued per + /// second" figure derived from its return value is therefore a count of + /// *attempts*, and stays pinned at the capture rate even while every + /// frame is being rejected downstream and the picture is frozen. + pub fn enqueue_stats(&self) -> sys::EnqueueStats { + let mut stats = sys::EnqueueStats::default(); + unsafe { breadcast_caststream_sender_take_stats(self.raw, &mut stats) }; + stats + } + /// True if the receiver wants a key frame as soon as possible. Cheap to /// poll frequently (e.g. once per captured frame, before encoding it). pub fn needs_key_frame(&self) -> bool { diff --git a/breadcastd/src/cast_mirror.rs b/breadcastd/src/cast_mirror.rs index 22fcb15..5bb928c 100644 --- a/breadcastd/src/cast_mirror.rs +++ b/breadcastd/src/cast_mirror.rs @@ -373,9 +373,25 @@ fn frame_pump_loop( current_kbps = next_kbps; set_video_bitrate_kbps(encoder, current_kbps); } + // `enqueued_fps` counts *posted* frames, not accepted ones (see + // `CastStreamSender::enqueue_stats`) -- it is the `accepted_fps` + // and `rejected_*` fields below that say whether video is + // actually reaching the receiver. A run where `enqueued_fps` + // holds at 30 while `accepted_fps` drops to 0 is a frozen + // picture, and nothing else logged here would show it. + let stats = sender.enqueue_stats(); tracing::debug!( pulled_fps = pulled_since_log, enqueued_fps = enqueued_since_log, + accepted_fps = stats.enqueue_ok, + rejected_in_flight = stats.enqueue_max_duration_in_flight, + rejected_id_span = stats.enqueue_id_span_limit, + rejected_too_large = stats.enqueue_payload_too_large, + dropped_non_monotonic = stats.dropped_non_monotonic, + in_flight_frames = stats.in_flight_frames, + in_flight_ms = stats.in_flight_ms, + max_in_flight_ms = stats.max_in_flight_ms, + rtt_ms = stats.round_trip_time_ms, bitrate_kbps = current_kbps, estimated_bandwidth_bps = sender.estimated_bandwidth_bps(), "frame pump rate"