//! Background caching benchmark: how fast the RAM preview fills a comp, and where the time goes. //! //! `cargo run --release -p effectcraft-ui-egui --example cache_bench -- [options]` //! //! Without `--project` it builds a comp like a typical edit: eight 1080p30 H.264 clips one after //! another (encoded once into `target/cache-bench/media` with the Render Queue, no committed //! media) under an adjustment layer with Gaussian Blur. It then fills the comp's RAM preview the //! way idle caching does, through [`Frames`], and prints frames per second with the decoder, //! footage-cache and disk-cache counters. //! //! Options: `--project P --comp C` (a saved project's comp instead), `--scale S` (render scale, //! default 0.5: a viewer at half size), `--frames N` (frames to cache, default the whole comp), //! `--slots N` (frames in flight, at least 1, default one per lane as the app does when idle), //! `--lane-width W` (threads per lane; the app's default when absent; `--play` takes it too), //! `--disk` (with a fresh disk cache in `target/cache-bench/disk`), `--no-adjustment`, //! `--gpu` (composite on a GPU of its own, as the desktop app does with Mercury GPU Acceleration: //! the GPU or the CPU, whichever Auto measures faster per comp, read back to the CPU; the viewer's //! backend), `--backend cpu|gpu|auto` (with `--gpu`: force one compositor, default `auto`). //! //! `--play SECS` instead plays the comp in the app (headless, a viewer at 100 %, Resolution //! Auto, nothing cached, Cache Frames When Idle off) for SECS seconds of wall time, as a first //! playback, and prints the frames shown per second, the time stalled and the scale it played at. //! With `--gpu` the app composites on the GPU (Mercury Auto), otherwise on the CPU; `--res N` //! sets the comp's Resolution to every N-th pixel instead of Auto. use std::sync::Arc; use std::time::{Duration, Instant}; use effectcraft_engine::Session; use effectcraft_engine::project::ItemId; use effectcraft_engine::render::RenderOpts; use effectcraft_ui_egui::frames::{FrameKey, Frames, RenderSource, opts_hash}; use serde_json::{Value, json}; fn arg(name: &str) -> Option { let a: Vec = std::env::args().collect(); a.iter().position(|x| x == name).and_then(|i| a.get(i + 1).cloned()) } /// `--lane-width W`: threads per frame lane (the app's default when absent). fn lane_width() -> Option { arg("--lane-width").and_then(|v| v.parse().ok()) } fn run(s: &mut Session, cmd: &str, p: Value) -> Value { s.execute(cmd, p).unwrap_or_else(|e| panic!("{cmd}: {e}")) } /// Eight copies of one generated clip (separate files: separate decoders, as with real clips). fn clips(dir: &std::path::Path) -> Vec { let media = dir.join("media"); std::fs::create_dir_all(&media).expect("media folder"); let first = media.join("clip0.mp4"); if !first.exists() { eprintln!("encoding the source clip (once)…"); let mut s = effectcraft_host::session(); run(&mut s, "comp.new", json!({"name": "Src", "width": 1920, "height": 1080, "frameRate": 30, "duration": 4.25})); let l = run(&mut s, "layer.newSolid", json!({"color": "#808080"}))["layer"].clone(); run(&mut s, "effect.apply", json!({"layers": [l], "effect": "Fractal Noise"})); run(&mut s, "prop.addKey", json!({"layer": l, "path": "effects/#1/evolution", "time": 0.0, "value": 0.0})); run(&mut s, "prop.addKey", json!({"layer": l, "path": "effects/#1/evolution", "time": 4.25, "value": 720.0})); run(&mut s, "renderQueue.add", json!({"comp": "Src", "format": "h264", "output": first.to_string_lossy()})); run(&mut s, "renderQueue.render", json!({"wait": true})); } (0..8) .map(|i| { let p = media.join(format!("clip{i}.mp4")); if !p.exists() { std::fs::copy(&first, &p).expect("copy clip"); } p.to_string_lossy().to_string() }) .collect() } fn main() { let dir = std::path::PathBuf::from(env!("CARGO_MANIFEST_DIR")).join("../../target/cache-bench"); let mut s = effectcraft_host::session(); let pool = Arc::new(effectcraft_media::MediaPool::new()); s.footage = pool.clone(); if std::env::args().any(|a| a == "--disk") { let disk = dir.join("disk"); if let Err(e) = std::fs::remove_dir_all(&disk) && e.kind() != std::io::ErrorKind::NotFound { eprintln!("can't clear the disk cache at {}: {e}", disk.display()); std::process::exit(2); } s.prefs.disk.disk_cache_enabled = true; s.prefs.disk.disk_cache_folder = disk.to_string_lossy().to_string(); s.configure_disk_cache(); } let cid = match arg("--project") { Some(p) => { run(&mut s, "file.open", json!({"path": p})); let comp = match arg("--comp") { Some(c) => s.project.comps().find(|(id, _)| s.project.item(**id).is_some_and(|it| it.name == c) || id.0.to_string() == c).map(|(id, _)| *id), None => s.active_comp_id(), }; comp.unwrap_or_else(|| { eprintln!("no such composition: {}", arg("--comp").unwrap_or_else(|| "(no active comp; pass --comp)".into())); std::process::exit(2) }) } None => { let paths = clips(&dir); let cid = ItemId( run(&mut s, "comp.new", json!({"name": "Edit", "width": 1920, "height": 1080, "frameRate": 30, "duration": 34}))["comp"] .as_u64() .expect("comp"), ); let items = run(&mut s, "file.import", json!({"paths": paths}))["items"].clone(); for (i, item) in items.as_array().expect("items").iter().enumerate() { let l = run(&mut s, "layer.addItem", json!({"item": item}))["layer"].as_u64().expect("layer"); let c = Arc::make_mut(&mut s.project).comp_mut(cid).expect("comp"); let fr = c.frame_rate; let l = c.layer_mut(effectcraft_engine::project::LayerId(l)).expect("layer"); let at = fr.tick_of(i as i64 * 1275 / 10); (l.start_time, l.in_point, l.out_point) = (at, at, fr.tick_of((i as i64 + 1) * 1275 / 10)); } if !std::env::args().any(|a| a == "--no-adjustment") { let adj = run(&mut s, "layer.newAdjustment", json!({}))["layer"].clone(); run(&mut s, "effect.apply", json!({"layers": [adj], "effect": "Gaussian Blur"})); run(&mut s, "prop.set", json!({"layer": adj, "path": "effects/#1/blurriness", "value": 4.0})); } cid } }; if let Some(secs) = arg("--play").and_then(|v| v.parse().ok()) { play(s, cid, secs, std::env::args().any(|a| a == "--gpu")); return; } let comp = s.project.comp(cid).expect("comp").clone(); let total = comp.frame_rate.frame_at(comp.duration); let n = arg("--frames").and_then(|v| v.parse().ok()).unwrap_or(total).min(total); let scale: f64 = arg("--scale").and_then(|v| v.parse().ok()).unwrap_or(0.5); let frames = lane_width().map_or_else(Frames::default, Frames::with_lane_width); // (as Cache Frames When Idle: one frame per lane, see `app/prefetch.rs`) let slots: usize = arg("--slots").and_then(|v| v.parse().ok()).map(|n: usize| n.max(1)).unwrap_or(frames.lanes()); // Room for every frame: this measures speed, not eviction. frames.set_budget(64 << 30); use effectcraft_engine::render::Backend; let backend = match arg("--backend").as_deref() { Some("cpu") => Backend::Cpu, Some("gpu") => Backend::Gpu, _ => Backend::Auto, }; let opts = RenderOpts { scale, motion_blur: true, backend, ..Default::default() }; let gpu = std::env::args().any(|a| a == "--gpu").then(|| { effectcraft_gpu::Gpu::headless().unwrap_or_else(|| { eprintln!("--gpu: no usable GPU adapter"); std::process::exit(2) }) }); let src = RenderSource { project: s.project.clone(), footage: s.footage.clone(), expr: s.expr.clone(), layer_cache: s.layer_cache.clone(), gpu, gpu_display: false, disk: s.disk_cache.clone(), }; let series = FrameKey { revision: 1, content: frames.content_of(&src.project, 1, cid), comp: cid.0, frame: 0, scale: (scale * 1000.0).round() as u32, view: 0, opts: opts_hash(&opts), }; eprintln!( "caching {n} frames of {}×{} at scale {scale} with {slots} in flight on {} lanes{}…", comp.width, comp.height, frames.lanes(), if src.gpu.is_some() { " on the GPU" } else { "" } ); let (gop0, t0) = (effectcraft_media::gop_stats(), Instant::now()); let mut next = 0; loop { while next < n && frames.inflight() < slots { frames.request_background(&src, FrameKey { frame: next, ..series }, cid, comp.frame_rate.tick_of(next), opts); next += 1; } if next >= n && frames.inflight() == 0 { break; } std::thread::sleep(Duration::from_millis(1)); } let secs = t0.elapsed().as_secs_f64(); let gop = effectcraft_media::gop_stats(); let cached = frames.cached_frames(&series).len(); println!("frames cached {cached}/{n} in {secs:.2} s: {:.1} frames/s, {:.1} ms each", cached as f64 / secs, secs * 1000.0 / cached.max(1) as f64); println!( "video decoding {:.2} s in decoders, {} samples decoded, {} seeks, {} cache hits", (gop.decode_ns - gop0.decode_ns) as f64 / 1e9, gop.decoded - gop0.decoded, gop.seeks - gop0.seeks, gop.hits - gop0.hits ); if let Some(g) = &src.gpu && let Some(p) = effectcraft_engine::render::Accelerator::auto_pick(g) && let Some(a) = p.stats(effectcraft_engine::render::AutoKey::new(cid, scale, false)) { let ms = |v: Option| v.map_or("–".into(), |v| format!("{v:.1} ms")); println!("auto (Mercury) GPU {} over {} frames, CPU {} over {} frames", ms(a.gpu_ms), a.gpu_frames, ms(a.cpu_ms), a.cpu_frames); } let p = pool.stats(); println!("footage cache {} hits, {} misses, {} frames ({} MB) kept", p.hits, p.misses, p.frames, p.bytes >> 20); if let Some(dc) = &s.disk_cache { // (writes finish on the disk cache's own thread) let t = Instant::now(); dc.flush(); let flushed = t.elapsed().as_secs_f64(); let d = dc.stats(); println!("disk cache {} written, {} dropped, {} entries ({} MB), flushed in {flushed:.2} s", d.writes, d.dropped, d.entries, d.bytes >> 20); } } /// `--play`: a first playback of `cid` in the app, as someone pressing play in it would see. fn play(session: effectcraft_engine::Session, cid: ItemId, secs: f64, gpu: bool) { use effectcraft_ui_egui::{ControlRequest, EffectcraftApp}; let (tx, rx) = std::sync::mpsc::channel::(); let builder = egui_kittest::Harness::builder().with_size(egui::vec2(1920.0, 1200.0)).with_pixels_per_point(1.0); let builder = if gpu { builder.wgpu() } else { builder }; let mut h = builder.build_eframe(move |_| EffectcraftApp::new(session).with_control(rx)); { let app = h.state_mut(); if let Some(w) = lane_width() { app.frames = effectcraft_ui_egui::frames::Frames::with_lane_width(w); } let _ = app.session.execute("comp.open", json!({"comp": cid.0})); app.ui.viewer.zoom = Some(1.0); app.ui.cache_when_idle = false; if let (Some(n), Some(c)) = (arg("--res").and_then(|v| v.parse().ok()), Arc::make_mut(&mut app.session.project).comp_mut(cid)) { c.resolution = effectcraft_engine::project::Resolution::from_factor(n); } } // Let the UI settle (fonts, the GPU compositor's pipelines) before the clock starts. let ready = Instant::now() + Duration::from_secs(if gpu { 8 } else { 2 }); while Instant::now() < ready { h.step(); std::thread::sleep(Duration::from_millis(10)); } h.state().frames.clear(); let (reply, _r) = std::sync::mpsc::channel(); let _ = tx.send(ControlRequest { method: "ui.playback".into(), params: json!({"action": "play"}), reply }); let t0 = Instant::now(); let (mut started, mut stalled, mut last, mut scales) = (None, 0.0, t0, std::collections::BTreeMap::::new()); // When each new frame went on screen (seconds since play was pressed): the cadence. The // current time, not `Playback::shown`: frames shown while the clock holds don't count there. let fr = h.state().session.project.comp(cid).map(|c| c.frame_rate); let (mut shown_at, mut last_frame) = (Vec::::new(), None); while t0.elapsed().as_secs_f64() < secs { h.step(); let now = Instant::now(); let app = h.state(); if app.playback.playing { let t = *started.get_or_insert(now); if app.playback.waiting && now > t { stalled += (now - last).as_secs_f64(); } } let frame = fr.map(|fr| fr.frame_at(app.session.time())); if app.playback.playing && frame != last_frame { last_frame = frame; shown_at.push((now - t0).as_secs_f64()); } *scales.entry(app.shown_series(cid).scale).or_default() += 1; last = now; std::thread::sleep(Duration::from_millis(2)); } let app = h.state(); let played = started.map_or(0.0, |t| t.elapsed().as_secs_f64()); let shown = shown_at.len(); let frame = fr.map_or(0, |fr| fr.frame_at(app.session.time())); println!( "played {shown} frames shown in {played:.2} s: {:.1} frames/s, stalled {stalled:.2} s, reached frame {frame}{}", shown as f64 / played.max(1e-9), if gpu { " (GPU)" } else { "" } ); // Cadence: how evenly the frames went on screen (the intervals between consecutive shown // frames after the first), and how long the first two took. let mut gaps: Vec = shown_at.windows(2).map(|w| w[1] - w[0]).collect(); gaps.sort_by(f64::total_cmp); let at = |q: f64| gaps.get(((gaps.len() as f64 - 1.0) * q).round() as usize).copied().unwrap_or(0.0) * 1000.0; let holds = gaps.iter().filter(|g| **g > 0.2).count(); println!( "cadence first frame {:.2} s, second {:.2} s; gaps median {:.0} ms, p95 {:.0} ms, max {:.0} ms, {holds} holds > 200 ms", shown_at.first().copied().unwrap_or(0.0), shown_at.get(1).copied().unwrap_or(0.0), at(0.5), at(0.95), at(1.0) ); // The opening (the first 3 s, before an adaptive step down can have taken effect): how // evenly the uncached frames at the starting resolution went on screen. let mut early: Vec = shown_at.windows(2).filter(|w| w[1] <= 3.0).map(|w| w[1] - w[0]).collect(); early.sort_by(f64::total_cmp); let at = |q: f64| early.get(((early.len() as f64 - 1.0) * q).round() as usize).copied().unwrap_or(0.0) * 1000.0; println!( "opening (3 s) {} frames; gaps median {:.0} ms, p95 {:.0} ms, max {:.0} ms, {} holds > 200 ms", early.len() + usize::from(!early.is_empty()), at(0.5), at(0.95), at(1.0), early.iter().filter(|g| **g > 0.2).count() ); let passes: u64 = scales.values().sum(); let s: Vec = scales.iter().map(|(k, v)| format!("{:.3}: {:.0} %", *k as f64 / 1000.0, 100.0 * *v as f64 / passes.max(1) as f64)).collect(); println!("viewer scale {}", s.join(", ")); }