diff --git a/crates/editor/examples/scrub-benchmark.rs b/crates/editor/examples/scrub-benchmark.rs new file mode 100644 index 0000000000..e89a889945 --- /dev/null +++ b/crates/editor/examples/scrub-benchmark.rs @@ -0,0 +1,227 @@ +use std::{ + path::PathBuf, + sync::mpsc, + time::{Duration, Instant}, +}; + +use cap_editor::{EditorFrameOutput, EditorInstance, FrameLayout}; +use cap_project::XY; + +const FPS: u32 = 60; +const MOUSE_HZ: f64 = 120.0; + +fn arg_value<'a>(args: &'a [String], flag: &str) -> Option<&'a str> { + args.iter() + .position(|arg| arg == flag) + .and_then(|idx| args.get(idx + 1)) + .map(String::as_str) +} + +fn presented_frame(output: &EditorFrameOutput) -> u32 { + match output { + EditorFrameOutput::Rgba(frame) => frame.frame_number, + EditorFrameOutput::Nv12(frame) => frame.frame_number, + #[cfg(target_os = "macos")] + EditorFrameOutput::Surface(frame) => frame.frame_number, + } +} + +struct SweepResult { + requests: usize, + presented: usize, + longest_gap_ms: f64, + settle_ms: f64, +} + +async fn sweep( + editor: &EditorInstance, + frames_rx: &mpsc::Receiver<(Instant, u32)>, + from: u32, + to: u32, + sweep_secs: f64, + resolution: XY, +) -> SweepResult { + while frames_rx.try_recv().is_ok() {} + + let steps = (sweep_secs * MOUSE_HZ).round().max(1.0) as usize; + let interval = Duration::from_secs_f64(1.0 / MOUSE_HZ); + let started = Instant::now(); + let mut presented = Vec::new(); + let mut last_send = started; + let mut after_last_send = 0; + + for step in 0..=steps { + let progress = step as f64 / steps as f64; + let frame = (from as f64 + (to as f64 - from as f64) * progress).round() as u32; + editor + .preview_tx + .send_modify(|value| *value = Some((frame, FPS, resolution))); + last_send = Instant::now(); + after_last_send = presented.len(); + while let Ok(event) = frames_rx.try_recv() { + presented.push(event); + } + if step < steps { + let deadline = started + interval * (step as u32 + 1); + tokio::time::sleep_until(deadline.into()).await; + } + } + + let already_presented = presented[after_last_send..] + .iter() + .find(|(_, frame)| *frame == to) + .map(|(at, _)| *at); + let final_at = match already_presented { + Some(at) => at, + None => loop { + match frames_rx.recv_timeout(Duration::from_secs(10)) { + Ok((at, frame)) => { + presented.push((at, frame)); + if frame == to { + break at; + } + } + Err(_) => panic!("final frame {to} never presented"), + } + }, + }; + let settle_ms = final_at.saturating_duration_since(last_send).as_secs_f64() * 1000.0; + + let during_drag = || presented.iter().filter(|(at, _)| *at <= last_send); + let presented_during_drag = during_drag().count(); + let mut longest_gap = Duration::ZERO; + let mut previous = started; + for (at, _) in during_drag() { + longest_gap = longest_gap.max(at.saturating_duration_since(previous)); + previous = *at; + } + longest_gap = longest_gap.max(last_send.saturating_duration_since(previous)); + + SweepResult { + requests: steps + 1, + presented: presented_during_drag, + longest_gap_ms: longest_gap.as_secs_f64() * 1000.0, + settle_ms, + } +} + +#[tokio::main] +async fn main() { + let args: Vec = std::env::args().collect(); + let recording_path = arg_value(&args, "--recording-path") + .map(PathBuf::from) + .expect("Usage: scrub-benchmark --recording-path [--runs ]"); + let runs = arg_value(&args, "--runs") + .and_then(|value| value.parse::().ok()) + .unwrap_or(3) + .max(1); + let resolution = XY::new(960, 540); + + let (frames_tx, frames_rx) = mpsc::channel::<(Instant, u32)>(); + let editor = EditorInstance::new( + recording_path.clone(), + |_| {}, + Box::new(move |output: EditorFrameOutput, _: FrameLayout| { + let _ = frames_tx.send((Instant::now(), presented_frame(&output))); + }), + None, + ) + .await + .expect("Failed to create editor instance"); + + let timeline_duration = editor + .project_config + .1 + .borrow() + .timeline + .as_ref() + .map(|timeline| timeline.duration()); + let duration = timeline_duration + .unwrap_or_else(|| f64::from(editor.get_total_frames(FPS)) / f64::from(FPS)); + let last_frame = ((duration * FPS as f64).floor() as u32).saturating_sub(2); + assert!( + last_frame > 0, + "the recording is too short to benchmark scrubbing" + ); + + editor + .preview_tx + .send_modify(|value| *value = Some((0, FPS, resolution))); + frames_rx + .recv_timeout(Duration::from_secs(10)) + .expect("first preview frame"); + tokio::time::sleep(Duration::from_millis(500)).await; + + println!("Recording: {}", recording_path.display()); + println!( + "Timeline: {duration:.1}s, preview {}x{}, mouse {MOUSE_HZ} Hz", + resolution.x, resolution.y + ); + + let cases: [(&str, f64, bool); 4] = [ + ("fast drag, whole timeline in 2 s", 2.0, false), + ("fast drag back", 2.0, true), + ("slow drag, whole timeline in 8 s", 8.0, false), + ("slow drag back", 8.0, true), + ]; + for (name, secs, backward) in cases { + let mut results = Vec::new(); + for _ in 0..runs { + let (from, to) = if backward { + (last_frame, 0) + } else { + (0, last_frame) + }; + editor + .preview_tx + .send_modify(|value| *value = Some((from, FPS, resolution))); + tokio::time::sleep(Duration::from_millis(800)).await; + results.push(sweep(&editor, &frames_rx, from, to, secs, resolution).await); + tokio::time::sleep(Duration::from_millis(300)).await; + } + let mean = + |f: fn(&SweepResult) -> f64| results.iter().map(f).sum::() / results.len() as f64; + println!( + "{name:<34} requests={:>4} presented={:>6.1} ({:>5.1}/s) longest_gap={:>7.1}ms settle={:>6.1}ms", + results[0].requests, + mean(|r| r.presented as f64), + mean(|r| r.presented as f64) / secs, + mean(|r| r.longest_gap_ms), + mean(|r| r.settle_ms), + ); + } + + let mut seek_ms = Vec::new(); + let mut seed = 0x2545F4914F6CDD1Du64; + for _ in 0..30 { + seed ^= seed << 13; + seed ^= seed >> 7; + seed ^= seed << 17; + let target = (seed % u64::from(last_frame)) as u32; + while frames_rx.try_recv().is_ok() {} + let sent = Instant::now(); + editor + .preview_tx + .send_modify(|value| *value = Some((target, FPS, resolution))); + loop { + let (at, frame) = frames_rx + .recv_timeout(Duration::from_secs(10)) + .expect("seek target never presented"); + if frame == target { + seek_ms.push(at.saturating_duration_since(sent).as_secs_f64() * 1000.0); + break; + } + } + tokio::time::sleep(Duration::from_millis(400)).await; + } + seek_ms.sort_by(f64::total_cmp); + println!( + "{:<34} p50={:>6.1}ms p90={:>6.1}ms max={:>6.1}ms", + "single random seek (idle)", + seek_ms[seek_ms.len() / 2], + seek_ms[seek_ms.len() * 9 / 10], + seek_ms[seek_ms.len() - 1] + ); + + editor.dispose().await; +} diff --git a/crates/editor/src/editor_instance.rs b/crates/editor/src/editor_instance.rs index ab94eb4661..71ca1fff17 100644 --- a/crates/editor/src/editor_instance.rs +++ b/crates/editor/src/editor_instance.rs @@ -18,6 +18,7 @@ use std::{ Arc, atomic::{AtomicBool, AtomicU64, Ordering}, }, + time::{Duration, Instant}, }; use tokio::sync::{Mutex, watch}; use tokio_util::sync::CancellationToken; @@ -26,6 +27,32 @@ use tracing::warn; pub(super) const PREVIEW_RENDER_MAX_ATTEMPTS: u32 = 3; pub(super) const PREVIEW_RENDER_RETRY_DELAY_MS: u64 = 120; const PREVIEW_CURSOR_CACHE_CAPACITY: usize = 2; +const PREVIEW_SCRUB_FRAME_INTERVAL: Duration = Duration::from_millis(33); + +type PreviewRequest = Option; + +// A scrub sends a new request faster than a seek can decode. Abandoning the +// in-flight frame for every newer request starves the preview until the mouse +// stops, so a newer request only wins while a frame was presented recently. +fn preview_frame_overdue(last_presented: Option) -> bool { + last_presented.is_none_or(|at| at.elapsed() >= PREVIEW_SCRUB_FRAME_INTERVAL) +} + +fn preview_superseded( + preview_rx: &watch::Receiver, + last_presented: Option, +) -> bool { + preview_rx.has_changed().unwrap_or(false) && !preview_frame_overdue(last_presented) +} + +async fn preview_superseded_while_fresh( + mut probe: watch::Receiver, + last_presented: Option, +) { + if probe.changed().await.is_err() || preview_frame_overdue(last_presented) { + std::future::pending::<()>().await; + } +} pub(super) fn cursor_timeline_settings(cursor: &cap_project::CursorConfiguration) -> [u32; 7] { let click_spring = cursor.click_spring_config(); @@ -1006,10 +1033,11 @@ impl EditorInstance { fn spawn_preview_renderer( self: Arc, - mut preview_rx: watch::Receiver)>>, + mut preview_rx: watch::Receiver, ) -> tokio::task::JoinHandle<()> { tokio::spawn(async move { let mut prefetch_cancel_token: Option = None; + let mut last_presented: Option = None; let mut cursor_cache = PreviewCursorCache::default(); let mut project_rx = self.project_config.1.clone(); let mut project = Arc::new(project_rx.borrow_and_update().clone()); @@ -1095,7 +1123,7 @@ impl EditorInstance { tokio::select! { biased; - _ = preview_rx.changed() => { + _ = preview_superseded_while_fresh(preview_rx.clone(), last_presented) => { continue; } @@ -1105,7 +1133,7 @@ impl EditorInstance { true, clip_offsets, ) => { - if preview_rx.has_changed().unwrap_or(false) { + if preview_superseded(&preview_rx, last_presented) { continue; } @@ -1155,7 +1183,10 @@ impl EditorInstance { .unwrap_or_default(); let outgoing_frames = tokio::select! { biased; - _ = preview_rx.changed() => { + _ = preview_superseded_while_fresh( + preview_rx.clone(), + last_presented, + ) => { continue; } frames = async { @@ -1196,7 +1227,7 @@ impl EditorInstance { &outgoing_media.cursor, &project, ); - if preview_rx.has_changed().unwrap_or(false) { + if preview_superseded(&preview_rx, last_presented) { continue; } let outgoing_uniforms = if let Some(cursor_timeline) = @@ -1241,7 +1272,7 @@ impl EditorInstance { None }; - if preview_rx.has_changed().unwrap_or(false) { + if preview_superseded(&preview_rx, last_presented) { continue; } @@ -1250,7 +1281,7 @@ impl EditorInstance { &segment_medias.cursor, &project, ); - if preview_rx.has_changed().unwrap_or(false) { + if preview_superseded(&preview_rx, last_presented) { continue; } @@ -1324,6 +1355,7 @@ impl EditorInstance { }; if render_confirmed { rendered = true; + last_presented = Some(Instant::now()); break; } @@ -1915,6 +1947,61 @@ mod tests { use super::*; use cap_project::{AudioGapSummary, CursorClickEvent, CursorConfiguration, CursorMoveEvent}; + fn scrub_request(frame: u32) -> PreviewRequest { + Some((frame, 60, XY::new(960, 540))) + } + + fn overdue_frame() -> Option { + Instant::now().checked_sub(PREVIEW_SCRUB_FRAME_INTERVAL) + } + + #[test] + fn preview_frames_go_overdue_after_the_scrub_interval() { + assert!(preview_frame_overdue(None)); + assert!(!preview_frame_overdue(Some(Instant::now()))); + assert!(preview_frame_overdue(overdue_frame())); + } + + #[test] + fn newer_requests_cancel_only_while_a_frame_is_fresh() { + let (tx, rx) = watch::channel(scrub_request(0)); + assert!(!preview_superseded(&rx, Some(Instant::now()))); + + tx.send_modify(|request| *request = scrub_request(10)); + assert!(preview_superseded(&rx, Some(Instant::now()))); + assert!(!preview_superseded(&rx, overdue_frame())); + assert!(!preview_superseded(&rx, None)); + } + + #[tokio::test] + async fn fresh_frames_yield_to_newer_requests_and_keep_them_queued() { + let (tx, mut rx) = watch::channel(scrub_request(0)); + let superseded = preview_superseded_while_fresh(rx.clone(), Some(Instant::now())); + tx.send_modify(|request| *request = scrub_request(10)); + + tokio::time::timeout(Duration::from_secs(1), superseded) + .await + .expect("a newer request should cancel a frame while the last one is fresh"); + assert!(rx.has_changed().unwrap()); + assert_eq!(*rx.borrow_and_update(), scrub_request(10)); + } + + #[tokio::test] + async fn overdue_frames_finish_before_newer_requests() { + let (tx, mut rx) = watch::channel(scrub_request(0)); + let superseded = preview_superseded_while_fresh(rx.clone(), overdue_frame()); + tx.send_modify(|request| *request = scrub_request(10)); + + assert!( + tokio::time::timeout(Duration::from_millis(100), superseded) + .await + .is_err(), + "an overdue frame should not be cancelled by a newer request" + ); + assert!(rx.has_changed().unwrap()); + assert_eq!(*rx.borrow_and_update(), scrub_request(10)); + } + #[tokio::test] async fn completed_pcm_loader_reuses_arc_without_opening_a_missing_file() { let audio = crate::completed_audio::tests::audio();