mirror of
https://github.com/storytold/filmcraft.git
synced 2026-10-24 10:10:05 -06:00
M4.6: headless playback benchmark (cargo xtask bench-playback) and a correct dropped-frame count
- crates/ui-egui/examples/bench_playback.rs drives the Program monitor's own FrameServer, prefetch (now FrameServer::schedule_playback, shared with the monitor) and PlaybackMeter at a simulated 60 Hz display, optionally compositing on a headless wgpu device. Scenarios: h264-1080, stack3 (3 × 1080p, scaled/rotated/opacity), h264-2160, demo, after-preview (live play → Render Effects In to Out → 2 plays), seek-storm. Reports latency percentiles, on-time ratio, worker/decode wall and thread-CPU time, UI-thread present time, process CPU per frame, decoder seeks/samples (codecs::gop_stats) and wasted jobs; --json for machine output. Fixtures are generated with ffmpeg into target/fixtures/playback. - FrameServer records per-job timings (thread CPU via rustix clocks) while profiling is on. - Dropped/shown were counted per UI refresh: "shown" counted every refresh that had the frame (322 "shown" in an 8 s play of 192 frames) and "dropped" counted a frame that arrived a few ms after its first refresh. PlaybackMeter counts timeline frames: shown when the exact picture was on screen while due, dropped otherwise, including frames passed over without a refresh. Baseline (GPU path, 8 s, load avg 104–168 on 14 cores; CPU columns are load-robust): h264-1080 Full 191/1 shown/dropped, 46 ms CPU/frame; Half 188/4 stack3 Full 189/3, 102 ms CPU/frame; Half 157/35 (3 extra decoder seeks) h264-2160 Full 8/184, 313 ms CPU/frame, 10 seeks; demo Full 114/78, Half 191/1 after-preview: live 0/192; 1st play after render 124/67, 2nd 119/73 (UI-thread present p50 21 ms / p95 45 ms); seek-storm: 0 of 40 seeks shown within 150 ms Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Brandon Thomas
co-authored by
Claude Opus 5.5
Claude Opus 5.5
parent
9e54812b2a
commit
5170376dcb
Generated
+3
@@ -1610,6 +1610,7 @@ dependencies = [
|
||||
"eframe",
|
||||
"egui",
|
||||
"filmcraft-audio-dsp",
|
||||
"filmcraft-codecs",
|
||||
"filmcraft-color",
|
||||
"filmcraft-edit",
|
||||
"filmcraft-engine",
|
||||
@@ -1621,7 +1622,9 @@ dependencies = [
|
||||
"filmcraft-render",
|
||||
"filmcraft-time",
|
||||
"log",
|
||||
"pollster 0.4.0",
|
||||
"rayon",
|
||||
"rustix 1.1.5",
|
||||
"serde",
|
||||
"serde_json",
|
||||
]
|
||||
|
||||
@@ -5,6 +5,7 @@
|
||||
//! for the next frames therefore hit the cache or continue the running decoder without re-seeking.
|
||||
|
||||
use std::collections::BTreeMap;
|
||||
use std::sync::atomic::{AtomicU64, Ordering};
|
||||
use std::sync::{Arc, Mutex};
|
||||
|
||||
use filmcraft_color::ColorInfo;
|
||||
@@ -13,6 +14,51 @@ use filmcraft_frame::VideoFrame;
|
||||
use crate::CodecError;
|
||||
use crate::video::VideoDecoder;
|
||||
|
||||
/// Process-wide decode counters of every [`GopCache`] (benchmarks and diagnostics).
|
||||
#[derive(Clone, Copy, Debug, Default, PartialEq, Eq)]
|
||||
pub struct GopStats {
|
||||
/// Requests answered from the decoded-frame cache.
|
||||
pub hits: u64,
|
||||
/// Requests that had to decode.
|
||||
pub misses: u64,
|
||||
/// Decoder restarts at a sync sample (seeks).
|
||||
pub seeks: u64,
|
||||
/// Samples fed to decoders.
|
||||
pub decoded: u64,
|
||||
/// Decoded frames evicted from the cache.
|
||||
pub evicted: u64,
|
||||
}
|
||||
|
||||
static HITS: AtomicU64 = AtomicU64::new(0);
|
||||
static MISSES: AtomicU64 = AtomicU64::new(0);
|
||||
static SEEKS: AtomicU64 = AtomicU64::new(0);
|
||||
static DECODED: AtomicU64 = AtomicU64::new(0);
|
||||
static EVICTED: AtomicU64 = AtomicU64::new(0);
|
||||
|
||||
/// The counters so far (they only grow; subtract two snapshots to measure an interval).
|
||||
pub fn gop_stats() -> GopStats {
|
||||
GopStats {
|
||||
hits: HITS.load(Ordering::Relaxed),
|
||||
misses: MISSES.load(Ordering::Relaxed),
|
||||
seeks: SEEKS.load(Ordering::Relaxed),
|
||||
decoded: DECODED.load(Ordering::Relaxed),
|
||||
evicted: EVICTED.load(Ordering::Relaxed),
|
||||
}
|
||||
}
|
||||
|
||||
impl std::ops::Sub for GopStats {
|
||||
type Output = GopStats;
|
||||
fn sub(self, o: GopStats) -> GopStats {
|
||||
GopStats {
|
||||
hits: self.hits - o.hits,
|
||||
misses: self.misses - o.misses,
|
||||
seeks: self.seeks - o.seeks,
|
||||
decoded: self.decoded - o.decoded,
|
||||
evicted: self.evicted - o.evicted,
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// A container's video sample table, in decode (file) order.
|
||||
pub trait VideoSamples {
|
||||
fn count(&self) -> usize;
|
||||
@@ -63,6 +109,7 @@ impl GopCache {
|
||||
let victim = if pts - first > last - pts { first } else { last };
|
||||
if let Some(v) = st.frames.remove(&victim) {
|
||||
st.bytes -= v.byte_size();
|
||||
EVICTED.fetch_add(1, Ordering::Relaxed);
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -74,8 +121,10 @@ impl GopCache {
|
||||
let want_pts = s.pts(i);
|
||||
let mut st = self.state.lock().unwrap_or_else(|e| e.into_inner());
|
||||
if let Some(f) = st.frames.get(&want_pts) {
|
||||
HITS.fetch_add(1, Ordering::Relaxed);
|
||||
return Ok(f.clone());
|
||||
}
|
||||
MISSES.fetch_add(1, Ordering::Relaxed);
|
||||
if st.decoder.is_none() {
|
||||
st.decoder = Some(s.make_decoder()?);
|
||||
st.next = usize::MAX;
|
||||
@@ -84,6 +133,7 @@ impl GopCache {
|
||||
// Continue the running decoder when the wanted sample is ahead within this GOP run.
|
||||
let continuing = st.next != usize::MAX && st.next > key && st.next <= i + 16 && st.next <= n;
|
||||
if !continuing {
|
||||
SEEKS.fetch_add(1, Ordering::Relaxed);
|
||||
if let Some(d) = st.decoder.as_mut() {
|
||||
d.reset();
|
||||
}
|
||||
@@ -95,6 +145,7 @@ impl GopCache {
|
||||
let data = s.read(k)?;
|
||||
let out = st.decoder.as_mut().expect("decoder").decode(&data, s.pts(k))?;
|
||||
st.next += 1;
|
||||
DECODED.fetch_add(1, Ordering::Relaxed);
|
||||
for d in out {
|
||||
self.store(&mut st, d.pts, d.frame);
|
||||
}
|
||||
|
||||
@@ -19,6 +19,7 @@ pub mod video;
|
||||
use std::sync::{Arc, RwLock};
|
||||
|
||||
pub use audio::AudioFileSource;
|
||||
pub use gop::{GopStats, gop_stats};
|
||||
pub use mkv::MkvSource;
|
||||
pub use mp4::Mp4Source;
|
||||
pub use video::{DecodedFrame, VideoDecoder, VideoDecoderFactory};
|
||||
|
||||
@@ -27,3 +27,11 @@ serde = { workspace = true }
|
||||
serde_json = { workspace = true }
|
||||
log = { workspace = true }
|
||||
rayon = { workspace = true }
|
||||
|
||||
# Thread/process CPU clocks for frame-job profiling (safe wrappers; see frames.rs).
|
||||
[target.'cfg(unix)'.dependencies]
|
||||
rustix = { version = "1", default-features = false, features = ["std", "time"] }
|
||||
|
||||
[dev-dependencies]
|
||||
pollster = "0.4"
|
||||
filmcraft-codecs = { workspace = true }
|
||||
|
||||
@@ -0,0 +1,677 @@
|
||||
//! Headless playback benchmark: drives the Program monitor's frame scheduler, prefetch and cache
|
||||
//! ([`FrameServer`], [`PlaybackMeter`]) exactly as the UI does, without a window.
|
||||
//!
|
||||
//! ```sh
|
||||
//! cargo xtask bench-playback # all scenarios, GPU path, Full + Half
|
||||
//! cargo run --release -p filmcraft-ui-egui --example bench_playback -- --scenario stack3 --res full --cpu
|
||||
//! ```
|
||||
//!
|
||||
//! Each play simulates display refreshes at `--refresh` Hz on the wall clock (as the app does
|
||||
//! without an audio device) and counts shown/dropped frames with the same meter as the app. Wall-
|
||||
//! clock numbers depend on machine load, so every run also reports CPU time (process and per
|
||||
//! frame-worker thread), which does not. See `docs/testing.md` §5.
|
||||
//!
|
||||
//! Fixtures are generated with ffmpeg into `target/fixtures/playback/` on first use (never
|
||||
//! committed). Scenarios that need them are skipped when ffmpeg is missing.
|
||||
|
||||
use std::collections::HashMap;
|
||||
use std::path::{Path, PathBuf};
|
||||
use std::process::Command;
|
||||
use std::time::{Duration, Instant};
|
||||
|
||||
use filmcraft_engine::Session;
|
||||
use filmcraft_project::{ItemId, ParamValue, Project, SequenceSettings, TrackKind, find_effect, resolve_auto_points};
|
||||
use filmcraft_time::{FrameRate, Tick, TimeRange};
|
||||
use filmcraft_ui_egui::frames::{FrameKey, FrameServer, JobRecord, PlaybackMeter, Target, process_cpu_time, thread_cpu_time};
|
||||
use serde_json::{Value, json};
|
||||
|
||||
// ------------------------------------------------------------------------------------ fixtures
|
||||
|
||||
/// `<repo>/target/fixtures/playback`, or `$FILMCRAFT_FIXTURES/playback` (lets worktrees share one set).
|
||||
fn fixtures_dir() -> PathBuf {
|
||||
match std::env::var_os("FILMCRAFT_FIXTURES") {
|
||||
Some(d) => PathBuf::from(d).join("playback"),
|
||||
None => Path::new(env!("CARGO_MANIFEST_DIR")).join("../../target/fixtures/playback"),
|
||||
}
|
||||
}
|
||||
|
||||
fn ffmpeg() -> Option<PathBuf> {
|
||||
["/opt/homebrew/bin/ffmpeg", "/usr/local/bin/ffmpeg", "/usr/bin/ffmpeg"].iter().map(PathBuf::from).find(|p| p.exists())
|
||||
}
|
||||
|
||||
/// (file, lavfi video source, seconds, with audio)
|
||||
const FIXTURES: &[(&str, &str, u32, bool)] = &[
|
||||
("a1080.mp4", "testsrc2=s=1920x1080:r=24000/1001:d=20,noise=alls=6:allf=t", 20, true),
|
||||
("b1080.mp4", "mandelbrot=s=1920x1080:r=24000/1001,trim=duration=20,noise=alls=6:allf=t", 20, false),
|
||||
("c1080.mp4", "smptehdbars=s=1920x1080:r=24000/1001:d=20,noise=alls=10:allf=t+u", 20, false),
|
||||
("a2160.mp4", "testsrc2=s=3840x2160:r=24000/1001:d=10,noise=alls=6:allf=t", 10, false),
|
||||
];
|
||||
|
||||
fn fixture(name: &str) -> Option<PathBuf> {
|
||||
let dir = fixtures_dir();
|
||||
let path = dir.join(name);
|
||||
if path.exists() {
|
||||
return Some(path);
|
||||
}
|
||||
let ff = ffmpeg()?;
|
||||
let &(_, src, secs, audio) = FIXTURES.iter().find(|f| f.0 == name)?;
|
||||
std::fs::create_dir_all(&dir).ok()?;
|
||||
eprintln!("generating {}", path.display());
|
||||
let mut c = Command::new(ff);
|
||||
c.args(["-v", "error", "-y", "-f", "lavfi", "-i", src]);
|
||||
if audio {
|
||||
c.args(["-f", "lavfi", "-i", &format!("sine=f=440:d={secs}"), "-c:a", "aac", "-shortest"]);
|
||||
}
|
||||
c.args(["-c:v", "libx264", "-preset", "fast", "-crf", "20", "-pix_fmt", "yuv420p", "-movflags", "+faststart"]);
|
||||
c.arg(&path);
|
||||
c.status().ok()?.success().then_some(path)
|
||||
}
|
||||
|
||||
// ------------------------------------------------------------------------------------ projects
|
||||
|
||||
fn import(s: &mut Session, path: &Path) -> ItemId {
|
||||
let r = s.execute("file.import", json!({ "paths": [path.to_string_lossy()] })).expect("import");
|
||||
ItemId(r["items"].as_array().and_then(|a| a.first()).and_then(Value::as_u64).unwrap_or_else(|| panic!("import {}: {r}", path.display())))
|
||||
}
|
||||
|
||||
/// One clip per track from t = 0 (`layers[0]` on V1), with (scale %, position, rotation°,
|
||||
/// opacity %) Motion/Opacity settings per layer.
|
||||
fn build_sequence(s: &mut Session, w: u32, h: u32, layers: &[(ItemId, f64, Option<(f64, f64)>, f64, f64)], effects: &[&str], secs: f64) -> ItemId {
|
||||
let rate = FrameRate::FPS_23_976;
|
||||
let sizes: Vec<(u32, u32)> = layers
|
||||
.iter()
|
||||
.map(|l| match s.project.item(l.0).map(|i| &i.kind) {
|
||||
Some(filmcraft_project::ItemKind::Media(m)) => m.info.video.as_ref().map(|v| (v.width, v.height)).unwrap_or((w, h)),
|
||||
_ => (w, h),
|
||||
})
|
||||
.collect();
|
||||
s.edit("bench sequence", |p: &mut Project, st| {
|
||||
let settings = SequenceSettings { width: w, height: h, frame_rate: rate, ..SequenceSettings::default() };
|
||||
let seq = p.new_sequence("Bench", settings, layers.len().max(1), 1, None);
|
||||
for (i, &(item, scale, pos, rot, opacity)) in layers.iter().enumerate() {
|
||||
let range = TimeRange::new(Tick::ZERO, rate.snap(Tick::from_seconds_f64(secs)));
|
||||
let mut v = p.make_track_item(item, TrackKind::Video, Tick::ZERO, range, rate).expect("track item");
|
||||
for e in &mut v.effects {
|
||||
resolve_auto_points(e, (w, h), sizes[i]);
|
||||
}
|
||||
if let Some(m) = v.effect_mut("motion") {
|
||||
if let Some(x) = m.params.get_mut("scale") {
|
||||
x.value = ParamValue::Float(scale);
|
||||
}
|
||||
if let (Some(x), Some((px, py))) = (m.params.get_mut("position"), pos) {
|
||||
x.value = ParamValue::Vec2(filmcraft_geom::Vec2::new(px, py));
|
||||
}
|
||||
if let Some(x) = m.params.get_mut("rotation") {
|
||||
x.value = ParamValue::Float(rot);
|
||||
}
|
||||
}
|
||||
if let Some(o) = v.effect_mut("opacity").and_then(|o| o.params.get_mut("opacity")) {
|
||||
o.value = ParamValue::Float(opacity);
|
||||
}
|
||||
if i == 0 {
|
||||
for (k, id) in effects.iter().enumerate() {
|
||||
let mut e = find_effect(id).unwrap_or_else(|| panic!("effect {id}")).instance();
|
||||
let set: &[(&str, f64)] = match *id {
|
||||
"lumetri" => &[("temperature", 18.0), ("contrast", 22.0)],
|
||||
"sharpen" => &[("amount", 40.0)],
|
||||
_ => &[],
|
||||
};
|
||||
for (name, val) in set {
|
||||
if let Some(p) = e.params.get_mut(*name) {
|
||||
p.value = ParamValue::Float(*val);
|
||||
}
|
||||
}
|
||||
v.effects.insert(k, e);
|
||||
}
|
||||
}
|
||||
p.sequence_mut(seq).expect("seq").video_tracks[i].items.push(v);
|
||||
}
|
||||
st.active_sequence = Some(seq);
|
||||
st.open_sequences = vec![seq];
|
||||
st.playheads.insert(seq, Tick::ZERO);
|
||||
Ok(seq)
|
||||
})
|
||||
.expect("sequence")
|
||||
}
|
||||
|
||||
// ------------------------------------------------------------------------------------ display
|
||||
|
||||
/// The UI side of a monitor: presents the frame it gets (GPU composite or texture conversion)
|
||||
/// and times that work, as `gpu_present` / `texture_for` do in the app.
|
||||
struct Display {
|
||||
gpu: Option<(filmcraft_gpu::GpuCompositor, eframe::wgpu::Device)>,
|
||||
last: Option<FrameKey>,
|
||||
present: Vec<Duration>,
|
||||
ui_cpu: Duration,
|
||||
uploaded: u64,
|
||||
}
|
||||
|
||||
impl Display {
|
||||
fn new(gpu: bool) -> Self {
|
||||
let gpu = if gpu {
|
||||
let instance = eframe::wgpu::Instance::default();
|
||||
let adapter = pollster::block_on(instance.request_adapter(&eframe::wgpu::RequestAdapterOptions::default())).ok();
|
||||
adapter.and_then(|a| pollster::block_on(a.request_device(&eframe::wgpu::DeviceDescriptor::default())).ok()).map(|(d, q)| {
|
||||
let c = filmcraft_gpu::GpuCompositor::new(&d, &q);
|
||||
(c, d)
|
||||
})
|
||||
} else {
|
||||
None
|
||||
};
|
||||
Self { gpu, last: None, present: Vec::new(), ui_cpu: Duration::ZERO, uploaded: 0 }
|
||||
}
|
||||
|
||||
fn target(&self, seq: ItemId) -> Target {
|
||||
if self.gpu.is_some() { Target::SequencePlan(seq) } else { Target::Sequence(seq) }
|
||||
}
|
||||
|
||||
/// Show the exact frame, or the nearest earlier cached one; returns whether it was exact.
|
||||
fn refresh(&mut self, server: &FrameServer, key: FrameKey) -> bool {
|
||||
let (c0, t0) = (thread_cpu_time().unwrap_or_default(), Instant::now());
|
||||
let exact;
|
||||
let mut presented = false;
|
||||
if let Some((comp, dev)) = self.gpu.as_mut() {
|
||||
let plan = server.get_plan(&key).map(|p| (key, p));
|
||||
exact = plan.is_some();
|
||||
if let Some((k, plan)) = plan.or_else(|| server.nearest_plan(key, 6))
|
||||
&& self.last != Some(k)
|
||||
{
|
||||
let before = comp.uploaded_bytes;
|
||||
let _ = comp.composite(&plan);
|
||||
// Wait for the GPU so the time includes the upload and the draw.
|
||||
let _ = dev.poll(eframe::wgpu::PollType::wait_indefinitely());
|
||||
self.uploaded += comp.uploaded_bytes - before;
|
||||
self.last = Some(k);
|
||||
presented = true;
|
||||
}
|
||||
} else {
|
||||
let img = server.get(&key).map(|i| (key, i));
|
||||
exact = img.is_some();
|
||||
let near = img.or_else(|| server.nearest(key.target, key.frame, key.size, key.revision, 6).map(|i| (FrameKey { frame: key.frame - 1, ..key }, i)));
|
||||
if let Some((k, img)) = near
|
||||
&& self.last != Some(k)
|
||||
{
|
||||
let ci = egui::ColorImage::from_rgba_unmultiplied([img.w, img.h], &img.px);
|
||||
std::hint::black_box(&ci);
|
||||
self.uploaded += img.px.len() as u64;
|
||||
self.last = Some(k);
|
||||
presented = true;
|
||||
}
|
||||
}
|
||||
if presented {
|
||||
self.present.push(t0.elapsed());
|
||||
}
|
||||
self.ui_cpu += thread_cpu_time().unwrap_or_default().saturating_sub(c0);
|
||||
exact
|
||||
}
|
||||
}
|
||||
|
||||
// ------------------------------------------------------------------------------------ measuring
|
||||
|
||||
#[derive(Default)]
|
||||
struct PlayReport {
|
||||
label: String,
|
||||
seconds: f64,
|
||||
shown: u64,
|
||||
dropped: u64,
|
||||
/// Due frames whose job finished before the frame was due.
|
||||
on_time: usize,
|
||||
due: usize,
|
||||
/// ms: queue→done latency, service time, (due − done) slack of due frames.
|
||||
latency: Vec<f64>,
|
||||
service: Vec<f64>,
|
||||
slack: Vec<f64>,
|
||||
/// ms per job: worker thread CPU, source fetch (decode) wall and thread CPU.
|
||||
job_cpu: Vec<f64>,
|
||||
src_wall: Vec<f64>,
|
||||
src_cpu: Vec<f64>,
|
||||
present: Vec<f64>,
|
||||
process_cpu: f64,
|
||||
ui_cpu: f64,
|
||||
jobs: usize,
|
||||
wasted_jobs: usize,
|
||||
preview_jobs: usize,
|
||||
gop: filmcraft_codecs::GopStats,
|
||||
uploaded_mb: f64,
|
||||
load: String,
|
||||
}
|
||||
|
||||
fn pct(v: &[f64], p: f64) -> f64 {
|
||||
if v.is_empty() {
|
||||
return f64::NAN;
|
||||
}
|
||||
let mut s = v.to_vec();
|
||||
s.sort_by(|a, b| a.total_cmp(b));
|
||||
s[((s.len() - 1) as f64 * p).round() as usize]
|
||||
}
|
||||
|
||||
fn ms(d: Duration) -> f64 {
|
||||
d.as_secs_f64() * 1000.0
|
||||
}
|
||||
|
||||
fn load_avg() -> String {
|
||||
Command::new("sysctl")
|
||||
.args(["-n", "vm.loadavg"])
|
||||
.output()
|
||||
.ok()
|
||||
.map(|o| String::from_utf8_lossy(&o.stdout).trim().trim_matches(['{', '}', ' ']).to_string())
|
||||
.unwrap_or_default()
|
||||
}
|
||||
|
||||
struct Bench {
|
||||
server: FrameServer,
|
||||
refresh_hz: f64,
|
||||
seconds: f64,
|
||||
}
|
||||
|
||||
impl Bench {
|
||||
/// Play `seconds` from `start` at `scale`, refreshing like the UI.
|
||||
fn play(&self, s: &Session, seq: ItemId, display: &mut Display, scale: f32, start: Tick, label: &str) -> PlayReport {
|
||||
let q = s.project.sequence(seq).expect("seq");
|
||||
let rate = q.settings.frame_rate;
|
||||
let end = (start + Tick::from_seconds_f64(self.seconds)).min(q.duration());
|
||||
let project = s.project.clone();
|
||||
let target = display.target(seq);
|
||||
let size = (scale * 1000.0) as u32;
|
||||
let mut meter = PlaybackMeter::default();
|
||||
meter.start(1.0);
|
||||
self.server.take_records();
|
||||
let gop0 = filmcraft_codecs::gop_stats();
|
||||
let (p0, ui0, up0) = (process_cpu_time().unwrap_or_default(), display.ui_cpu, display.uploaded);
|
||||
display.present.clear();
|
||||
let period = Duration::from_secs_f64(1.0 / self.refresh_hz);
|
||||
let anchor = Instant::now();
|
||||
let mut due_at: HashMap<i64, Instant> = HashMap::new();
|
||||
let mut next = anchor;
|
||||
let mut frame;
|
||||
loop {
|
||||
let now = Instant::now();
|
||||
let t = start + Tick::from_seconds_f64((now - anchor).as_secs_f64());
|
||||
if t >= end {
|
||||
break;
|
||||
}
|
||||
frame = rate.frame_at(t);
|
||||
due_at.entry(frame).or_insert(now);
|
||||
let key = FrameKey { target, frame, size, revision: s.revision };
|
||||
self.server.schedule_playback(key, rate, scale, &project, 1.0);
|
||||
let exact = display.refresh(&self.server, key);
|
||||
meter.refresh(frame, exact);
|
||||
next += period;
|
||||
let now = Instant::now();
|
||||
if next > now {
|
||||
std::thread::sleep(next - now);
|
||||
} else {
|
||||
next = now;
|
||||
}
|
||||
}
|
||||
meter.finish();
|
||||
let wall = anchor.elapsed().as_secs_f64();
|
||||
// Let in-flight jobs finish so their CPU is counted, then drop the rest of the queue.
|
||||
self.server.retain_queue(|_| false);
|
||||
std::thread::sleep(Duration::from_millis(50));
|
||||
let process_cpu = ms(process_cpu_time().unwrap_or_default().saturating_sub(p0));
|
||||
let recs: Vec<JobRecord> = self.server.take_records();
|
||||
let mut by_frame: HashMap<i64, JobRecord> = HashMap::new();
|
||||
for r in &recs {
|
||||
if r.key.target == target && r.key.size == size {
|
||||
by_frame.insert(r.key.frame, *r);
|
||||
}
|
||||
}
|
||||
let mut rep = PlayReport {
|
||||
label: label.to_string(),
|
||||
seconds: wall,
|
||||
shown: meter.shown,
|
||||
dropped: meter.dropped,
|
||||
process_cpu,
|
||||
ui_cpu: ms(display.ui_cpu - ui0),
|
||||
jobs: recs.len(),
|
||||
gop: filmcraft_codecs::gop_stats() - gop0,
|
||||
uploaded_mb: (display.uploaded - up0) as f64 / 1e6,
|
||||
load: load_avg(),
|
||||
..Default::default()
|
||||
};
|
||||
let first = rate.frame_at(start);
|
||||
let last = rate.frame_at(end - Tick(1));
|
||||
for f in first..=last {
|
||||
let Some(due) = due_at.get(&f) else { continue };
|
||||
rep.due += 1;
|
||||
if let Some(r) = by_frame.get(&f) {
|
||||
if r.finished <= *due {
|
||||
rep.on_time += 1;
|
||||
rep.slack.push(ms(*due - r.finished));
|
||||
} else {
|
||||
rep.slack.push(-ms(r.finished - *due));
|
||||
}
|
||||
}
|
||||
}
|
||||
for r in &recs {
|
||||
rep.latency.push(ms(r.finished - r.queued));
|
||||
rep.service.push(ms(r.finished - r.started));
|
||||
rep.job_cpu.push(ms(r.cpu));
|
||||
rep.src_wall.push(ms(r.source_wall));
|
||||
rep.src_cpu.push(ms(r.source_cpu));
|
||||
if !due_at.contains_key(&r.key.frame) || r.key.target != target {
|
||||
rep.wasted_jobs += 1;
|
||||
}
|
||||
if r.preview {
|
||||
rep.preview_jobs += 1;
|
||||
}
|
||||
}
|
||||
rep.present = display.present.iter().map(|d| ms(*d)).collect();
|
||||
rep
|
||||
}
|
||||
|
||||
/// Scrub: jump to a new random frame every `dwell` and measure how long the exact frame takes.
|
||||
fn seek_storm(&self, s: &Session, seq: ItemId, display: &mut Display, scale: f32, jumps: usize, dwell: Duration) -> PlayReport {
|
||||
let q = s.project.sequence(seq).expect("seq");
|
||||
let rate = q.settings.frame_rate;
|
||||
let frames = rate.frame_at(q.duration()).max(1);
|
||||
let project = s.project.clone();
|
||||
let target = display.target(seq);
|
||||
let size = (scale * 1000.0) as u32;
|
||||
self.server.take_records();
|
||||
let gop0 = filmcraft_codecs::gop_stats();
|
||||
let p0 = process_cpu_time().unwrap_or_default();
|
||||
let t0 = Instant::now();
|
||||
let mut rng = 0x2545_f491_4f6c_dd1du64;
|
||||
let mut rep = PlayReport { label: format!("seek storm ({jumps} jumps, {} ms)", dwell.as_millis()), ..Default::default() };
|
||||
let period = Duration::from_secs_f64(1.0 / self.refresh_hz);
|
||||
for _ in 0..jumps {
|
||||
rng ^= rng << 13;
|
||||
rng ^= rng >> 7;
|
||||
rng ^= rng << 17;
|
||||
let frame = (rng % frames as u64) as i64;
|
||||
let key = FrameKey { target, frame, size, revision: s.revision };
|
||||
let start = Instant::now();
|
||||
rep.due += 1;
|
||||
loop {
|
||||
// As the monitor does while not playing: request the frame under the playhead.
|
||||
self.server.request(key, rate.tick_of(frame), scale, &project, 0);
|
||||
if display.refresh(&self.server, key) {
|
||||
rep.on_time += 1;
|
||||
rep.latency.push(ms(start.elapsed()));
|
||||
break;
|
||||
}
|
||||
if start.elapsed() >= dwell {
|
||||
rep.dropped += 1;
|
||||
break;
|
||||
}
|
||||
std::thread::sleep(period);
|
||||
}
|
||||
let left = dwell.saturating_sub(start.elapsed());
|
||||
std::thread::sleep(left);
|
||||
}
|
||||
self.server.retain_queue(|_| false);
|
||||
std::thread::sleep(Duration::from_millis(50));
|
||||
rep.seconds = t0.elapsed().as_secs_f64();
|
||||
rep.process_cpu = ms(process_cpu_time().unwrap_or_default().saturating_sub(p0));
|
||||
let recs = self.server.take_records();
|
||||
rep.jobs = recs.len();
|
||||
for r in &recs {
|
||||
rep.service.push(ms(r.finished - r.started));
|
||||
rep.job_cpu.push(ms(r.cpu));
|
||||
rep.src_wall.push(ms(r.source_wall));
|
||||
rep.src_cpu.push(ms(r.source_cpu));
|
||||
}
|
||||
rep.shown = rep.on_time as u64;
|
||||
rep.gop = filmcraft_codecs::gop_stats() - gop0;
|
||||
rep.load = load_avg();
|
||||
rep
|
||||
}
|
||||
}
|
||||
|
||||
fn print_header() {
|
||||
println!(
|
||||
"{:<34} {:>6} {:>5} {:>5} {:>7} | {:>6} {:>6} {:>6} | {:>6} {:>6} | {:>6} {:>6} {:>6} | {:>6} {:>6} | {:>7} {:>6} | {:>5} {:>5} {:>5} | load",
|
||||
"scenario",
|
||||
"wall s",
|
||||
"shown",
|
||||
"drop",
|
||||
"ontime",
|
||||
"lat50",
|
||||
"lat95",
|
||||
"lat99",
|
||||
"svc50",
|
||||
"svc95",
|
||||
"cpu/j",
|
||||
"src/j",
|
||||
"srcC/j",
|
||||
"ui p50",
|
||||
"ui p95",
|
||||
"cpu ms/f",
|
||||
"cores",
|
||||
"seeks",
|
||||
"dec",
|
||||
"waste"
|
||||
);
|
||||
}
|
||||
|
||||
fn print_row(r: &PlayReport, fps: f64) {
|
||||
let frames = (r.shown + r.dropped).max(1) as f64;
|
||||
let cpu_per_frame = r.process_cpu / frames;
|
||||
println!(
|
||||
"{:<34} {:>6.2} {:>5} {:>5} {:>6.0}% | {:>6.1} {:>6.1} {:>6.1} | {:>6.1} {:>6.1} | {:>6.1} {:>6.1} {:>6.1} | {:>6.2} {:>6.2} | {:>7.1} {:>6.2} | {:>5} {:>5} {:>5} | {}",
|
||||
r.label,
|
||||
r.seconds,
|
||||
r.shown,
|
||||
r.dropped,
|
||||
100.0 * r.on_time as f64 / r.due.max(1) as f64,
|
||||
pct(&r.latency, 0.5),
|
||||
pct(&r.latency, 0.95),
|
||||
pct(&r.latency, 0.99),
|
||||
pct(&r.service, 0.5),
|
||||
pct(&r.service, 0.95),
|
||||
r.job_cpu.iter().sum::<f64>() / r.jobs.max(1) as f64,
|
||||
r.src_wall.iter().sum::<f64>() / r.jobs.max(1) as f64,
|
||||
r.src_cpu.iter().sum::<f64>() / r.jobs.max(1) as f64,
|
||||
pct(&r.present, 0.5),
|
||||
pct(&r.present, 0.95),
|
||||
cpu_per_frame,
|
||||
cpu_per_frame * fps / 1000.0,
|
||||
r.gop.seeks,
|
||||
r.gop.decoded,
|
||||
r.wasted_jobs,
|
||||
r.load
|
||||
);
|
||||
}
|
||||
|
||||
fn to_json(r: &PlayReport, scenario: &str, res: &str, path: &str) -> Value {
|
||||
let frames = (r.shown + r.dropped).max(1) as f64;
|
||||
json!({
|
||||
"scenario": scenario, "res": res, "path": path, "play": r.label, "wall_s": r.seconds,
|
||||
"shown": r.shown, "dropped": r.dropped, "on_time": r.on_time, "due": r.due,
|
||||
"latency_ms": {"p50": pct(&r.latency, 0.5), "p95": pct(&r.latency, 0.95), "p99": pct(&r.latency, 0.99), "max": pct(&r.latency, 1.0)},
|
||||
"service_ms": {"p50": pct(&r.service, 0.5), "p95": pct(&r.service, 0.95)},
|
||||
"slack_ms": {"p5": pct(&r.slack, 0.05), "p50": pct(&r.slack, 0.5)},
|
||||
"job_cpu_ms_mean": r.job_cpu.iter().sum::<f64>() / r.jobs.max(1) as f64,
|
||||
"source_wall_ms_mean": r.src_wall.iter().sum::<f64>() / r.jobs.max(1) as f64,
|
||||
"source_cpu_ms_mean": r.src_cpu.iter().sum::<f64>() / r.jobs.max(1) as f64,
|
||||
"present_ms": {"p50": pct(&r.present, 0.5), "p95": pct(&r.present, 0.95), "max": pct(&r.present, 1.0)},
|
||||
"ui_cpu_ms": r.ui_cpu, "process_cpu_ms": r.process_cpu, "cpu_ms_per_frame": r.process_cpu / frames,
|
||||
"jobs": r.jobs, "wasted_jobs": r.wasted_jobs, "preview_jobs": r.preview_jobs, "uploaded_mb": r.uploaded_mb,
|
||||
"gop": {"hits": r.gop.hits, "misses": r.gop.misses, "seeks": r.gop.seeks, "decoded": r.gop.decoded, "evicted": r.gop.evicted},
|
||||
"loadavg": r.load,
|
||||
})
|
||||
}
|
||||
|
||||
// ------------------------------------------------------------------------------------ main
|
||||
|
||||
struct Args {
|
||||
scenarios: Vec<String>,
|
||||
res: Vec<(String, f32)>,
|
||||
gpu: bool,
|
||||
seconds: f64,
|
||||
refresh: f64,
|
||||
workers: usize,
|
||||
json: Option<String>,
|
||||
repeat: usize,
|
||||
}
|
||||
|
||||
fn parse_args() -> Args {
|
||||
let mut a = Args {
|
||||
scenarios: vec![],
|
||||
res: vec![("full".into(), 1.0), ("half".into(), 0.5)],
|
||||
gpu: true,
|
||||
seconds: 8.0,
|
||||
refresh: 60.0,
|
||||
workers: FrameServer::default_workers(),
|
||||
json: None,
|
||||
repeat: 1,
|
||||
};
|
||||
let mut it = std::env::args().skip(1);
|
||||
while let Some(x) = it.next() {
|
||||
match x.as_str() {
|
||||
"--scenario" | "-s" => a.scenarios.extend(it.next().unwrap_or_default().split(',').map(str::to_string)),
|
||||
"--res" => {
|
||||
a.res = it
|
||||
.next()
|
||||
.unwrap_or_default()
|
||||
.split(',')
|
||||
.map(|r| match r {
|
||||
"half" => ("half".to_string(), 0.5),
|
||||
"quarter" => ("quarter".to_string(), 0.25),
|
||||
_ => ("full".to_string(), 1.0),
|
||||
})
|
||||
.collect()
|
||||
}
|
||||
"--cpu" => a.gpu = false,
|
||||
"--gpu" => a.gpu = true,
|
||||
"--seconds" => a.seconds = it.next().and_then(|v| v.parse().ok()).unwrap_or(8.0),
|
||||
"--refresh" => a.refresh = it.next().and_then(|v| v.parse().ok()).unwrap_or(60.0),
|
||||
"--workers" => a.workers = it.next().and_then(|v| v.parse().ok()).unwrap_or(a.workers),
|
||||
"--repeat" => a.repeat = it.next().and_then(|v| v.parse().ok()).unwrap_or(1),
|
||||
"--json" => a.json = it.next(),
|
||||
"--help" | "-h" => {
|
||||
println!(
|
||||
"bench_playback [--scenario h264-1080,stack3,h264-2160,demo,after-preview,seek-storm] [--res full,half] [--cpu|--gpu] [--seconds 8] [--refresh 60] [--workers N] [--repeat N] [--json out.json]"
|
||||
);
|
||||
std::process::exit(0);
|
||||
}
|
||||
other => eprintln!("ignoring argument {other}"),
|
||||
}
|
||||
}
|
||||
if a.scenarios.is_empty() {
|
||||
a.scenarios = ["h264-1080", "stack3", "h264-2160", "demo", "after-preview", "seek-storm"].iter().map(|s| s.to_string()).collect();
|
||||
}
|
||||
a
|
||||
}
|
||||
|
||||
/// Build the session for a scenario (None when its fixtures are unavailable).
|
||||
fn scenario_session(name: &str) -> Option<(Session, ItemId)> {
|
||||
let mut s = Session::default();
|
||||
let seq = match name {
|
||||
"h264-1080" | "seek-storm" => {
|
||||
let a = import(&mut s, &fixture("a1080.mp4")?);
|
||||
build_sequence(&mut s, 1920, 1080, &[(a, 100.0, None, 0.0, 100.0)], &[], 20.0)
|
||||
}
|
||||
"stack3" => {
|
||||
let (a, b, c) = (fixture("a1080.mp4")?, fixture("b1080.mp4")?, fixture("c1080.mp4")?);
|
||||
let (a, b, c) = (import(&mut s, &a), import(&mut s, &b), import(&mut s, &c));
|
||||
build_sequence(
|
||||
&mut s,
|
||||
1920,
|
||||
1080,
|
||||
&[(a, 100.0, None, 0.0, 100.0), (b, 60.0, Some((700.0, 420.0)), 0.0, 70.0), (c, 40.0, Some((1450.0, 760.0)), 12.0, 85.0)],
|
||||
&[],
|
||||
20.0,
|
||||
)
|
||||
}
|
||||
"h264-2160" => {
|
||||
let a = import(&mut s, &fixture("a2160.mp4")?);
|
||||
build_sequence(&mut s, 3840, 2160, &[(a, 100.0, None, 0.0, 100.0)], &[], 10.0)
|
||||
}
|
||||
"after-preview" => {
|
||||
let a = import(&mut s, &fixture("a1080.mp4")?);
|
||||
let seq = build_sequence(&mut s, 1920, 1080, &[(a, 100.0, None, 0.0, 100.0)], &["lumetri", "sharpen", "levels", "tint"], 20.0);
|
||||
s.edit("marks", |p, _| {
|
||||
let q = p.sequence_mut(seq).expect("seq");
|
||||
q.mark_in = Some(Tick::ZERO);
|
||||
q.mark_out = Some(q.settings.frame_rate.tick_of(8 * 24));
|
||||
Ok(())
|
||||
})
|
||||
.ok()?;
|
||||
seq
|
||||
}
|
||||
"demo" => {
|
||||
s.execute("file.openDemoProject", json!({})).ok()?;
|
||||
s.state.active_sequence?
|
||||
}
|
||||
_ => {
|
||||
eprintln!("unknown scenario {name}");
|
||||
return None;
|
||||
}
|
||||
};
|
||||
Some((s, seq))
|
||||
}
|
||||
|
||||
fn main() {
|
||||
let args = parse_args();
|
||||
let cores = std::thread::available_parallelism().map(|n| n.get()).unwrap_or(1);
|
||||
println!(
|
||||
"FilmCraft playback bench: {} path, {} frame workers, {} cores, refresh {} Hz, {} s per play; load avg {}",
|
||||
if args.gpu { "GPU" } else { "CPU" },
|
||||
args.workers,
|
||||
cores,
|
||||
args.refresh,
|
||||
args.seconds,
|
||||
load_avg()
|
||||
);
|
||||
println!(
|
||||
"lat = queue→ready per job, svc = worker time per job, cpu/j = worker thread CPU, src/j = source fetch (decode) wall, srcC/j = its thread CPU,\nui = present time on the UI thread (GPU upload+draw / texture conversion), cpu ms/f = process CPU per due frame, cores = CPU cores that rate needs at the sequence fps,\nseeks/dec = decoder restarts / samples decoded, waste = finished jobs for frames never due (all times ms)\n"
|
||||
);
|
||||
print_header();
|
||||
let mut out = Vec::new();
|
||||
for name in &args.scenarios {
|
||||
for (res_name, scale) in &args.res {
|
||||
if name == "seek-storm" && res_name != "full" && args.res.len() > 1 {
|
||||
continue;
|
||||
}
|
||||
let Some((mut s, seq)) = scenario_session(name) else {
|
||||
println!("{name}: skipped (fixtures unavailable: is ffmpeg installed?)");
|
||||
continue;
|
||||
};
|
||||
let fps = s.project.sequence(seq).map(|q| q.settings.frame_rate.as_f64()).unwrap_or(24.0);
|
||||
for rep_i in 0..args.repeat {
|
||||
// A fresh frame server per run so caches start cold, as after opening a project.
|
||||
let server = FrameServer::new(s.media.clone(), s.services.clone(), s.previews.clone(), args.workers);
|
||||
server.set_profiling(true);
|
||||
let bench = Bench { server, refresh_hz: args.refresh, seconds: args.seconds };
|
||||
let mut display = Display::new(args.gpu);
|
||||
if args.gpu && display.gpu.is_none() {
|
||||
eprintln!("no GPU adapter; using the CPU path");
|
||||
}
|
||||
let path = if display.gpu.is_some() { "gpu" } else { "cpu" };
|
||||
let tag = |l: &str| if args.repeat > 1 { format!("{name} {res_name} {l} #{}", rep_i + 1) } else { format!("{name} {res_name} {l}") };
|
||||
let mut reports = Vec::new();
|
||||
match name.as_str() {
|
||||
"seek-storm" => {
|
||||
let mut r = bench.seek_storm(&s, seq, &mut display, *scale, 40, Duration::from_millis(150));
|
||||
r.label = tag("seek");
|
||||
reports.push(r);
|
||||
}
|
||||
"after-preview" => {
|
||||
// Live play (effects rendered per frame), render previews, then play twice.
|
||||
reports.push(bench.play(&s, seq, &mut display, *scale, Tick::ZERO, &tag("live")));
|
||||
let t0 = Instant::now();
|
||||
s.execute("sequence.renderEffectsInToOut", json!({"wait": true})).expect("render previews");
|
||||
eprintln!(" rendered previews in {:.1}s (load {})", t0.elapsed().as_secs_f64(), load_avg());
|
||||
reports.push(bench.play(&s, seq, &mut display, *scale, Tick::ZERO, &tag("1st after")));
|
||||
reports.push(bench.play(&s, seq, &mut display, *scale, Tick::ZERO, &tag("2nd after")));
|
||||
s.previews.delete(None);
|
||||
}
|
||||
_ => reports.push(bench.play(&s, seq, &mut display, *scale, Tick::ZERO, &tag("play"))),
|
||||
}
|
||||
for r in &reports {
|
||||
print_row(r, fps);
|
||||
out.push(to_json(r, name, res_name, path));
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
if let Some(p) = args.json {
|
||||
let doc = json!({"cores": cores, "workers": args.workers, "refresh_hz": args.refresh, "seconds": args.seconds, "runs": out});
|
||||
if let Err(e) = std::fs::write(&p, serde_json::to_string_pretty(&doc).unwrap_or_default()) {
|
||||
eprintln!("{p}: {e}");
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -300,7 +300,7 @@ pub fn inspect(app: &FilmcraftApp, ctx: &egui::Context) -> Value {
|
||||
"pixelsPerPoint": ctx.pixels_per_point(),
|
||||
"fps": app.fps,
|
||||
"ui": app.ui,
|
||||
"playback": {"playing": app.playback.playing, "speed": app.playback.speed, "loop": app.playback.looping, "audioClock": app.playback.audio_clock, "dropped": app.playback.dropped, "shown": app.playback.shown},
|
||||
"playback": {"playing": app.playback.playing, "speed": app.playback.speed, "loop": app.playback.looping, "audioClock": app.playback.audio_clock, "dropped": app.playback.meter.counts().1, "shown": app.playback.meter.counts().0},
|
||||
"playhead": app.session.playhead().0,
|
||||
"activeSequence": app.session.state.active_sequence.map(|i| i.0),
|
||||
"selection": app.session.state.selection.iter().map(|c| c.0).collect::<Vec<_>>(),
|
||||
|
||||
+307
-34
@@ -7,8 +7,11 @@
|
||||
//! Sequence frames inside a rendered segment come from its render preview instead of the live
|
||||
//! render (see `filmcraft_engine::previews`).
|
||||
|
||||
use std::cell::Cell;
|
||||
use std::collections::{HashMap, VecDeque};
|
||||
use std::sync::atomic::{AtomicBool, Ordering};
|
||||
use std::sync::{Arc, Condvar, Mutex};
|
||||
use std::time::{Duration, Instant};
|
||||
|
||||
use filmcraft_engine::previews::PreviewStore;
|
||||
use filmcraft_engine::{MediaPool, Services};
|
||||
@@ -42,6 +45,7 @@ pub struct Rgba {
|
||||
|
||||
struct Job {
|
||||
key: FrameKey,
|
||||
queued: Instant,
|
||||
time: Tick,
|
||||
/// Output scale relative to the target's frame size.
|
||||
scale: f32,
|
||||
@@ -55,6 +59,98 @@ struct Shared {
|
||||
done: Mutex<Cache>,
|
||||
plans: Mutex<HashMap<FrameKey, (Arc<filmcraft_render::plan::FramePlan>, u64)>>,
|
||||
in_flight: Mutex<Vec<FrameKey>>,
|
||||
/// Per-job timings, collected while profiling is on (benchmarks, `ui.inspect`).
|
||||
profiling: AtomicBool,
|
||||
records: Mutex<Vec<JobRecord>>,
|
||||
}
|
||||
|
||||
/// Timing of one finished frame job (collected while [`FrameServer::set_profiling`] is on).
|
||||
#[derive(Clone, Copy, Debug)]
|
||||
pub struct JobRecord {
|
||||
pub key: FrameKey,
|
||||
pub prio: u32,
|
||||
pub queued: Instant,
|
||||
pub started: Instant,
|
||||
pub finished: Instant,
|
||||
/// Thread-CPU time of the whole job (robust to machine load; zero where unsupported).
|
||||
pub cpu: Duration,
|
||||
/// Wall and thread-CPU time spent getting source frames (decode, including waits on a
|
||||
/// source's decoder lock; the decoder's own worker threads are not included in `source_cpu`).
|
||||
pub source_wall: Duration,
|
||||
pub source_cpu: Duration,
|
||||
/// The frame came from a render preview.
|
||||
pub preview: bool,
|
||||
}
|
||||
|
||||
/// CPU time consumed by the calling thread (None where the platform has no thread clock).
|
||||
pub fn thread_cpu_time() -> Option<Duration> {
|
||||
#[cfg(all(unix, not(target_arch = "wasm32")))]
|
||||
{
|
||||
let t = rustix::time::clock_gettime(rustix::time::ClockId::ThreadCPUTime);
|
||||
Some(Duration::new(t.tv_sec as u64, t.tv_nsec as u32))
|
||||
}
|
||||
#[cfg(not(all(unix, not(target_arch = "wasm32"))))]
|
||||
{
|
||||
None
|
||||
}
|
||||
}
|
||||
|
||||
/// CPU time consumed by the whole process, all threads (None where unsupported).
|
||||
pub fn process_cpu_time() -> Option<Duration> {
|
||||
#[cfg(all(unix, not(target_arch = "wasm32")))]
|
||||
{
|
||||
let t = rustix::time::clock_gettime(rustix::time::ClockId::ProcessCPUTime);
|
||||
Some(Duration::new(t.tv_sec as u64, t.tv_nsec as u32))
|
||||
}
|
||||
#[cfg(not(all(unix, not(target_arch = "wasm32"))))]
|
||||
{
|
||||
None
|
||||
}
|
||||
}
|
||||
|
||||
thread_local! {
|
||||
/// (wall, cpu) spent in source `video_frame` calls by this worker during the current job.
|
||||
static SOURCE_TIME: Cell<(Duration, Duration)> = const { Cell::new((Duration::ZERO, Duration::ZERO)) };
|
||||
}
|
||||
|
||||
/// Run `f`, adding its wall/CPU time to this thread's source-time accumulator.
|
||||
fn timed_source<R>(f: impl FnOnce() -> R) -> R {
|
||||
let (w0, c0) = (Instant::now(), thread_cpu_time().unwrap_or_default());
|
||||
let r = f();
|
||||
let (dw, dc) = (w0.elapsed(), thread_cpu_time().unwrap_or_default().saturating_sub(c0));
|
||||
SOURCE_TIME.with(|s| {
|
||||
let (w, c) = s.get();
|
||||
s.set((w + dw, c + dc));
|
||||
});
|
||||
r
|
||||
}
|
||||
|
||||
/// A media source that times its `video_frame` calls (see [`JobRecord::source_wall`]).
|
||||
struct TimedSource(filmcraft_media::SharedSource);
|
||||
|
||||
impl filmcraft_media::MediaSource for TimedSource {
|
||||
fn info(&self) -> &filmcraft_media::MediaInfo {
|
||||
self.0.info()
|
||||
}
|
||||
fn video_frame(&self, req: filmcraft_media::FrameRequest) -> filmcraft_media::Result<Arc<filmcraft_frame::VideoFrame>> {
|
||||
timed_source(|| self.0.video_frame(req))
|
||||
}
|
||||
fn audio(&self, start: i64, frames: usize, sample_rate: u32) -> filmcraft_media::Result<filmcraft_frame::AudioBuffer> {
|
||||
self.0.audio(start, frames, sample_rate)
|
||||
}
|
||||
}
|
||||
|
||||
/// The job's source provider: the pool, wrapped with timing while profiling.
|
||||
struct JobProvider {
|
||||
inner: filmcraft_engine::media_pool::PoolProvider,
|
||||
timed: bool,
|
||||
}
|
||||
|
||||
impl filmcraft_render::SourceProvider for JobProvider {
|
||||
fn source(&self, item: ItemId) -> Option<filmcraft_media::SharedSource> {
|
||||
let s = self.inner.source(item)?;
|
||||
Some(if self.timed { Arc::new(TimedSource(s)) } else { s })
|
||||
}
|
||||
}
|
||||
|
||||
struct Cache {
|
||||
@@ -90,7 +186,13 @@ pub struct FrameServer {
|
||||
pub pool: Arc<MediaPool>,
|
||||
pub services: Arc<dyn Services>,
|
||||
pub previews: Arc<PreviewStore>,
|
||||
repaint: Arc<Mutex<Option<egui::Context>>>,
|
||||
repaint: Arc<Mutex<Option<Box<dyn Fn() + Send + Sync>>>>,
|
||||
}
|
||||
|
||||
/// Frames queued ahead of the playhead while playing (and how far ahead a queued job may be
|
||||
/// before it is dropped as stale).
|
||||
pub fn prefetch_depth(speed: f64) -> i64 {
|
||||
if speed.abs() > 1.5 { 24 } else { 14 }
|
||||
}
|
||||
|
||||
impl FrameServer {
|
||||
@@ -101,8 +203,10 @@ impl FrameServer {
|
||||
done: Mutex::new(Cache { map: HashMap::new(), bytes: 0, budget: 768 << 20, clock: 0 }),
|
||||
plans: Mutex::new(HashMap::new()),
|
||||
in_flight: Mutex::new(Vec::new()),
|
||||
profiling: AtomicBool::new(false),
|
||||
records: Mutex::new(Vec::new()),
|
||||
});
|
||||
let repaint: Arc<Mutex<Option<egui::Context>>> = Arc::new(Mutex::new(None));
|
||||
let repaint: Arc<Mutex<Option<Box<dyn Fn() + Send + Sync>>>> = Arc::new(Mutex::new(None));
|
||||
#[cfg(not(target_arch = "wasm32"))]
|
||||
for i in 0..workers.max(1) {
|
||||
let sh = shared.clone();
|
||||
@@ -117,13 +221,28 @@ impl FrameServer {
|
||||
Self { shared, pool, services, previews, repaint }
|
||||
}
|
||||
|
||||
/// The default number of frame workers for this machine.
|
||||
pub fn default_workers() -> usize {
|
||||
std::thread::available_parallelism().map(|n| n.get().clamp(2, 6)).unwrap_or(3)
|
||||
}
|
||||
|
||||
pub fn set_context(&self, ctx: &egui::Context) {
|
||||
let mut g = self.repaint.lock().unwrap_or_else(|e| e.into_inner());
|
||||
if g.is_none() {
|
||||
*g = Some(ctx.clone());
|
||||
let ctx = ctx.clone();
|
||||
*g = Some(Box::new(move || ctx.request_repaint()));
|
||||
}
|
||||
}
|
||||
|
||||
/// Collect a [`JobRecord`] per finished job (benchmarks); `take_records` drains them.
|
||||
pub fn set_profiling(&self, on: bool) {
|
||||
self.shared.profiling.store(on, Ordering::Relaxed);
|
||||
}
|
||||
|
||||
pub fn take_records(&self) -> Vec<JobRecord> {
|
||||
std::mem::take(&mut *self.shared.records.lock().unwrap_or_else(|e| e.into_inner()))
|
||||
}
|
||||
|
||||
pub fn get(&self, k: &FrameKey) -> Option<Arc<Rgba>> {
|
||||
let mut c = self.shared.done.lock().unwrap_or_else(|e| e.into_inner());
|
||||
c.clock += 1;
|
||||
@@ -138,6 +257,14 @@ impl FrameServer {
|
||||
self.shared.plans.lock().unwrap_or_else(|e| e.into_inner()).get(k).map(|(p, _)| p.clone())
|
||||
}
|
||||
|
||||
/// Whether the exact frame (image or plan) is ready.
|
||||
pub fn is_ready(&self, k: &FrameKey) -> bool {
|
||||
match k.target {
|
||||
Target::SequencePlan(_) => self.shared.plans.lock().unwrap_or_else(|e| e.into_inner()).contains_key(k),
|
||||
_ => self.shared.done.lock().unwrap_or_else(|e| e.into_inner()).map.contains_key(k),
|
||||
}
|
||||
}
|
||||
|
||||
/// Nearest cached plan at or before `frame`.
|
||||
pub fn nearest_plan(&self, key: FrameKey, max_back: i64) -> Option<(FrameKey, Arc<filmcraft_render::plan::FramePlan>)> {
|
||||
let g = self.shared.plans.lock().unwrap_or_else(|e| e.into_inner());
|
||||
@@ -162,13 +289,31 @@ impl FrameServer {
|
||||
j.prio = j.prio.min(prio);
|
||||
return;
|
||||
}
|
||||
q.push_back(Job { key, time, scale, project: project.clone(), prio });
|
||||
q.push_back(Job { key, queued: Instant::now(), time, scale, project: project.clone(), prio });
|
||||
drop(q);
|
||||
self.shared.cv.notify_one();
|
||||
#[cfg(target_arch = "wasm32")]
|
||||
self.run_one_sync();
|
||||
}
|
||||
|
||||
/// Playback scheduling for the monitor showing `key` (the frame due now): request it first,
|
||||
/// then the next frames in display order, and drop queued jobs for this target that are
|
||||
/// stale (old revision, behind the playhead or too far ahead).
|
||||
pub fn schedule_playback(&self, key: FrameKey, rate: filmcraft_time::FrameRate, scale: f32, project: &Arc<Project>, speed: f64) {
|
||||
self.request(key, rate.tick_of(key.frame), scale, project, 0);
|
||||
let dir = if speed < 0.0 { -1 } else { 1 };
|
||||
let ahead = prefetch_depth(speed);
|
||||
let step = speed.abs().max(1.0) as i64;
|
||||
for i in 1..=ahead {
|
||||
let f = key.frame + i * dir * step;
|
||||
if f >= 0 {
|
||||
self.request(FrameKey { frame: f, ..key }, rate.tick_of(f), scale, project, i as u32);
|
||||
}
|
||||
}
|
||||
let (target, rev, cur) = (key.target, key.revision, key.frame);
|
||||
self.retain_queue(|k| k.target != target || (k.revision == rev && (k.frame - cur) * dir >= 0 && (k.frame - cur).abs() < 40));
|
||||
}
|
||||
|
||||
/// Drop queued jobs that fail `keep` (e.g. stale revisions or frames far from the playhead).
|
||||
pub fn retain_queue(&self, keep: impl Fn(&FrameKey) -> bool) {
|
||||
self.shared.queue.lock().unwrap_or_else(|e| e.into_inner()).retain(|j| keep(&j.key));
|
||||
@@ -193,18 +338,88 @@ impl FrameServer {
|
||||
let job = { self.shared.queue.lock().unwrap_or_else(|e| e.into_inner()).pop_front() };
|
||||
if let Some(job) = job {
|
||||
if let Target::SequencePlan(seq) = job.key.target {
|
||||
let plan = plan_job(&job, seq, &self.pool, &self.services, &self.previews);
|
||||
let (plan, _) = plan_job(&job, seq, &self.pool, &self.services, &self.previews, false);
|
||||
self.shared.plans.lock().unwrap_or_else(|e| e.into_inner()).insert(job.key, (Arc::new(plan), 0));
|
||||
} else {
|
||||
let img = render_job(&job, &self.pool, &self.services, &self.previews);
|
||||
let (img, _) = render_job(&job, &self.pool, &self.services, &self.previews, false);
|
||||
self.shared.done.lock().unwrap_or_else(|e| e.into_inner()).insert(job.key, Arc::new(img));
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// Counts shown and dropped frames while playing.
|
||||
///
|
||||
/// A frame of the timeline is *shown* when its exact picture was on screen at some refresh while
|
||||
/// it was the frame due, and *dropped* otherwise — including frames the playhead skipped because
|
||||
/// no refresh happened during their interval. Frames left out on purpose (fast-forward speeds
|
||||
/// step over frames) are not counted.
|
||||
#[derive(Clone, Debug, Default)]
|
||||
pub struct PlaybackMeter {
|
||||
pub shown: u64,
|
||||
pub dropped: u64,
|
||||
/// Frame due at the last refresh, and whether its exact picture has been shown.
|
||||
current: Option<(i64, bool)>,
|
||||
/// Frames advanced per displayed frame (speed), and direction.
|
||||
step: i64,
|
||||
}
|
||||
|
||||
impl PlaybackMeter {
|
||||
pub fn start(&mut self, speed: f64) {
|
||||
*self = Self { step: (speed.abs().max(1.0) as i64) * if speed < 0.0 { -1 } else { 1 }, ..Default::default() };
|
||||
}
|
||||
|
||||
/// Record one display refresh: `frame` is due now and `exact` says whether it is on screen.
|
||||
pub fn refresh(&mut self, frame: i64, exact: bool) {
|
||||
let step = if self.step == 0 { 1 } else { self.step };
|
||||
match self.current {
|
||||
Some((f, seen)) if f == frame => self.current = Some((f, seen || exact)),
|
||||
Some((f, seen)) => {
|
||||
self.close(seen);
|
||||
let moved = (frame - f) / step;
|
||||
// Forward progress: count frames passed over without a refresh. A jump backwards
|
||||
// (loop restart) or a huge jump is a discontinuity, not a drop.
|
||||
if moved > 1 && moved < 1000 {
|
||||
self.dropped += (moved - 1) as u64;
|
||||
}
|
||||
self.current = Some((frame, exact));
|
||||
}
|
||||
None => self.current = Some((frame, exact)),
|
||||
}
|
||||
}
|
||||
|
||||
fn close(&mut self, seen: bool) {
|
||||
if seen {
|
||||
self.shown += 1;
|
||||
} else {
|
||||
self.dropped += 1;
|
||||
}
|
||||
}
|
||||
|
||||
/// Playback stopped: account for the frame on screen.
|
||||
pub fn finish(&mut self) {
|
||||
if let Some((_, seen)) = self.current.take() {
|
||||
self.close(seen);
|
||||
}
|
||||
}
|
||||
|
||||
/// Shown and dropped so far, counting the frame currently due as shown when it is.
|
||||
pub fn counts(&self) -> (u64, u64) {
|
||||
match self.current {
|
||||
Some((_, true)) => (self.shown + 1, self.dropped),
|
||||
_ => (self.shown, self.dropped),
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
#[cfg(not(target_arch = "wasm32"))]
|
||||
fn worker(sh: Arc<Shared>, pool: Arc<MediaPool>, services: Arc<dyn Services>, previews: Arc<PreviewStore>, repaint: Arc<Mutex<Option<egui::Context>>>) {
|
||||
fn worker(
|
||||
sh: Arc<Shared>,
|
||||
pool: Arc<MediaPool>,
|
||||
services: Arc<dyn Services>,
|
||||
previews: Arc<PreviewStore>,
|
||||
repaint: Arc<Mutex<Option<Box<dyn Fn() + Send + Sync>>>>,
|
||||
) {
|
||||
loop {
|
||||
let job = {
|
||||
let mut q = sh.queue.lock().unwrap_or_else(|e| e.into_inner());
|
||||
@@ -218,8 +433,13 @@ fn worker(sh: Arc<Shared>, pool: Arc<MediaPool>, services: Arc<dyn Services>, pr
|
||||
}
|
||||
};
|
||||
sh.in_flight.lock().unwrap_or_else(|e| e.into_inner()).push(job.key);
|
||||
let profiling = sh.profiling.load(Ordering::Relaxed);
|
||||
let (started, cpu0) = (Instant::now(), if profiling { thread_cpu_time().unwrap_or_default() } else { Duration::ZERO });
|
||||
SOURCE_TIME.with(|s| s.set((Duration::ZERO, Duration::ZERO)));
|
||||
let preview;
|
||||
if let Target::SequencePlan(seq) = job.key.target {
|
||||
let plan = plan_job(&job, seq, &pool, &services, &previews);
|
||||
let (plan, pv) = plan_job(&job, seq, &pool, &services, &previews, profiling);
|
||||
preview = pv;
|
||||
let mut g = sh.plans.lock().unwrap_or_else(|e| e.into_inner());
|
||||
let clock = g.values().map(|v| v.1).max().unwrap_or(0) + 1;
|
||||
g.insert(job.key, (Arc::new(plan), clock));
|
||||
@@ -231,12 +451,28 @@ fn worker(sh: Arc<Shared>, pool: Arc<MediaPool>, services: Arc<dyn Services>, pr
|
||||
}
|
||||
}
|
||||
} else {
|
||||
let img = render_job(&job, &pool, &services, &previews);
|
||||
let (img, pv) = render_job(&job, &pool, &services, &previews, profiling);
|
||||
preview = pv;
|
||||
sh.done.lock().unwrap_or_else(|e| e.into_inner()).insert(job.key, Arc::new(img));
|
||||
}
|
||||
sh.in_flight.lock().unwrap_or_else(|e| e.into_inner()).retain(|k| *k != job.key);
|
||||
if let Some(ctx) = repaint.lock().unwrap_or_else(|e| e.into_inner()).as_ref() {
|
||||
ctx.request_repaint();
|
||||
if profiling {
|
||||
let (source_wall, source_cpu) = SOURCE_TIME.with(|s| s.get());
|
||||
let rec = JobRecord {
|
||||
key: job.key,
|
||||
prio: job.prio,
|
||||
queued: job.queued,
|
||||
started,
|
||||
finished: Instant::now(),
|
||||
cpu: thread_cpu_time().unwrap_or_default().saturating_sub(cpu0),
|
||||
source_wall,
|
||||
source_cpu,
|
||||
preview,
|
||||
};
|
||||
sh.records.lock().unwrap_or_else(|e| e.into_inner()).push(rec);
|
||||
}
|
||||
if let Some(f) = repaint.lock().unwrap_or_else(|e| e.into_inner()).as_ref() {
|
||||
f();
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -244,10 +480,21 @@ fn worker(sh: Arc<Shared>, pool: Arc<MediaPool>, services: Arc<dyn Services>, pr
|
||||
/// The preview frame for a sequence job, when its segment has been rendered.
|
||||
fn preview_frame(job: &Job, seq: ItemId, pool: &MediaPool, previews: &PreviewStore) -> Option<Arc<filmcraft_frame::VideoFrame>> {
|
||||
let rate = job.project.sequence(seq)?.settings.frame_rate;
|
||||
previews.frame(pool, &job.project, seq, rate.frame_at(job.time), job.scale)
|
||||
timed_source(|| previews.frame(pool, &job.project, seq, rate.frame_at(job.time), job.scale))
|
||||
}
|
||||
|
||||
fn plan_job(job: &Job, seq: ItemId, pool: &Arc<MediaPool>, services: &Arc<dyn Services>, previews: &PreviewStore) -> filmcraft_render::plan::FramePlan {
|
||||
fn provider(job: &Job, pool: &Arc<MediaPool>, services: &Arc<dyn Services>, timed: bool) -> JobProvider {
|
||||
JobProvider { inner: pool.provider(job.project.clone(), services.clone()), timed }
|
||||
}
|
||||
|
||||
fn plan_job(
|
||||
job: &Job,
|
||||
seq: ItemId,
|
||||
pool: &Arc<MediaPool>,
|
||||
services: &Arc<dyn Services>,
|
||||
previews: &PreviewStore,
|
||||
timed: bool,
|
||||
) -> (filmcraft_render::plan::FramePlan, bool) {
|
||||
let opts = filmcraft_render::RenderOptions { scale: job.scale, captions: true, ..Default::default() };
|
||||
if let Some(frame) = preview_frame(job, seq, pool, previews)
|
||||
&& let Some(q) = job.project.sequence(seq)
|
||||
@@ -264,13 +511,14 @@ fn plan_job(job: &Job, seq: ItemId, pool: &Arc<MediaPool>, services: &Arc<dyn Se
|
||||
opacity: 1.0,
|
||||
});
|
||||
}
|
||||
return filmcraft_render::plan::FramePlan::Layers { width: w, height: h, layers };
|
||||
return (filmcraft_render::plan::FramePlan::Layers { width: w, height: h, layers }, true);
|
||||
}
|
||||
let provider = pool.provider(job.project.clone(), services.clone());
|
||||
filmcraft_render::plan::plan_frame(&job.project, seq, job.time, opts, &provider)
|
||||
let provider = provider(job, pool, services, timed);
|
||||
(filmcraft_render::plan::plan_frame(&job.project, seq, job.time, opts, &provider), false)
|
||||
}
|
||||
|
||||
fn render_job(job: &Job, pool: &Arc<MediaPool>, services: &Arc<dyn Services>, previews: &PreviewStore) -> Rgba {
|
||||
/// Render a job to RGBA8; the flag says whether it came from a render preview.
|
||||
fn render_job(job: &Job, pool: &Arc<MediaPool>, services: &Arc<dyn Services>, previews: &PreviewStore, timed: bool) -> (Rgba, bool) {
|
||||
if let Target::Sequence(seq) | Target::SequencePlan(seq) = job.key.target
|
||||
&& let Some(f) = preview_frame(job, seq, pool, previews)
|
||||
&& let Some(q) = job.project.sequence(seq)
|
||||
@@ -287,28 +535,53 @@ fn render_job(job: &Job, pool: &Arc<MediaPool>, services: &Arc<dyn Services>, pr
|
||||
o.composite_onto(&mut img.px, w, h);
|
||||
}
|
||||
}
|
||||
return Rgba { w: img.w, h: img.h, px: img.over_black_rgba8() };
|
||||
return (Rgba { w: img.w, h: img.h, px: img.over_black_rgba8() }, true);
|
||||
}
|
||||
let provider = pool.provider(job.project.clone(), services.clone());
|
||||
let provider = provider(job, pool, services, timed);
|
||||
let opts = filmcraft_render::RenderOptions { scale: job.scale, captions: true, ..Default::default() };
|
||||
let img = match job.key.target {
|
||||
Target::Sequence(seq) => Some(filmcraft_render::render_sequence(
|
||||
&job.project,
|
||||
seq,
|
||||
job.time,
|
||||
filmcraft_render::RenderOptions { scale: job.scale, captions: true, ..Default::default() },
|
||||
&provider,
|
||||
)),
|
||||
Target::Sequence(seq) | Target::SequencePlan(seq) => Some(filmcraft_render::render_sequence(&job.project, seq, job.time, opts, &provider)),
|
||||
Target::Item(item) => filmcraft_render::render_item(&job.project, item, job.time, job.scale, &provider),
|
||||
Target::SequencePlan(seq) => Some(filmcraft_render::render_sequence(
|
||||
&job.project,
|
||||
seq,
|
||||
job.time,
|
||||
filmcraft_render::RenderOptions { scale: job.scale, captions: true, ..Default::default() },
|
||||
&provider,
|
||||
)),
|
||||
};
|
||||
match img {
|
||||
let rgba = match img {
|
||||
Some(img) => Rgba { w: img.w, h: img.h, px: img.over_black_rgba8() },
|
||||
None => Rgba { w: 1, h: 1, px: vec![0, 0, 0, 255] },
|
||||
};
|
||||
(rgba, false)
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::PlaybackMeter;
|
||||
|
||||
#[test]
|
||||
fn meter_counts_frames_not_refreshes() {
|
||||
// 24 fps on a 60 Hz display: each frame is due for 2–3 refreshes.
|
||||
let mut m = PlaybackMeter::default();
|
||||
m.start(1.0);
|
||||
for (f, exact) in [(0, true), (0, true), (0, true), (1, false), (1, true), (2, false), (2, false), (3, true)] {
|
||||
m.refresh(f, exact);
|
||||
}
|
||||
m.finish();
|
||||
// frame 1 arrived late but was on screen while due → shown; frame 2 never → dropped.
|
||||
assert_eq!((m.shown, m.dropped), (3, 1));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn meter_counts_skipped_frames_but_not_speed_steps_or_loops() {
|
||||
let mut m = PlaybackMeter::default();
|
||||
m.start(1.0);
|
||||
m.refresh(10, true);
|
||||
m.refresh(14, true); // no refresh during 11..13 (UI stalled)
|
||||
m.refresh(0, true); // loop restart
|
||||
m.finish();
|
||||
assert_eq!((m.shown, m.dropped), (3, 3));
|
||||
let mut m = PlaybackMeter::default();
|
||||
m.start(2.0); // 2× steps over every other frame on purpose
|
||||
for f in [0, 2, 4, 6] {
|
||||
m.refresh(f, true);
|
||||
}
|
||||
m.finish();
|
||||
assert_eq!((m.shown, m.dropped), (4, 0));
|
||||
}
|
||||
}
|
||||
|
||||
@@ -69,9 +69,8 @@ pub struct Playback {
|
||||
anchor_tick: Tick,
|
||||
/// Audio frames played at anchor (when the audio clock drives).
|
||||
pub audio_clock: bool,
|
||||
pub dropped: u64,
|
||||
pub shown: u64,
|
||||
last_frame: i64,
|
||||
/// Shown / dropped frame accounting for the current (or last) play.
|
||||
pub meter: frames::PlaybackMeter,
|
||||
}
|
||||
|
||||
pub struct FilmcraftApp {
|
||||
@@ -162,12 +161,7 @@ impl FilmcraftApp {
|
||||
|
||||
impl FilmcraftApp {
|
||||
pub fn new(session: Session) -> Self {
|
||||
let frames = Arc::new(FrameServer::new(
|
||||
session.media.clone(),
|
||||
session.services.clone(),
|
||||
session.previews.clone(),
|
||||
std::thread::available_parallelism().map(|n| n.get().clamp(2, 6)).unwrap_or(3),
|
||||
));
|
||||
let frames = Arc::new(FrameServer::new(session.media.clone(), session.services.clone(), session.previews.clone(), FrameServer::default_workers()));
|
||||
Self {
|
||||
session,
|
||||
ui: UiState::default(),
|
||||
@@ -220,7 +214,7 @@ impl FilmcraftApp {
|
||||
self.session.media.clone(),
|
||||
self.session.services.clone(),
|
||||
self.session.previews.clone(),
|
||||
std::thread::available_parallelism().map(|n| n.get().clamp(2, 6)).unwrap_or(3),
|
||||
FrameServer::default_workers(),
|
||||
));
|
||||
self.textures.clear();
|
||||
}
|
||||
@@ -282,17 +276,20 @@ impl FilmcraftApp {
|
||||
if speed > 0.0 && self.session.playhead() >= dur - self.session.sequence_rate().frame_duration() {
|
||||
self.session.set_playhead(Tick::ZERO);
|
||||
}
|
||||
// A loop restart keeps counting into the same meter.
|
||||
if !self.playback.playing || self.playback.speed != speed {
|
||||
self.playback.meter.start(speed);
|
||||
}
|
||||
self.playback.playing = true;
|
||||
self.playback.speed = speed;
|
||||
self.playback.anchor_tick = self.session.playhead();
|
||||
self.playback.anchor_time = -1.0; // set on next frame
|
||||
self.playback.dropped = 0;
|
||||
self.playback.shown = 0;
|
||||
self.start_audio();
|
||||
}
|
||||
|
||||
pub fn stop(&mut self) {
|
||||
self.playback.playing = false;
|
||||
self.playback.meter.finish();
|
||||
if let Some(a) = self.audio.as_mut() {
|
||||
a.stop();
|
||||
}
|
||||
|
||||
@@ -100,49 +100,32 @@ pub fn show(app: &mut FilmcraftApp, ui: &mut egui::Ui, rect: Rect, which: Which)
|
||||
let key = FrameKey { target, frame, size: size_key, revision: rev };
|
||||
let project = app.session.project.clone();
|
||||
let playing = which == Which::Program && app.playback.playing;
|
||||
app.frames.request(key, rate.tick_of(frame), scale, &project, 0);
|
||||
if playing {
|
||||
let dir = if app.playback.speed < 0.0 { -1 } else { 1 };
|
||||
let ahead = if app.playback.speed.abs() > 1.5 { 24 } else { 14 };
|
||||
for i in 1..=ahead {
|
||||
let f = frame + i * dir * (app.playback.speed.abs().max(1.0) as i64);
|
||||
if f >= 0 {
|
||||
app.frames.request(FrameKey { frame: f, ..key }, rate.tick_of(f), scale, &project, i as u32);
|
||||
}
|
||||
}
|
||||
// drop stale prefetch jobs
|
||||
let cur = frame;
|
||||
app.frames.retain_queue(|k| k.target != target || (k.revision == rev && (k.frame - cur) * dir >= 0 && (k.frame - cur).abs() < 40));
|
||||
app.frames.schedule_playback(key, rate, scale, &project, app.playback.speed);
|
||||
} else {
|
||||
app.frames.request(key, rate.tick_of(frame), scale, &project, 0);
|
||||
}
|
||||
let tex_name = format!("monitor-{prefix}");
|
||||
let shown = if use_gpu {
|
||||
let (shown, exact) = if use_gpu {
|
||||
let exact = app.frames.get_plan(&key).map(|p| (key, p));
|
||||
if exact.is_some() {
|
||||
if playing {
|
||||
app.playback.shown += 1;
|
||||
}
|
||||
} else if playing && app.playback.last_frame_shown() != frame {
|
||||
app.playback.dropped += 1;
|
||||
}
|
||||
match exact.or_else(|| app.frames.nearest_plan(key, 6)) {
|
||||
let is_exact = exact.is_some();
|
||||
let tex = match exact.or_else(|| app.frames.nearest_plan(key, 6)) {
|
||||
Some((k, plan)) => app.gpu_present(k, &plan).map(|(id, _)| id),
|
||||
None => app.gpu.as_ref().and_then(|g| g.texture),
|
||||
}
|
||||
};
|
||||
(tex, is_exact)
|
||||
} else if let Some(img) = app.frames.get(&key) {
|
||||
if playing {
|
||||
app.playback.shown += 1;
|
||||
}
|
||||
Some(app.texture_for(&ctx, &tex_name, key, &img))
|
||||
(Some(app.texture_for(&ctx, &tex_name, key, &img)), true)
|
||||
} else {
|
||||
if playing && app.playback.last_frame_shown() != frame {
|
||||
app.playback.dropped += 1;
|
||||
}
|
||||
match app.frames.nearest(target, frame, size_key, rev, 6) {
|
||||
let tex = match app.frames.nearest(target, frame, size_key, rev, 6) {
|
||||
Some(img) => Some(app.texture_for(&ctx, &tex_name, FrameKey { frame: frame - 1, ..key }, &img)),
|
||||
None => app.texture_existing(&tex_name).map(|(id, _)| id),
|
||||
}
|
||||
};
|
||||
(tex, false)
|
||||
};
|
||||
app.playback.set_last_frame(frame);
|
||||
if playing {
|
||||
app.playback.meter.refresh(frame, exact);
|
||||
}
|
||||
if let Some(tex) = shown {
|
||||
ui.painter().image(tex, pic, Rect::from_min_max(pos2(0.0, 0.0), pos2(1.0, 1.0)), Color32::WHITE);
|
||||
}
|
||||
@@ -162,7 +145,7 @@ pub fn show(app: &mut FilmcraftApp, ui: &mut egui::Ui, rect: Rect, which: Which)
|
||||
}
|
||||
// Dropped-frame indicator (Program only)
|
||||
if which == Which::Program && app.playback.playing {
|
||||
let c = if app.playback.dropped > 0 { t.render_yellow } else { t.render_green };
|
||||
let c = if app.playback.meter.counts().1 > 0 { t.render_yellow } else { t.render_green };
|
||||
ui.painter().circle_filled(pos2(video_area.min.x + 10.0, video_area.min.y + 10.0), 4.0, c);
|
||||
}
|
||||
// Click/drag in the picture: the Hand tool pans, otherwise focus.
|
||||
@@ -404,12 +387,3 @@ fn source_nav(app: &mut FilmcraftApp, cmd: &str) {
|
||||
};
|
||||
let _ = app.session.execute("source.setPlayhead", json!({"time": t.0}));
|
||||
}
|
||||
|
||||
impl crate::Playback {
|
||||
pub fn last_frame_shown(&self) -> i64 {
|
||||
self.last_frame
|
||||
}
|
||||
pub fn set_last_frame(&mut self, f: i64) {
|
||||
self.last_frame = f;
|
||||
}
|
||||
}
|
||||
|
||||
@@ -94,3 +94,44 @@ engine behaviour without a window.
|
||||
The perf tests check bit-exactness before they time anything. Results go in the crate README's
|
||||
performance table, with machine and thread count. Headline numbers go in
|
||||
[ROADMAP.md](../ROADMAP.md). Measure on an idle machine: parallel agent builds distort timings.
|
||||
|
||||
### Playback benchmark
|
||||
|
||||
`cargo xtask bench-playback` (the example `crates/ui-egui/examples/bench_playback.rs`) plays
|
||||
sequences headlessly through the Program monitor's own frame scheduler: the `FrameServer` worker
|
||||
pool, `schedule_playback` (prefetch order and stale-job dropping), its caches, and the
|
||||
`PlaybackMeter` that counts shown/dropped frames in the app. On the GPU path it also composites
|
||||
each plan with `filmcraft-gpu`, as the monitor does on the UI thread.
|
||||
|
||||
```sh
|
||||
cargo xtask bench-playback # every scenario, GPU path, Full and Half
|
||||
cargo xtask bench-playback --scenario stack3 --res full --cpu
|
||||
cargo xtask bench-playback --json target/bench-playback.json # machine-readable results
|
||||
```
|
||||
|
||||
| Scenario | What plays |
|
||||
|---|---|
|
||||
| `h264-1080` | one 1080p23.976 H.264 clip (testsrc2 + grain, ~45 Mbit/s, 250-frame GOP) |
|
||||
| `stack3` | three 1080p H.264 clips on V1–V3; V2/V3 scaled, positioned, rotated, 70–85 % opacity |
|
||||
| `h264-2160` | one 2160p23.976 H.264 clip |
|
||||
| `demo` | the built-in demo project (procedural footage, transitions, effects) |
|
||||
| `after-preview` | 1080p H.264 + Lumetri/Sharpen/Levels/Tint: a live play, Render Effects In to Out, then two plays of the green segment |
|
||||
| `seek-storm` | 40 jumps to random frames 150 ms apart (scrubbing), time until the exact frame shows |
|
||||
|
||||
Options: `--res full,half,quarter`, `--cpu` (CPU compositor + texture conversion instead of the
|
||||
GPU path), `--seconds`, `--refresh` (display Hz), `--workers`, `--repeat`, `--json <file>`.
|
||||
Fixtures are made with ffmpeg in `target/fixtures/playback/` (set `FILMCRAFT_FIXTURES` to share one
|
||||
set between worktrees).
|
||||
|
||||
Columns: **shown/drop** as counted in the app (a frame is shown when its exact picture was on
|
||||
screen at a refresh while it was due; frames passed over without a refresh count as dropped);
|
||||
**ontime** = due frames whose job finished before they were due; **lat** = queue→ready per job,
|
||||
**svc** = worker time per job; **cpu/j**, **src/j**, **srcC/j** = worker thread CPU, source fetch
|
||||
(decode) wall and thread CPU per job; **ui** = time on the UI thread to present a frame (GPU upload
|
||||
and draw, or texture conversion); **cpu ms/f** = process CPU per frame and **cores** = the cores that
|
||||
needs at the sequence frame rate; **seeks/dec** = decoder restarts and samples decoded; **waste** =
|
||||
jobs for frames that were never due.
|
||||
|
||||
Wall-clock columns (shown/drop, ontime, latencies) depend on machine load, so each row prints the
|
||||
load average. CPU columns (thread and process CPU time) and the structural counters (seeks,
|
||||
samples decoded, wasted jobs) do not, and are what to compare between runs on a busy machine.
|
||||
|
||||
+9
-1
@@ -246,6 +246,13 @@ fn ci() -> Result<(), String> {
|
||||
wasm()
|
||||
}
|
||||
|
||||
/// The headless playback benchmark (`crates/ui-egui/examples/bench_playback.rs`); extra
|
||||
/// arguments go to the benchmark (`cargo xtask bench-playback --scenario stack3 --res full`).
|
||||
fn bench_playback() -> Result<(), String> {
|
||||
let extra: Vec<String> = std::env::args().skip(2).collect();
|
||||
run(Command::new(env!("CARGO")).args(["run", "--release", "-p", "filmcraft-ui-egui", "--example", "bench_playback", "--"]).args(&extra))
|
||||
}
|
||||
|
||||
fn main() -> ExitCode {
|
||||
let task = std::env::args().nth(1).unwrap_or_default();
|
||||
let r = match task.as_str() {
|
||||
@@ -253,7 +260,8 @@ fn main() -> ExitCode {
|
||||
"wasm" => wasm(),
|
||||
"assets" => assets(),
|
||||
"ci" => ci(),
|
||||
_ => Err("usage: cargo xtask <layers|assets|wasm|ci>".into()),
|
||||
"bench-playback" => bench_playback(),
|
||||
_ => Err("usage: cargo xtask <layers|assets|wasm|ci|bench-playback [args]>".into()),
|
||||
};
|
||||
match r {
|
||||
Ok(()) => ExitCode::SUCCESS,
|
||||
|
||||
Reference in New Issue
Block a user