Skip to main content

retex_engine/
timing.rs

1//! Phase timing for performance work: with `RETEX_TIMING` set in the
2//! environment, [`mark`] prints the time elapsed since the first mark to
3//! stderr, and [`Accumulator`]s report their totals at [`report`].
4
5use std::cell::Cell;
6use std::sync::OnceLock;
7use std::time::{Duration, Instant};
8
9fn start() -> Option<Instant> {
10    static START: OnceLock<Option<Instant>> = OnceLock::new();
11    *START.get_or_init(|| std::env::var_os("RETEX_TIMING").map(|_| Instant::now()))
12}
13
14/// Whether timing is enabled.
15pub fn enabled() -> bool {
16    start().is_some()
17}
18
19/// Prints `label` with the time since the first call.
20pub fn mark(label: &str) {
21    if let Some(t0) = start() {
22        eprintln!(
23            "[timing] {:>9.3} ms  {label}",
24            t0.elapsed().as_secs_f64() * 1e3
25        );
26    }
27}
28
29/// A running total of time spent in some activity, with a call count.
30#[derive(Default)]
31pub struct Accumulator {
32    total: Cell<Duration>,
33    count: Cell<u64>,
34}
35
36impl Accumulator {
37    /// Adds the time since `since`.
38    pub fn add(&self, since: Instant) {
39        self.total.set(self.total.get() + since.elapsed());
40        self.count.set(self.count.get() + 1);
41    }
42
43    /// Prints the total under `label`.
44    pub fn report(&self, label: &str) {
45        if enabled() {
46            eprintln!(
47                "[timing] {:>9.3} ms  total in {label} ({} calls)",
48                self.total.get().as_secs_f64() * 1e3,
49                self.count.get()
50            );
51        }
52    }
53}
54
55thread_local! {
56    /// Time spent running Lua code (`\directlua`, `\luafunction`, callbacks).
57    pub static LUA: Accumulator = Accumulator::default();
58    /// Time spent loading fonts in the `define_font` callback.
59    pub static FONTS: Accumulator = Accumulator::default();
60}