retex-engine 1.3.0-rc.3

//! Phase timing for performance work: with `RETEX_TIMING` set in the
//! environment, [`mark`] prints the time elapsed since the first mark to
//! stderr, and [`Accumulator`]s report their totals at [`report`].

use std::cell::Cell;
use std::sync::OnceLock;
use std::time::{Duration, Instant};

fn start() -> Option<Instant> {
    static START: OnceLock<Option<Instant>> = OnceLock::new();
    *START.get_or_init(|| std::env::var_os("RETEX_TIMING").map(|_| Instant::now()))
}

/// Whether timing is enabled.
pub fn enabled() -> bool {
    start().is_some()
}

/// Prints `label` with the time since the first call.
pub fn mark(label: &str) {
    if let Some(t0) = start() {
        eprintln!(
            "[timing] {:>9.3} ms  {label}",
            t0.elapsed().as_secs_f64() * 1e3
        );
    }
}

/// A running total of time spent in some activity, with a call count.
#[derive(Default)]
pub struct Accumulator {
    total: Cell<Duration>,
    count: Cell<u64>,
}

impl Accumulator {
    /// Adds the time since `since`.
    pub fn add(&self, since: Instant) {
        self.total.set(self.total.get() + since.elapsed());
        self.count.set(self.count.get() + 1);
    }

    /// Prints the total under `label`.
    pub fn report(&self, label: &str) {
        if enabled() {
            eprintln!(
                "[timing] {:>9.3} ms  total in {label} ({} calls)",
                self.total.get().as_secs_f64() * 1e3,
                self.count.get()
            );
        }
    }
}

thread_local! {
    /// Time spent running Lua code (`\directlua`, `\luafunction`, callbacks).
    pub static LUA: Accumulator = Accumulator::default();
    /// Time spent loading fonts in the `define_font` callback.
    pub static FONTS: Accumulator = Accumulator::default();
}