WZP-P2-T1-S1: Automated drift measurement - New drift_test.rs: DriftTestConfig, DriftResult, run_drift_test() - CLI --drift-test <secs>: sends tone, measures actual vs expected duration - Interpretation tiers: EXCELLENT (<50ms) / GOOD / FAIR / POOR - 2 unit tests: drift math verification, config defaults WZP-P2-T1-S2: Jitter buffer telemetry - JitterStats gains: total_decoded, underruns, overruns, max_depth_seen - JitterBuffer: record_underrun(), record_decode(), reset_stats() - CallDecoder: stats() getter, reset_stats() - JitterTelemetry: periodic tracing::info! logger with configurable interval - 4 unit tests: ingestion tracking, underrun tracking, reset, interval WZP-P2-T1-S3: Parameter sweep - New sweep.rs: SweepConfig, SweepResult, run_local_sweep() - Tests 20 jitter buffer configs (5 target × 4 max depths) locally - CLI --sweep: runs sweep, prints ASCII comparison table - No network needed — pure encoder→decoder pipeline test - 3 unit tests: config defaults, local sweep runs, table formatting 216 tests passing across all crates. Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
294 lines
10 KiB
Rust
294 lines
10 KiB
Rust
//! Automated clock-drift measurement tool.
|
|
//!
|
|
//! Sends N seconds of a known 440 Hz tone through the transport, records
|
|
//! received frame timestamps on the other side, and compares actual received
|
|
//! duration vs expected duration to quantify timing drift and packet loss.
|
|
|
|
use std::time::{Duration, Instant};
|
|
|
|
use tracing::info;
|
|
|
|
use wzp_proto::MediaTransport;
|
|
|
|
use crate::call::{CallConfig, CallDecoder, CallEncoder};
|
|
|
|
const FRAME_SAMPLES: usize = 960; // 20ms @ 48kHz
|
|
const SAMPLE_RATE: u32 = 48_000;
|
|
|
|
/// Configuration for a drift measurement run.
|
|
#[derive(Debug, Clone)]
|
|
pub struct DriftTestConfig {
|
|
/// How many seconds of tone to send.
|
|
pub duration_secs: u32,
|
|
/// Frequency of the test tone (Hz).
|
|
pub tone_freq_hz: f32,
|
|
}
|
|
|
|
impl Default for DriftTestConfig {
|
|
fn default() -> Self {
|
|
Self {
|
|
duration_secs: 10,
|
|
tone_freq_hz: 440.0,
|
|
}
|
|
}
|
|
}
|
|
|
|
/// Results from a drift measurement run.
|
|
#[derive(Debug, Clone)]
|
|
pub struct DriftResult {
|
|
/// Expected duration in milliseconds (`duration_secs * 1000`).
|
|
pub expected_duration_ms: u64,
|
|
/// Actual measured duration in milliseconds (last_recv - first_recv).
|
|
pub actual_duration_ms: u64,
|
|
/// Drift: `actual - expected` (positive = receiver clock ran slow / packets delayed).
|
|
pub drift_ms: i64,
|
|
/// Drift as a percentage of expected duration.
|
|
pub drift_pct: f64,
|
|
/// Total frames sent by the sender.
|
|
pub frames_sent: u64,
|
|
/// Total frames successfully received and decoded.
|
|
pub frames_received: u64,
|
|
/// Packet loss percentage: `(1 - frames_received / frames_sent) * 100`.
|
|
pub loss_pct: f64,
|
|
}
|
|
|
|
impl DriftResult {
|
|
/// Compute a `DriftResult` from raw counters and timestamps.
|
|
pub fn compute(
|
|
expected_duration_ms: u64,
|
|
actual_duration_ms: u64,
|
|
frames_sent: u64,
|
|
frames_received: u64,
|
|
) -> Self {
|
|
let drift_ms = actual_duration_ms as i64 - expected_duration_ms as i64;
|
|
let drift_pct = if expected_duration_ms > 0 {
|
|
drift_ms as f64 / expected_duration_ms as f64 * 100.0
|
|
} else {
|
|
0.0
|
|
};
|
|
let loss_pct = if frames_sent > 0 {
|
|
(1.0 - frames_received as f64 / frames_sent as f64) * 100.0
|
|
} else {
|
|
0.0
|
|
};
|
|
Self {
|
|
expected_duration_ms,
|
|
actual_duration_ms,
|
|
drift_ms,
|
|
drift_pct,
|
|
frames_sent,
|
|
frames_received,
|
|
loss_pct,
|
|
}
|
|
}
|
|
}
|
|
|
|
/// Generate a sine wave frame at a given frequency.
|
|
fn sine_frame(freq_hz: f32, frame_offset: u64) -> Vec<i16> {
|
|
let start = frame_offset * FRAME_SAMPLES as u64;
|
|
(0..FRAME_SAMPLES)
|
|
.map(|i| {
|
|
let t = (start + i as u64) as f32 / SAMPLE_RATE as f32;
|
|
(f32::sin(2.0 * std::f32::consts::PI * freq_hz * t) * 16000.0) as i16
|
|
})
|
|
.collect()
|
|
}
|
|
|
|
/// Run the drift measurement test.
|
|
///
|
|
/// 1. Spawns a send task that encodes `duration_secs` of tone at 20 ms intervals.
|
|
/// 2. Spawns a recv task that counts decoded frames and tracks first/last timestamps.
|
|
/// 3. After the sender finishes, waits 2 seconds for trailing packets.
|
|
/// 4. Computes and returns the `DriftResult`.
|
|
pub async fn run_drift_test(
|
|
transport: &(dyn MediaTransport + Send + Sync),
|
|
config: &DriftTestConfig,
|
|
) -> anyhow::Result<DriftResult> {
|
|
let call_config = CallConfig::default();
|
|
let mut encoder = CallEncoder::new(&call_config);
|
|
let mut decoder = CallDecoder::new(&call_config);
|
|
|
|
let total_frames: u64 = config.duration_secs as u64 * 50; // 50 frames/s at 20 ms
|
|
let frame_duration = Duration::from_millis(20);
|
|
let mut pcm_buf = vec![0i16; FRAME_SAMPLES];
|
|
|
|
let mut frames_sent: u64 = 0;
|
|
let mut frames_received: u64 = 0;
|
|
let mut first_recv_time: Option<Instant> = None;
|
|
let mut last_recv_time: Option<Instant> = None;
|
|
|
|
info!(
|
|
duration_secs = config.duration_secs,
|
|
tone_hz = config.tone_freq_hz,
|
|
total_frames = total_frames,
|
|
"starting drift measurement"
|
|
);
|
|
|
|
let start = Instant::now();
|
|
|
|
// Send + interleaved receive loop (same pattern as echo_test)
|
|
for frame_idx in 0..total_frames {
|
|
// --- send ---
|
|
let pcm = sine_frame(config.tone_freq_hz, frame_idx);
|
|
let packets = encoder.encode_frame(&pcm)?;
|
|
for pkt in &packets {
|
|
transport.send_media(pkt).await?;
|
|
}
|
|
frames_sent += 1;
|
|
|
|
// --- try to receive (short window so we don't block the sender) ---
|
|
let recv_deadline = Instant::now() + Duration::from_millis(5);
|
|
loop {
|
|
if Instant::now() >= recv_deadline {
|
|
break;
|
|
}
|
|
match tokio::time::timeout(Duration::from_millis(2), transport.recv_media()).await {
|
|
Ok(Ok(Some(pkt))) => {
|
|
let is_repair = pkt.header.is_repair;
|
|
decoder.ingest(pkt);
|
|
if !is_repair {
|
|
if let Some(_n) = decoder.decode_next(&mut pcm_buf) {
|
|
let now = Instant::now();
|
|
if first_recv_time.is_none() {
|
|
first_recv_time = Some(now);
|
|
}
|
|
last_recv_time = Some(now);
|
|
frames_received += 1;
|
|
}
|
|
}
|
|
}
|
|
_ => break,
|
|
}
|
|
}
|
|
|
|
if (frame_idx + 1) % 250 == 0 {
|
|
info!(
|
|
frame = frame_idx + 1,
|
|
sent = frames_sent,
|
|
recv = frames_received,
|
|
elapsed = format!("{:.1}s", start.elapsed().as_secs_f64()),
|
|
"drift-test progress"
|
|
);
|
|
}
|
|
|
|
tokio::time::sleep(frame_duration).await;
|
|
}
|
|
|
|
// Drain trailing packets for 2 seconds
|
|
info!("sender done, draining trailing packets for 2s...");
|
|
let drain_deadline = Instant::now() + Duration::from_secs(2);
|
|
while Instant::now() < drain_deadline {
|
|
match tokio::time::timeout(Duration::from_millis(100), transport.recv_media()).await {
|
|
Ok(Ok(Some(pkt))) => {
|
|
let is_repair = pkt.header.is_repair;
|
|
decoder.ingest(pkt);
|
|
if !is_repair {
|
|
if let Some(_n) = decoder.decode_next(&mut pcm_buf) {
|
|
let now = Instant::now();
|
|
if first_recv_time.is_none() {
|
|
first_recv_time = Some(now);
|
|
}
|
|
last_recv_time = Some(now);
|
|
frames_received += 1;
|
|
}
|
|
}
|
|
}
|
|
_ => break,
|
|
}
|
|
}
|
|
|
|
// Compute result
|
|
let expected_duration_ms = config.duration_secs as u64 * 1000;
|
|
let actual_duration_ms = match (first_recv_time, last_recv_time) {
|
|
(Some(first), Some(last)) => last.duration_since(first).as_millis() as u64,
|
|
_ => 0,
|
|
};
|
|
|
|
let result = DriftResult::compute(
|
|
expected_duration_ms,
|
|
actual_duration_ms,
|
|
frames_sent,
|
|
frames_received,
|
|
);
|
|
|
|
info!(
|
|
expected_ms = result.expected_duration_ms,
|
|
actual_ms = result.actual_duration_ms,
|
|
drift_ms = result.drift_ms,
|
|
drift_pct = format!("{:.4}%", result.drift_pct),
|
|
loss_pct = format!("{:.1}%", result.loss_pct),
|
|
"drift measurement complete"
|
|
);
|
|
|
|
Ok(result)
|
|
}
|
|
|
|
/// Pretty-print the drift measurement results.
|
|
pub fn print_drift_report(result: &DriftResult) {
|
|
println!();
|
|
println!("=== Drift Measurement Report ===");
|
|
println!();
|
|
println!("Frames sent: {}", result.frames_sent);
|
|
println!("Frames received: {}", result.frames_received);
|
|
println!("Packet loss: {:.1}%", result.loss_pct);
|
|
println!();
|
|
println!("Expected duration: {} ms", result.expected_duration_ms);
|
|
println!("Actual duration: {} ms", result.actual_duration_ms);
|
|
println!("Drift: {} ms ({:+.4}%)", result.drift_ms, result.drift_pct);
|
|
println!();
|
|
|
|
// Interpretation
|
|
let abs_drift = result.drift_ms.unsigned_abs();
|
|
if result.frames_received == 0 {
|
|
println!("WARNING: No frames received. Transport may be non-functional.");
|
|
} else if abs_drift < 5 {
|
|
println!("Result: EXCELLENT -- drift is negligible (<5 ms).");
|
|
} else if abs_drift < 20 {
|
|
println!("Result: GOOD -- drift is within acceptable bounds (<20 ms).");
|
|
} else if abs_drift < 100 {
|
|
println!("Result: FAIR -- noticeable drift ({} ms). Clock sync may be needed.", abs_drift);
|
|
} else {
|
|
println!("Result: POOR -- significant drift ({} ms). Investigate clock sources.", abs_drift);
|
|
}
|
|
println!();
|
|
}
|
|
|
|
#[cfg(test)]
|
|
mod tests {
|
|
use super::*;
|
|
|
|
#[test]
|
|
fn drift_result_calculations() {
|
|
// Perfect case: no drift, no loss
|
|
let r = DriftResult::compute(10_000, 10_000, 500, 500);
|
|
assert_eq!(r.drift_ms, 0);
|
|
assert!((r.drift_pct - 0.0).abs() < f64::EPSILON);
|
|
assert!((r.loss_pct - 0.0).abs() < f64::EPSILON);
|
|
|
|
// Positive drift (receiver duration longer than expected)
|
|
let r = DriftResult::compute(10_000, 10_050, 500, 490);
|
|
assert_eq!(r.drift_ms, 50);
|
|
assert!((r.drift_pct - 0.5).abs() < 1e-9); // 50/10000 * 100 = 0.5%
|
|
assert!((r.loss_pct - 2.0).abs() < 1e-9); // (1 - 490/500) * 100 = 2.0%
|
|
|
|
// Negative drift (receiver duration shorter than expected)
|
|
let r = DriftResult::compute(10_000, 9_900, 500, 450);
|
|
assert_eq!(r.drift_ms, -100);
|
|
assert!((r.drift_pct - (-1.0)).abs() < 1e-9); // -100/10000 * 100 = -1.0%
|
|
assert!((r.loss_pct - 10.0).abs() < 1e-9); // (1 - 450/500) * 100 = 10.0%
|
|
|
|
// Edge: zero frames sent (avoid division by zero)
|
|
let r = DriftResult::compute(0, 0, 0, 0);
|
|
assert_eq!(r.drift_ms, 0);
|
|
assert!((r.drift_pct - 0.0).abs() < f64::EPSILON);
|
|
assert!((r.loss_pct - 0.0).abs() < f64::EPSILON);
|
|
}
|
|
|
|
#[test]
|
|
fn drift_config_defaults() {
|
|
let cfg = DriftTestConfig::default();
|
|
assert_eq!(cfg.duration_secs, 10);
|
|
assert!((cfg.tone_freq_hz - 440.0).abs() < f32::EPSILON);
|
|
}
|
|
}
|