molgfx_render/engine/
profiling.rs

1//! Capability-gated whole-graph GPU and CPU frame timing.
2
3use super::image::ImagePurpose;
4use super::{Engine, ImageConfig, MotionBlur, QualityTier, TemporalOptions};
5use crate::ResidencyMetrics;
6use crate::error::RenderError;
7use molgfx_core::Scene;
8use molgfx_gpu::{
9    BufferDesc, BufferUsage, CommandEncoder as _, Device, Queue as _, TextureDesc, TextureUsage,
10    TextureViewDesc,
11};
12use molgfx_math::Camera;
13// Uses the host monotonic clock on both native and browser targets.
14use web_time::Instant;
15
16const QUERY_BYTES: u64 = 2 * std::mem::size_of::<u64>() as u64;
17
18/// One measured frame. GPU time covers the complete scheduled render graph;
19/// CPU time covers scene synchronization, graph recording, and submission.
20#[derive(Clone, Copy, PartialEq, Eq, Debug)]
21pub struct FrameTiming {
22    /// Device execution time in nanoseconds.
23    pub gpu_ns: u64,
24    /// Whether the timestamp query readback resolved this duration.
25    ///
26    /// A zero duration is evidence only when this is `true`. Backends may
27    /// expose timestamp queries while returning an unresolved zero sentinel.
28    pub gpu_timing_resolved: bool,
29    /// Host frame-construction time in nanoseconds.
30    pub cpu_ns: u64,
31    /// End-to-end blocking profile duration, including device completion and
32    /// timestamp readback. This is the conservative frame-budget metric when
33    /// an adapter reports unusable timestamp values.
34    pub frame_ns: u64,
35    /// Real residency, upload, command and backpressure counters at completion.
36    pub residency: ResidencyMetrics,
37}
38
39impl FrameTiming {
40    /// Flat cumulative residency counters at measurement completion.
41    #[must_use]
42    pub fn residency_counters(self) -> crate::ResidencyCounters {
43        self.residency.counters()
44    }
45}
46
47#[derive(Debug)]
48pub(crate) struct GpuProfiler<D: Device> {
49    queries: D::QuerySet,
50    resolve: D::Buffer,
51    readback: D::Buffer,
52    target: Option<D::Texture>,
53    target_view: Option<D::TextureView>,
54    target_size: (u32, u32),
55    target_format: molgfx_gpu::TextureFormat,
56    pending_start: Option<u64>,
57}
58
59impl<D: Device> GpuProfiler<D> {
60    pub(crate) fn new(
61        device: &D,
62        target_format: molgfx_gpu::TextureFormat,
63    ) -> Result<Option<Self>, RenderError> {
64        if !device.capabilities().timestamp_queries() {
65            return Ok(None);
66        }
67        Ok(Some(Self {
68            queries: device.create_timestamp_query_set(2)?,
69            resolve: device.create_buffer(&BufferDesc {
70                label: "frame timestamp resolve",
71                size: QUERY_BYTES,
72                usage: BufferUsage::QUERY_RESOLVE.union(BufferUsage::COPY_SRC),
73            })?,
74            readback: device.create_buffer(&BufferDesc {
75                label: "frame timestamp readback",
76                size: QUERY_BYTES,
77                usage: BufferUsage::COPY_DST.union(BufferUsage::MAP_READ),
78            })?,
79            target: None,
80            target_view: None,
81            target_size: (0, 0),
82            target_format,
83            pending_start: None,
84        }))
85    }
86
87    fn ensure_target(&mut self, device: &D, config: ImageConfig) -> Result<(), RenderError> {
88        if self.target_size == (config.width, config.height) {
89            return Ok(());
90        }
91        let target = device.create_texture(&TextureDesc {
92            label: "profiling target",
93            width: config.width,
94            height: config.height,
95            depth: 1,
96            dimension: molgfx_gpu::TextureDimension::D2,
97            format: self.target_format,
98            usage: TextureUsage::RENDER_ATTACHMENT,
99        })?;
100        self.target_view = Some(device.create_texture_view(&target, &TextureViewDesc::default()));
101        self.target = Some(target);
102        self.target_size = (config.width, config.height);
103        Ok(())
104    }
105
106    async fn read_timing_async(
107        &mut self,
108        device: &D,
109        queue: &D::Queue,
110    ) -> Result<DecodedTiming, RenderError> {
111        let data = queue
112            .read_buffer_async(device, &self.readback, 0, QUERY_BYTES)
113            .await?;
114        self.decode_timing(&data, queue.timestamp_period())
115    }
116
117    #[cfg(not(target_arch = "wasm32"))]
118    fn read_timing(&mut self, device: &D, queue: &D::Queue) -> Result<DecodedTiming, RenderError> {
119        let data = queue.read_buffer_blocking(device, &self.readback, 0, QUERY_BYTES)?;
120        self.decode_timing(&data, queue.timestamp_period())
121    }
122
123    fn decode_timing(
124        &mut self,
125        data: &[u8],
126        timestamp_period: f32,
127    ) -> Result<DecodedTiming, RenderError> {
128        let Some(start) = read_u64(data, 0) else {
129            return Err(molgfx_gpu::GpuError::DeviceLost.into());
130        };
131        let Some(end) = read_u64(data, std::mem::size_of::<u64>()) else {
132            return Err(molgfx_gpu::GpuError::DeviceLost.into());
133        };
134        let previous_start = self.pending_start.replace(start);
135        let Some(ticks) = timestamp_delta(start, end, previous_start) else {
136            return Ok(DecodedTiming::unresolved());
137        };
138        let ticks = crate::fallback(u32::try_from(ticks), u32::MAX);
139        let seconds = f64::from(ticks) * f64::from(timestamp_period) / 1_000_000_000.0;
140        let duration = std::time::Duration::try_from_secs_f64(seconds)
141            .map_err(|_| molgfx_gpu::GpuError::DeviceLost)?;
142        Ok(DecodedTiming {
143            nanoseconds: duration_ns(duration),
144            resolved: true,
145        })
146    }
147}
148
149impl<D: Device> Engine<D> {
150    /// Measures sustained native throughput with several frames in flight and
151    /// one completion wait. The returned durations are per-frame averages;
152    /// unlike [`Self::profile_frame`], the end-to-end value does not charge a
153    /// blocking buffer map to every frame.
154    ///
155    /// # Errors
156    ///
157    /// Returns a capability error when timestamps are unavailable, or a typed
158    /// rendering/device error.
159    #[cfg(not(target_arch = "wasm32"))]
160    pub fn profile_frame_batch(
161        &mut self,
162        scene: &Scene,
163        camera: &Camera,
164        config: ImageConfig,
165        frames: std::num::NonZeroU32,
166    ) -> Result<FrameTiming, RenderError> {
167        let frame_start = Instant::now();
168        let Some(mut profiler) = self.profiler.take() else {
169            return Err(molgfx_gpu::GpuError::Capability {
170                name: "timestamp queries",
171            }
172            .into());
173        };
174        let mut cpu_ns = 0_u64;
175        let result = (|| {
176            for _ in 0..frames.get() {
177                let (cpu_start, quality) = self.prepare_profile(scene, camera, config)?;
178                cpu_ns = cpu_ns.saturating_add(self.submit_profile(
179                    &mut profiler,
180                    cpu_start,
181                    config,
182                    quality,
183                )?);
184            }
185            let gpu = profiler.read_timing(&self.device, &self.queue)?;
186            let count = u64::from(frames.get());
187            Ok(FrameTiming {
188                gpu_ns: gpu.nanoseconds,
189                gpu_timing_resolved: gpu.resolved,
190                cpu_ns: cpu_ns / count,
191                frame_ns: duration_ns(frame_start.elapsed()) / count,
192                residency: self.scene_gpu.residency_metrics(),
193            })
194        })();
195        self.profiler = Some(profiler);
196        result
197    }
198
199    /// Asynchronously measures one headless frame using timestamp queries.
200    ///
201    /// # Errors
202    ///
203    /// Returns a capability error when the adapter exposes no timestamps,
204    /// or a typed rendering/device error.
205    pub async fn profile_frame_async(
206        &mut self,
207        scene: &Scene,
208        camera: &Camera,
209        config: ImageConfig,
210    ) -> Result<FrameTiming, RenderError> {
211        let frame_start = Instant::now();
212        let (cpu_start, quality) = self.prepare_profile(scene, camera, config)?;
213        let Some(mut profiler) = self.profiler.take() else {
214            return Err(molgfx_gpu::GpuError::Capability {
215                name: "timestamp queries",
216            }
217            .into());
218        };
219        let result = match self.submit_profile(&mut profiler, cpu_start, config, quality) {
220            Ok(cpu_ns) => profiler
221                .read_timing_async(&self.device, &self.queue)
222                .await
223                .map(|gpu| FrameTiming {
224                    gpu_ns: gpu.nanoseconds,
225                    gpu_timing_resolved: gpu.resolved,
226                    cpu_ns,
227                    frame_ns: duration_ns(frame_start.elapsed()),
228                    residency: self.scene_gpu.residency_metrics(),
229                }),
230            Err(error) => Err(error),
231        };
232        self.profiler = Some(profiler);
233        result
234    }
235
236    /// Measures one headless frame using device timestamp queries. Callers
237    /// should discard warmup frames before applying percentile gates.
238    ///
239    /// # Errors
240    ///
241    /// Returns a capability error when the adapter exposes no timestamps,
242    /// or a typed rendering/device error.
243    #[cfg(not(target_arch = "wasm32"))]
244    pub fn profile_frame(
245        &mut self,
246        scene: &Scene,
247        camera: &Camera,
248        config: ImageConfig,
249    ) -> Result<FrameTiming, RenderError> {
250        let frame_start = Instant::now();
251        let (cpu_start, quality) = self.prepare_profile(scene, camera, config)?;
252        let Some(mut profiler) = self.profiler.take() else {
253            return Err(molgfx_gpu::GpuError::Capability {
254                name: "timestamp queries",
255            }
256            .into());
257        };
258        let result = self.profile_with(&mut profiler, cpu_start, frame_start, config, quality);
259        self.profiler = Some(profiler);
260        result
261    }
262
263    fn prepare_profile(
264        &mut self,
265        scene: &Scene,
266        camera: &Camera,
267        config: ImageConfig,
268    ) -> Result<(Instant, bool), RenderError> {
269        config.validate(self.device.capabilities().max_texture_dim)?;
270        self.scene_gpu.begin_frame();
271        let cpu_start = Instant::now();
272        self.width = config.width;
273        self.height = config.height;
274        let preparation = self.prepare_image(scene, ImagePurpose::Publication)?;
275        let identity = scene.cache_identity();
276        let scene_reset = self.temporal_scene_identity.replace(identity) != Some(identity);
277        let camera_changed = self.temporal.camera_changed(camera);
278        let quality = self.tier() >= QualityTier::Standard;
279        let optics = self.resolve_optics(scene, camera)?;
280        let shadow = self.shadow_bound.fit(
281            scene,
282            camera,
283            self.resolved_plan.lighting(),
284            preparation.scene_changed || preparation.rebuild,
285        );
286        let uniforms = self.temporal.prepare(
287            camera,
288            &TemporalOptions {
289                extent: [self.width, self.height],
290                reset: scene_reset
291                    || preparation.rebuild
292                    || (self.tier() >= QualityTier::Standard && camera_changed),
293                quality,
294                publication: false,
295                illustration: self.resolved_plan.illustration(),
296                depth_cue: self.resolved_plan.packed_depth_cue(),
297                optics,
298                motion_blur: self
299                    .resolved_plan
300                    .motion_blur()
301                    .map_or([0.0; 4], MotionBlur::packed),
302                atmosphere: self
303                    .resolved_plan
304                    .packed_presentation(self.scene_gpu.has_translucency()),
305                lighting: self.resolved_plan.packed_lighting(),
306                shadow_view: shadow.view,
307                shadow_projection: shadow.projection,
308                shadow_view_proj: shadow.view_projection,
309            },
310        );
311        self.scene_gpu
312            .write_frame_uniforms(&self.queue, &uniforms)?;
313        Ok((cpu_start, quality))
314    }
315
316    #[cfg(not(target_arch = "wasm32"))]
317    fn profile_with(
318        &mut self,
319        profiler: &mut GpuProfiler<D>,
320        cpu_start: Instant,
321        frame_start: Instant,
322        config: ImageConfig,
323        quality: bool,
324    ) -> Result<FrameTiming, RenderError> {
325        let cpu_ns = self.submit_profile(profiler, cpu_start, config, quality)?;
326        let gpu = profiler.read_timing(&self.device, &self.queue)?;
327        Ok(FrameTiming {
328            gpu_ns: gpu.nanoseconds,
329            gpu_timing_resolved: gpu.resolved,
330            cpu_ns,
331            frame_ns: duration_ns(frame_start.elapsed()),
332            residency: self.scene_gpu.residency_metrics(),
333        })
334    }
335
336    fn submit_profile(
337        &mut self,
338        profiler: &mut GpuProfiler<D>,
339        cpu_start: Instant,
340        config: ImageConfig,
341        quality: bool,
342    ) -> Result<u64, RenderError> {
343        profiler.ensure_target(&self.device, config)?;
344        let Some(target) = &profiler.target_view else {
345            return Err(molgfx_gpu::GpuError::DeviceLost.into());
346        };
347        let mut encoder = self.device.create_command_encoder();
348        self.passes
349            .cull
350            .record_attribute_timelines(&self.scene_gpu, &mut encoder);
351        self.passes
352            .cull
353            .record_instance_timelines(&self.scene_gpu, &mut encoder);
354        let point_coordinates_changed = self
355            .passes
356            .cull
357            .record_point_timelines(&self.scene_gpu, &mut encoder);
358        self.scene_gpu
359            .record_particle_motion(&mut encoder, &self.passes.particle_motion);
360        let timestamps_started = self.scene_gpu.record_trajectories(
361            &mut encoder,
362            &self.passes.trajectory,
363            Some(molgfx_gpu::TimestampWrites {
364                queries: &profiler.queries,
365                beginning: Some(0),
366                end: None,
367            }),
368        );
369        let paged_coordinates_changed = self
370            .passes
371            .cull
372            .record_paged_trajectories(&self.scene_gpu, &mut encoder);
373        self.scene_gpu.record_dynamic_relations(
374            &mut encoder,
375            &self.passes.relation_resolve,
376            timestamps_started || paged_coordinates_changed || point_coordinates_changed,
377        );
378        self.scene_gpu
379            .record_occupancies(&mut encoder, self.passes.occupancy.as_ref());
380        self.scene_gpu.record_surface_fields(
381            &mut encoder,
382            &self.passes.surface_field,
383            &self.passes.surface_components,
384        );
385        self.scene_gpu
386            .record_quality_hardware(&mut encoder, quality);
387        self.record_image(
388            &mut encoder,
389            target,
390            Some(&profiler.queries),
391            quality,
392            timestamps_started,
393        );
394        encoder.resolve_query_set(&profiler.queries, 0..2, &profiler.resolve, 0);
395        encoder.copy_buffer_to_buffer(&profiler.resolve, 0, &profiler.readback, 0, QUERY_BYTES);
396        self.queue.submit(encoder);
397        Ok(duration_ns(cpu_start.elapsed()))
398    }
399}
400
401fn read_u64(bytes: &[u8], offset: usize) -> Option<u64> {
402    let slice = bytes.get(offset..offset + std::mem::size_of::<u64>())?;
403    let mut array = [0; std::mem::size_of::<u64>()];
404    array.copy_from_slice(slice);
405    Some(u64::from_le_bytes(array))
406}
407
408#[derive(Clone, Copy, Debug)]
409struct DecodedTiming {
410    nanoseconds: u64,
411    resolved: bool,
412}
413
414impl DecodedTiming {
415    const fn unresolved() -> Self {
416        Self {
417            nanoseconds: 0,
418            resolved: false,
419        }
420    }
421}
422
423fn timestamp_delta(
424    current_start: u64,
425    visible_end: u64,
426    previous_start: Option<u64>,
427) -> Option<u64> {
428    if current_start == 0 && visible_end == 0 {
429        return None;
430    }
431    if visible_end >= current_start {
432        return Some(visible_end - current_start);
433    }
434    previous_start.and_then(|start| visible_end.checked_sub(start))
435}
436
437fn duration_ns(duration: std::time::Duration) -> u64 {
438    crate::fallback(u64::try_from(duration.as_nanos()), u64::MAX)
439}
440
441#[cfg(test)]
442#[path = "profiling_tests.rs"]
443mod tests;
molgfx_render/engine/profiling.rs

molgfx_render/engine/
profiling.rs
