zsh/extensions/
ftime.rs

1//! TEMPORARY measurement scaffold — per-shell-function inclusive timing.
2//!
3//! `zsh/zprof` cannot be used to profile zshrs: `zprof_wrapper` is ported
4//! but never registered (`boot_` returns 0 where C returns
5//! `addwrapper(m, wrapper)`, zprof.c:362) and there is no `funcwrap`
6//! infrastructure to register it with. This stands in until that is built.
7//!
8//! Gated on `ZSHRS_LOG` containing `ftime`; when the gate is off every
9//! entry point is a single relaxed atomic load and returns `None`.
10//!
11//! Times are INCLUSIVE (like zprof's `time` column, not `self`): a nested
12//! call is counted in its own row and in every ancestor's.
13
14use std::collections::HashMap;
15use std::sync::atomic::{AtomicBool, Ordering};
16use std::sync::{Mutex, OnceLock};
17use std::time::Instant;
18
19fn enabled() -> bool {
20    static ON: OnceLock<bool> = OnceLock::new();
21    *ON.get_or_init(|| std::env::var("ZSHRS_LOG").is_ok_and(|v| v.contains("ftime")))
22}
23
24static DIRTY: AtomicBool = AtomicBool::new(false);
25
26#[allow(clippy::type_complexity)]
27fn table() -> &'static Mutex<HashMap<String, (u128, u32)>> {
28    static T: OnceLock<Mutex<HashMap<String, (u128, u32)>>> = OnceLock::new();
29    T.get_or_init(|| Mutex::new(HashMap::new()))
30}
31
32/// Begin timing `name`; `None` when the gate is off.
33pub fn start(name: &str) -> Option<(String, Instant)> {
34    if !enabled() {
35        return None;
36    }
37    Some((name.to_string(), Instant::now()))
38}
39
40/// Accumulate the elapsed time for a span opened by [`start`].
41pub fn stop(span: Option<(String, Instant)>) {
42    let Some((name, t0)) = span else { return };
43    let ns = t0.elapsed().as_nanos();
44    if let Ok(mut t) = table().lock() {
45        let e = t.entry(name).or_insert((0, 0));
46        e.0 += ns;
47        e.1 += 1;
48    }
49    DIRTY.store(true, Ordering::Relaxed);
50}
51
52/// Write the aggregate to `/tmp/ftime.log`, highest total first, and reset.
53/// Called at the end of a completion so one TAB yields one report.
54pub fn dump_and_reset() {
55    if !enabled() || !DIRTY.swap(false, Ordering::Relaxed) {
56        return;
57    }
58    let Ok(mut t) = table().lock() else { return };
59    let mut rows: Vec<(String, u128, u32)> = t.iter().map(|(k, v)| (k.clone(), v.0, v.1)).collect();
60    rows.sort_by(|a, b| b.1.cmp(&a.1));
61    let mut out = String::from("  total_ms   calls  name (inclusive)\n");
62    for (name, ns, calls) in rows.iter().take(40) {
63        out.push_str(&format!(
64            "{:10.3} {:7}  {}\n",
65            *ns as f64 / 1e6,
66            calls,
67            name
68        ));
69    }
70    let _ = std::fs::write("/tmp/ftime.log", out);
71    t.clear();
72}
zsh/extensions/ftime.rs

zsh/extensions/
ftime.rs
