From 33d0b77e0772b6be15d33b7c78546eafdca74198 Mon Sep 17 00:00:00 2001 From: enricobuehler Date: Sat, 15 Aug 2026 18:54:00 +0200 Subject: [PATCH] fix(host): the behind-cadence deadline was the negotiated refresh, so a 60fps game pinned ABR at the floor A 2026-08-15 field session (2560x1440@120 negotiated, game delivering 53-74 fps) collapsed to the 5000 kbps ABR floor and was then held there for 23 minutes - 94% of the session - by our own climb gate: six 'bitrate climb refused - encode is behind cadence' refusals with loss_ppm=0 throughout. The behind test scored every frame's encode work against the negotiated interval (8.33 ms at 120 Hz), but a frame's real budget is the arrival of the next frame that actually exists: a 60 fps source gives every frame twice that. An encoder keeping up with every real frame could be marked behind on most of them, latch behind_score past DEPTH_DEGRADE, and refuse every climb the client asked for. The budget is now the OBSERVED source-delivery period: an EMA over real frames' arrival spacing (repeats excluded - a keepalive re-encode says nothing about the game's rate), clamped to [interval, 4x interval] so a source at or above the negotiated rate keeps bit-for-bit today's deadline and a hitchy source cannot disarm the detector. This also stops the same mis-scoring from spuriously escalating pipeline depth / pipelined retrieve on below-rate sources. And the gate becomes observable - the session above sat at the floor with NO trace of why: - every cadence_degraded transition logs behind_score, escalated, budget/interval/observed-period, rate-limited to one line per 5 s with suppressed flips counted (the score can oscillate +-1 around the latch threshold at frame rate); - the control task's climb-refusal line now carries the live behind_score (new shared AtomicU32), so a field log can finally discriminate 'the budget was wrong' from 'this encoder genuinely cannot keep up'. Gated: clippy --all-targets -D warnings + native::stream tests (25, incl. a new budget test pinning the field case) in the amd64 CI container; fmt clean. --- crates/punktfunk-host/src/native.rs | 6 + crates/punktfunk-host/src/native/control.rs | 5 + crates/punktfunk-host/src/native/stream.rs | 136 +++++++++++++++++++- 3 files changed, 142 insertions(+), 5 deletions(-) diff --git a/crates/punktfunk-host/src/native.rs b/crates/punktfunk-host/src/native.rs index 58929bfb..2017197e 100644 --- a/crates/punktfunk-host/src/native.rs +++ b/crates/punktfunk-host/src/native.rs @@ -1398,6 +1398,10 @@ async fn serve_session( let live_bitrate = Arc::new(AtomicU32::new(welcome.bitrate_kbps)); let encoder_ceiling_kbps = Arc::new(AtomicU32::new(0)); let cadence_degraded = Arc::new(AtomicBool::new(false)); + // The live behind-cadence score behind that flag, so the climb-refusal log line carries its + // evidence (a refusal without the score left a 23-minute floor-pinned field session with no + // trace of why). + let cadence_behind_score = Arc::new(AtomicU32::new(0)); let (probe_tx, probe_rx) = std::sync::mpsc::channel::(); let (probe_result_tx, probe_result_rx) = tokio::sync::mpsc::unbounded_channel::(); // Mode-switch outcome, data plane → control task (same pattern as `probe_result_tx`): the accept @@ -1520,6 +1524,7 @@ async fn serve_session( live_bitrate.clone(), encoder_ceiling_kbps.clone(), cadence_degraded.clone(), + cadence_behind_score.clone(), fec_target_ctl, phase_ctl_control, reconfig_tx, @@ -2103,6 +2108,7 @@ async fn serve_session( live_bitrate, encoder_ceiling_kbps, cadence_degraded, + cadence_behind_score, bitrate_auto, bit_depth, chroma, diff --git a/crates/punktfunk-host/src/native/control.rs b/crates/punktfunk-host/src/native/control.rs index 47e5bfe9..5ad596dd 100644 --- a/crates/punktfunk-host/src/native/control.rs +++ b/crates/punktfunk-host/src/native/control.rs @@ -29,6 +29,7 @@ pub(super) async fn run( live_bitrate: Arc, encoder_ceiling_kbps: Arc, cadence_degraded: Arc, + cadence_behind_score: Arc, fec_target_ctl: Arc, // Phase-locked capture bridge: client PhaseReports land here latest-wins; the encode loop's // controller drains at its own ~1 Hz cadence (design/phase-locked-capture.md). @@ -221,6 +222,10 @@ pub(super) async fn run( tracing::info!( requested_kbps = req.bitrate_kbps, held_kbps = live, + // The refusal's evidence: without it a field log shows WHAT was + // held but never WHY, and a session at the ABR floor is + // indistinguishable from a network problem. + behind_score = cadence_behind_score.load(Ordering::Relaxed), "bitrate climb refused — encode is behind cadence" ); r = live; diff --git a/crates/punktfunk-host/src/native/stream.rs b/crates/punktfunk-host/src/native/stream.rs index 11f3c0d2..2bade60a 100644 --- a/crates/punktfunk-host/src/native/stream.rs +++ b/crates/punktfunk-host/src/native/stream.rs @@ -1314,6 +1314,11 @@ pub(super) struct SessionContext { /// session escalated): while set, the control task refuses bitrate CLIMBS — the network /// isn't the bottleneck, feeding the encoder more bits deepens the miss. pub(super) cadence_degraded: Arc, + /// The live behind-cadence leaky-bucket score, exported so the control task's climb-refusal + /// log line can say WHY (a field session sat at the ABR floor for 23 minutes with no trace + /// of what held it there — the score is the missing discriminator between "the detector's + /// budget is wrong" and "this encoder genuinely can't hold cadence"). + pub(super) cadence_behind_score: Arc, /// The client asked for "Automatic" (`Hello::bitrate_kbps == 0`), so `bitrate_kbps` came from /// the host's codec-aware default. For PyroWave that default is the ~1.6 bpp operating point of /// the NEGOTIATED MODE (`resolve_bitrate_kbps_for`) — a mid-stream mode switch re-resolves it @@ -1588,6 +1593,7 @@ pub(super) fn virtual_stream(ctx: SessionContext, prepared: Option = None; + let mut last_real_cap: Option = None; + // Transition edge + rate limit for the cadence_degraded log lines: around the latch + // threshold the score can cross ±1 every other frame, and 60 lines/s in a field log is + // worse than none. One line per direction per 5 s window; flips swallowed by the limiter + // are counted so an oscillation is still visible in the next line. + let mut was_degraded = false; + let mut last_cadence_log: Option = None; + let mut cadence_flips_suppressed: u32 = 0; + const CADENCE_LOG_MIN_GAP: std::time::Duration = std::time::Duration::from_secs(5); // Second escalation stage (§7 LN3): once depth is maxed (or was never available — Linux), // ask the encoder for pipelined retrieve exactly once. Latched whether it accepts or not. let mut pipeline_asked = false; @@ -2931,6 +2957,20 @@ pub(super) fn virtual_stream(ctx: SessionContext, prepared: Option { frame = f; diag_new += 1; + // Source-cadence estimate (see the declaration above): `t_cap` on the + // frame-driven path is taken right after `wait_arrival` wakes, so real-frame + // deltas track the game's actual delivery spacing. Deltas past 8×interval are + // a gap/hitch (mid-rebuild, alt-tab), not cadence — skipped, not averaged in. + if let Some(prev) = last_real_cap { + let d = t_cap.duration_since(prev).as_nanos() as u64; + if d <= interval.as_nanos() as u64 * 8 { + src_period_ns = Some(match src_period_ns { + Some(e) => (e as i64 + (d as i64 - e as i64) / 8) as u64, + None => d, + }); + } + } + last_real_cap = Some(t_cap); // Phase-locked capture: hold the fresh frame so its ARRIVAL at the client lands a // constant small lead before the client's display latch (§3 hold-then-submit; the // capture slot is newest-wins, so a long hold samples fresher content next tick, @@ -3825,7 +3865,13 @@ pub(super) fn virtual_stream(ctx: SessionContext, prepared: Option DEPTH_WARMUP_FRAMES { - let behind = std::time::Instant::now() >= next; + // The deadline is `next` (post-submit + negotiated interval) stretched by how + // much slower the source actually delivers: encode work only has to beat the + // NEXT REAL FRAME's arrival, not a refresh the game never reaches. For a + // full-rate source the budget equals the interval and this is bit-for-bit the + // old test. + let budget = cadence_budget(interval, src_period_ns); + let behind = std::time::Instant::now() >= next + (budget - interval); behind_score = if behind { (behind_score + 1).min(DEPTH_BEHIND_CAP) } else { @@ -3847,10 +3893,44 @@ pub(super) fn virtual_stream(ctx: SessionContext, prepared: Option= CADENCE_LOG_MIN_GAP) + { + let budget = cadence_budget(interval, src_period_ns); + if degraded { + tracing::info!( + behind_score, + escalated, + budget_us = budget.as_micros() as u64, + interval_us = interval.as_micros() as u64, + src_period_us = + src_period_ns.map(|p| p / 1_000).unwrap_or_default(), + flips_suppressed = cadence_flips_suppressed, + "encode behind cadence — ABR climbs will be refused until it \ + recovers" + ); + } else { + tracing::info!( + behind_score, + flips_suppressed = cadence_flips_suppressed, + "encode cadence recovered — ABR climbs allowed again" + ); + } + last_cadence_log = Some(now); + cadence_flips_suppressed = 0; + } else { + cadence_flips_suppressed += 1; + } + was_degraded = degraded; + } if deescalating { // A requested wind-back completes at the encoder's drained safe point — // poll it (the call is a cheap latch check until then). @@ -4551,6 +4631,24 @@ fn encode_behind_cadence(escalated: bool, behind_score: u32, degrade_at: u32) -> behind_score >= degrade_at || (escalated && behind_score > 0) } +/// The behind-cadence budget for one frame: how long its work may run before the frame counts as +/// "behind". This is the OBSERVED source-delivery period, not the negotiated refresh — encode +/// only has to finish before the next frame that actually exists, and a game delivering 60 fps +/// on a 120 Hz mode gives every frame twice the interval's budget. Clamped below to the +/// negotiated interval (a source faster than the mode is paced down to it, so the interval IS +/// its delivery period) and above to 4× (a hitchy or near-idle source must not disarm the +/// detector — past 4× the mode is so mismatched that the wider budget is moot anyway). +/// No estimate yet (startup, an all-repeat stretch) keeps the plain interval. +fn cadence_budget( + interval: std::time::Duration, + src_period_ns: Option, +) -> std::time::Duration { + match src_period_ns { + Some(p) => std::time::Duration::from_nanos(p).clamp(interval, interval * 4), + None => interval, + } +} + /// Adopt the rate a freshly built pipeline's encoder was actually opened at. /// /// The session's own `bitrate_kbps` is the number every later decision reads — the ABR controller's @@ -4867,6 +4965,34 @@ mod tests { assert!(!encode_behind_cadence(true, 0, DEGRADE)); } + /// The 2026-08-15 field session: negotiated 2560×1440@120 (interval 8333 µs) while the game + /// delivered 53–74 fps (observed period 13.5–18.9 ms). Scoring encode work against the bare + /// interval marked a keeping-up encoder "behind" on most frames, latched `cadence_degraded`, + /// and held the session at the 5000 kbps ABR floor for 23 minutes. The budget must be the + /// observed delivery period — bounded so the two failure edges (an overdriven source, a + /// hitching source) keep the detector honest. + #[test] + fn the_behind_budget_tracks_the_source_not_the_negotiated_refresh() { + let interval = std::time::Duration::from_micros(8333); // 120 Hz mode + let us = |d: std::time::Duration| d.as_micros() as u64; + + // No estimate yet (startup / all-repeat stretch): the plain interval, i.e. the old test. + assert_eq!(cadence_budget(interval, None), interval); + // The field case: a ~60 fps source on the 120 Hz mode gets its real ~2× budget. + assert_eq!( + us(cadence_budget(interval, Some(16_600_000))), + 16_600, + "a 60 fps source's frames have 16.6 ms of real budget" + ); + // A source at (or paced to) the negotiated rate: unchanged from today. + assert_eq!(us(cadence_budget(interval, Some(8_333_000))), 8_333); + // An overdriven source can never SHRINK the budget below the interval — pacing floors + // delivery at the negotiated rate, so a smaller estimate is measurement noise. + assert_eq!(cadence_budget(interval, Some(4_000_000)), interval); + // A hitchy/near-idle source is clamped at 4× — the detector must not be disarmed. + assert_eq!(cadence_budget(interval, Some(500_000_000)), interval * 4); + } + #[test] fn adopting_a_rebuilt_rate_tells_the_client() { let live = Arc::new(AtomicU32::new(20_000)); -- 2.54.0