Skip to main content

brep_app/
perf.rs

1//! Where a frame's milliseconds go — the ONE per-frame timing record.
2//!
3//! A dropped frame rate and a frozen UI are the same fact on wasm: the app is
4//! single-threaded, so every millisecond spent between two `ui()` calls is a
5//! millisecond the browser cannot deliver a pointer event in. "Slow" is
6//! therefore not one number but a split, and the split is what names the owner:
7//! encode-and-submit time is the renderer's, publish time is the state
8//! registry's, and the gap between them is egui's.
9//!
10//! Measured with [`web_time::Instant`], which is `performance.now()` on wasm and
11//! the monotonic clock natively, so both shells report the same quantity.
12//!
13//! # Why a static, and why accumulate
14//!
15//! The phases are timed in three different modules (`app`, `viewport`,
16//! `viewport::blit`) that do not share a `&mut` path, so the record lives here
17//! as a static — the same shape [`crate::automation::registry`] uses, for the
18//! same reason. A phase may be entered SEVERAL times in one frame (the registry
19//! publishes from three places); each entry accumulates, and [`tick`] — called
20//! once at the top of the frame — banks the frame's totals into the rolling
21//! window. So every reported phase is "ms per frame", never "ms per call".
22//!
23//! `dt` is wall time between successive `tick`s: the frame PERIOD, including
24//! whatever the browser did between our frames. It is the number a user feels;
25//! the phases explain it.
26
27use std::sync::{Mutex, MutexGuard};
28use web_time::Instant;
29
30/// Frames kept in the rolling window (~2 s at 60 fps).
31const WINDOW: usize = 120;
32
33/// The timed phases, in report order. `Ui` brackets the whole of
34/// `BrepApp::ui`; the rest are nested inside it and do not sum to it — the
35/// remainder is egui's own layout, painting and tessellation.
36///
37/// The reported key for `Ui` is `"ui"`, NOT `"frame"`: a command reply carries
38/// its own `frame` (the frame NUMBER) at the top level, and a phase of that
39/// name would be overwritten by it in the merged result.
40#[derive(Clone, Copy, PartialEq, Eq, Debug)]
41pub enum Phase {
42    /// The whole `BrepApp::ui` body.
43    Ui,
44    /// The `__brep*` state-registry publish blocks.
45    Publish,
46    /// `RenderCore::sync_scene`.
47    Sync,
48    /// `EngineState::fit_camera_and_overlay` (rebuilds the widget overlay).
49    Fit,
50    /// `EngineState::ensure_overlays_current`.
51    Overlays,
52    /// `RenderCore::render_to_view` — encode + submit. On the GL/WebGL2 backend
53    /// the driver replays the command buffer synchronously inside submit, so
54    /// this is very nearly the whole GPU cost; on WebGPU/Vulkan it is encode
55    /// only and the GPU work shows up in `dt` instead.
56    Draw,
57}
58
59const PHASES: usize = 6;
60
61const NAMES: [&str; PHASES] = ["ui", "publish", "sync", "fit", "overlays", "draw"];
62
63fn slot(phase: Phase) -> usize {
64    match phase {
65        Phase::Ui => 0,
66        Phase::Publish => 1,
67        Phase::Sync => 2,
68        Phase::Fit => 3,
69        Phase::Overlays => 4,
70        Phase::Draw => 5,
71    }
72}
73
74/// A fixed-capacity rolling window of per-frame milliseconds.
75struct Ring {
76    samples: [f32; WINDOW],
77    len: usize,
78    next: usize,
79}
80
81impl Ring {
82    const fn new() -> Self {
83        Self { samples: [0.0; WINDOW], len: 0, next: 0 }
84    }
85
86    fn push(&mut self, ms: f32) {
87        self.samples[self.next] = ms;
88        self.next = (self.next + 1) % WINDOW;
89        self.len = (self.len + 1).min(WINDOW);
90    }
91
92    fn stats(&self) -> Stats {
93        if self.len == 0 {
94            return Stats::default();
95        }
96        let live = &self.samples[..self.len];
97        let sum: f32 = live.iter().sum();
98        let mut sorted: Vec<f32> = live.to_vec();
99        sorted.sort_by(|a, b| a.partial_cmp(b).unwrap_or(std::cmp::Ordering::Equal));
100        // p95 by nearest-rank, so a 120-frame window reports its 114th slowest.
101        let rank = ((self.len as f32 * 0.95).ceil() as usize).clamp(1, self.len) - 1;
102        Stats {
103            avg: sum / self.len as f32,
104            p95: sorted[rank],
105            max: sorted[self.len - 1],
106        }
107    }
108}
109
110#[derive(Default, Clone, Copy)]
111struct Stats {
112    avg: f32,
113    p95: f32,
114    max: f32,
115}
116
117struct Perf {
118    /// Banked per-frame totals, one ring per phase.
119    rings: [Ring; PHASES],
120    /// Frame period (wall time between `tick`s).
121    dt: Ring,
122    /// This frame's running totals, banked by the next `tick`.
123    pending: [f32; PHASES],
124    /// When the current frame started, for `dt`.
125    last_tick: Option<Instant>,
126    /// Frames banked since startup.
127    frames: u64,
128}
129
130static PERF: Mutex<Perf> = Mutex::new(Perf {
131    rings: [Ring::new(), Ring::new(), Ring::new(), Ring::new(), Ring::new(), Ring::new()],
132    dt: Ring::new(),
133    pending: [0.0; PHASES],
134    last_tick: None,
135    frames: 0,
136});
137
138fn lock() -> MutexGuard<'static, Perf> {
139    PERF.lock().unwrap_or_else(|p| p.into_inner())
140}
141
142/// Open the current frame: bank the previous frame's phase totals and record
143/// its period. Call ONCE, at the top of `BrepApp::ui`.
144pub fn tick() {
145    let now = Instant::now();
146    let mut perf = lock();
147    if let Some(last) = perf.last_tick {
148        let dt = now.duration_since(last).as_secs_f32() * 1000.0;
149        perf.dt.push(dt);
150        let pending = perf.pending;
151        for (index, ms) in pending.iter().enumerate() {
152            perf.rings[index].push(*ms);
153        }
154        perf.frames += 1;
155    }
156    perf.pending = [0.0; PHASES];
157    perf.last_tick = Some(now);
158}
159
160/// Time a block into `phase`; the span ends when the guard drops. Several spans
161/// of the same phase in one frame ADD UP — the window holds ms per frame.
162#[must_use = "the span ends when the guard drops; bind it to a name"]
163pub fn span(phase: Phase) -> Span {
164    Span { phase, start: Instant::now() }
165}
166
167pub struct Span {
168    phase: Phase,
169    start: Instant,
170}
171
172impl Drop for Span {
173    fn drop(&mut self) {
174        let ms = self.start.elapsed().as_secs_f32() * 1000.0;
175        let mut perf = lock();
176        perf.pending[slot(self.phase)] += ms;
177    }
178}
179
180/// The rolling window as JSON: the `__brepPerf` blob and the Info-window rows
181/// read this one value, so they cannot disagree.
182///
183/// `{"frames":N,"window":120,"dt":{"avg":..,"p95":..,"max":..},"frame":{..},…}`
184/// — every number in milliseconds.
185pub fn json() -> String {
186    let perf = lock();
187    let mut out = String::with_capacity(320);
188    out.push_str("{\"frames\":");
189    out.push_str(&perf.frames.to_string());
190    out.push_str(",\"window\":");
191    out.push_str(&perf.dt.len.to_string());
192    let push = |out: &mut String, name: &str, stats: Stats| {
193        out.push_str(",\"");
194        out.push_str(name);
195        out.push_str("\":{\"avg\":");
196        out.push_str(&format!("{:.3}", stats.avg));
197        out.push_str(",\"p95\":");
198        out.push_str(&format!("{:.3}", stats.p95));
199        out.push_str(",\"max\":");
200        out.push_str(&format!("{:.3}", stats.max));
201        out.push('}');
202    };
203    push(&mut out, "dt", perf.dt.stats());
204    for (index, name) in NAMES.iter().enumerate() {
205        push(&mut out, name, perf.rings[index].stats());
206    }
207    out.push('}');
208    out
209}
210
211/// Drop every sample, keeping the frame counter's meaning ("frames banked")
212/// intact only for the new window. A measurement resets, then spins, then
213/// reads — otherwise the idle frames before the spin dominate the average.
214pub fn reset() {
215    let mut perf = lock();
216    for ring in perf.rings.iter_mut() {
217        *ring = Ring::new();
218    }
219    perf.dt = Ring::new();
220    perf.pending = [0.0; PHASES];
221    perf.frames = 0;
222    perf.last_tick = None;
223}