OXYGENHUB
# e0d56dfca51d oxygen / crates / oxy-core / src / timing.rs
2.5 KiB · Rust · last changed Memory per phase with a counting allocator 1 month ago source blame history raw
1 
//! Opt-in phase timings (`OXY_TIMINGS=1`): each named phase prints its
2 
//! duration to stderr, for measuring where a command spends its time
3 
//! without a profiler. With the counting allocator installed (the `oxy`
4 
//! binary's `alloc-stats` feature), each also prints live and peak memory
5 
//! and what the phase allocated.
6
7 
use std::sync::OnceLock;
8 
use std::time::Instant;
9
10 
fn enabled() -> bool {
11 
    static ON: OnceLock<bool> = OnceLock::new();
12 
    *ON.get_or_init(|| std::env::var_os("OXY_TIMINGS").is_some_and(|v| !v.is_empty() && v != "0"))
13 
}
14
15 
/// Report a duration measured by hand (several intervals summed), if timings are on.
16 
pub fn record(name: &str, d: std::time::Duration) {
17 
    if enabled() {
18 
        eprintln!("timing {:<28} {:>9.2} ms", name, d.as_secs_f64() * 1000.0);
19 
    }
20 
}
21
22 
/// Prints `timing <name> <ms>` when dropped, if timings are on.
23 
pub struct Phase {
24 
    name: &'static str,
25 
    started: Option<Instant>,
26 
    /// Allocator counters at the start, when counting.
27 
    mem: Option<crate::alloc_stats::Stats>,
28 
}
29
30 
/// Start timing a phase; the guard reports when it goes out of scope.
31 
pub fn phase(name: &'static str) -> Phase {
32 
    let on = enabled();
33 
    Phase {
34 
        name,
35 
        started: on.then(Instant::now),
36 
        mem: if on {
37 
            crate::alloc_stats::stats()
38 
        } else {
39 
            None
40 
        },
41 
    }
42 
}
43
44 
fn mib(n: usize) -> f64 {
45 
    n as f64 / (1024.0 * 1024.0)
46 
}
47
48 
/// The allocator's counters as one line, when counting: for the end of a
49 
/// command.
50 
pub fn memory_summary() {
51 
    if let (true, Some(s)) = (enabled(), crate::alloc_stats::stats()) {
52 
        eprintln!(
53 
            "memory peak {:.1} MiB, live {:.1} MiB, {:.1} MiB in {} allocations",
54 
            mib(s.peak),
55 
            mib(s.live),
56 
            mib(s.total),
57 
            s.count
58 
        );
59 
    }
60 
}
61
62 
impl Drop for Phase {
63 
    fn drop(&mut self) {
64 
        if let Some(t) = self.started {
65 
            let ms = t.elapsed().as_secs_f64() * 1000.0;
66 
            match (self.mem, crate::alloc_stats::stats()) {
67 
                (Some(a), Some(b)) => eprintln!(
68 
                    "timing {:<28} {:>9.2} ms  live {:>8.1} MiB  peak {:>8.1} MiB  +{:.1} MiB in {} allocs",
69 
                    self.name,
70 
                    ms,
71 
                    mib(b.live),
72 
                    mib(b.peak),
73 
                    mib(b.total - a.total),
74 
                    b.count - a.count
75 
                ),
76 
                _ => eprintln!("timing {:<28} {:>9.2} ms", self.name, ms),
77 
            }
78 
        }
79 
    }
80 
}