media: tighten microphone capture freshness

This commit is contained in:
Brad Stein 2026-05-02 01:52:41 -03:00
parent 00cc3c9acc
commit a8b9cc2b82
10 changed files with 85 additions and 17 deletions

View File

@ -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: 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-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.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.

6
Cargo.lock generated
View File

@ -1652,7 +1652,7 @@ checksum = "09edd9e8b54e49e587e4f6295a7d29c3ea94d469cb40ab8ca70b288248a81db2"
[[package]] [[package]]
name = "lesavka_client" name = "lesavka_client"
version = "0.17.3" version = "0.17.4"
dependencies = [ dependencies = [
"anyhow", "anyhow",
"async-stream", "async-stream",
@ -1686,7 +1686,7 @@ dependencies = [
[[package]] [[package]]
name = "lesavka_common" name = "lesavka_common"
version = "0.17.3" version = "0.17.4"
dependencies = [ dependencies = [
"anyhow", "anyhow",
"base64", "base64",
@ -1698,7 +1698,7 @@ dependencies = [
[[package]] [[package]]
name = "lesavka_server" name = "lesavka_server"
version = "0.17.3" version = "0.17.4"
dependencies = [ dependencies = [
"anyhow", "anyhow",
"base64", "base64",

View File

@ -4,7 +4,7 @@ path = "src/main.rs"
[package] [package]
name = "lesavka_client" name = "lesavka_client"
version = "0.17.3" version = "0.17.4"
edition = "2024" edition = "2024"
[dependencies] [dependencies]

View File

@ -23,9 +23,16 @@ use tracing::{error, info, trace};
const MIC_GAIN_ENV: &str = "LESAVKA_MIC_GAIN"; const MIC_GAIN_ENV: &str = "LESAVKA_MIC_GAIN";
const MIC_GAIN_CONTROL_ENV: &str = "LESAVKA_MIC_GAIN_CONTROL"; const MIC_GAIN_CONTROL_ENV: &str = "LESAVKA_MIC_GAIN_CONTROL";
const MIC_LEVEL_TAP_ENV: &str = "LESAVKA_UPLINK_MIC_LEVEL"; 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_SAMPLE_RATE: u64 = 48_000;
const MIC_CHANNELS: usize = 2; const MIC_CHANNELS: usize = 2;
const MIC_SAMPLE_BYTES: usize = std::mem::size_of::<i16>(); const MIC_SAMPLE_BYTES: usize = std::mem::size_of::<i16>();
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 { pub struct MicrophoneCapture {
#[allow(dead_code)] // kept alive to hold PLAYING state #[allow(dead_code)] // kept alive to hold PLAYING state
@ -201,14 +208,20 @@ impl MicrophoneCapture {
} }
fn pulse_source_desc(source: Option<&str>) -> String { 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 { match source {
Some(source) if !source.trim().is_empty() => { Some(source) if !source.trim().is_empty() => {
format!( 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()) 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} ! \ audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \
volume name=mic_input_gain volume={gain} ! \ volume name=mic_input_gain volume={gain} ! \
tee name=t \ 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} ! \ 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 ! \ t. ! queue max-size-buffers=8 leaky=downstream ! \
audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \ 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" 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 ! \ audioconvert ! audioresample ! \
audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \ audio/x-raw,format=S16LE,channels={MIC_CHANNELS},rate={MIC_SAMPLE_RATE} ! \
volume name=mic_input_gain volume={gain} ! \ volume name=mic_input_gain volume={gain} ! \
queue max-size-buffers=64 leaky=downstream ! \ 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=50 drop=true" 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 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::<u64>().ok())
.filter(|value| *value > 0)
.unwrap_or(default_value)
}
/// Detect launcher catalog names that should be opened through Pulse directly. /// Detect launcher catalog names that should be opened through Pulse directly.
fn looks_like_pulse_source_name(source: &str) -> bool { fn looks_like_pulse_source_name(source: &str) -> bool {
let source = source.trim(); let source = source.trim();

View File

@ -1,6 +1,6 @@
[package] [package]
name = "lesavka_common" name = "lesavka_common"
version = "0.17.3" version = "0.17.4"
edition = "2024" edition = "2024"
build = "build.rs" build = "build.rs"

View File

@ -305,9 +305,18 @@ print_lesavka_versions
print_upstream_sync_state "before mirrored run" print_upstream_sync_state "before mirrored run"
start_local_stimulus start_local_stimulus
start_real_lesavka_client 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" 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 "==> mirrored probe complete"
echo "artifact_dir: ${ARTIFACT_DIR}" echo "artifact_dir: ${ARTIFACT_DIR}"
echo "client_log: ${CLIENT_LOG}" echo "client_log: ${CLIENT_LOG}"

View File

@ -10,7 +10,7 @@ bench = false
[package] [package]
name = "lesavka_server" name = "lesavka_server"
version = "0.17.3" version = "0.17.4"
edition = "2024" edition = "2024"
autobins = false autobins = false

View File

@ -106,6 +106,10 @@ fn mirrored_sync_script_uses_real_client_capture_path() {
"server_version=", "server_version=",
"server_revision=", "server_revision=",
"combined version+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!( assert!(
MIRRORED_SYNC_SCRIPT.contains(expected), MIRRORED_SYNC_SCRIPT.contains(expected),

View File

@ -86,6 +86,8 @@ exit 0
desc.contains("pulsesrc device=alsa_input.usb-DeskMic_5678-00.analog-stereo"), desc.contains("pulsesrc device=alsa_input.usb-DeskMic_5678-00.analog-stereo"),
"expected escaped non-monitor source argument: {desc}" "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!(MicrophoneCapture::pulse_source_by_substr("anything").is_none());
assert_eq!( assert_eq!(
MicrophoneCapture::pulse_source_desc(None), 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] #[test]
fn pipewire_source_desc_formats_selected_and_default_sources() { fn pipewire_source_desc_formats_selected_and_default_sources() {
let selected = MicrophoneCapture::pipewire_source_desc(Some("alsa input/Desk Mic")); let selected = MicrophoneCapture::pipewire_source_desc(Some("alsa input/Desk Mic"));
@ -149,7 +164,8 @@ JSON
gst::init().ok(); gst::init().ok();
let desc = MicrophoneCapture::default_source_desc(); let desc = MicrophoneCapture::default_source_desc();
assert!( 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}" "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); let without_tap = microphone_pipeline_desc("audiotestsrc is-live=true", 1.0, false);
assert!(!without_tap.contains("level_sink")); 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] #[test]

View File

@ -84,6 +84,8 @@ JSON
desc.contains("pulsesrc device=alsa_input.usb-Bumblebee_II-00.mono-fallback"), desc.contains("pulsesrc device=alsa_input.usb-Bumblebee_II-00.mono-fallback"),
"Pulse catalog source names should route through pulsesrc: {desc}" "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"), || { with_var("LESAVKA_MIC_DISABLE_PIPEWIRE", Some("1"), || {
assert_eq!( assert_eq!(
MicrophoneCapture::default_source_desc(), MicrophoneCapture::default_source_desc(),
"pulsesrc do-timestamp=true" "pulsesrc do-timestamp=true buffer-time=40000 latency-time=10000"
); );
}); });
}); });