ashlar_app/
stats.rs

1//! Frame-time statistics: how long producing each frame took (logic + UI, not the time between
2//! frames, which is unbounded for an app that repaints on demand).
3//!
4//! The headline numbers (`p50_ms`, `p95_ms`, `max_ms`) time [`crate::Runtime::ui`], the part of
5//! the frame the app and the runtime control. The rest of the frame is kept per phase: `pass` is
6//! the whole egui pass (input, logic, UI and egui's end of pass), `tessellate` turns the pass's
7//! shapes into meshes, and `frame_cpu` is the whole frame on the CPU (the headless driver: pass +
8//! tessellation; a native window: what eframe reports, including painting).
9
10use std::collections::VecDeque;
11use std::time::Duration;
12
13use serde::Serialize;
14
15/// Frames kept for the percentiles.
16pub const WINDOW: usize = 1024;
17
18/// The recent durations of one phase.
19#[derive(Debug, Default)]
20struct Series {
21    recent: VecDeque<Duration>,
22}
23
24impl Series {
25    fn push(&mut self, d: Duration) {
26        if self.recent.len() >= WINDOW {
27            self.recent.pop_front();
28        }
29        self.recent.push_back(d);
30    }
31
32    fn summary(&self) -> PhaseSummary {
33        let mut v: Vec<Duration> = self.recent.iter().copied().collect();
34        v.sort_unstable();
35        let pick = |q: f64| -> f64 {
36            if v.is_empty() {
37                return 0.0;
38            }
39            let i = ((v.len() as f64 - 1.0) * q).round() as usize;
40            v.get(i.min(v.len() - 1)).copied().map_or(0.0, ms)
41        };
42        PhaseSummary { window: v.len(), p50_ms: pick(0.5), p95_ms: pick(0.95), max_ms: v.last().copied().map_or(0.0, ms) }
43    }
44}
45
46/// Recent frame times.
47#[derive(Debug, Default)]
48pub struct FrameStats {
49    ui: Series,
50    pass: Series,
51    tessellate: Series,
52    frame_cpu: Series,
53    frames: u64,
54    first_frame: Option<Duration>,
55    launch: LaunchTimes,
56    max_ever: Duration,
57}
58
59/// How long a native launch took, from the first line of `run()`. Times in milliseconds; `None`
60/// headless and on the web.
61#[derive(Clone, Copy, Debug, Default, PartialEq, Serialize)]
62pub struct LaunchTimes {
63    /// Until eframe had built the window and its wgpu surface.
64    pub to_window_ms: Option<f64>,
65    /// Until the end of the first [`crate::Runtime::ui`].
66    pub to_first_frame_ms: Option<f64>,
67    /// Until the first frame had been painted and presented (the start of the next frame).
68    pub launch_to_present_ms: Option<f64>,
69}
70
71/// Percentiles of one phase over the window. Times in milliseconds.
72#[derive(Clone, Debug, Default, PartialEq, Serialize)]
73pub struct PhaseSummary {
74    /// Frames in the percentile window that recorded this phase.
75    pub window: usize,
76    pub p50_ms: f64,
77    pub p95_ms: f64,
78    pub max_ms: f64,
79}
80
81/// A summary for telemetry and `app.stats`. Times in milliseconds.
82#[derive(Clone, Debug, Default, PartialEq, Serialize)]
83pub struct StatsSummary {
84    /// Frames produced since start.
85    pub frames: u64,
86    /// Frames in the percentile window.
87    pub window: usize,
88    /// [`crate::Runtime::ui`] only.
89    pub p50_ms: f64,
90    pub p95_ms: f64,
91    pub max_ms: f64,
92    /// Slowest frame since start.
93    pub max_ever_ms: f64,
94    /// Time from runtime creation to the end of the first frame.
95    pub first_frame_ms: Option<f64>,
96    /// Process start to window, first frame and first present (native windows only).
97    pub launch: LaunchTimes,
98    /// The whole egui pass (input, logic, UI, end of pass); recorded by the headless driver.
99    pub pass: PhaseSummary,
100    /// Shapes to meshes; recorded by the headless driver.
101    pub tessellate: PhaseSummary,
102    /// The whole frame on the CPU: pass + tessellation headless, eframe's own figure (painting
103    /// included) in a native window.
104    pub frame_cpu: PhaseSummary,
105}
106
107fn ms(d: Duration) -> f64 {
108    d.as_secs_f64() * 1000.0
109}
110
111impl FrameStats {
112    /// Record the time [`crate::Runtime::ui`] took.
113    pub fn record(&mut self, d: Duration) {
114        self.ui.push(d);
115        self.frames = self.frames.saturating_add(1);
116        self.max_ever = self.max_ever.max(d);
117    }
118
119    /// Record a whole egui pass.
120    pub fn record_pass(&mut self, d: Duration) {
121        self.pass.push(d);
122    }
123
124    /// Record a tessellation.
125    pub fn record_tessellate(&mut self, d: Duration) {
126        self.tessellate.push(d);
127    }
128
129    /// Record a whole frame's CPU time.
130    pub fn record_frame_cpu(&mut self, d: Duration) {
131        self.frame_cpu.push(d);
132    }
133
134    pub fn set_first_frame(&mut self, d: Duration) {
135        self.first_frame.get_or_insert(d);
136    }
137
138    pub(crate) fn set_to_window(&mut self, d: Duration) {
139        self.launch.to_window_ms.get_or_insert(ms(d));
140    }
141
142    pub(crate) fn set_to_first_frame(&mut self, d: Duration) {
143        self.launch.to_first_frame_ms.get_or_insert(ms(d));
144    }
145
146    pub(crate) fn set_presented(&mut self, d: Duration) {
147        self.launch.launch_to_present_ms.get_or_insert(ms(d));
148    }
149
150    /// Process start to window, first frame and first present.
151    pub fn launch(&self) -> LaunchTimes {
152        self.launch
153    }
154
155    pub fn frames(&self) -> u64 {
156        self.frames
157    }
158
159    /// Forget the percentile windows (start a measurement).
160    pub fn reset_window(&mut self) {
161        self.ui.recent.clear();
162        self.pass.recent.clear();
163        self.tessellate.recent.clear();
164        self.frame_cpu.recent.clear();
165    }
166
167    pub fn summary(&self) -> StatsSummary {
168        let ui = self.ui.summary();
169        StatsSummary {
170            frames: self.frames,
171            window: ui.window,
172            p50_ms: ui.p50_ms,
173            p95_ms: ui.p95_ms,
174            max_ms: ui.max_ms,
175            max_ever_ms: ms(self.max_ever),
176            first_frame_ms: self.first_frame.map(ms),
177            launch: self.launch,
178            pass: self.pass.summary(),
179            tessellate: self.tessellate.summary(),
180            frame_cpu: self.frame_cpu.summary(),
181        }
182    }
183}
184
185/// This process, for `app.stats` → `process`. A field is `null` where the platform cannot say:
186/// everything is `null` on the web.
187#[derive(Clone, Copy, Debug, Default, PartialEq, Serialize)]
188pub struct ProcessStats {
189    /// What the system charges the process for: macOS physical footprint, Linux private resident
190    /// + swap, Windows private commit (`ashlar_native::memory`).
191    pub footprint_bytes: Option<u64>,
192    /// The highest footprint since the process started: the OS's own lifetime peak where it keeps
193    /// one (macOS, Windows), so a spike between samples counts; on Linux the highest footprint
194    /// sampled (at most once a second while frames run, and at every reading).
195    pub peak_bytes: Option<u64>,
196    /// CPU time used by every thread since the process started, in seconds.
197    pub cpu_s: Option<f64>,
198    /// Threads in the process.
199    pub threads: Option<u64>,
200}
201
202/// Reads [`ProcessStats`] and keeps the peak footprint.
203#[derive(Debug, Default)]
204pub struct ProcessProbe {
205    peak: Option<u64>,
206    last_tick: Option<std::time::Instant>,
207}
208
209impl ProcessProbe {
210    /// Called every frame: sample the footprint for the peak, at most once a second.
211    pub fn tick(&mut self) {
212        let Some(now) = crate::session::now() else { return };
213        if self.last_tick.is_some_and(|t| now.duration_since(t) < Duration::from_secs(1)) {
214            return;
215        }
216        self.last_tick = Some(now);
217        self.footprint();
218    }
219
220    fn footprint(&mut self) -> Option<u64> {
221        let m = ashlar_native::memory::process_memory()?;
222        let seen = m.peak.map_or(m.footprint, |p| p.max(m.footprint));
223        self.peak = Some(self.peak.map_or(seen, |p| p.max(seen)));
224        Some(m.footprint)
225    }
226
227    /// Read the process now.
228    pub fn read(&mut self) -> ProcessStats {
229        let footprint_bytes = self.footprint();
230        ProcessStats { footprint_bytes, peak_bytes: self.peak, cpu_s: process_cpu_s(), threads: threads() }
231    }
232}
233
234fn process_cpu_s() -> Option<f64> {
235    #[cfg(not(target_arch = "wasm32"))]
236    {
237        cpu_time::ProcessTime::try_now().ok().map(|t| t.as_duration().as_secs_f64())
238    }
239    #[cfg(target_arch = "wasm32")]
240    {
241        None
242    }
243}
244
245fn threads() -> Option<u64> {
246    ashlar_native::memory::thread_count()
247}
248
249#[cfg(test)]
250mod tests {
251    use super::*;
252
253    #[test]
254    fn the_process_is_read_and_its_peak_kept() {
255        let mut p = ProcessProbe::default();
256        p.tick();
257        let s = p.read();
258        if cfg!(any(target_os = "macos", target_os = "linux", target_os = "windows")) {
259            let f = s.footprint_bytes.unwrap();
260            assert!(f > 0 && s.peak_bytes.unwrap() >= f, "{s:?}");
261            assert!(s.cpu_s.unwrap() > 0.0, "{s:?}");
262        }
263        if cfg!(any(target_os = "macos", target_os = "linux", target_os = "windows")) {
264            assert!(s.threads.unwrap() >= 1, "{s:?}");
265        }
266        let v = serde_json::to_value(s).unwrap();
267        for k in ["footprint_bytes", "peak_bytes", "cpu_s", "threads"] {
268            assert!(v.get(k).is_some(), "{k} in {v}");
269        }
270    }
271
272    #[test]
273    fn app_stats_reports_the_process() {
274        let mut d = crate::Driver::new(crate::App::<i64>::new("statstest", "0.0.0").runtime());
275        d.frame();
276        let v = d.call("app.stats", serde_json::json!({})).unwrap();
277        let p = &v["process"];
278        for k in ["footprint_bytes", "peak_bytes", "cpu_s", "threads"] {
279            assert!(p.get(k).is_some(), "{k} in {p}");
280        }
281        if cfg!(any(target_os = "macos", target_os = "linux", target_os = "windows")) {
282            assert!(p["footprint_bytes"].as_u64().is_some_and(|f| f > 0), "{p}");
283            assert!(p["peak_bytes"].as_u64() >= p["footprint_bytes"].as_u64(), "{p}");
284            assert!(p["threads"].as_u64().is_some_and(|t| t >= 1), "{p}");
285        }
286    }
287
288    #[test]
289    fn percentiles() {
290        let mut s = FrameStats::default();
291        for i in 1..=100u64 {
292            s.record(Duration::from_millis(i));
293        }
294        let sum = s.summary();
295        assert_eq!(sum.frames, 100);
296        assert!((sum.p50_ms - 50.0).abs() <= 1.0);
297        assert!((sum.p95_ms - 95.0).abs() <= 1.0);
298        assert!((sum.max_ms - 100.0).abs() < 1e-9);
299        assert_eq!(FrameStats::default().summary().p95_ms, 0.0);
300    }
301
302    #[test]
303    fn phases_are_kept_apart() {
304        let mut s = FrameStats::default();
305        s.record(Duration::from_millis(1));
306        s.record_pass(Duration::from_millis(2));
307        s.record_tessellate(Duration::from_millis(3));
308        s.record_frame_cpu(Duration::from_millis(5));
309        let sum = s.summary();
310        assert!((sum.p95_ms - 1.0).abs() < 1e-9);
311        assert!((sum.pass.p95_ms - 2.0).abs() < 1e-9);
312        assert!((sum.tessellate.max_ms - 3.0).abs() < 1e-9);
313        assert!((sum.frame_cpu.p50_ms - 5.0).abs() < 1e-9);
314        assert_eq!((sum.window, sum.pass.window, sum.tessellate.window, sum.frame_cpu.window), (1, 1, 1, 1));
315        s.reset_window();
316        let sum = s.summary();
317        assert_eq!((sum.window, sum.pass.window, sum.tessellate.window, sum.frame_cpu.window), (0, 0, 0, 0));
318        assert_eq!(sum.frames, 1);
319    }
320
321    #[test]
322    fn the_window_is_bounded() {
323        let mut s = FrameStats::default();
324        for _ in 0..(WINDOW * 3) {
325            s.record(Duration::from_micros(10));
326        }
327        assert_eq!(s.summary().window, WINDOW);
328        assert_eq!(s.frames() as usize, WINDOW * 3);
329    }
330}
ashlar_app/stats.rs

ashlar_app/
stats.rs
