diff --git a/AGENTS.md b/AGENTS.md index c1238bd..3f9e5b1 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -226,3 +226,4 @@ Context: 0.16.x proved that queue tweaks and static calibration cannot guarantee - 2026-05-01: Release identity cleanup: bumped the patched build to clean semver `0.17.1`; probe attribution now prints `client_version`/`server_version` separately from `client_revision`/`server_revision` and refuses old `client_full_version` output. - 2026-05-01: 0.17.1 mirrored probe failed with video about `1.18-1.31s` behind audio and 761 planner video freezes. Root cause candidate: the client rebaser forced independent camera/mic pipelines onto one first-packet capture base, so a later-starting camera path was timestamped too early and looked permanently behind audio. Patch 0.17.2 anchors each stream to the shared monotonic clock at its own first packet time. - 2026-05-02: 0.17.2 mirrored probe and Google Meet test showed major improvement but persistent sub-second late video. Root cause follow-up: the temporary `+350ms` factory MJPEG video playout offset matched the observed browser skew and also made the server skew guard freeze video against its own offset. Patch 0.17.3 restores factory video offset to `0ms`, migrates untouched `+350ms` install/calibration defaults back to `0ms`, and makes the skew guard offset-aware for intentional site calibration. +- 2026-05-02: 0.17.3 Google Meet manual test improved to roughly sub-second/near-quarter-second lip sync, but the mirrored analyzer could not pair pulses and the user still heard choppy background audio. Client logs showed Pulse microphone packets arriving unevenly with ages around `90-240ms`; patch 0.17.4 lowers Pulse mic `buffer-time`/`latency-time`, bounds the mic queue/appsink, and keeps mirrored-probe after-run planner diagnostics even when analysis fails. diff --git a/Cargo.lock b/Cargo.lock index bf80114..8e43c47 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1652,7 +1652,7 @@ checksum = "09edd9e8b54e49e587e4f6295a7d29c3ea94d469cb40ab8ca70b288248a81db2" [[package]] name = "lesavka_client" -version = "0.17.3" +version = "0.17.4" dependencies = [ "anyhow", "async-stream", @@ -1686,7 +1686,7 @@ dependencies = [ [[package]] name = "lesavka_common" -version = "0.17.3" +version = "0.17.4" dependencies = [ "anyhow", "base64", @@ -1698,7 +1698,7 @@ dependencies = [ [[package]] name = "lesavka_server" -version = "0.17.3" +version = "0.17.4" dependencies = [ "anyhow", "base64", diff --git a/client/Cargo.toml b/client/Cargo.toml index 7060715..b1cafe1 100644 --- a/client/Cargo.toml +++ b/client/Cargo.toml @@ -4,7 +4,7 @@ path = "src/main.rs" [package] name = "lesavka_client" -version = "0.17.3" +version = "0.17.4" edition = "2024" [dependencies] diff --git a/client/src/input/microphone.rs b/client/src/input/microphone.rs index bca07ec..f03447e 100644 --- a/client/src/input/microphone.rs +++ b/client/src/input/microphone.rs @@ -23,9 +23,16 @@ use tracing::{error, info, trace}; const MIC_GAIN_ENV: &str = "LESAVKA_MIC_GAIN"; const MIC_GAIN_CONTROL_ENV: &str = "LESAVKA_MIC_GAIN_CONTROL"; const MIC_LEVEL_TAP_ENV: &str = "LESAVKA_UPLINK_MIC_LEVEL"; +const MIC_PULSE_BUFFER_TIME_ENV: &str = "LESAVKA_MIC_PULSE_BUFFER_TIME_US"; +const MIC_PULSE_LATENCY_TIME_ENV: &str = "LESAVKA_MIC_PULSE_LATENCY_TIME_US"; const MIC_SAMPLE_RATE: u64 = 48_000; const MIC_CHANNELS: usize = 2; const MIC_SAMPLE_BYTES: usize = std::mem::size_of::(); +const DEFAULT_MIC_PULSE_BUFFER_TIME_US: u64 = 40_000; +const DEFAULT_MIC_PULSE_LATENCY_TIME_US: u64 = 10_000; +const MIC_MAIN_QUEUE_MAX_BUFFERS: u32 = 8; +const MIC_MAIN_QUEUE_MAX_TIME_NS: u64 = 80_000_000; +const MIC_APPSINK_MAX_BUFFERS: u32 = 8; pub struct MicrophoneCapture { #[allow(dead_code)] // kept alive to hold PLAYING state @@ -201,14 +208,20 @@ impl MicrophoneCapture { } fn pulse_source_desc(source: Option<&str>) -> String { + let buffer_time_us = mic_pulse_buffer_time_us(); + let latency_time_us = mic_pulse_latency_time_us().min(buffer_time_us); match source { Some(source) if !source.trim().is_empty() => { format!( - "pulsesrc device={} do-timestamp=true", + "pulsesrc device={} do-timestamp=true buffer-time={buffer_time_us} latency-time={latency_time_us}", escape(source.to_string().into()) ) } - _ => "pulsesrc do-timestamp=true".to_string(), + _ => { + format!( + "pulsesrc do-timestamp=true buffer-time={buffer_time_us} latency-time={latency_time_us}" + ) + } } } @@ -283,9 +296,9 @@ fn microphone_pipeline_desc(source_desc: &str, gain: f64, level_tap_enabled: boo audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \ volume name=mic_input_gain volume={gain} ! \ tee name=t \ - t. ! queue max-size-buffers=64 leaky=downstream ! \ + t. ! queue max-size-buffers={MIC_MAIN_QUEUE_MAX_BUFFERS} max-size-time={MIC_MAIN_QUEUE_MAX_TIME_NS} leaky=downstream ! \ audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \ - appsink name=asink emit-signals=true max-buffers=50 drop=true \ + appsink name=asink emit-signals=true max-buffers={MIC_APPSINK_MAX_BUFFERS} drop=true \ t. ! queue max-size-buffers=8 leaky=downstream ! \ audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \ appsink name=level_sink emit-signals=false sync=false max-buffers=8 drop=true" @@ -296,8 +309,8 @@ fn microphone_pipeline_desc(source_desc: &str, gain: f64, level_tap_enabled: boo audioconvert ! audioresample ! \ audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \ volume name=mic_input_gain volume={gain} ! \ - queue max-size-buffers=64 leaky=downstream ! \ - appsink name=asink emit-signals=true max-buffers=50 drop=true" + queue max-size-buffers={MIC_MAIN_QUEUE_MAX_BUFFERS} max-size-time={MIC_MAIN_QUEUE_MAX_TIME_NS} leaky=downstream ! \ + appsink name=asink emit-signals=true max-buffers={MIC_APPSINK_MAX_BUFFERS} drop=true" ) } } @@ -330,6 +343,25 @@ fn duration_matches_pcm_payload(reported_us: u64, payload_us: u64) -> bool { reported_us >= lower && reported_us <= upper } +fn mic_pulse_buffer_time_us() -> u64 { + positive_u64_env(MIC_PULSE_BUFFER_TIME_ENV, DEFAULT_MIC_PULSE_BUFFER_TIME_US) +} + +fn mic_pulse_latency_time_us() -> u64 { + positive_u64_env( + MIC_PULSE_LATENCY_TIME_ENV, + DEFAULT_MIC_PULSE_LATENCY_TIME_US, + ) +} + +fn positive_u64_env(name: &str, default_value: u64) -> u64 { + std::env::var(name) + .ok() + .and_then(|value| value.trim().parse::().ok()) + .filter(|value| *value > 0) + .unwrap_or(default_value) +} + /// Detect launcher catalog names that should be opened through Pulse directly. fn looks_like_pulse_source_name(source: &str) -> bool { let source = source.trim(); diff --git a/common/Cargo.toml b/common/Cargo.toml index 2aa6848..872d8bc 100644 --- a/common/Cargo.toml +++ b/common/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "lesavka_common" -version = "0.17.3" +version = "0.17.4" edition = "2024" build = "build.rs" diff --git a/scripts/manual/run_upstream_mirrored_av_sync.sh b/scripts/manual/run_upstream_mirrored_av_sync.sh index 204e8e1..1129786 100755 --- a/scripts/manual/run_upstream_mirrored_av_sync.sh +++ b/scripts/manual/run_upstream_mirrored_av_sync.sh @@ -305,9 +305,18 @@ print_lesavka_versions print_upstream_sync_state "before mirrored run" start_local_stimulus start_real_lesavka_client -run_browser_capture_with_real_driver +run_status=0 +run_browser_capture_with_real_driver || run_status=$? print_upstream_sync_state "after mirrored run" +if ((run_status != 0)); then + echo "==> mirrored probe failed" + echo "artifact_dir: ${ARTIFACT_DIR}" + echo "client_log: ${CLIENT_LOG}" + echo "stimulus_status: ${STIMULUS_STATUS}" + exit "${run_status}" +fi + echo "==> mirrored probe complete" echo "artifact_dir: ${ARTIFACT_DIR}" echo "client_log: ${CLIENT_LOG}" diff --git a/server/Cargo.toml b/server/Cargo.toml index 5fdc735..acd6815 100644 --- a/server/Cargo.toml +++ b/server/Cargo.toml @@ -10,7 +10,7 @@ bench = false [package] name = "lesavka_server" -version = "0.17.3" +version = "0.17.4" edition = "2024" autobins = false diff --git a/testing/tests/client_manual_sync_script_contract.rs b/testing/tests/client_manual_sync_script_contract.rs index 8b00914..a3d8e7a 100644 --- a/testing/tests/client_manual_sync_script_contract.rs +++ b/testing/tests/client_manual_sync_script_contract.rs @@ -106,6 +106,10 @@ fn mirrored_sync_script_uses_real_client_capture_path() { "server_version=", "server_revision=", "combined version+revision", + "run_status=0", + "run_browser_capture_with_real_driver || run_status=$?", + "print_upstream_sync_state \"after mirrored run\"", + "==> mirrored probe failed", ] { assert!( MIRRORED_SYNC_SCRIPT.contains(expected), diff --git a/testing/tests/client_microphone_include_contract.rs b/testing/tests/client_microphone_include_contract.rs index 63647e8..ccf1e8e 100644 --- a/testing/tests/client_microphone_include_contract.rs +++ b/testing/tests/client_microphone_include_contract.rs @@ -86,6 +86,8 @@ exit 0 desc.contains("pulsesrc device=alsa_input.usb-DeskMic_5678-00.analog-stereo"), "expected escaped non-monitor source argument: {desc}" ); + assert!(desc.contains("buffer-time=40000")); + assert!(desc.contains("latency-time=10000")); }); } @@ -96,11 +98,24 @@ exit 0 assert!(MicrophoneCapture::pulse_source_by_substr("anything").is_none()); assert_eq!( MicrophoneCapture::pulse_source_desc(None), - "pulsesrc do-timestamp=true" + "pulsesrc do-timestamp=true buffer-time=40000 latency-time=10000" ); }); } + #[test] + #[serial] + fn pulse_source_desc_allows_low_latency_overrides_with_safe_clamp() { + with_var("LESAVKA_MIC_PULSE_BUFFER_TIME_US", Some("20000"), || { + with_var("LESAVKA_MIC_PULSE_LATENCY_TIME_US", Some("50000"), || { + assert_eq!( + MicrophoneCapture::pulse_source_desc(None), + "pulsesrc do-timestamp=true buffer-time=20000 latency-time=20000" + ); + }); + }); + } + #[test] fn pipewire_source_desc_formats_selected_and_default_sources() { let selected = MicrophoneCapture::pipewire_source_desc(Some("alsa input/Desk Mic")); @@ -149,7 +164,8 @@ JSON gst::init().ok(); let desc = MicrophoneCapture::default_source_desc(); assert!( - desc == "pipewiresrc do-timestamp=true" || desc == "pulsesrc do-timestamp=true", + desc == "pipewiresrc do-timestamp=true" + || desc == "pulsesrc do-timestamp=true buffer-time=40000 latency-time=10000", "default source should stay a simple PipeWire/Pulse source: {desc}" ); } @@ -188,7 +204,11 @@ JSON let without_tap = microphone_pipeline_desc("audiotestsrc is-live=true", 1.0, false); assert!(!without_tap.contains("level_sink")); - assert!(without_tap.contains("queue max-size-buffers=64 leaky=downstream")); + assert!( + without_tap + .contains("queue max-size-buffers=8 max-size-time=80000000 leaky=downstream") + ); + assert!(without_tap.contains("appsink name=asink emit-signals=true max-buffers=8")); } #[test] diff --git a/testing/tests/client_microphone_source_contract.rs b/testing/tests/client_microphone_source_contract.rs index ec03d83..3aa195d 100644 --- a/testing/tests/client_microphone_source_contract.rs +++ b/testing/tests/client_microphone_source_contract.rs @@ -84,6 +84,8 @@ JSON desc.contains("pulsesrc device=alsa_input.usb-Bumblebee_II-00.mono-fallback"), "Pulse catalog source names should route through pulsesrc: {desc}" ); + assert!(desc.contains("buffer-time=40000")); + assert!(desc.contains("latency-time=10000")); }); }); } @@ -96,7 +98,7 @@ JSON with_var("LESAVKA_MIC_DISABLE_PIPEWIRE", Some("1"), || { assert_eq!( MicrophoneCapture::default_source_desc(), - "pulsesrc do-timestamp=true" + "pulsesrc do-timestamp=true buffer-time=40000 latency-time=10000" ); }); });