From 23002bbbfa88f2fa6e090bbf5fa4d37f89c66c03 Mon Sep 17 00:00:00 2001 From: Brad Stein Date: Fri, 1 May 2026 19:48:00 -0300 Subject: [PATCH] media: compensate upstream browser sync path --- AGENTS.md | 4 +- client/src/bin/lesavka-sync-analyze.rs | 11 ++--- client/src/sync_probe/analyze/report.rs | 48 +++++++++++-------- docs/operational-env.md | 2 +- scripts/install/server.sh | 3 +- server/src/calibration.rs | 38 ++++++++++----- .../upstream_media_runtime/tests/config.rs | 2 +- .../tests/server_install_script_contract.rs | 6 +++ 8 files changed, 74 insertions(+), 40 deletions(-) diff --git a/AGENTS.md b/AGENTS.md index de18338..ad48d32 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -212,7 +212,7 @@ Context: 0.16.x proved that queue tweaks and static calibration cannot guarantee - [x] Contract tests for installer defaults and version reporting. - [x] `cargo check -p lesavka_client -p lesavka_server --bins`. - [x] Focused `lesavka_testing` media/runtime contracts. -- [ ] Only after all of the above, run the mirrored browser probe. +- [x] Only after all of the above, run the mirrored browser probe. ### Progress Log - 2026-05-01: Added 0.17 planner defaults (`350ms` target playout, `1000ms` max live lag, `60000ms` startup timeout, `80000us` pair slack), reset MJPEG audio factory offset to `0`, and migrated old `-45ms`, `+720ms`, and `+1260ms` untouched baselines. @@ -220,3 +220,5 @@ Context: 0.16.x proved that queue tweaks and static calibration cannot guarantee - 2026-05-01: Runtime tests green for stale audio drop, stale video drop, audio-master/video-follower freeze, repeated reanchor, paired startup timeout, and planner snapshot basics: `cargo test -p lesavka_server upstream_media_runtime::tests -- --nocapture`. - 2026-05-01: Added `GetUpstreamSync` RPC, `lesavka-relayctl upstream-sync`, launcher diagnostics text, and mirrored-probe before/after planner snapshots so 0.17 probe runs report the exact planner state under test. - 2026-05-01: Validation green: `cargo test -p lesavka_server --lib --bins`, `cargo test -p lesavka_testing`, `cargo test -p lesavka_client --bins --lib`, and targeted installer/RPC/layout contracts. +- 2026-05-01: First installed 0.17.0 mirrored browser probe on client/server commit `3920e0a` failed honestly: planner reported fresh live state (`live_lag_ms=10`, `skew_ms=+20.7`) but browser-observed paired pulses showed audio late by median `+349.1ms`, p95 `429.1ms`, with 6 video freezes/skew drops. Replayed artifact after analyzer hardening now reports `gross_failure` instead of false raw-start `catastrophic_failure`. +- 2026-05-01: Patch follow-up models the observed MJPEG/UVC browser egress delta by defaulting video playout offset to `+350ms` and preserving the 1s freshness ceiling. Raw activity-start evidence is now ignored for verdict/calibration when it disagrees with paired pulses that are already failing directly. diff --git a/client/src/bin/lesavka-sync-analyze.rs b/client/src/bin/lesavka-sync-analyze.rs index 1a70b01..13634c8 100644 --- a/client/src/bin/lesavka-sync-analyze.rs +++ b/client/src/bin/lesavka-sync-analyze.rs @@ -169,12 +169,11 @@ fn format_human_report( .unwrap_or(0.0); let unpaired_video = format_onset_list(&unpaired_video_onsets(report)); let unpaired_audio = format_onset_list(&unpaired_audio_onsets(report)); - let raw_activity_handling = - if report.coded_events && !report.raw_activity_start_confirms_pairs() { - "reported only; ignored for verdict/calibration because it disagrees with coded pairs" - } else { - "used as verdict evidence" - }; + let raw_activity_handling = if report.raw_activity_start_is_verdict_relevant() { + "used as verdict evidence" + } else { + "reported only; ignored for verdict/calibration because it disagrees with paired pulses" + }; format!( "\ A/V sync report for {capture} diff --git a/client/src/sync_probe/analyze/report.rs b/client/src/sync_probe/analyze/report.rs index 9439980..5c55836 100644 --- a/client/src/sync_probe/analyze/report.rs +++ b/client/src/sync_probe/analyze/report.rs @@ -191,7 +191,7 @@ impl SyncAnalysisReport { } let start_median_disagreement_ms = self.activity_start_pair_disagreement_ms(); - if !self.coded_events + if self.raw_activity_start_is_verdict_relevant() && start_median_disagreement_ms.abs() > CALIBRATION_MAX_START_MEDIAN_DISAGREEMENT_MS { return SyncCalibrationRecommendation { @@ -242,19 +242,28 @@ impl SyncAnalysisReport { <= RAW_ACTIVITY_CONFIRMS_PAIR_MAX_DISAGREEMENT_MS } - fn raw_activity_start_is_verdict_relevant(&self) -> bool { - !self.coded_events || self.raw_activity_start_confirms_pairs() + pub fn raw_activity_start_is_verdict_relevant(&self) -> bool { + if self.raw_activity_start_confirms_pairs() { + return true; + } + if self.coded_events || self.paired_event_count < VERDICT_MIN_PAIRED_EVENTS { + return false; + } + // Cadence-only pairing can alias by a whole pulse period and look + // deceptively good. Use raw activity as a guard only when paired + // evidence otherwise appears passable; if paired pulses already fail, + // report that direct failure instead of promoting a noisy raw edge. + percentile_abs(&self.skews_ms, 0.95) <= VERDICT_ACCEPTABLE_P95_ABS_SKEW_MS } fn raw_activity_note(&self) -> String { - if !self.coded_events - || self.activity_start_delta_ms.abs() < VERDICT_CATASTROPHIC_MAX_ABS_SKEW_MS - || self.raw_activity_start_confirms_pairs() + if self.activity_start_delta_ms.abs() < VERDICT_CATASTROPHIC_MAX_ABS_SKEW_MS + || self.raw_activity_start_is_verdict_relevant() { String::new() } else { format!( - "; raw activity start delta {:+.1} ms is reported separately because it disagrees with coded pairs by {:.1} ms", + "; raw activity start delta {:+.1} ms is reported separately because it disagrees with paired pulses by {:.1} ms", self.activity_start_delta_ms, self.activity_start_pair_disagreement_ms().abs() ) @@ -262,11 +271,11 @@ impl SyncAnalysisReport { } fn raw_activity_calibration_note(&self) -> String { - if !self.coded_events || self.raw_activity_start_confirms_pairs() { + if self.raw_activity_start_is_verdict_relevant() { String::new() } else { format!( - "; raw activity start delta {:+.1} ms is not used for calibration because coded pairs disagree by {:.1} ms", + "; raw activity start delta {:+.1} ms is not used for calibration because paired pulses disagree by {:.1} ms", self.activity_start_delta_ms, self.activity_start_pair_disagreement_ms().abs() ) @@ -443,7 +452,7 @@ mod tests { } #[test] - fn calibration_recommendation_rejects_start_delta_that_disagrees_with_pairs() { + fn calibration_recommendation_uses_pairs_when_raw_activity_disagrees() { let report = SyncAnalysisReport { video_event_count: 16, audio_event_count: 16, @@ -465,8 +474,9 @@ mod tests { }; let recommendation = report.calibration_recommendation(); - assert!(!recommendation.ready); - assert!(recommendation.note.contains("disagrees with median skew")); + assert!(recommendation.ready); + assert_eq!(recommendation.recommended_audio_offset_adjust_us, 99_000); + assert!(recommendation.note.contains("paired pulses disagree")); } #[test] @@ -494,7 +504,7 @@ mod tests { let recommendation = report.calibration_recommendation(); assert!(recommendation.ready); assert_eq!(recommendation.recommended_audio_offset_adjust_us, 188_400); - assert!(recommendation.note.contains("coded pairs disagree")); + assert!(recommendation.note.contains("paired pulses disagree")); } #[test] @@ -589,13 +599,13 @@ mod tests { activity_start_delta_ms: 20_000.0, raw_first_video_activity_s: 0.0, raw_first_audio_activity_s: 0.0, - first_skew_ms: 0.0, - last_skew_ms: 0.0, - mean_skew_ms: 0.0, - median_skew_ms: 0.0, - max_abs_skew_ms: 0.0, + first_skew_ms: 900.0, + last_skew_ms: 900.0, + mean_skew_ms: 19_900.0, + median_skew_ms: 19_900.0, + max_abs_skew_ms: 900.0, drift_ms: 0.0, - skews_ms: vec![0.0; 20], + skews_ms: vec![900.0; 20], video_onsets_s: vec![], audio_onsets_s: vec![], paired_events: vec![], diff --git a/docs/operational-env.md b/docs/operational-env.md index bc0adf1..dc58e44 100644 --- a/docs/operational-env.md +++ b/docs/operational-env.md @@ -254,7 +254,7 @@ from `LESAVKA_CLIENT_PKI_SSH_SOURCE` over SSH. Runtime clients require the insta | `LESAVKA_UPSTREAM_STARTUP_TIMEOUT_MS` | server upstream startup guard; paired startup must converge before this timeout or fail visibly, defaults to `60000` | | `LESAVKA_UPSTREAM_STALE_DROP_MS` | server upstream freshness override; late audio/video that miss this budget are dropped instead of silently extending lag, defaults to `80` | | `LESAVKA_UPSTREAM_TIMING_TRACE` | upstream capture/rebase trace override for sync debugging | -| `LESAVKA_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US` | server upstream playout override; shifts webcam-video presentation relative to the shared playout epoch | +| `LESAVKA_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US` | server upstream playout override; shifts webcam-video presentation relative to the shared playout epoch, defaults to `350000` for MJPEG/UVC browser egress compensation | | `LESAVKA_UPLINK_CAMERA_PREVIEW` | client media capture/playback override | | `LESAVKA_UPLINK_MIC_LEVEL` | client media capture/playback override | | `LESAVKA_INSTALL_UVC_CODEC` | installer override; sets the persisted default UVC webcam codec in `/etc/lesavka/server.env` and `/etc/lesavka/uvc.env` | diff --git a/scripts/install/server.sh b/scripts/install/server.sh index 6cfbc98..bbf0bea 100755 --- a/scripts/install/server.sh +++ b/scripts/install/server.sh @@ -15,6 +15,7 @@ INSTALL_SERVER_BIND_ADDR=${LESAVKA_INSTALL_SERVER_BIND_ADDR:-0.0.0.0:50051} LESAVKA_TLS_DIR=${LESAVKA_TLS_DIR:-/etc/lesavka/pki} LESAVKA_CLIENT_BUNDLE=${LESAVKA_CLIENT_BUNDLE:-/etc/lesavka/lesavka-client-pki.tar.gz} DEFAULT_MJPEG_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=0 +DEFAULT_MJPEG_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US=350000 LEGACY_MJPEG_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=-45000 PREVIOUS_MJPEG_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=720000 PREVIOUS_TUNED_MJPEG_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=1260000 @@ -979,7 +980,7 @@ fi printf 'LESAVKA_UPSTREAM_MAX_LIVE_LAG_MS=%s\n' "${LESAVKA_UPSTREAM_MAX_LIVE_LAG_MS:-1000}" printf 'LESAVKA_UPSTREAM_STARTUP_TIMEOUT_MS=%s\n' "${LESAVKA_UPSTREAM_STARTUP_TIMEOUT_MS:-60000}" printf 'LESAVKA_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=%s\n' "$(resolve_upstream_audio_playout_offset_us)" - printf 'LESAVKA_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US=%s\n' "${LESAVKA_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US:-0}" + printf 'LESAVKA_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US=%s\n' "${LESAVKA_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US:-$DEFAULT_MJPEG_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US}" printf 'LESAVKA_UPSTREAM_PAIR_SLACK_US=%s\n' "${LESAVKA_UPSTREAM_PAIR_SLACK_US:-80000}" printf 'LESAVKA_UPSTREAM_STALE_DROP_MS=%s\n' "${LESAVKA_UPSTREAM_STALE_DROP_MS:-80}" printf 'LESAVKA_SERVER_BIND_ADDR=%s\n' "${INSTALL_SERVER_BIND_ADDR}" diff --git a/server/src/calibration.rs b/server/src/calibration.rs index fe1f2c6..b866dea 100644 --- a/server/src/calibration.rs +++ b/server/src/calibration.rs @@ -10,10 +10,11 @@ use lesavka_common::lesavka::{ use crate::upstream_media_runtime::UpstreamMediaRuntime; pub const FACTORY_MJPEG_AUDIO_OFFSET_US: i64 = 0; -pub const FACTORY_MJPEG_VIDEO_OFFSET_US: i64 = 0; +pub const FACTORY_MJPEG_VIDEO_OFFSET_US: i64 = 350_000; const LEGACY_FACTORY_MJPEG_AUDIO_OFFSET_US: i64 = -45_000; const PREVIOUS_FACTORY_MJPEG_AUDIO_OFFSET_US: i64 = 720_000; const PREVIOUS_TUNED_MJPEG_AUDIO_OFFSET_US: i64 = 1_260_000; +const PREVIOUS_FACTORY_MJPEG_VIDEO_OFFSET_US: i64 = 0; const PROFILE: &str = "mjpeg"; const FACTORY_CONFIDENCE: &str = "factory"; const OFFSET_LIMIT_US: i64 = 500_000; @@ -249,8 +250,9 @@ fn migrate_legacy_snapshot(mut state: CalibrationSnapshot) -> CalibrationSnapsho | PREVIOUS_TUNED_MJPEG_AUDIO_OFFSET_US ) || clamped_previous_baseline) && state.active_audio_offset_us == state.default_audio_offset_us; - let untouched_legacy_video = state.default_video_offset_us == FACTORY_MJPEG_VIDEO_OFFSET_US - && state.active_video_offset_us == FACTORY_MJPEG_VIDEO_OFFSET_US; + let untouched_legacy_video = state.default_video_offset_us + == PREVIOUS_FACTORY_MJPEG_VIDEO_OFFSET_US + && state.active_video_offset_us == PREVIOUS_FACTORY_MJPEG_VIDEO_OFFSET_US; if state.profile == PROFILE && source_allows_migration && confidence_allows_migration @@ -258,14 +260,19 @@ fn migrate_legacy_snapshot(mut state: CalibrationSnapshot) -> CalibrationSnapsho && untouched_legacy_video { let old_audio_offset_us = state.default_audio_offset_us; + let old_video_offset_us = state.default_video_offset_us; state.default_audio_offset_us = FACTORY_MJPEG_AUDIO_OFFSET_US; state.active_audio_offset_us = FACTORY_MJPEG_AUDIO_OFFSET_US; + state.default_video_offset_us = FACTORY_MJPEG_VIDEO_OFFSET_US; + state.active_video_offset_us = FACTORY_MJPEG_VIDEO_OFFSET_US; state.source = "factory".to_string(); state.confidence = FACTORY_CONFIDENCE.to_string(); state.detail = format!( - "migrated legacy MJPEG upstream A/V baseline from {:+.1}ms to {:+.1}ms", + "migrated legacy MJPEG upstream A/V baseline from audio {:+.1}ms/video {:+.1}ms to audio {:+.1}ms/video {:+.1}ms", old_audio_offset_us as f64 / 1000.0, - FACTORY_MJPEG_AUDIO_OFFSET_US as f64 / 1000.0 + old_video_offset_us as f64 / 1000.0, + FACTORY_MJPEG_AUDIO_OFFSET_US as f64 / 1000.0, + FACTORY_MJPEG_VIDEO_OFFSET_US as f64 / 1000.0 ); touch(&mut state); } @@ -330,7 +337,7 @@ mod tests { || { let state = snapshot_from_env(); assert_eq!(state.default_audio_offset_us, 0); - assert_eq!(state.active_video_offset_us, 0); + assert_eq!(state.active_video_offset_us, 350_000); assert_eq!(state.source, "factory"); }, ); @@ -354,7 +361,7 @@ mod tests { }) .expect("manual adjust applies"); assert_eq!(state.active_audio_offset_us, -5_000); - assert_eq!(runtime.playout_offsets(), (0, -5_000)); + assert_eq!(runtime.playout_offsets(), (350_000, -5_000)); let raw = std::fs::read_to_string(file.path()).expect("persisted calibration"); assert!(raw.contains("active_audio_offset_us=-5000")); }); @@ -439,8 +446,10 @@ mod tests { let state = store.current(); assert_eq!(state.active_audio_offset_us, 0); assert_eq!(state.default_audio_offset_us, 0); + assert_eq!(state.active_video_offset_us, 350_000); + assert_eq!(state.default_video_offset_us, 350_000); assert_eq!(state.source, "factory"); - assert_eq!(runtime.playout_offsets(), (0, 0)); + assert_eq!(runtime.playout_offsets(), (350_000, 0)); assert!(state.detail.contains("migrated legacy MJPEG")); }); } @@ -469,9 +478,11 @@ mod tests { let state = store.current(); assert_eq!(state.active_audio_offset_us, 0); assert_eq!(state.default_audio_offset_us, 0); + assert_eq!(state.active_video_offset_us, 350_000); + assert_eq!(state.default_video_offset_us, 350_000); assert_eq!(state.source, "factory"); - assert_eq!(runtime.playout_offsets(), (0, 0)); - assert!(state.detail.contains("to +0.0ms")); + assert_eq!(runtime.playout_offsets(), (350_000, 0)); + assert!(state.detail.contains("to audio +0.0ms/video +350.0ms")); }); } @@ -498,6 +509,7 @@ mod tests { let store = CalibrationStore::load(runtime.clone()); let state = store.current(); assert_eq!(state.active_audio_offset_us, -45_000); + assert_eq!(state.active_video_offset_us, 0); assert_eq!(state.source, "manual"); assert_eq!(runtime.playout_offsets(), (0, -45_000)); }); @@ -527,7 +539,7 @@ mod tests { .expect("blind estimate"); assert_eq!(blind.source, "blind"); assert!(blind.detail.contains("delivery skew 44.0ms")); - assert_eq!(runtime.playout_offsets(), (-2_000, 5_000)); + assert_eq!(runtime.playout_offsets(), (348_000, 5_000)); let manual = store .apply(CalibrationRequest { @@ -560,6 +572,10 @@ mod tests { factory.active_audio_offset_us, FACTORY_MJPEG_AUDIO_OFFSET_US ); + assert_eq!( + factory.active_video_offset_us, + FACTORY_MJPEG_VIDEO_OFFSET_US + ); assert_eq!(factory.source, "factory"); let restored = store diff --git a/server/src/upstream_media_runtime/tests/config.rs b/server/src/upstream_media_runtime/tests/config.rs index eb2388e..7374124 100644 --- a/server/src/upstream_media_runtime/tests/config.rs +++ b/server/src/upstream_media_runtime/tests/config.rs @@ -74,7 +74,7 @@ fn upstream_playout_offsets_default_to_mjpeg_calibration_and_accept_overrides() ); assert_eq!( super::upstream_playout_offset_us(UpstreamMediaKind::Camera), - 0 + 350_000 ); }); }); diff --git a/testing/tests/server_install_script_contract.rs b/testing/tests/server_install_script_contract.rs index 1855776..c979f93 100644 --- a/testing/tests/server_install_script_contract.rs +++ b/testing/tests/server_install_script_contract.rs @@ -55,6 +55,12 @@ fn server_install_pins_hdmi_camera_and_display_defaults() { assert!(SERVER_INSTALL.contains("${LESAVKA_UPSTREAM_MAX_LIVE_LAG_MS:-1000}")); assert!(SERVER_INSTALL.contains("${LESAVKA_UPSTREAM_STARTUP_TIMEOUT_MS:-60000}")); assert!(SERVER_INSTALL.contains("DEFAULT_MJPEG_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=0")); + assert!(SERVER_INSTALL.contains("DEFAULT_MJPEG_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US=350000")); + assert!( + SERVER_INSTALL.contains( + "${LESAVKA_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US:-$DEFAULT_MJPEG_UPSTREAM_VIDEO_PLAYOUT_OFFSET_US}" + ) + ); assert!(SERVER_INSTALL.contains("LEGACY_MJPEG_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=-45000")); assert!( SERVER_INSTALL.contains("PREVIOUS_TUNED_MJPEG_UPSTREAM_AUDIO_PLAYOUT_OFFSET_US=1260000")