anno_eval/eval/
profiling.rs

1//! Profiling utilities for performance analysis.
2//!
3//! Provides timing instrumentation to identify bottlenecks in evaluation.
4
5use std::collections::HashMap;
6use std::time::{Duration, Instant};
7
8/// Profiling timer that tracks time spent in different operations.
9#[derive(Debug, Clone)]
10pub struct Profiler {
11    timings: HashMap<String, Vec<Duration>>,
12    current_timers: HashMap<String, Instant>,
13}
14
15impl Profiler {
16    /// Create a new profiler.
17    pub fn new() -> Self {
18        Self {
19            timings: HashMap::new(),
20            current_timers: HashMap::new(),
21        }
22    }
23
24    /// Start timing an operation.
25    pub fn start(&mut self, operation: &str) {
26        self.current_timers
27            .insert(operation.to_string(), Instant::now());
28    }
29
30    /// Stop timing an operation and record the duration.
31    pub fn stop(&mut self, operation: &str) {
32        if let Some(start) = self.current_timers.remove(operation) {
33            let duration = start.elapsed();
34            self.timings
35                .entry(operation.to_string())
36                .or_default()
37                .push(duration);
38        }
39    }
40
41    /// Time a closure and record the duration.
42    pub fn time<F, R>(&mut self, operation: &str, f: F) -> R
43    where
44        F: FnOnce() -> R,
45    {
46        self.start(operation);
47        let result = f();
48        self.stop(operation);
49        result
50    }
51
52    /// Get summary statistics for all timed operations.
53    pub fn summary(&self) -> HashMap<String, TimingStats> {
54        self.timings
55            .iter()
56            .map(|(name, durations)| {
57                let total: Duration = durations.iter().sum();
58                let count = durations.len();
59                let avg = if count > 0 {
60                    total / count as u32
61                } else {
62                    Duration::ZERO
63                };
64                let min = durations.iter().min().copied().unwrap_or(Duration::ZERO);
65                let max = durations.iter().max().copied().unwrap_or(Duration::ZERO);
66
67                (
68                    name.clone(),
69                    TimingStats {
70                        total,
71                        count,
72                        avg,
73                        min,
74                        max,
75                    },
76                )
77            })
78            .collect()
79    }
80
81    /// Print a human-readable summary to stderr.
82    pub fn print_summary(&self) {
83        let summary = self.summary();
84        eprintln!("\n=== Profiling Summary ===");
85        eprintln!(
86            "{:<30} {:>10} {:>10} {:>10} {:>10} {:>10}",
87            "Operation", "Count", "Total (ms)", "Avg (ms)", "Min (ms)", "Max (ms)"
88        );
89        eprintln!("{}", "-".repeat(90));
90
91        let mut sorted: Vec<_> = summary.iter().collect();
92        sorted.sort_by(|a, b| b.1.total.cmp(&a.1.total)); // Sort by total time descending
93
94        for (name, stats) in sorted {
95            eprintln!(
96                "{:<30} {:>10} {:>10.2} {:>10.2} {:>10.2} {:>10.2}",
97                name,
98                stats.count,
99                stats.total.as_secs_f64() * 1000.0,
100                stats.avg.as_secs_f64() * 1000.0,
101                stats.min.as_secs_f64() * 1000.0,
102                stats.max.as_secs_f64() * 1000.0,
103            );
104        }
105        eprintln!();
106    }
107}
108
109impl Default for Profiler {
110    fn default() -> Self {
111        Self::new()
112    }
113}
114
115/// Statistics for a timed operation.
116#[derive(Debug, Clone)]
117pub struct TimingStats {
118    /// Total time spent in this operation
119    pub total: Duration,
120    /// Number of times this operation was called
121    pub count: usize,
122    /// Average time per call
123    pub avg: Duration,
124    /// Minimum time for a single call
125    pub min: Duration,
126    /// Maximum time for a single call
127    pub max: Duration,
128}
129
130// Global profiler instance (thread-local for thread safety).
131#[cfg(feature = "eval-profiling")]
132thread_local! {
133    static PROFILER: std::cell::RefCell<Profiler> = std::cell::RefCell::new(Profiler::new());
134}
135
136/// Start timing an operation (if profiling is enabled).
137#[cfg(feature = "eval-profiling")]
138pub fn start(operation: &str) {
139    PROFILER.with(|p| p.borrow_mut().start(operation));
140}
141
142/// Stop timing an operation (if profiling is enabled).
143#[cfg(feature = "eval-profiling")]
144pub fn stop(operation: &str) {
145    PROFILER.with(|p| p.borrow_mut().stop(operation));
146}
147
148/// Time a closure (if profiling is enabled).
149#[cfg(feature = "eval-profiling")]
150pub fn time<F, R>(operation: &str, f: F) -> R
151where
152    F: FnOnce() -> R,
153{
154    PROFILER.with(|p| p.borrow_mut().time(operation, f))
155}
156
157/// Print profiling summary (if profiling is enabled).
158#[cfg(feature = "eval-profiling")]
159pub fn print_summary() {
160    PROFILER.with(|p| p.borrow().print_summary());
161}
162
163/// No-op implementations when profiling is disabled.
164#[cfg(not(feature = "eval-profiling"))]
165pub fn start(_operation: &str) {}
166
167#[cfg(not(feature = "eval-profiling"))]
168pub fn stop(_operation: &str) {}
169
170#[cfg(not(feature = "eval-profiling"))]
171pub fn time<F, R>(_operation: &str, f: F) -> R
172where
173    F: FnOnce() -> R,
174{
175    f()
176}
177
178#[cfg(not(feature = "eval-profiling"))]
179pub fn print_summary() {}
anno_eval/eval/profiling.rs

anno_eval/eval/
profiling.rs
