From 5093ae120c5c0244b26991285ad5b49c10facb87 Mon Sep 17 00:00:00 2001 From: VladimirK <47093374+VladimirKras@users.noreply.github.com> Date: Tue, 25 Aug 2026 07:24:28 +0300 Subject: [PATCH 1/3] Avoid blocking GPU poll after Vello frames Use nonblocking device maintenance after presenting in both GPU Vello window renderers. Surface acquisition still supplies bounded presentation backpressure while the CPU can prepare the next frame before the previous submission completes. Assisted-by: Codex/gpt-5 --- crates/anyrender_vello/src/window_renderer.rs | 10 +++++----- crates/anyrender_vello_hybrid/src/window_renderer.rs | 10 +++++----- 2 files changed, 10 insertions(+), 10 deletions(-) diff --git a/crates/anyrender_vello/src/window_renderer.rs b/crates/anyrender_vello/src/window_renderer.rs index cbb0b29..fbf4132 100644 --- a/crates/anyrender_vello/src/window_renderer.rs +++ b/crates/anyrender_vello/src/window_renderer.rs @@ -489,12 +489,12 @@ impl WindowRenderer for VelloWindowRenderer { } timer.record_time("present"); - render_surface - .device() - .poll(wgpu::PollType::wait_indefinitely()) - .unwrap(); + // Progress cleanup and callbacks without serializing the next frame + // behind completion of this frame's GPU work. Surface acquisition + // provides bounded backpressure via desired_maximum_frame_latency. + render_surface.device().poll(wgpu::PollType::Poll).unwrap(); - timer.record_time("wait"); + timer.record_time("poll"); timer.print_times("vello: "); // Empty the Vello scene (memory optimisation) diff --git a/crates/anyrender_vello_hybrid/src/window_renderer.rs b/crates/anyrender_vello_hybrid/src/window_renderer.rs index 89d63ba..4b19ea0 100644 --- a/crates/anyrender_vello_hybrid/src/window_renderer.rs +++ b/crates/anyrender_vello_hybrid/src/window_renderer.rs @@ -579,12 +579,12 @@ impl WindowRenderer for VelloHybridWindowRenderer { } timer.record_time("present"); - render_surface - .device() - .poll(wgpu::PollType::wait_indefinitely()) - .unwrap(); + // Progress cleanup and callbacks without serializing the next frame + // behind completion of this frame's GPU work. Surface acquisition + // provides bounded backpressure via desired_maximum_frame_latency. + render_surface.device().poll(wgpu::PollType::Poll).unwrap(); - timer.record_time("wait"); + timer.record_time("poll"); timer.print_times("vello_hybrid: "); // Empty the Vello scene (memory optimisation) From 223de2e9604cfeb72e90bcade4784adda1167023 Mon Sep 17 00:00:00 2001 From: Nico Burns Date: Tue, 20 Oct 2026 16:32:53 -0700 Subject: [PATCH 2/3] Add previous-frame GPU time and acquire stages to log_frame_times --- crates/anyrender_vello/Cargo.toml | 2 +- crates/anyrender_vello/src/window_renderer.rs | 12 ++- crates/anyrender_vello_hybrid/Cargo.toml | 2 +- .../src/window_renderer.rs | 14 ++- crates/wgpu_context/Cargo.toml | 3 + crates/wgpu_context/src/gpu_frame_timer.rs | 86 +++++++++++++++++++ crates/wgpu_context/src/lib.rs | 2 + 7 files changed, 117 insertions(+), 4 deletions(-) create mode 100644 crates/wgpu_context/src/gpu_frame_timer.rs diff --git a/crates/anyrender_vello/Cargo.toml b/crates/anyrender_vello/Cargo.toml index 6df65d2..a4ec74a 100644 --- a/crates/anyrender_vello/Cargo.toml +++ b/crates/anyrender_vello/Cargo.toml @@ -9,7 +9,7 @@ license.workspace = true edition.workspace = true [features] -log_frame_times = ["debug_timer/enable"] +log_frame_times = ["debug_timer/enable", "wgpu_context/log_frame_times"] [dependencies] anyrender = { workspace = true } diff --git a/crates/anyrender_vello/src/window_renderer.rs b/crates/anyrender_vello/src/window_renderer.rs index fbf4132..70aadfa 100644 --- a/crates/anyrender_vello/src/window_renderer.rs +++ b/crates/anyrender_vello/src/window_renderer.rs @@ -16,7 +16,7 @@ use wgpu::{ TextureUsages, }; use wgpu_context::{ - AlphaConversion, DeviceHandle, SurfaceRenderer, SurfaceRendererConfiguration, + AlphaConversion, DeviceHandle, GpuFrameTimer, SurfaceRenderer, SurfaceRendererConfiguration, TextureConfiguration, WGPUContext, }; @@ -164,6 +164,7 @@ pub struct VelloWindowRenderer { wgpu_context: WGPUContext, scene: VelloScene, config: VelloRendererOptions, + gpu_timer: GpuFrameTimer, // Resources texture_handles: FxHashMap, @@ -181,6 +182,7 @@ impl VelloWindowRenderer { render_state: RenderState::Suspended, wgpu_context: build_wgpu_context(&config), config, + gpu_timer: GpuFrameTimer::new(), window_handle: None, scene: VelloScene::new(), texture_handles: FxHashMap::default(), @@ -464,6 +466,7 @@ impl WindowRenderer for VelloWindowRenderer { state.renderer.mark_override_image_dirty(handle); } + self.gpu_timer.start_frame(); state .renderer .render_to_texture( @@ -483,10 +486,16 @@ impl WindowRenderer for VelloWindowRenderer { drop(texture_view); + if render_surface.ensure_current_surface_texture().is_err() { + return; + } + timer.record_time("acquire"); + if render_surface.maybe_blit_and_present().is_err() { self.scene.reset(); return; } + self.gpu_timer.end_frame(render_surface.queue()); timer.record_time("present"); // Progress cleanup and callbacks without serializing the next frame @@ -496,6 +505,7 @@ impl WindowRenderer for VelloWindowRenderer { timer.record_time("poll"); timer.print_times("vello: "); + self.gpu_timer.print_completed("vello: "); // Empty the Vello scene (memory optimisation) self.scene.reset(); diff --git a/crates/anyrender_vello_hybrid/Cargo.toml b/crates/anyrender_vello_hybrid/Cargo.toml index 495935c..ec03852 100644 --- a/crates/anyrender_vello_hybrid/Cargo.toml +++ b/crates/anyrender_vello_hybrid/Cargo.toml @@ -9,7 +9,7 @@ license.workspace = true edition.workspace = true [features] -log_frame_times = ["debug_timer/enable"] +log_frame_times = ["debug_timer/enable", "wgpu_context/log_frame_times"] webgl = ["vello_gpu/webgl"] [dependencies] diff --git a/crates/anyrender_vello_hybrid/src/window_renderer.rs b/crates/anyrender_vello_hybrid/src/window_renderer.rs index 4b19ea0..cac9f76 100644 --- a/crates/anyrender_vello_hybrid/src/window_renderer.rs +++ b/crates/anyrender_vello_hybrid/src/window_renderer.rs @@ -16,7 +16,9 @@ use wgpu::{ CommandEncoderDescriptor, CompositeAlphaMode, Features, Limits, PresentMode, Texture, TextureFormat, TextureView, TextureViewDescriptor, }; -use wgpu_context::{DeviceHandle, SurfaceRenderer, SurfaceRendererConfiguration, WGPUContext}; +use wgpu_context::{ + DeviceHandle, GpuFrameTimer, SurfaceRenderer, SurfaceRendererConfiguration, WGPUContext, +}; use crate::{VelloHybridScenePainter, scene::ImageManager}; @@ -173,6 +175,7 @@ pub struct VelloHybridWindowRenderer { wgpu_context: WGPUContext, scene: VelloHybridScene, config: VelloHybridRendererOptions, + gpu_timer: GpuFrameTimer, cached_images: FxHashMap, } impl VelloHybridWindowRenderer { @@ -188,6 +191,7 @@ impl VelloHybridWindowRenderer { Self { render_state: RenderState::Suspended, config, + gpu_timer: GpuFrameTimer::new(), wgpu_context, window_handle: None, scene: VelloHybridScene::new_with(0, 0, render_settings.level), @@ -568,15 +572,22 @@ impl WindowRenderer for VelloHybridWindowRenderer { TargetInit::Clear(ClearSettings::default()), ) .expect("failed to render to texture"); + self.gpu_timer.start_frame(); render_surface.queue().submit([encoder.finish()]); timer.record_time("render"); drop(texture_view); + if render_surface.ensure_current_surface_texture().is_err() { + return; + } + timer.record_time("acquire"); + if render_surface.maybe_blit_and_present().is_err() { self.scene.reset(); return; } + self.gpu_timer.end_frame(render_surface.queue()); timer.record_time("present"); // Progress cleanup and callbacks without serializing the next frame @@ -586,6 +597,7 @@ impl WindowRenderer for VelloHybridWindowRenderer { timer.record_time("poll"); timer.print_times("vello_hybrid: "); + self.gpu_timer.print_completed("vello_hybrid: "); // Empty the Vello scene (memory optimisation) self.scene.reset(); diff --git a/crates/wgpu_context/Cargo.toml b/crates/wgpu_context/Cargo.toml index 769a825..380530d 100644 --- a/crates/wgpu_context/Cargo.toml +++ b/crates/wgpu_context/Cargo.toml @@ -8,6 +8,9 @@ repository.workspace = true license.workspace = true edition.workspace = true +[features] +log_frame_times = [] + [dependencies] wgpu = { workspace = true } futures-intrusive = { workspace = true } diff --git a/crates/wgpu_context/src/gpu_frame_timer.rs b/crates/wgpu_context/src/gpu_frame_timer.rs new file mode 100644 index 0000000..8d01e92 --- /dev/null +++ b/crates/wgpu_context/src/gpu_frame_timer.rs @@ -0,0 +1,86 @@ +//! Wall-clock timing of a frame's GPU work, for `log_frame_times`-style debug output. + +#[cfg(feature = "log_frame_times")] +mod real { + use std::io::{Write, stdout}; + use std::sync::{Arc, Mutex}; + use std::time::{Duration, Instant}; + use wgpu::Queue; + + /// Measures the wall-clock time from a frame's first GPU submission until the GPU has + /// finished its last one, using `Queue::on_submitted_work_done`. The callback runs during a + /// later `Device::poll`/`Queue::submit`, so a frame's time is available one frame late. + /// Any swapchain wait made between the submissions is included, so this bounds GPU execution + /// time from above; timestamp queries are needed for exact GPU time. + pub struct GpuFrameTimer { + frame_start: Option, + completed: Arc>>, + } + + impl GpuFrameTimer { + pub fn new() -> Self { + Self { + frame_start: None, + completed: Arc::new(Mutex::new(None)), + } + } + + /// Mark the start of this frame's GPU work. Call before the frame's first submission. + pub fn start_frame(&mut self) { + self.frame_start = Some(Instant::now()); + } + + /// Register for completion of this frame's GPU work. Call after the frame's last submission. + pub fn end_frame(&mut self, queue: &Queue) { + let Some(start) = self.frame_start.take() else { + return; + }; + let completed = self.completed.clone(); + queue.on_submitted_work_done(move || { + *completed.lock().unwrap() = Some(start.elapsed()); + }); + } + + /// Print the time taken by the most recently completed frame, if one has completed + /// since the last call. + pub fn print_completed(&self, message: &str) { + if let Some(duration) = self.completed.lock().unwrap().take() { + let ms = duration.as_secs_f64() * 1000.0; + let mut out = stdout().lock(); + writeln!(out, "{message}gpu: {ms:.2}ms (previous frame)").unwrap(); + } + } + } +} + +#[cfg(not(feature = "log_frame_times"))] +mod dummy { + use wgpu::Queue; + + /// No-op stand-in for the `log_frame_times` GPU frame timer. + pub struct GpuFrameTimer; + + impl GpuFrameTimer { + #[inline(always)] + pub fn new() -> Self { + Self + } + #[inline(always)] + pub fn start_frame(&mut self) {} + #[inline(always)] + pub fn end_frame(&mut self, _queue: &Queue) {} + #[inline(always)] + pub fn print_completed(&self, _message: &str) {} + } +} + +#[cfg(not(feature = "log_frame_times"))] +pub use dummy::GpuFrameTimer; +#[cfg(feature = "log_frame_times")] +pub use real::GpuFrameTimer; + +impl Default for GpuFrameTimer { + fn default() -> Self { + Self::new() + } +} diff --git a/crates/wgpu_context/src/lib.rs b/crates/wgpu_context/src/lib.rs index 62dd1a2..eec9aec 100644 --- a/crates/wgpu_context/src/lib.rs +++ b/crates/wgpu_context/src/lib.rs @@ -10,12 +10,14 @@ use wgpu::{ mod alpha_blitter; mod buffer_renderer; mod error; +mod gpu_frame_timer; mod surface_renderer; mod util; pub use alpha_blitter::{AlphaConversion, AlphaConvertBlitter}; pub use buffer_renderer::{BufferRenderer, BufferRendererConfig}; pub use error::WgpuContextError; +pub use gpu_frame_timer::GpuFrameTimer; pub use surface_renderer::{SurfaceRenderer, SurfaceRendererConfiguration, TextureConfiguration}; pub use util::block_on_wgpu; From b3fee79b4008acbde2415b11610bd901b9ffa110 Mon Sep 17 00:00:00 2001 From: Nico Burns Date: Tue, 20 Oct 2026 16:46:58 -0700 Subject: [PATCH 3/3] Poll the device from a thread while timing GPU work; split render/blit; skip acquire/blit stages without an intermediate texture; drop the poll stage --- crates/anyrender_vello/src/window_renderer.rs | 11 +- .../src/window_renderer.rs | 22 ++-- crates/wgpu_context/src/gpu_frame_timer.rs | 102 +++++++++++++----- crates/wgpu_context/src/surface_renderer.rs | 6 ++ 4 files changed, 105 insertions(+), 36 deletions(-) diff --git a/crates/anyrender_vello/src/window_renderer.rs b/crates/anyrender_vello/src/window_renderer.rs index 70aadfa..83423cd 100644 --- a/crates/anyrender_vello/src/window_renderer.rs +++ b/crates/anyrender_vello/src/window_renderer.rs @@ -466,7 +466,7 @@ impl WindowRenderer for VelloWindowRenderer { state.renderer.mark_override_image_dirty(handle); } - self.gpu_timer.start_frame(); + self.gpu_timer.start(); state .renderer .render_to_texture( @@ -482,6 +482,8 @@ impl WindowRenderer for VelloWindowRenderer { }, ) .expect("failed to render to texture"); + self.gpu_timer + .submitted("render", render_surface.device(), render_surface.queue()); timer.record_time("render"); drop(texture_view); @@ -491,19 +493,20 @@ impl WindowRenderer for VelloWindowRenderer { } timer.record_time("acquire"); + self.gpu_timer.start(); + if render_surface.maybe_blit_and_present().is_err() { self.scene.reset(); return; } - self.gpu_timer.end_frame(render_surface.queue()); + self.gpu_timer + .submitted("blit", render_surface.device(), render_surface.queue()); timer.record_time("present"); // Progress cleanup and callbacks without serializing the next frame // behind completion of this frame's GPU work. Surface acquisition // provides bounded backpressure via desired_maximum_frame_latency. render_surface.device().poll(wgpu::PollType::Poll).unwrap(); - - timer.record_time("poll"); timer.print_times("vello: "); self.gpu_timer.print_completed("vello: "); diff --git a/crates/anyrender_vello_hybrid/src/window_renderer.rs b/crates/anyrender_vello_hybrid/src/window_renderer.rs index cac9f76..cc85bb5 100644 --- a/crates/anyrender_vello_hybrid/src/window_renderer.rs +++ b/crates/anyrender_vello_hybrid/src/window_renderer.rs @@ -547,6 +547,10 @@ impl WindowRenderer for VelloHybridWindowRenderer { self.scene.reset(); return; }; + // Without an intermediate texture the surface texture was just acquired above + if !render_surface.has_intermediate_texture() { + timer.record_time("acquire"); + } // Construct Vello Hybrid TextureBindings let mut texture_bindings = TextureBindings::new(); @@ -572,30 +576,34 @@ impl WindowRenderer for VelloHybridWindowRenderer { TargetInit::Clear(ClearSettings::default()), ) .expect("failed to render to texture"); - self.gpu_timer.start_frame(); + self.gpu_timer.start(); render_surface.queue().submit([encoder.finish()]); + self.gpu_timer + .submitted("render", render_surface.device(), render_surface.queue()); timer.record_time("render"); drop(texture_view); - if render_surface.ensure_current_surface_texture().is_err() { - return; + if render_surface.has_intermediate_texture() { + if render_surface.ensure_current_surface_texture().is_err() { + return; + } + timer.record_time("acquire"); + self.gpu_timer.start(); } - timer.record_time("acquire"); if render_surface.maybe_blit_and_present().is_err() { self.scene.reset(); return; } - self.gpu_timer.end_frame(render_surface.queue()); + self.gpu_timer + .submitted("blit", render_surface.device(), render_surface.queue()); timer.record_time("present"); // Progress cleanup and callbacks without serializing the next frame // behind completion of this frame's GPU work. Surface acquisition // provides bounded backpressure via desired_maximum_frame_latency. render_surface.device().poll(wgpu::PollType::Poll).unwrap(); - - timer.record_time("poll"); timer.print_times("vello_hybrid: "); self.gpu_timer.print_completed("vello_hybrid: "); diff --git a/crates/wgpu_context/src/gpu_frame_timer.rs b/crates/wgpu_context/src/gpu_frame_timer.rs index 8d01e92..f0c2231 100644 --- a/crates/wgpu_context/src/gpu_frame_timer.rs +++ b/crates/wgpu_context/src/gpu_frame_timer.rs @@ -3,59 +3,111 @@ #[cfg(feature = "log_frame_times")] mod real { use std::io::{Write, stdout}; + use std::sync::atomic::{AtomicUsize, Ordering}; use std::sync::{Arc, Mutex}; use std::time::{Duration, Instant}; - use wgpu::Queue; + use wgpu::{Device, Queue}; - /// Measures the wall-clock time from a frame's first GPU submission until the GPU has - /// finished its last one, using `Queue::on_submitted_work_done`. The callback runs during a - /// later `Device::poll`/`Queue::submit`, so a frame's time is available one frame late. - /// Any swapchain wait made between the submissions is included, so this bounds GPU execution + /// How often the polling thread checks the device while frames are in flight. + const POLL_INTERVAL: Duration = Duration::from_micros(250); + + /// Measures the wall-clock time from `start` until the GPU has finished the work submitted + /// by the following `submitted` call, using `Queue::on_submitted_work_done`. CPU work done + /// between the two calls (e.g. vello's encoding) is included, so this bounds GPU execution /// time from above; timestamp queries are needed for exact GPU time. + /// + /// wgpu only runs the callback from `Device::poll`/`Queue::submit`, which the render loop + /// calls about once per frame, so on native a thread polls the device every + /// `POLL_INTERVAL` while frames are in flight (WebGPU polls by itself). Completed times are + /// printed on the next frame. pub struct GpuFrameTimer { - frame_start: Option, - completed: Arc>>, + start: Option, + shared: Arc, + poller: Option, + } + + #[derive(Default)] + struct Shared { + completed: Mutex>, + in_flight: AtomicUsize, } impl GpuFrameTimer { pub fn new() -> Self { Self { - frame_start: None, - completed: Arc::new(Mutex::new(None)), + start: None, + shared: Arc::new(Shared::default()), + poller: None, } } - /// Mark the start of this frame's GPU work. Call before the frame's first submission. - pub fn start_frame(&mut self) { - self.frame_start = Some(Instant::now()); + /// Mark the start of a piece of GPU work. Call before it is submitted. + pub fn start(&mut self) { + self.start = Some(Instant::now()); } - /// Register for completion of this frame's GPU work. Call after the frame's last submission. - pub fn end_frame(&mut self, queue: &Queue) { - let Some(start) = self.frame_start.take() else { + /// Register for completion of the work submitted since `start`. Call after its submission. + pub fn submitted(&mut self, label: &'static str, device: &Device, queue: &Queue) { + let Some(start) = self.start.take() else { return; }; - let completed = self.completed.clone(); + let shared = self.shared.clone(); + shared.in_flight.fetch_add(1, Ordering::AcqRel); queue.on_submitted_work_done(move || { - *completed.lock().unwrap() = Some(start.elapsed()); + shared + .completed + .lock() + .unwrap() + .push((label, start.elapsed())); + shared.in_flight.fetch_sub(1, Ordering::AcqRel); }); + self.wake_poller(device); } - /// Print the time taken by the most recently completed frame, if one has completed - /// since the last call. + /// Print the time taken by each piece of work that has completed since the last call. pub fn print_completed(&self, message: &str) { - if let Some(duration) = self.completed.lock().unwrap().take() { - let ms = duration.as_secs_f64() * 1000.0; + let completed = std::mem::take(&mut *self.shared.completed.lock().unwrap()); + if !completed.is_empty() { let mut out = stdout().lock(); - writeln!(out, "{message}gpu: {ms:.2}ms (previous frame)").unwrap(); + for (label, duration) in completed { + let ms = duration.as_secs_f64() * 1000.0; + writeln!(out, "{message}gpu {label}: {ms:.2}ms (previous frame)").unwrap(); + } } } + + #[cfg(target_arch = "wasm32")] + fn wake_poller(&mut self, _device: &Device) {} + + #[cfg(not(target_arch = "wasm32"))] + fn wake_poller(&mut self, device: &Device) { + let poller = self.poller.get_or_insert_with(|| { + let device = device.clone(); + let shared = self.shared.clone(); + std::thread::Builder::new() + .name("gpu-frame-timer".into()) + .spawn(move || { + loop { + if shared.in_flight.load(Ordering::Acquire) == 0 { + std::thread::park(); + continue; + } + let _ = device.poll(wgpu::PollType::Poll); + std::thread::sleep(POLL_INTERVAL); + } + }) + .unwrap() + .thread() + .clone() + }); + poller.unpark(); + } } } #[cfg(not(feature = "log_frame_times"))] mod dummy { - use wgpu::Queue; + use wgpu::{Device, Queue}; /// No-op stand-in for the `log_frame_times` GPU frame timer. pub struct GpuFrameTimer; @@ -66,9 +118,9 @@ mod dummy { Self } #[inline(always)] - pub fn start_frame(&mut self) {} + pub fn start(&mut self) {} #[inline(always)] - pub fn end_frame(&mut self, _queue: &Queue) {} + pub fn submitted(&mut self, _label: &'static str, _device: &Device, _queue: &Queue) {} #[inline(always)] pub fn print_completed(&self, _message: &str) {} } diff --git a/crates/wgpu_context/src/surface_renderer.rs b/crates/wgpu_context/src/surface_renderer.rs index 5c7bb5b..4693d15 100644 --- a/crates/wgpu_context/src/surface_renderer.rs +++ b/crates/wgpu_context/src/surface_renderer.rs @@ -288,6 +288,12 @@ impl<'s> SurfaceRenderer<'s> { /// /// If there is an intermediate texture, this is a view of that intermediate texture, otherwise /// it is a view of the surface texture. + /// Whether rendering goes via an intermediate texture that is blitted to the surface on + /// present, rather than directly into the surface texture. + pub fn has_intermediate_texture(&self) -> bool { + self.intermediate_texture.is_some() + } + pub fn target_texture_view(&mut self) -> Result { match &self.intermediate_texture { Some(intermediate_texture) => Ok(intermediate_texture.texture_view.clone()),