sql_cli/
debug_trace.rs

1#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord)]
2pub enum DebugLevel {
3    Off,
4    Error,
5    Warn,
6    Info,
7    Debug,
8    Trace,
9}
10
11impl DebugLevel {
12    pub fn enabled(&self, level: DebugLevel) -> bool {
13        *self >= level
14    }
15}
16
17#[derive(Clone)]
18pub struct DebugContext {
19    level: DebugLevel,
20    component_filter: Option<Vec<String>>,
21}
22
23impl Default for DebugContext {
24    fn default() -> Self {
25        Self::new(DebugLevel::Off)
26    }
27}
28
29impl DebugContext {
30    pub fn new(level: DebugLevel) -> Self {
31        Self {
32            level,
33            component_filter: None,
34        }
35    }
36
37    pub fn with_filter(mut self, components: Vec<String>) -> Self {
38        self.component_filter = Some(components);
39        self
40    }
41
42    #[inline(always)]
43    pub fn is_enabled(&self, level: DebugLevel) -> bool {
44        self.level.enabled(level)
45    }
46
47    #[inline(always)]
48    pub fn should_log(&self, component: &str, level: DebugLevel) -> bool {
49        if !self.is_enabled(level) {
50            return false;
51        }
52
53        if let Some(ref filter) = self.component_filter {
54            filter.iter().any(|c| component.starts_with(c))
55        } else {
56            true
57        }
58    }
59}
60
61pub struct QueryTrace {
62    context: DebugContext,
63    traces: Vec<TraceEntry>,
64}
65
66#[derive(Clone)]
67pub struct TraceEntry {
68    pub component: String,
69    pub phase: String,
70    pub message: String,
71    pub timing_us: Option<u64>,
72}
73
74impl QueryTrace {
75    pub fn new(context: DebugContext) -> Self {
76        Self {
77            context,
78            traces: Vec::new(),
79        }
80    }
81
82    #[inline(always)]
83    pub fn is_enabled(&self) -> bool {
84        self.context.level != DebugLevel::Off
85    }
86
87    #[inline(always)]
88    pub fn log<C, P, M>(&mut self, component: C, phase: P, message: M)
89    where
90        C: Into<String>,
91        P: Into<String>,
92        M: Into<String>,
93    {
94        if self.is_enabled() {
95            let component = component.into();
96            if self.context.should_log(&component, DebugLevel::Debug) {
97                self.traces.push(TraceEntry {
98                    component,
99                    phase: phase.into(),
100                    message: message.into(),
101                    timing_us: None,
102                });
103            }
104        }
105    }
106
107    #[inline(always)]
108    pub fn log_timed<C, P, M>(&mut self, component: C, phase: P, message: M, timing_us: u64)
109    where
110        C: Into<String>,
111        P: Into<String>,
112        M: Into<String>,
113    {
114        if self.is_enabled() {
115            let component = component.into();
116            if self.context.should_log(&component, DebugLevel::Debug) {
117                self.traces.push(TraceEntry {
118                    component,
119                    phase: phase.into(),
120                    message: message.into(),
121                    timing_us: Some(timing_us),
122                });
123            }
124        }
125    }
126
127    pub fn format_output(&self) -> String {
128        if self.traces.is_empty() {
129            return String::new();
130        }
131
132        let mut output = String::from("\n=== QUERY EXECUTION TRACE ===\n");
133        let mut current_component = String::new();
134
135        for entry in &self.traces {
136            if entry.component != current_component {
137                output.push_str(&format!("\n[{}]\n", entry.component));
138                current_component = entry.component.clone();
139            }
140
141            if let Some(timing) = entry.timing_us {
142                output.push_str(&format!(
143                    "  {}: {} ({:.3}ms)\n",
144                    entry.phase,
145                    entry.message,
146                    timing as f64 / 1000.0
147                ));
148            } else {
149                output.push_str(&format!("  {}: {}\n", entry.phase, entry.message));
150            }
151        }
152
153        output.push_str("\n=== END TRACE ===\n");
154        output
155    }
156
157    pub fn get_traces(&self) -> &[TraceEntry] {
158        &self.traces
159    }
160}
161
162#[macro_export]
163macro_rules! trace_log {
164    ($trace:expr, $component:expr, $phase:expr, $($arg:tt)*) => {
165        if $trace.is_enabled() {
166            $trace.log($component, $phase, format!($($arg)*));
167        }
168    };
169}
170
171#[macro_export]
172macro_rules! trace_timed {
173    ($trace:expr, $component:expr, $phase:expr, $timing:expr, $($arg:tt)*) => {
174        if $trace.is_enabled() {
175            $trace.log_timed($component, $phase, format!($($arg)*), $timing);
176        }
177    };
178}
179
180pub struct ScopedTimer {
181    start: std::time::Instant,
182}
183
184impl ScopedTimer {
185    pub fn new() -> Self {
186        Self {
187            start: std::time::Instant::now(),
188        }
189    }
190
191    pub fn elapsed_us(&self) -> u64 {
192        self.start.elapsed().as_micros() as u64
193    }
194
195    pub fn elapsed_ms(&self) -> f64 {
196        self.start.elapsed().as_secs_f64() * 1000.0
197    }
198}