frust_gpu/diag.rs
1//! GPU-side frame diagnostics: [`TimestampRing`], real GPU time per pass.
2//!
3//! A frame's `encode_us`/`submit_us` are CPU wall-clock spans around calls that
4//! only *record* and *queue* work — they say how long the CPU spent, never how
5//! long the GPU took. This module answers the second question directly, by
6//! having the GPU stamp its own clock at each pass boundary.
7//!
8//! # Pass boundaries only
9//!
10//! Every timestamp this ring takes is written through
11//! `wgpu::RenderPassDescriptor::timestamp_writes`, which needs only
12//! `wgpu::Features::TIMESTAMP_QUERY`. `CommandEncoder::write_timestamp` and
13//! `RenderPass::write_timestamp` are deliberately never used: they need
14//! `TIMESTAMP_QUERY_INSIDE_ENCODERS`/`TIMESTAMP_QUERY_INSIDE_PASSES`, which
15//! `wgpu` documents as unavailable on tile-based GPUs — Adreno, and Apple's own
16//! Metal families — i.e. exactly the mobile adapters this tier exists for. A
17//! probe that only works on desktop would answer the wrong question.
18//!
19//! # Inert unless the device really has the feature
20//!
21//! `TIMESTAMP_QUERY` is requested only by a `perf-trace` build, and only when
22//! the adapter offers it ([`crate::context`]'s `required_features`). This ring
23//! makes no assumption about that: it asks the **device** it is handed what it
24//! was created with, and when the answer is no it becomes inert — no query set,
25//! no buffers, no per-frame work, and [`TimestampRing::latest`] answering
26//! `None` forever. An inert ring is what a caller reports as `gpu_q=0`.
27//!
28//! # The ring
29//!
30//! Reading a timestamp back means mapping a buffer, which is only ready some
31//! frames after the submit that wrote it. So the ring holds [`RING_FRAMES`]
32//! independent slots — query set, resolve buffer, readback buffer — and a
33//! frame's slot is not read until the ring comes back around to it, by which
34//! time its map has long since completed. Nothing on the frame path ever
35//! blocks: the map is polled, never waited on, and a slot whose map has not
36//! landed simply goes untimed for that frame rather than stalling it.
37//!
38//! # Resolved only once the frame's GPU work has completed
39//!
40//! A slot's queries are resolved by a *later* frame's encoder, once
41//! `wgpu::Queue::on_submitted_work_done` has reported the frame that wrote them
42//! finished — never by the encoder that recorded the passes. On Metal the
43//! resolve is a blit encoder's `resolveCounters`, and a counter sample buffer
44//! is not a hazard-tracked resource, so a blit in the same command buffer can
45//! run while the frame's *last* render pass is still in its fragment stage:
46//! that pass's begin sample is already written, its end-of-fragment sample is
47//! not yet, and the copy reads it unwritten. Observed on an Apple M4: the last
48//! pass's end read `0` at resolve, and the same query slot read a plausible end
49//! one ring lap later. Waiting for completion costs a frame or two of reading
50//! lag and nothing on the frame path — the ring never blocks either way.
51//!
52//! # A pass that draws nothing may measure nothing
53//!
54//! Metal samples a render pass's counters at the vertex/fragment *stage*
55//! boundaries (start of vertex, end of fragment), so a pass that runs no
56//! fragment work — a pure clear, an empty pass — can leave its end sample
57//! unwritten for good, and the ring drops the pair rather than reporting a
58//! garbage span (see `span_duration`). This is a measurement gap, never a
59//! correctness one: an untimed pass draws exactly what it always did.
60//!
61//! A span made of several passes absorbs it when another of its passes draws.
62//! A span whose *only* pass draws nothing cannot: `frust-engine`'s merged
63//! surface opening carries the frame's clear on the same pass as its first
64//! drawing surface work, so the clear is measured with that work — but a frame
65//! whose surface draws nothing at all records the opening clear-only, and on
66//! Metal its main span then has no valid pair. [`GpuFrameSpans::is_measured`]
67//! is how a reader tells that "not measured" from a span that really took no
68//! time; [`GpuFrameSpans::span`] reads zero for both.
69//!
70//! One frame's shape, in call order:
71//!
72//! 1. [`TimestampRing::begin_frame`] — advance to the next slot and harvest
73//! whatever an earlier frame that used it left mapped.
74//! 2. [`TimestampRing::pass_writes`] once per timed pass, naming the span the
75//! pass belongs to. Each call takes a *fresh* query pair, so several passes
76//! may share one span and their durations add up.
77//! 3. [`TimestampRing::resolve`] into the frame's encoder, before the caller
78//! submits it. It records the resolve of every *earlier* frame whose work
79//! has completed, not this frame's (see above).
80//! 4. [`TimestampRing::end_frame`] after that submit (or
81//! [`TimestampRing::abandon_frame`] when the frame was refused and nothing
82//! was submitted).
83
84use std::sync::Arc;
85use std::sync::atomic::{AtomicBool, AtomicU8, AtomicU32, Ordering};
86use std::time::Duration;
87
88/// How many frames-in-flight the ring keeps independent slots for.
89///
90/// Four is the depth a triple-buffered swapchain plus one in-flight submit can
91/// reach, so a slot's map has always completed by the time the ring returns to
92/// it — nothing on the frame path ever waits on a map.
93pub const RING_FRAMES: usize = 4;
94
95/// The largest number of named spans one frame can be split into.
96///
97/// A fixed ceiling rather than a `Vec` so [`GpuFrameSpans`] stays `Copy` and a
98/// caller can carry one through a frame record without allocating.
99pub const MAX_SPANS: usize = 8;
100
101// `GpuFrameSpans::measured` keeps one bit per span in a `u8`.
102const _: () = assert!(MAX_SPANS <= u8::BITS as usize);
103
104/// How many individual passes one frame can time by default.
105///
106/// Each timed pass costs its own query pair, so this is what fixes the query
107/// set's `count` at `2 * PASSES`. A frame with more passes than this times the
108/// first `DEFAULT_PASS_CAPACITY` and leaves the rest untimed — draw-correct
109/// either way, since a pass with no `timestamp_writes` is an ordinary pass.
110pub const DEFAULT_PASS_CAPACITY: usize = 24;
111
112/// The hard ceiling on a slot's query count, from `wgpu`'s own
113/// `QUERY_SET_MAX_QUERIES`. Halved because every pass takes a *pair*.
114const MAX_PASS_CAPACITY: usize = (wgpu::QUERY_SET_MAX_QUERIES / 2) as usize;
115
116/// Bytes one resolved timestamp query occupies (`wgpu::QUERY_SIZE`).
117const QUERY_BYTES: u64 = wgpu::QUERY_SIZE as u64;
118
119/// A single pass span longer than this is discarded rather than reported.
120///
121/// A GPU pass measured in whole seconds is not a slow frame, it is a garbage
122/// tick pair: an unwritten query, a driver that reset its clock across a
123/// submit, or a counter wrap. Reporting it would poison every percentile
124/// computed off the raw series, so the span is dropped and its frame simply
125/// reads a little low.
126const IMPLAUSIBLE_SPAN_NANOS: u64 = 1_000_000_000;
127
128/// The `AtomicU8` states a slot's map callback moves through.
129mod map_state {
130 /// The map was requested and has not answered yet.
131 pub const PENDING: u8 = 0;
132 /// The map completed and the buffer holds this frame's resolved queries.
133 pub const READY: u8 = 1;
134 /// The map failed; the slot is recycled without producing a reading.
135 pub const FAILED: u8 = 2;
136}
137
138/// One frame's GPU span durations, in the caller's own span order.
139///
140/// The span *names* are the caller's business — this crate knows only how many
141/// there are and which index each pass was charged to. `frust-engine`'s
142/// `diag::EngineSpan` is the naming this repo's engine tier uses.
143#[derive(Debug, Clone, Copy, PartialEq, Eq)]
144pub struct GpuFrameSpans {
145 durations: [Duration; MAX_SPANS],
146 len: usize,
147 /// One bit per span: set once any valid pass pair was charged to it.
148 measured: u8,
149}
150
151impl Default for GpuFrameSpans {
152 fn default() -> Self {
153 Self {
154 durations: [Duration::ZERO; MAX_SPANS],
155 len: 0,
156 measured: 0,
157 }
158 }
159}
160
161impl GpuFrameSpans {
162 /// An all-zero reading over `len` spans (clamped to [`MAX_SPANS`]).
163 #[must_use]
164 pub fn zeroed(len: usize) -> Self {
165 Self {
166 durations: [Duration::ZERO; MAX_SPANS],
167 len: len.min(MAX_SPANS),
168 measured: 0,
169 }
170 }
171
172 /// How many spans this reading covers.
173 #[must_use]
174 pub fn len(&self) -> usize {
175 self.len
176 }
177
178 /// Whether this reading covers no spans at all.
179 #[must_use]
180 pub fn is_empty(&self) -> bool {
181 self.len == 0
182 }
183
184 /// The duration charged to `index`, or [`Duration::ZERO`] past the end —
185 /// a span no pass was charged to is genuinely zero, so an out-of-range
186 /// index answering the same is the honest reading rather than a silent
187 /// failure mode.
188 #[must_use]
189 pub fn span(&self, index: usize) -> Duration {
190 self.durations.get(index).copied().unwrap_or(Duration::ZERO)
191 }
192
193 /// Whether at least one valid pass measurement was charged to `index`.
194 ///
195 /// `false` both for a span no pass was charged to and for one whose every
196 /// pass left its query pair unwritten (see the module doc's *A pass that
197 /// draws nothing may measure nothing*) — the two cases [`Self::span`]
198 /// cannot tell apart from a span that genuinely took no time, since it
199 /// reads [`Duration::ZERO`] for all three.
200 #[must_use]
201 pub fn is_measured(&self, index: usize) -> bool {
202 index < self.len && self.measured & (1 << index) != 0
203 }
204
205 /// Every span in order.
206 #[must_use]
207 pub fn as_slice(&self) -> &[Duration] {
208 &self.durations[..self.len]
209 }
210
211 /// The sum of every span — the frame's total *attributed* GPU pass time.
212 ///
213 /// Deliberately a sum rather than last-end-minus-first-begin: the gaps
214 /// between a frame's passes are queue and driver time this ring cannot
215 /// attribute to any pass, and folding them into a "total" would report
216 /// work the breakdown below it does not account for.
217 #[must_use]
218 pub fn total(&self) -> Duration {
219 self.as_slice()
220 .iter()
221 .copied()
222 .fold(Duration::ZERO, |acc, span| acc.saturating_add(span))
223 }
224
225 /// Charges `span` with `duration` on top of whatever it already holds.
226 fn add(&mut self, span: usize, duration: Duration) {
227 if span >= self.len {
228 return;
229 }
230 if let Some(slot) = self.durations.get_mut(span) {
231 *slot = slot.saturating_add(duration);
232 self.measured |= 1 << span;
233 }
234 }
235}
236
237/// One frame-in-flight's own query set and its two staging buffers.
238#[derive(Debug)]
239struct RingFrame {
240 queries: wgpu::QuerySet,
241 /// `QUERY_RESOLVE | COPY_SRC` — what `resolve_query_set` writes into. It
242 /// cannot also be `MAP_READ`, which is why the readback below exists.
243 resolve: wgpu::Buffer,
244 /// `COPY_DST | MAP_READ` — the mappable copy the harvest reads.
245 readback: wgpu::Buffer,
246 /// Next free pass pair, bumped by [`TimestampRing::pass_writes`].
247 ///
248 /// Atomic rather than a `Cell` so the ring stays `Sync`: a renderer that
249 /// records its passes off the thread that owns the ring is a shape this
250 /// type should not rule out, and the counter is uncontended in every
251 /// current caller anyway.
252 cursor: AtomicU32,
253 /// Which span each pass pair was charged to, indexed by pair.
254 owners: Vec<AtomicU8>,
255 /// Set by the `on_submitted_work_done` callback once the frame that wrote
256 /// this slot's queries has finished on the GPU. Allocated once with the
257 /// slot and re-armed per frame, so the callback costs no `Arc` of its own.
258 done: Arc<AtomicBool>,
259 /// The readback map's [`map_state`], allocated once with the slot.
260 map: Arc<AtomicU8>,
261 /// Set by [`TimestampRing::resolve`] when it recorded this slot's resolve
262 /// into the caller's encoder; consumed by [`TimestampRing::end_frame`]
263 /// (which maps it) or [`TimestampRing::abandon_frame`] (which drops it).
264 /// Atomic because `resolve` takes `&self`.
265 resolve_recorded: AtomicBool,
266 state: SlotState,
267}
268
269/// Where one ring slot is in the record → complete → resolve → map → harvest
270/// cycle.
271#[derive(Debug)]
272enum SlotState {
273 /// Holds nothing; free to record into.
274 Idle,
275 /// This frame's passes are being recorded into it.
276 Recording,
277 /// Submitted; `used` pass pairs were written, and are resolved by a later
278 /// frame's encoder once `done` is set (see the module doc's *Resolved only
279 /// once the frame's GPU work has completed*).
280 Running { used: usize },
281 /// Resolved and mapping; `used` pass pairs are staged in `readback`.
282 Mapping { used: usize },
283}
284
285/// A ring of per-frame GPU timestamp query sets — see the module header.
286#[derive(Debug)]
287pub struct TimestampRing {
288 /// How many named spans a frame is split into.
289 spans: usize,
290 /// How many passes one frame can time.
291 passes: usize,
292 /// Nanoseconds per timestamp tick, from `queue.get_timestamp_period()`.
293 period_ns: f32,
294 /// The queue the frames are submitted to — what reports a slot's frame
295 /// complete. `None` when inert.
296 queue: Option<wgpu::Queue>,
297 /// Empty when inert — the one thing every method keys off.
298 frames: Vec<RingFrame>,
299 /// Which slot the frame in progress is recording into.
300 current: usize,
301 /// Whether the current frame's slot was actually free to record into.
302 armed: bool,
303 /// The most recently harvested reading.
304 latest: Option<GpuFrameSpans>,
305 /// How many frames have been harvested, so a consumer can tell a fresh
306 /// reading from the one it already reported.
307 harvested: u64,
308}
309
310impl TimestampRing {
311 /// A ring timing `spans` named spans per frame, over
312 /// [`DEFAULT_PASS_CAPACITY`] passes.
313 ///
314 /// Inert — no GPU resource created at all — when `device` was not created
315 /// with `wgpu::Features::TIMESTAMP_QUERY`, which is every build that did
316 /// not compile `perf-trace` in and every adapter that does not offer the
317 /// feature.
318 #[must_use]
319 pub fn new(device: &wgpu::Device, queue: &wgpu::Queue, spans: usize, label: &str) -> Self {
320 Self::with_capacity(device, queue, spans, DEFAULT_PASS_CAPACITY, label)
321 }
322
323 /// [`Self::new`] with an explicit per-frame pass capacity.
324 #[must_use]
325 pub fn with_capacity(
326 device: &wgpu::Device,
327 queue: &wgpu::Queue,
328 spans: usize,
329 passes: usize,
330 label: &str,
331 ) -> Self {
332 let spans = spans.min(MAX_SPANS);
333 let passes = passes.min(MAX_PASS_CAPACITY);
334 if spans == 0 || passes == 0 || !device.features().contains(wgpu::Features::TIMESTAMP_QUERY)
335 {
336 return Self::inert(spans);
337 }
338
339 // A non-finite or non-positive period would scale every tick delta
340 // into nonsense, and there is no sound reading to fall back on — an
341 // inert ring reporting nothing beats a ring reporting garbage.
342 let period_ns = queue.get_timestamp_period();
343 if !period_ns.is_finite() || period_ns <= 0.0 {
344 log::warn!(
345 "frust-gpu: timestamp period {period_ns} is unusable; GPU pass timing is off"
346 );
347 return Self::inert(spans);
348 }
349
350 let query_count = (passes * 2) as u32;
351 let staged_bytes = u64::from(query_count) * QUERY_BYTES;
352 // `resolve_query_set`'s destination offset is 256-byte aligned; the
353 // buffer is rounded up to the same grid so a future non-zero offset
354 // needs no re-sizing rule of its own.
355 let buffer_bytes = staged_bytes.next_multiple_of(wgpu::QUERY_RESOLVE_BUFFER_ALIGNMENT);
356
357 let frames = (0..RING_FRAMES)
358 .map(|slot| RingFrame {
359 queries: device.create_query_set(&wgpu::QuerySetDescriptor {
360 label: Some(&format!("{label} queries {slot}")),
361 ty: wgpu::QueryType::Timestamp,
362 count: query_count,
363 }),
364 resolve: device.create_buffer(&wgpu::BufferDescriptor {
365 label: Some(&format!("{label} resolve {slot}")),
366 size: buffer_bytes,
367 usage: wgpu::BufferUsages::QUERY_RESOLVE | wgpu::BufferUsages::COPY_SRC,
368 mapped_at_creation: false,
369 }),
370 readback: device.create_buffer(&wgpu::BufferDescriptor {
371 label: Some(&format!("{label} readback {slot}")),
372 size: buffer_bytes,
373 usage: wgpu::BufferUsages::COPY_DST | wgpu::BufferUsages::MAP_READ,
374 mapped_at_creation: false,
375 }),
376 cursor: AtomicU32::new(0),
377 owners: (0..passes).map(|_| AtomicU8::new(0)).collect(),
378 done: Arc::new(AtomicBool::new(false)),
379 map: Arc::new(AtomicU8::new(map_state::PENDING)),
380 resolve_recorded: AtomicBool::new(false),
381 state: SlotState::Idle,
382 })
383 .collect();
384
385 Self {
386 spans,
387 passes,
388 period_ns,
389 queue: Some(queue.clone()),
390 frames,
391 // The first `begin_frame` advances onto slot 0.
392 current: RING_FRAMES - 1,
393 armed: false,
394 latest: None,
395 harvested: 0,
396 }
397 }
398
399 /// A ring that measures nothing, for a device without `TIMESTAMP_QUERY`
400 /// and for a caller that wants the `gpu_q=0` shape without a GPU at all.
401 #[must_use]
402 pub fn inert(spans: usize) -> Self {
403 Self {
404 spans: spans.min(MAX_SPANS),
405 passes: 0,
406 period_ns: 0.0,
407 queue: None,
408 frames: Vec::new(),
409 current: 0,
410 armed: false,
411 latest: None,
412 harvested: 0,
413 }
414 }
415
416 /// Whether this ring holds real query sets, i.e. whether a frame line
417 /// should report `gpu_q=1`.
418 #[must_use]
419 pub fn is_active(&self) -> bool {
420 !self.frames.is_empty()
421 }
422
423 /// How many named spans a frame is split into.
424 #[must_use]
425 pub fn spans(&self) -> usize {
426 self.spans
427 }
428
429 /// Nanoseconds per timestamp tick, `0.0` on an inert ring.
430 #[must_use]
431 pub fn timestamp_period_ns(&self) -> f32 {
432 self.period_ns
433 }
434
435 /// The most recently harvested frame's spans, or `None` before the first
436 /// reading lands (and forever on an inert ring).
437 ///
438 /// The reading lags the CPU frame that asks for it by up to
439 /// [`RING_FRAMES`] frames — the price of never blocking on a map. In
440 /// steady state one fresh reading lands per frame, so the lag is a
441 /// constant offset rather than a gap in the series; [`Self::harvested`]
442 /// is how a consumer tells a repeat from a fresh reading.
443 #[must_use]
444 pub fn latest(&self) -> Option<GpuFrameSpans> {
445 self.latest
446 }
447
448 /// How many frame readings this ring has harvested.
449 #[must_use]
450 pub fn harvested(&self) -> u64 {
451 self.harvested
452 }
453
454 /// Advances onto the next slot and harvests whatever the frame that last
455 /// used it left mapped.
456 ///
457 /// Polls `device` once, without blocking: a map that has not landed leaves
458 /// its slot alone and the frame goes untimed rather than stalling on it.
459 pub fn begin_frame(&mut self, device: &wgpu::Device) {
460 if self.frames.is_empty() {
461 return;
462 }
463 self.current = (self.current + 1) % self.frames.len();
464
465 // One non-blocking poll, which is what actually invokes any map
466 // callback whose copy has completed. A poll failure is not worth
467 // reporting per frame: the slot simply stays pending and this frame
468 // goes untimed.
469 let _ = device.poll(wgpu::PollType::Poll);
470
471 let spans = self.spans;
472 let period_ns = self.period_ns;
473 let Some(slot) = self.frames.get_mut(self.current) else {
474 self.armed = false;
475 return;
476 };
477
478 match &slot.state {
479 // Still waiting on its frame's completion or on its resolve: its
480 // queries are not read yet and must not be overwritten, so this
481 // frame goes untimed.
482 SlotState::Running { .. } => {
483 self.armed = false;
484 return;
485 }
486 SlotState::Mapping { used } => match slot.map.load(Ordering::Acquire) {
487 map_state::PENDING => {
488 // Still in flight: leave the slot exactly as it is (its
489 // readback buffer is mapped-in-progress and must not be
490 // written again) and skip timing this frame.
491 self.armed = false;
492 return;
493 }
494 map_state::READY => {
495 let reading = harvest(slot, *used, spans, period_ns);
496 slot.readback.unmap();
497 self.latest = Some(reading);
498 self.harvested = self.harvested.saturating_add(1);
499 }
500 // A failed map leaves `wgpu`'s own map context marked, so the
501 // slot is unmapped anyway before it is recorded into again.
502 _ => slot.readback.unmap(),
503 },
504 SlotState::Idle | SlotState::Recording => {}
505 }
506
507 slot.cursor.store(0, Ordering::Relaxed);
508 slot.state = SlotState::Recording;
509 self.armed = true;
510 }
511
512 /// The `timestamp_writes` for one pass belonging to `span`.
513 ///
514 /// Each call takes a fresh query pair, so a span made of several passes
515 /// (the frame's own strip passes, a layer's page rounds) sums correctly.
516 /// `None` — an untimed pass — when the ring is inert, the slot was not
517 /// free this frame, `span` is out of range, or the frame has already used
518 /// its pass capacity.
519 #[must_use]
520 pub fn pass_writes(&self, span: usize) -> Option<wgpu::RenderPassTimestampWrites<'_>> {
521 if !self.armed || span >= self.spans {
522 return None;
523 }
524 let slot = self.frames.get(self.current)?;
525 let pair = slot.cursor.fetch_add(1, Ordering::Relaxed) as usize;
526 if pair >= self.passes {
527 return None;
528 }
529 slot.owners.get(pair)?.store(span as u8, Ordering::Relaxed);
530 let first = (pair * 2) as u32;
531 Some(wgpu::RenderPassTimestampWrites {
532 query_set: &slot.queries,
533 beginning_of_pass_write_index: Some(first),
534 end_of_pass_write_index: Some(first + 1),
535 })
536 }
537
538 /// Records, into the caller's encoder, the query resolve and the copy into
539 /// the mappable readback buffer of every *earlier* frame whose GPU work has
540 /// completed. The caller submits that encoder.
541 ///
542 /// Never the frame in progress: its passes have not run yet when this
543 /// encoder is submitted, and a resolve in the same command buffer can read
544 /// the last pass's end sample before the GPU writes it (see the module
545 /// doc's *Resolved only once the frame's GPU work has completed*). Works
546 /// whether or not this frame is itself timed, so a run of untimed frames
547 /// still drains the ring.
548 ///
549 /// Only the pairs actually taken are resolved: an untouched query resolves
550 /// to whatever the driver left there, and reading it back would be
551 /// inventing a span rather than measuring one.
552 pub fn resolve(&self, encoder: &mut wgpu::CommandEncoder) {
553 for slot in &self.frames {
554 let SlotState::Running { used } = slot.state else {
555 continue;
556 };
557 if !slot.done.load(Ordering::Acquire) || slot.resolve_recorded.load(Ordering::Relaxed) {
558 continue;
559 }
560 let queries = (used * 2) as u32;
561 encoder.resolve_query_set(&slot.queries, 0..queries, &slot.resolve, 0);
562 encoder.copy_buffer_to_buffer(
563 &slot.resolve,
564 0,
565 &slot.readback,
566 0,
567 u64::from(queries) * QUERY_BYTES,
568 );
569 slot.resolve_recorded.store(true, Ordering::Relaxed);
570 }
571 }
572
573 /// Call after submitting the encoder [`Self::resolve`] was recorded into.
574 ///
575 /// Requests the map of every slot that encoder resolved — what a later
576 /// [`Self::begin_frame`] harvests — and asks the queue to report when this
577 /// frame's own work completes, which is what lets a later frame resolve
578 /// it.
579 ///
580 /// Allocation per timed frame is unchanged from a same-frame resolve: one
581 /// boxed map callback and one boxed completion callback, each holding a
582 /// clone of an `Arc` the slot allocated once.
583 pub fn end_frame(&mut self) {
584 for slot in &mut self.frames {
585 if !slot.resolve_recorded.swap(false, Ordering::Relaxed) {
586 continue;
587 }
588 let SlotState::Running { used } = slot.state else {
589 continue;
590 };
591 slot.map.store(map_state::PENDING, Ordering::Relaxed);
592 let callback = Arc::clone(&slot.map);
593 let bytes = (used * 2) as u64 * QUERY_BYTES;
594 slot.readback
595 .slice(0..bytes)
596 .map_async(wgpu::MapMode::Read, move |result| {
597 let state = if result.is_ok() {
598 map_state::READY
599 } else {
600 map_state::FAILED
601 };
602 callback.store(state, Ordering::Release);
603 });
604 slot.state = SlotState::Mapping { used };
605 }
606
607 if !self.armed {
608 return;
609 }
610 self.armed = false;
611 let passes = self.passes;
612 let Some(slot) = self.frames.get_mut(self.current) else {
613 return;
614 };
615 let used = (slot.cursor.load(Ordering::Relaxed) as usize).min(passes);
616 let Some(queue) = self.queue.as_ref().filter(|_| used > 0) else {
617 slot.state = SlotState::Idle;
618 return;
619 };
620 slot.done.store(false, Ordering::Relaxed);
621 let done = Arc::clone(&slot.done);
622 // "All work submitted so far" — this frame's included, since the
623 // caller submits before calling here.
624 queue.on_submitted_work_done(move || done.store(true, Ordering::Release));
625 slot.state = SlotState::Running { used };
626 }
627
628 /// Closes a frame that was refused before its encoder was submitted.
629 ///
630 /// Nothing was recorded and nothing will be, so the slot goes straight
631 /// back to idle without waiting on a completion — resolving queries no
632 /// pass ever wrote would harvest an earlier frame's ticks as if they were
633 /// this one's. Any earlier frame's resolve [`Self::resolve`] put into that
634 /// unsubmitted encoder is forgotten too, so the next frame records it
635 /// again.
636 pub fn abandon_frame(&mut self) {
637 for slot in &self.frames {
638 slot.resolve_recorded.store(false, Ordering::Relaxed);
639 }
640 if !self.armed {
641 return;
642 }
643 self.armed = false;
644 if let Some(slot) = self.frames.get_mut(self.current) {
645 slot.cursor.store(0, Ordering::Relaxed);
646 slot.state = SlotState::Idle;
647 }
648 }
649}
650
651/// Reads `used` resolved query pairs out of `slot`'s mapped readback buffer and
652/// charges each one to the span its pass named.
653fn harvest(slot: &RingFrame, used: usize, spans: usize, period_ns: f32) -> GpuFrameSpans {
654 let mut reading = GpuFrameSpans::zeroed(spans);
655 let bytes = (used * 2) as u64 * QUERY_BYTES;
656 let mapped =
657 slot.readback.slice(0..bytes).get_mapped_range().expect(
658 "frust-gpu diag: the harvested slot's readback is mapped over the resolved range",
659 );
660 let stride = (QUERY_BYTES * 2) as usize;
661 for pair in 0..used {
662 let at = pair * stride;
663 let Some(chunk) = mapped.get(at..at + stride) else {
664 break;
665 };
666 let (begin, end) = tick_pair(chunk);
667 let Some(duration) = span_duration(begin, end, period_ns) else {
668 continue;
669 };
670 let owner = slot
671 .owners
672 .get(pair)
673 .map_or(usize::MAX, |span| span.load(Ordering::Relaxed) as usize);
674 reading.add(owner, duration);
675 }
676 drop(mapped);
677 reading
678}
679
680/// The `(begin, end)` tick pair a 16-byte resolved chunk holds, little-endian
681/// as `wgpu` resolves it. A short chunk answers `(0, 0)`, which
682/// [`span_duration`] then rejects — the one shape that cannot be a real span.
683fn tick_pair(chunk: &[u8]) -> (u64, u64) {
684 fn tick(bytes: Option<&[u8]>) -> u64 {
685 bytes
686 .and_then(|slice| <[u8; 8]>::try_from(slice).ok())
687 .map_or(0, u64::from_le_bytes)
688 }
689 (tick(chunk.get(0..8)), tick(chunk.get(8..16)))
690}
691
692/// One pass's duration from its tick pair, or `None` when the pair cannot be a
693/// real measurement.
694///
695/// Rejected: a non-increasing pair (an unwritten query, or a counter that
696/// wrapped across the pass) and anything past [`IMPLAUSIBLE_SPAN_NANOS`] (see
697/// that constant). Both are dropped rather than clamped — a clamped garbage
698/// value is still reported as a measurement.
699fn span_duration(begin: u64, end: u64, period_ns: f32) -> Option<Duration> {
700 if end <= begin || !period_ns.is_finite() || period_ns <= 0.0 {
701 return None;
702 }
703 let nanos = (end - begin) as f64 * f64::from(period_ns);
704 if !nanos.is_finite() || nanos >= IMPLAUSIBLE_SPAN_NANOS as f64 {
705 return None;
706 }
707 Some(Duration::from_nanos(nanos as u64))
708}
709
710#[cfg(test)]
711mod tests {
712 use super::*;
713
714 #[test]
715 fn zeroed_reading_reports_its_span_count_and_no_time() {
716 let reading = GpuFrameSpans::zeroed(4);
717 assert_eq!(reading.len(), 4);
718 assert!(!reading.is_empty());
719 assert_eq!(reading.as_slice().len(), 4);
720 assert_eq!(reading.total(), Duration::ZERO);
721 for index in 0..4 {
722 assert_eq!(reading.span(index), Duration::ZERO);
723 }
724 }
725
726 #[test]
727 fn span_count_is_clamped_to_the_ceiling() {
728 assert_eq!(GpuFrameSpans::zeroed(MAX_SPANS + 9).len(), MAX_SPANS);
729 }
730
731 #[test]
732 fn an_index_past_the_end_reads_zero_rather_than_panicking() {
733 let reading = GpuFrameSpans::zeroed(2);
734 assert_eq!(reading.span(7), Duration::ZERO);
735 assert_eq!(reading.span(usize::MAX), Duration::ZERO);
736 }
737
738 #[test]
739 fn several_passes_charged_to_one_span_add_up() {
740 let mut reading = GpuFrameSpans::zeroed(3);
741 reading.add(1, Duration::from_micros(400));
742 reading.add(1, Duration::from_micros(250));
743 reading.add(2, Duration::from_micros(90));
744 assert_eq!(reading.span(0), Duration::ZERO);
745 assert_eq!(reading.span(1), Duration::from_micros(650));
746 assert_eq!(reading.span(2), Duration::from_micros(90));
747 assert_eq!(reading.total(), Duration::from_micros(740));
748 }
749
750 #[test]
751 fn a_span_is_measured_only_once_a_pass_was_charged_to_it() {
752 let mut reading = GpuFrameSpans::zeroed(3);
753 for index in 0..3 {
754 assert!(!reading.is_measured(index));
755 }
756 reading.add(1, Duration::from_micros(30));
757 // A measured span that really took no time is still measured — the
758 // case `span` alone cannot tell from an unwritten pair.
759 reading.add(2, Duration::ZERO);
760 assert!(!reading.is_measured(0));
761 assert!(reading.is_measured(1));
762 assert!(reading.is_measured(2));
763 assert_eq!(reading.span(2), Duration::ZERO);
764 assert!(!reading.is_measured(3));
765 assert!(!reading.is_measured(usize::MAX));
766 }
767
768 #[test]
769 fn a_charge_past_the_reading_length_is_neither_summed_nor_measured() {
770 let mut reading = GpuFrameSpans::zeroed(2);
771 reading.add(5, Duration::from_micros(10));
772 assert_eq!(reading.total(), Duration::ZERO);
773 assert!(!reading.is_measured(5));
774 }
775
776 #[test]
777 fn a_charge_past_the_span_ceiling_is_dropped_not_wrapped() {
778 let mut reading = GpuFrameSpans::zeroed(2);
779 reading.add(MAX_SPANS, Duration::from_secs(1));
780 assert_eq!(reading.total(), Duration::ZERO);
781 }
782
783 #[test]
784 fn span_duration_scales_ticks_by_the_period() {
785 // 1000 ticks at 1ns/tick, and the same 1000 ticks on an adapter whose
786 // tick is 38.4ns (a real Adreno-class period) — the same pair must
787 // read as two different durations, which is the whole point of
788 // scaling by the queue's own period rather than assuming nanoseconds.
789 assert_eq!(span_duration(0, 1_000, 1.0), Some(Duration::from_micros(1)));
790 assert_eq!(
791 span_duration(500, 1_500, 38.4),
792 Some(Duration::from_nanos(38_400))
793 );
794 }
795
796 #[test]
797 fn a_non_increasing_tick_pair_is_no_measurement() {
798 assert_eq!(span_duration(0, 0, 1.0), None);
799 assert_eq!(span_duration(900, 900, 1.0), None);
800 assert_eq!(span_duration(1_000, 999, 1.0), None);
801 }
802
803 #[test]
804 fn an_implausible_span_is_dropped_rather_than_reported() {
805 assert_eq!(span_duration(0, IMPLAUSIBLE_SPAN_NANOS, 1.0), None);
806 assert_eq!(span_duration(0, u64::MAX, 1.0), None);
807 // Just under the ceiling still reads.
808 assert!(span_duration(0, IMPLAUSIBLE_SPAN_NANOS - 1, 1.0).is_some());
809 }
810
811 #[test]
812 fn an_unusable_period_yields_no_measurement() {
813 assert_eq!(span_duration(0, 1_000, 0.0), None);
814 assert_eq!(span_duration(0, 1_000, -1.0), None);
815 assert_eq!(span_duration(0, 1_000, f32::NAN), None);
816 assert_eq!(span_duration(0, 1_000, f32::INFINITY), None);
817 }
818
819 #[test]
820 fn a_tick_pair_reads_little_endian_and_a_short_chunk_reads_zero() {
821 let mut chunk = [0_u8; 16];
822 chunk[..8].copy_from_slice(&7_u64.to_le_bytes());
823 chunk[8..].copy_from_slice(&19_u64.to_le_bytes());
824 assert_eq!(tick_pair(&chunk), (7, 19));
825 assert_eq!(tick_pair(&chunk[..12]), (7, 0));
826 assert_eq!(tick_pair(&[]), (0, 0));
827 }
828
829 #[test]
830 fn an_inert_ring_measures_nothing_and_never_reports_a_reading() {
831 // The `gpu_q=0` shape a device without TIMESTAMP_QUERY produces,
832 // exercised with no GPU in the loop at all.
833 let mut ring = TimestampRing::inert(4);
834 assert!(!ring.is_active());
835 assert_eq!(ring.spans(), 4);
836 assert_eq!(ring.timestamp_period_ns(), 0.0);
837 assert!(ring.pass_writes(0).is_none());
838 assert!(ring.latest().is_none());
839 ring.end_frame();
840 ring.abandon_frame();
841 assert!(ring.latest().is_none());
842 assert_eq!(ring.harvested(), 0);
843 }
844
845 /// A full-screen triangle drawn by the real-adapter test below, so each
846 /// timed pass runs the vertex and fragment stages Metal samples its
847 /// counters at — see that test's own comment.
848 const RING_TEST_WGSL: &str = "\
849@vertex
850fn vs_main(@builtin(vertex_index) index: u32) -> @builtin(position) vec4<f32> {
851 let uv = vec2<f32>(f32((index << 1u) & 2u), f32(index & 2u));
852 return vec4<f32>(uv * 2.0 - 1.0, 0.0, 1.0);
853}
854
855@fragment
856fn fs_main() -> @location(0) vec4<f32> {
857 return vec4<f32>(0.2, 0.4, 0.8, 1.0);
858}
859";
860
861 /// Blocks on `future` by polling it to completion — `wgpu`'s native
862 /// adapter and device requests resolve without an executor driving them,
863 /// and this crate has no async runtime of its own.
864 fn block_on<F: std::future::Future>(future: F) -> F::Output {
865 use std::task::{Context, Poll, Waker};
866
867 let waker = Waker::noop();
868 let mut cx = Context::from_waker(waker);
869 let mut future = std::pin::pin!(future);
870 loop {
871 match future.as_mut().poll(&mut cx) {
872 Poll::Ready(value) => return value,
873 Poll::Pending => std::thread::yield_now(),
874 }
875 }
876 }
877
878 #[test]
879 #[ignore = "needs a real GPU adapter offering TIMESTAMP_QUERY; run with \
880 `cargo test -p frust-gpu -- --ignored` (pin the adapter on a \
881 multi-GPU host with WGPU_BACKEND / WGPU_ADAPTER_NAME)"]
882 fn a_real_adapter_reports_plausible_per_pass_gpu_time() {
883 block_on(async {
884 let instance = wgpu::Instance::new(
885 wgpu::InstanceDescriptor::new_without_display_handle_from_env(),
886 );
887 let adapter = wgpu::util::initialize_adapter_from_env_or_default(&instance, None)
888 .await
889 .expect("no compatible GPU adapter");
890 println!("frust-gpu timestamp-ring adapter: {:?}", adapter.get_info());
891 if !adapter.features().contains(wgpu::Features::TIMESTAMP_QUERY) {
892 println!("adapter offers no TIMESTAMP_QUERY — the inert path is the whole story");
893 return;
894 }
895 let (device, queue) = adapter
896 .request_device(&wgpu::DeviceDescriptor {
897 label: Some("frust-gpu timestamp ring test device"),
898 required_features: wgpu::Features::TIMESTAMP_QUERY,
899 required_limits: wgpu::Limits::default(),
900 ..Default::default()
901 })
902 .await
903 .expect("failed to create the device");
904
905 // Two spans, three passes charged across them: two into span 0 and
906 // one into span 1, so the reading is per-span rather than per-pass
907 // and both spans must come back nonzero.
908 //
909 // Every pass DRAWS. A draw-less pass is not a shortcut here: Metal
910 // samples a render pass's counters at the vertex/fragment stage
911 // boundaries (`setStartOfVertexSampleIndex`/
912 // `setEndOfFragmentSampleIndex`), so a pass that runs neither stage
913 // can leave its query pair unwritten — the case
914 // [`span_duration`] drops rather than reports.
915 let mut ring = TimestampRing::new(&device, &queue, 2, "frust-gpu ring test");
916 assert!(
917 ring.is_active(),
918 "a TIMESTAMP_QUERY device must arm the ring"
919 );
920 let format = wgpu::TextureFormat::Rgba8Unorm;
921 let target = crate::HeadlessTarget::new(&device, 512, 512, format);
922 let shader = device.create_shader_module(wgpu::ShaderModuleDescriptor {
923 label: Some("frust-gpu ring test shader"),
924 source: wgpu::ShaderSource::Wgsl(RING_TEST_WGSL.into()),
925 });
926 let pipeline = device.create_render_pipeline(&wgpu::RenderPipelineDescriptor {
927 label: Some("frust-gpu ring test pipeline"),
928 layout: None,
929 vertex: wgpu::VertexState {
930 module: &shader,
931 entry_point: Some("vs_main"),
932 compilation_options: wgpu::PipelineCompilationOptions::default(),
933 buffers: &[],
934 },
935 fragment: Some(wgpu::FragmentState {
936 module: &shader,
937 entry_point: Some("fs_main"),
938 compilation_options: wgpu::PipelineCompilationOptions::default(),
939 targets: &[Some(format.into())],
940 }),
941 primitive: wgpu::PrimitiveState::default(),
942 depth_stencil: None,
943 multisample: wgpu::MultisampleState::default(),
944 multiview_mask: None,
945 cache: None,
946 });
947
948 let mut readings = 0_u64;
949 for frame in 0..(RING_FRAMES * 3) {
950 ring.begin_frame(&device);
951 let mut encoder = device.create_command_encoder(&wgpu::CommandEncoderDescriptor {
952 label: Some("frust-gpu ring test frame"),
953 });
954 for (span, instances) in [(0_usize, 64_u32), (0, 64), (1, 64)] {
955 let mut pass = encoder.begin_render_pass(&wgpu::RenderPassDescriptor {
956 label: Some("frust-gpu ring test pass"),
957 color_attachments: &[Some(wgpu::RenderPassColorAttachment {
958 view: target.view(),
959 depth_slice: None,
960 resolve_target: None,
961 ops: wgpu::Operations {
962 load: wgpu::LoadOp::Clear(wgpu::Color::BLACK),
963 store: wgpu::StoreOp::Store,
964 },
965 })],
966 depth_stencil_attachment: None,
967 timestamp_writes: ring.pass_writes(span),
968 occlusion_query_set: None,
969 multiview_mask: None,
970 });
971 pass.set_pipeline(&pipeline);
972 pass.draw(0..3, 0..instances);
973 }
974 ring.resolve(&mut encoder);
975 queue.submit([encoder.finish()]);
976 ring.end_frame();
977 // The frame path never waits on a map; a test may, and does,
978 // so the harvest is deterministic rather than timing-dependent.
979 let _ = device.poll(wgpu::PollType::wait_indefinitely());
980 if ring.harvested() > readings {
981 readings = ring.harvested();
982 println!("frame {frame}: {:?}", ring.latest());
983 }
984 }
985
986 let reading = ring
987 .latest()
988 .expect("a TIMESTAMP_QUERY device must have produced at least one reading");
989 assert_eq!(reading.len(), 2);
990 assert!(
991 reading.span(0) > Duration::ZERO,
992 "span 0 covered two real render passes: {reading:?}"
993 );
994 assert!(
995 reading.span(1) > Duration::ZERO,
996 "span 1 covered a real render pass: {reading:?}"
997 );
998 assert_eq!(reading.total(), reading.span(0) + reading.span(1));
999 assert!(
1000 reading.total() < Duration::from_millis(100),
1001 "three 256x256 clears cannot plausibly take {:?}",
1002 reading.total()
1003 );
1004 });
1005 }
1006}