fleischwolf_pdf/
timing.rs

1//! Lightweight, env-gated per-stage timing for profiling the PDF pipeline.
2//!
3//! Set `FLEISCHWOLF_TIMING=1` to accumulate wall-clock time per named stage
4//! across all pages and print a sorted breakdown at process exit. Zero cost
5//! when the env var is unset (the `Instant` is still taken but nothing is
6//! recorded — call sites guard the hot path themselves where it matters).
7
8use std::collections::BTreeMap;
9use std::sync::{Mutex, OnceLock};
10use std::time::Instant;
11
12fn enabled() -> bool {
13    static ON: OnceLock<bool> = OnceLock::new();
14    *ON.get_or_init(|| std::env::var("FLEISCHWOLF_TIMING").is_ok())
15}
16
17fn store() -> &'static Mutex<BTreeMap<&'static str, (u128, u64)>> {
18    static S: OnceLock<Mutex<BTreeMap<&'static str, (u128, u64)>>> = OnceLock::new();
19    S.get_or_init(|| Mutex::new(BTreeMap::new()))
20}
21
22/// Record `elapsed` nanoseconds against `stage`. No-op unless timing is enabled.
23pub fn record(stage: &'static str, nanos: u128) {
24    if !enabled() {
25        return;
26    }
27    let mut g = store().lock().unwrap();
28    let e = g.entry(stage).or_insert((0, 0));
29    e.0 += nanos;
30    e.1 += 1;
31}
32
33/// Time a closure and attribute its wall-clock to `stage`.
34pub fn timed<T>(stage: &'static str, f: impl FnOnce() -> T) -> T {
35    if !enabled() {
36        return f();
37    }
38    let t = Instant::now();
39    let out = f();
40    record(stage, t.elapsed().as_nanos());
41    out
42}
43
44/// Print the accumulated breakdown (descending by total time). Call once at the
45/// end of a conversion. No-op unless timing is enabled.
46pub fn report() {
47    if !enabled() {
48        return;
49    }
50    let g = store().lock().unwrap();
51    let mut rows: Vec<_> = g.iter().map(|(k, v)| (*k, v.0, v.1)).collect();
52    rows.sort_by_key(|r| std::cmp::Reverse(r.1));
53    let total: u128 = rows.iter().map(|r| r.1).sum();
54    eprintln!("=== FLEISCHWOLF timing (per stage, wall-clock) ===");
55    for (stage, nanos, calls) in &rows {
56        let ms = *nanos as f64 / 1e6;
57        let pct = if total > 0 {
58            *nanos as f64 / total as f64 * 100.0
59        } else {
60            0.0
61        };
62        eprintln!("  {stage:<22} {ms:>9.1} ms  {pct:>5.1}%  ({calls} calls)");
63    }
64    eprintln!("  {:<22} {:>9.1} ms", "TOTAL (summed)", total as f64 / 1e6);
65}
fleischwolf_pdf/timing.rs

fleischwolf_pdf/
timing.rs
