Skip to main content

qk_cache/
profile.rs

1//! Opt-in elapsed timings for cache operations, written to stderr.
2
3use std::sync::OnceLock;
4use std::time::Instant;
5
6static ENABLED: OnceLock<bool> = OnceLock::new();
7
8/// Enable timings for this process before its first cache operation.
9/// `QK_PROFILE_CACHE=1` also enables them when no caller configures profiling.
10pub fn enable() {
11    let _ = ENABLED.set(true);
12}
13
14pub(crate) struct Span<'a> {
15    task: &'a str,
16    stage: &'static str,
17    started: Option<Instant>,
18    counts: Vec<(&'static str, u64)>,
19}
20
21pub(crate) fn span<'a>(task: &'a str, stage: &'static str) -> Span<'a> {
22    let enabled = *ENABLED
23        .get_or_init(|| std::env::var_os("QK_PROFILE_CACHE").is_some_and(|value| value == "1"));
24    Span {
25        task,
26        stage,
27        started: enabled.then(Instant::now),
28        counts: Vec::new(),
29    }
30}
31
32impl Span<'_> {
33    /// Adds a count to the span's line, such as the bytes it received.
34    pub(crate) fn count(&mut self, name: &'static str, value: u64) {
35        if self.started.is_some() {
36            self.counts.push((name, value));
37        }
38    }
39}
40
41impl Drop for Span<'_> {
42    fn drop(&mut self) {
43        if let Some(started) = self.started {
44            let mut line = format!(
45                "qk profile: task={} stage={} ms={:.3}",
46                self.task,
47                self.stage,
48                started.elapsed().as_secs_f64() * 1000.0
49            );
50            for (name, value) in &self.counts {
51                line.push_str(&format!(" {name}={value}"));
52            }
53            line.push('\n');
54            qk_executor::report::output(true, line.as_bytes());
55        }
56    }
57}