diff --git a/crates/export/src/lib.rs b/crates/export/src/lib.rs index a92978a0..e94756eb 100644 --- a/crates/export/src/lib.rs +++ b/crates/export/src/lib.rs @@ -732,6 +732,7 @@ pub(crate) fn build_frame_renderer() -> Option> { static GPU_FRAMES: std::sync::atomic::AtomicU64 = std::sync::atomic::AtomicU64::new(0); static GPU_FALLBACKS: std::sync::atomic::AtomicU64 = std::sync::atomic::AtomicU64::new(0); +static LOCK_WAIT_NS: std::sync::atomic::AtomicU64 = std::sync::atomic::AtomicU64::new(0); /// A frame was composited by the registered GPU renderer. pub fn note_gpu_frame() { @@ -743,6 +744,21 @@ pub fn note_gpu_fallback() { GPU_FALLBACKS.fetch_add(1, Ordering::Relaxed); } +/// Time an export worker waited for a free GPU renderer (process-wide, for the bench). +pub(crate) fn note_lock_wait(d: std::time::Duration) { + LOCK_WAIT_NS.fetch_add(u64::try_from(d.as_nanos()).unwrap_or(u64::MAX), Ordering::Relaxed); +} + +/// Total time export workers waited for a GPU renderer since [`reset_export_lock_wait`]. +pub fn export_lock_wait() -> std::time::Duration { + std::time::Duration::from_nanos(LOCK_WAIT_NS.load(Ordering::Relaxed)) +} + +/// Start [`export_lock_wait`] again from zero. +pub fn reset_export_lock_wait() { + LOCK_WAIT_NS.store(0, Ordering::Relaxed); +} + /// GPU-vs-CPU frame counters of the export renderer (per-process, like the hardware ones). #[derive(Clone, Copy, Debug, PartialEq, Eq)] pub struct GpuRenderStats { diff --git a/crates/export/src/pipeline.rs b/crates/export/src/pipeline.rs index 6f744504..9ffbecb6 100644 --- a/crates/export/src/pipeline.rs +++ b/crates/export/src/pipeline.rs @@ -49,12 +49,43 @@ impl Geometry { } } +/// GPU renderers shared by the export workers: a worker takes a free one for a frame and puts it +/// back (a single renderer behind a mutex made the workers queue, GPU export ~20 % slower than CPU). +struct RendererPool { + renderers: std::sync::Mutex>>, + available: std::sync::Condvar, +} + +impl RendererPool { + /// `None` for an empty list (a pool nobody could take from). + fn new(renderers: Vec>) -> Option { + (!renderers.is_empty()).then(|| Self { renderers: std::sync::Mutex::new(renderers), available: std::sync::Condvar::new() }) + } + + /// Run `f` with a free renderer, waiting for one if all are busy. + fn with(&self, f: impl FnOnce(&mut dyn FrameRenderer) -> R) -> Option { + let mut free = self.renderers.lock().unwrap_or_else(std::sync::PoisonError::into_inner); + let mut r = loop { + match free.pop() { + Some(r) => break r, + None => free = self.available.wait(free).unwrap_or_else(std::sync::PoisonError::into_inner), + } + }; + drop(free); + // the renderer goes back even when `f` panics (the export worker runs under catch_unwind) + let res = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| f(&mut *r))); + self.renderers.lock().unwrap_or_else(std::sync::PoisonError::into_inner).push(r); + self.available.notify_one(); + res.ok() + } +} + /// The immutable part of an export: everything needed to produce one output frame. pub(crate) struct Pipeline { pub project: Arc, - /// The registered frame renderer (GPU compositor) when the setting allows and a factory - /// provided one; guarded because `frame` runs on several export threads at once. - renderer: Option>>, + /// The registered frame renderers (GPU compositors) when the setting allows and factories + /// provide them; pooled because `frame` runs on several export threads at once. + renderer: Option, pub seq: ItemId, /// Output frame rate (frame `f` is at `rate.tick_of(f)`). pub rate: FrameRate, @@ -97,7 +128,22 @@ impl Pipeline { } else { None }; - let renderer = if settings.gpu_rendering == GpuRendering::Off { None } else { build_frame_renderer().map(std::sync::Mutex::new) }; + let renderer = if settings.gpu_rendering == GpuRendering::Off { + None + } else { + // Four renderers: as fast as one per worker (measured on 16 threads, where more only + // contend for memory bandwidth in the read-back), with a quarter of the GPU memory. + let count = rayon::current_num_threads().clamp(2, 4); + let mut list = Vec::with_capacity(count); + for _ in 0..count { + if let Some(r) = build_frame_renderer() { + list.push(r); + } else { + break; + } + } + RendererPool::new(list) + }; Ok(Pipeline { renderer, seq_rate: q.settings.frame_rate, @@ -124,9 +170,13 @@ impl Pipeline { // The registered GPU renderer goes first; `None` (no adapter, a plan the GPU cannot // draw, any internal error) falls back to the CPU reference renderer below. let gpu = match self.renderer.as_ref() { - Some(r) => { - let mut r = r.lock().unwrap_or_else(|e| e.into_inner()); - r.render(&self.project, self.seq, t, self.opts, sources) + Some(pool) => { + let asked = std::time::Instant::now(); + pool.with(|r| { + crate::note_lock_wait(asked.elapsed()); + r.render(&self.project, self.seq, t, self.opts, sources) + }) + .flatten() } None => None, }; diff --git a/crates/gpu/src/export_renderer.rs b/crates/gpu/src/export_renderer.rs index 082d1a2d..af4696e1 100644 --- a/crates/gpu/src/export_renderer.rs +++ b/crates/gpu/src/export_renderer.rs @@ -4,7 +4,9 @@ //! `filmcraft_render::render_sequence`'s premultiplied linear-light RGBA and the export pipeline's //! placement, overlays and video limiter see exactly what the CPU renderer would have produced. //! -//! The renderer owns its own wgpu instance/adapter/device (no window). With no adapter (headless +//! Renderers share one off-screen wgpu device (no window), created by the first and kept for the +//! process, so an export can run several (one per export worker; each has its own compositor and +//! textures) without opening a device each. With no adapter (headless //! machine, unsupported GPU) [`ExportRenderer::new`] returns `None` and the export falls back to //! the CPU renderer; a `FramePlan::Image` plan (HDR / wide gamut / anything the plan sends to the //! CPU) is returned unchanged — it already is the CPU image. @@ -15,6 +17,61 @@ use filmcraft_render::plan::{FramePlan, plan_frame}; use filmcraft_render::{Image, RenderOptions, SourceProvider}; use filmcraft_time::Tick; +/// Where export rendering spends its time (process-wide totals, for the bench). +pub mod timing { + use std::sync::atomic::{AtomicU64, Ordering}; + use std::time::Duration; + + static SUBMIT_NS: AtomicU64 = AtomicU64::new(0); + static MAP_WAIT_NS: AtomicU64 = AtomicU64::new(0); + static CONVERT_NS: AtomicU64 = AtomicU64::new(0); + static FRAMES: AtomicU64 = AtomicU64::new(0); + + /// Totals since the last [`reset`]. + #[derive(Clone, Copy, Debug, Default, PartialEq, Eq)] + pub struct GpuTimings { + /// Recording and submitting the frame's commands. + pub submit: Duration, + /// Waiting for the GPU and the staging buffer's mapping. + pub map_wait: Duration, + /// Half float → f32 conversion of the read-back pixels. + pub convert: Duration, + /// Frames composited by the GPU. + pub frames: u64, + } + + fn add(counter: &AtomicU64, d: Duration) { + counter.fetch_add(u64::try_from(d.as_nanos()).unwrap_or(u64::MAX), Ordering::Relaxed); + } + + pub(crate) fn add_submit(d: Duration) { + add(&SUBMIT_NS, d); + } + + pub(crate) fn add_map_wait(d: Duration) { + add(&MAP_WAIT_NS, d); + } + + pub(crate) fn add_convert(d: Duration) { + add(&CONVERT_NS, d); + } + + pub(crate) fn add_frame() { + FRAMES.fetch_add(1, Ordering::Relaxed); + } + + pub fn get() -> GpuTimings { + let d = |c: &AtomicU64| Duration::from_nanos(c.load(Ordering::Relaxed)); + GpuTimings { submit: d(&SUBMIT_NS), map_wait: d(&MAP_WAIT_NS), convert: d(&CONVERT_NS), frames: FRAMES.load(Ordering::Relaxed) } + } + + pub fn reset() { + for c in [&SUBMIT_NS, &MAP_WAIT_NS, &CONVERT_NS, &FRAMES] { + c.store(0, Ordering::Relaxed); + } + } +} + pub struct ExportRenderer { _instance: wgpu::Instance, #[expect(dead_code, reason = "kept for future frame-accuracy flows (readback fences)")] @@ -27,9 +84,17 @@ pub struct ExportRenderer { impl ExportRenderer { /// The off-screen device, or `None` when this host has no usable adapter. pub fn new() -> Option { - let instance = wgpu::Instance::default(); - let adapter = pollster::block_on(instance.request_adapter(&wgpu::RequestAdapterOptions::default())).ok()?; - let (device, queue) = pollster::block_on(adapter.request_device(&wgpu::DeviceDescriptor::default())).ok()?; + // `None` is kept too: a machine without an adapter does not search again on every export + static SHARED: std::sync::OnceLock> = std::sync::OnceLock::new(); + let (instance, device, queue) = SHARED + .get_or_init(|| { + let instance = wgpu::Instance::default(); + let adapter = pollster::block_on(instance.request_adapter(&wgpu::RequestAdapterOptions::default())).ok()?; + let (device, queue) = pollster::block_on(adapter.request_device(&wgpu::DeviceDescriptor::default())).ok()?; + Some((instance, device, queue)) + }) + .as_ref()? + .clone(); let compositor = GpuCompositor::new(&device, &queue); Some(Self { _instance: instance, device, queue, compositor }) } @@ -43,8 +108,8 @@ impl ExportRenderer { FramePlan::Image(img) => Some(img.clone()), FramePlan::Layers { .. } => { let prep = prepare(&plan); - self.compositor.composite_prepared(&plan, Some(&prep)); - let (w, h, px) = self.compositor.read_accumulator()?; + let (w, h, px) = self.compositor.render_export_prepared(&plan, Some(&prep))?; + timing::add_frame(); Some(Image { w: w as usize, h: h as usize, px }) } } diff --git a/crates/gpu/src/lib.rs b/crates/gpu/src/lib.rs index b9379998..09800c6c 100644 --- a/crates/gpu/src/lib.rs +++ b/crates/gpu/src/lib.rs @@ -79,6 +79,7 @@ pub struct GpuCompositor { /// Copy of the accumulator under a blend-mode layer (allocated on first use). backdrop: Option<(wgpu::Texture, wgpu::TextureView, (u32, u32))>, output: Option<(wgpu::Texture, wgpu::TextureView, (u32, u32))>, + accum_readback_buf: Option<(wgpu::Buffer, u64)>, uploads: HashMap<(usize, u32, u32), Uploaded>, clock: u64, dummy: wgpu::TextureView, @@ -154,6 +155,23 @@ pub fn f16_to_f32(h: u16) -> f32 { f32::from_bits(bits) } +/// [`f16_to_f32`] with a branch-light path for normal numbers and zeros (the bulk of read-back +/// data); subnormals, infinities and NaNs take the general path. Same result for every input. +#[inline(always)] +pub fn f16_to_f32_fast(h: u16) -> f32 { + let u = u32::from(h); + let sign = (u & 0x8000) << 16; + let abs = u & 0x7fff; + if (0x0400..0x7c00).contains(&abs) { + // rebias the exponent (127 - 15 = 112) and widen the mantissa + f32::from_bits(sign | ((abs + (112 << 10)) << 13)) + } else if abs == 0 { + f32::from_bits(sign) + } else { + f16_to_f32(h) + } +} + /// Half-float texel data for one frame (one byte vector per plane), converted off the UI thread. /// 8-bit frames need no conversion and have none. #[derive(Clone, Debug, Default)] @@ -361,6 +379,7 @@ impl GpuCompositor { accum: None, backdrop: None, output: None, + accum_readback_buf: None, uploads: HashMap::new(), clock: 0, dummy, @@ -603,7 +622,7 @@ impl GpuCompositor { /// [`composite`](Self::composite) with texel conversions already done by [`prepare`] (the /// result is identical; only the upload work on this thread differs). - pub fn composite_prepared(&mut self, plan: &FramePlan, prep: Option<&PreparedPlan>) -> (wgpu::TextureView, (u32, u32)) { + fn draw_layers_into_accum(&mut self, plan: &FramePlan, prep: Option<&PreparedPlan>, enc: &mut wgpu::CommandEncoder) -> (wgpu::TextureView, (u32, u32)) { let owned; let (w, h, layers): (u32, u32, &[PlanLayer]) = match plan { FramePlan::Layers { width, height, layers } => (*width as u32, *height as u32, layers.as_slice()), @@ -629,7 +648,6 @@ impl GpuCompositor { } else { None }; - let out_view = Self::target(&self.device, &mut self.output, w, h, OUTPUT_FORMAT, wgpu::TextureUsages::COPY_SRC); // Layers whose effects the GPU stage can't run (no stage on this device, or a working image // larger than a texture) are rendered on the CPU here and drawn as plain RGBA layers. let max_side = self.device.limits().max_texture_dimension_2d; @@ -741,14 +759,9 @@ impl GpuCompositor { if let Some(f) = self.fx.as_mut() { f.end_frame(); } - let final_bg = self.device.create_bind_group(&wgpu::BindGroupDescriptor { - label: Some("final"), - layout: &self.final_bgl, - entries: &[wgpu::BindGroupEntry { binding: 0, resource: wgpu::BindingResource::TextureView(&accum_view) }], - }); - let mut enc = self.device.create_command_encoder(&wgpu::CommandEncoderDescriptor { label: Some("filmcraft-composite") }); // Runs of fixed-function layers draw in one pass. A layer that reads the destination // ends it, copies the accumulator under its quad into the backdrop and draws on its own. + let accum_tex = self.accum.as_ref().map(|a| a.0.clone()); let backdrop_tex = self.backdrop.as_ref().map(|b| b.0.clone()); let mut cleared = false; @@ -757,13 +770,13 @@ impl GpuCompositor { // a layer's effects run right before it is drawn (pooled working textures are reused // by the next layer with effects) if let (Some(Some(job)), Some(f)) = (jobs.get(i), self.fx.as_ref()) { - f.record(&mut enc, job); + f.record(enc, job); } if let Some((bg, Some(region))) = bind_groups.get(i) { i += 1; let (Some(rect), Some(src), Some(dst)) = (region, &accum_tex, &backdrop_tex) else { continue }; if !cleared { - accum_pass(&mut enc, &accum_view, wgpu::LoadOp::Clear(wgpu::Color::TRANSPARENT)); + accum_pass(enc, &accum_view, wgpu::LoadOp::Clear(wgpu::Color::TRANSPARENT)); cleared = true; } let origin = wgpu::Origin3d { x: rect.0, y: rect.1, z: 0 }; @@ -772,7 +785,7 @@ impl GpuCompositor { wgpu::TexelCopyTextureInfo { texture: dst, mip_level: 0, origin, aspect: wgpu::TextureAspect::All }, wgpu::Extent3d { width: rect.2, height: rect.3, depth_or_array_layers: 1 }, ); - let mut pass = accum_pass(&mut enc, &accum_view, wgpu::LoadOp::Load); + let mut pass = accum_pass(enc, &accum_view, wgpu::LoadOp::Load); pass.set_pipeline(&self.blend_pipeline); pass.set_bind_group(0, bg, &[]); pass.draw(0..6, 0..1); @@ -783,7 +796,7 @@ impl GpuCompositor { let breaks = |j: &usize| bind_groups.get(*j).is_some_and(|(_, r)| r.is_some()) || jobs.get(*j).is_some_and(Option::is_some); let end = (i + 1..bind_groups.len()).find(breaks).unwrap_or(bind_groups.len()).max(i); let load = if cleared { wgpu::LoadOp::Load } else { wgpu::LoadOp::Clear(wgpu::Color::TRANSPARENT) }; - let mut pass = accum_pass(&mut enc, &accum_view, load); + let mut pass = accum_pass(enc, &accum_view, load); cleared = true; pass.set_pipeline(&self.layer_pipeline); for (bg, _) in bind_groups.get(i..end).unwrap_or_default() { @@ -792,6 +805,20 @@ impl GpuCompositor { } i = end; } + (accum_view, (w, h)) + } + + /// [`composite`](Self::composite) with texel conversions already done by [`prepare`] (the + /// result is identical; only the upload work on this thread differs). + pub fn composite_prepared(&mut self, plan: &FramePlan, prep: Option<&PreparedPlan>) -> (wgpu::TextureView, (u32, u32)) { + let mut enc = self.device.create_command_encoder(&wgpu::CommandEncoderDescriptor { label: Some("filmcraft-composite") }); + let (accum_view, (w, h)) = self.draw_layers_into_accum(plan, prep, &mut enc); + let out_view = Self::target(&self.device, &mut self.output, w, h, OUTPUT_FORMAT, wgpu::TextureUsages::COPY_SRC); + let final_bg = self.device.create_bind_group(&wgpu::BindGroupDescriptor { + label: Some("final"), + layout: &self.final_bgl, + entries: &[wgpu::BindGroupEntry { binding: 0, resource: wgpu::BindingResource::TextureView(&accum_view) }], + }); { let mut pass = enc.begin_render_pass(&wgpu::RenderPassDescriptor { label: Some("resolve"), @@ -814,6 +841,20 @@ impl GpuCompositor { (out_view, (w, h)) } + /// Export rendering in one submission: `plan` composited into the linear float accumulator, + /// which is copied to a reused staging buffer and read back as premultiplied RGBA f32 (what + /// [`composite_prepared`](Self::composite_prepared) + [`read_accumulator`](Self::read_accumulator) + /// give, without the sRGB resolve or a second submission). + pub fn render_export_prepared(&mut self, plan: &FramePlan, prep: Option<&PreparedPlan>) -> Option<(u32, u32, Vec)> { + let t = std::time::Instant::now(); + let mut enc = self.device.create_command_encoder(&wgpu::CommandEncoderDescriptor { label: Some("filmcraft-composite-export") }); + self.draw_layers_into_accum(plan, prep, &mut enc); + let size = self.copy_accumulator(&mut enc)?; + self.queue.submit([enc.finish()]); + export_renderer::timing::add_submit(t.elapsed()); + self.map_accumulator(size) + } + /// Run the effect stage of a layer alone: `frame` decoded into its working image and `fx` /// applied, read back as linear premultiplied RGBA f32 (what `LayerFx` ops produce on the /// CPU from the same frame). None when the working image does not fit in a texture. @@ -877,22 +918,47 @@ impl GpuCompositor { /// the display texture this crate's [`read_output`](Self::read_output) resolves is sRGB 8-bit /// and would clip the working-space data HDR exports need. The accumulator must have been /// composited first ([`composite`](Self::composite) / [`composite_prepared`](Self::composite_prepared)). - pub fn read_accumulator(&self) -> Option<(u32, u32, Vec)> { - let (tex, _, (w, h)) = self.accum.as_ref()?; - let row = (w * 8).div_ceil(256) * 256; - let buf = self.device.create_buffer(&wgpu::BufferDescriptor { - label: Some("accum-readback"), - size: (row * h) as u64, - usage: wgpu::BufferUsages::COPY_DST | wgpu::BufferUsages::MAP_READ, - mapped_at_creation: false, - }); + pub fn read_accumulator(&mut self) -> Option<(u32, u32, Vec)> { let mut enc = self.device.create_command_encoder(&Default::default()); + let size = self.copy_accumulator(&mut enc)?; + self.queue.submit([enc.finish()]); + self.map_accumulator(size) + } + + /// Record a copy of the accumulator into the staging buffer (grown when too small, reused + /// otherwise); returns its width, height and row pitch in bytes. + fn copy_accumulator(&mut self, enc: &mut wgpu::CommandEncoder) -> Option<(u32, u32, u32)> { + let (_, _, (w, h)) = self.accum.as_ref()?; + let (w, h) = (*w, *h); + let row = w.checked_mul(8)?.div_ceil(256).checked_mul(256)?; + let needed = u64::from(row) * u64::from(h); + if self.accum_readback_buf.as_ref().is_none_or(|(_, size)| *size < needed) { + let b = self.device.create_buffer(&wgpu::BufferDescriptor { + label: Some("accum-readback"), + size: needed, + usage: wgpu::BufferUsages::COPY_DST | wgpu::BufferUsages::MAP_READ, + mapped_at_creation: false, + }); + self.accum_readback_buf = Some((b, needed)); + } + let (tex, _, _) = self.accum.as_ref()?; + let (buf, _) = self.accum_readback_buf.as_ref()?; enc.copy_texture_to_buffer( wgpu::TexelCopyTextureInfo { texture: tex, mip_level: 0, origin: wgpu::Origin3d::ZERO, aspect: wgpu::TextureAspect::All }, - wgpu::TexelCopyBufferInfo { buffer: &buf, layout: wgpu::TexelCopyBufferLayout { offset: 0, bytes_per_row: Some(row), rows_per_image: Some(*h) } }, - wgpu::Extent3d { width: *w, height: *h, depth_or_array_layers: 1 }, + wgpu::TexelCopyBufferInfo { buffer: buf, layout: wgpu::TexelCopyBufferLayout { offset: 0, bytes_per_row: Some(row), rows_per_image: Some(h) } }, + wgpu::Extent3d { width: w, height: h, depth_or_array_layers: 1 }, ); - self.queue.submit([enc.finish()]); + Some((w, h, row)) + } + + /// Wait for the staging buffer filled by [`copy_accumulator`](Self::copy_accumulator) and + /// convert its half floats to f32. + fn map_accumulator(&self, (w, h, row): (u32, u32, u32)) -> Option<(u32, u32, Vec)> { + if w == 0 || h == 0 { + return None; + } + let t = std::time::Instant::now(); + let (buf, _) = self.accum_readback_buf.as_ref()?; let slice = buf.slice(..); let (tx, rx) = std::sync::mpsc::channel(); slice.map_async(wgpu::MapMode::Read, move |r| { @@ -900,15 +966,23 @@ impl GpuCompositor { }); let _ = self.device.poll(wgpu::PollType::wait_indefinitely()); rx.recv().ok()?.ok()?; + export_renderer::timing::add_map_wait(t.elapsed()); + let t = std::time::Instant::now(); + let (width, row) = (w as usize, row as usize); + let mut out = filmcraft_frame::pool::take_f32_overwritten(width.checked_mul(h as usize)?.checked_mul(4)?); let data = slice.get_mapped_range().ok()?; - let mut out = Vec::with_capacity((w * h * 4) as usize); - for y in 0..*h { - let r = data.get((y * row) as usize..(y * row + w * 8) as usize)?; - out.extend(r.as_chunks::<2>().0.iter().map(|b| f16_to_f32(u16::from_le_bytes(*b)))); - } + // every row must be there: the pooled output holds stale values until written + let converted = out.chunks_exact_mut(width * 4).enumerate().all(|(y, dst)| { + let Some(src) = data.get(y * row..y * row + width * 8) else { return false }; + for (d, s) in dst.iter_mut().zip(src.as_chunks::<2>().0) { + *d = f16_to_f32_fast(u16::from_le_bytes(*s)); + } + true + }); drop(data); buf.unmap(); - Some((*w, *h, out)) + export_renderer::timing::add_convert(t.elapsed()); + converted.then_some((w, h, out)) } /// Read the output back as RGBA8 (tests / screenshots / thumbnails). diff --git a/crates/gpu/src/tests.rs b/crates/gpu/src/tests.rs index a11cef8b..87b69cc9 100644 --- a/crates/gpu/src/tests.rs +++ b/crates/gpu/src/tests.rs @@ -320,3 +320,11 @@ fn gpu_draws_yuv_alpha_plane_like_the_cpu() { assert!(r != at(&bg, w - 2), "{bits}-bit: right edge {r:?} should differ from the background"); } } + +#[test] +fn fast_half_float_conversion_matches_the_reference_for_every_value() { + for h in 0..=u16::MAX { + let (fast, slow) = (f16_to_f32_fast(h), f16_to_f32(h)); + assert!(fast.to_bits() == slow.to_bits() || (fast.is_nan() && slow.is_nan()), "{h:#06x}: {fast} vs {slow}"); + } +} diff --git a/crates/ui-egui/examples/bench/sections.rs b/crates/ui-egui/examples/bench/sections.rs index 7953a763..e7c06751 100644 --- a/crates/ui-egui/examples/bench/sections.rs +++ b/crates/ui-egui/examples/bench/sections.rs @@ -484,6 +484,8 @@ pub fn export(o: &Opts) -> Vec { .expect("audio"); frames = s.project.sequence(seq).map(|q| q.settings.frame_rate.frame_at(q.duration())).unwrap_or(0); let out = dir.join(format!("out.{ext}")); + filmcraft_export::reset_export_lock_wait(); + filmcraft_gpu::export_renderer::timing::reset(); let (t0, c0) = (Instant::now(), cpu_now()); // `--hw auto`: the hardware encoder too (NVENC H.264 on Windows); `--hw off`: ours let hardware = if o.hw == "off" { "off" } else { "auto" }; @@ -497,6 +499,22 @@ pub fn export(o: &Opts) -> Vec { eprintln!("export {format}: {e}"); break; } + let lock_wait = filmcraft_export::export_lock_wait(); + let gpu_timings = filmcraft_gpu::export_renderer::timing::get(); + if gpu_timings.frames > 0 { + let f = gpu_timings.frames as f64; + eprintln!( + " [GPU timings for {format}] lock_wait: {:.1} ms ({:.2} ms/f), submit: {:.1} ms ({:.2} ms/f), map_wait: {:.1} ms ({:.2} ms/f), convert: {:.1} ms ({:.2} ms/f)", + lock_wait.as_secs_f64() * 1000.0, + lock_wait.as_secs_f64() * 1000.0 / f, + gpu_timings.submit.as_secs_f64() * 1000.0, + gpu_timings.submit.as_secs_f64() * 1000.0 / f, + gpu_timings.map_wait.as_secs_f64() * 1000.0, + gpu_timings.map_wait.as_secs_f64() * 1000.0 / f, + gpu_timings.convert.as_secs_f64() * 1000.0, + gpu_timings.convert.as_secs_f64() * 1000.0 / f, + ); + } runs.push(dt); cpu.push(ms(cpu_now() - c0) / frames.max(1) as f64); bytes = std::fs::metadata(&out).map(|m| m.len()).unwrap_or(0);