vibesql_executor/
debug_output.rs

1//! Structured debug output infrastructure
2//!
3//! This module provides a unified interface for debug/profiling output that can emit
4//! either human-readable text (default) or machine-parseable JSON.
5//!
6//! # Environment Variables
7//!
8//! - `VIBESQL_DEBUG_FORMAT=json` - Output JSON to stderr (for agents/CI)
9//! - `VIBESQL_DEBUG_FORMAT=text` - Output human-readable text (default)
10//!
11//! # JSON Schema
12//!
13//! All JSON output follows this structure:
14//! ```json
15//! {
16//!   "timestamp": "2024-01-15T10:30:00.123Z",
17//!   "category": "optimizer",
18//!   "event": "join_reorder",
19//!   "data": { ... }
20//! }
21//! ```
22//!
23//! # Categories
24//!
25//! - `optimizer` - Query optimization decisions (join reorder, table elimination, etc.)
26//! - `execution` - Execution timing and statistics
27//! - `index` - Index selection and usage
28//! - `dml` - DML operation timing (insert, update, delete)
29//! - `profile` - General profiling output
30
31use std::{
32    sync::atomic::{AtomicU8, Ordering},
33    time::{SystemTime, UNIX_EPOCH},
34};
35
36/// Output format for debug messages
37#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
38#[repr(u8)]
39pub enum DebugFormat {
40    /// Human-readable text output (default)
41    #[default]
42    Text = 0,
43    /// Machine-parseable JSON output
44    Json = 1,
45}
46
47/// Global format setting (0 = Text, 1 = Json)
48static DEBUG_FORMAT: AtomicU8 = AtomicU8::new(0);
49
50/// Initialize debug format from environment variable.
51/// Call this once at program start.
52pub fn init() {
53    if let Ok(format) = std::env::var("VIBESQL_DEBUG_FORMAT") {
54        match format.to_lowercase().as_str() {
55            "json" => DEBUG_FORMAT.store(1, Ordering::Relaxed),
56            "text" | "" => DEBUG_FORMAT.store(0, Ordering::Relaxed),
57            _ => {
58                eprintln!("[WARNING] Unknown VIBESQL_DEBUG_FORMAT='{}', using 'text'", format);
59                DEBUG_FORMAT.store(0, Ordering::Relaxed);
60            }
61        }
62    }
63}
64
65/// Get the current debug output format
66pub fn get_format() -> DebugFormat {
67    match DEBUG_FORMAT.load(Ordering::Relaxed) {
68        1 => DebugFormat::Json,
69        _ => DebugFormat::Text,
70    }
71}
72
73/// Check if JSON output is enabled
74pub fn is_json() -> bool {
75    DEBUG_FORMAT.load(Ordering::Relaxed) == 1
76}
77
78/// Debug output categories
79#[derive(Debug, Clone, Copy)]
80pub enum Category {
81    /// Query optimization decisions
82    Optimizer,
83    /// Execution timing and statistics
84    Execution,
85    /// Index selection and usage
86    Index,
87    /// DML operation timing
88    Dml,
89    /// General profiling
90    Profile,
91}
92
93impl Category {
94    pub fn as_str(&self) -> &'static str {
95        match self {
96            Category::Optimizer => "optimizer",
97            Category::Execution => "execution",
98            Category::Index => "index",
99            Category::Dml => "dml",
100            Category::Profile => "profile",
101        }
102    }
103}
104
105/// Get current timestamp in ISO 8601 format
106fn iso_timestamp() -> String {
107    let now = SystemTime::now();
108    let duration = now.duration_since(UNIX_EPOCH).unwrap_or_default();
109    let secs = duration.as_secs();
110    let millis = duration.subsec_millis();
111
112    // Convert to date/time components (simplified UTC)
113    let days_since_epoch = secs / 86400;
114    let time_of_day = secs % 86400;
115    let hours = time_of_day / 3600;
116    let minutes = (time_of_day % 3600) / 60;
117    let seconds = time_of_day % 60;
118
119    // Simplified date calculation (good enough for debugging purposes)
120    // This handles dates from 1970-2099 reasonably well
121    let mut year = 1970;
122    let mut remaining_days = days_since_epoch as i64;
123
124    loop {
125        let days_in_year =
126            if year % 4 == 0 && (year % 100 != 0 || year % 400 == 0) { 366 } else { 365 };
127        if remaining_days < days_in_year {
128            break;
129        }
130        remaining_days -= days_in_year;
131        year += 1;
132    }
133
134    let is_leap = year % 4 == 0 && (year % 100 != 0 || year % 400 == 0);
135    let days_in_months: [i64; 12] = if is_leap {
136        [31, 29, 31, 30, 31, 30, 31, 31, 30, 31, 30, 31]
137    } else {
138        [31, 28, 31, 30, 31, 30, 31, 31, 30, 31, 30, 31]
139    };
140
141    let mut month = 1;
142    for &days in &days_in_months {
143        if remaining_days < days {
144            break;
145        }
146        remaining_days -= days;
147        month += 1;
148    }
149    let day = remaining_days + 1;
150
151    format!(
152        "{:04}-{:02}-{:02}T{:02}:{:02}:{:02}.{:03}Z",
153        year, month, day, hours, minutes, seconds, millis
154    )
155}
156
157/// Escape a string for JSON output
158fn json_escape(s: &str) -> String {
159    let mut result = String::with_capacity(s.len() + 16);
160    for c in s.chars() {
161        match c {
162            '"' => result.push_str("\\\""),
163            '\\' => result.push_str("\\\\"),
164            '\n' => result.push_str("\\n"),
165            '\r' => result.push_str("\\r"),
166            '\t' => result.push_str("\\t"),
167            c if c.is_control() => {
168                result.push_str(&format!("\\u{:04x}", c as u32));
169            }
170            c => result.push(c),
171        }
172    }
173    result
174}
175
176/// A builder for constructing debug output with optional JSON fields
177pub struct DebugEvent {
178    category: Category,
179    event: &'static str,
180    tag: &'static str,
181    text_parts: Vec<String>,
182    json_fields: Vec<(String, JsonValue)>,
183}
184
185/// JSON value types (simplified, no external dependency)
186pub enum JsonValue {
187    String(String),
188    Number(f64),
189    Int(i64),
190    Bool(bool),
191    Array(Vec<JsonValue>),
192    Object(Vec<(String, JsonValue)>),
193    Null,
194}
195
196impl JsonValue {
197    /// Format as JSON string
198    pub fn to_json(&self) -> String {
199        match self {
200            JsonValue::String(s) => format!("\"{}\"", json_escape(s)),
201            JsonValue::Number(n) => {
202                if n.is_finite() {
203                    format!("{}", n)
204                } else {
205                    "null".to_string()
206                }
207            }
208            JsonValue::Int(n) => format!("{}", n),
209            JsonValue::Bool(b) => if *b { "true" } else { "false" }.to_string(),
210            JsonValue::Array(arr) => {
211                let items: Vec<String> = arr.iter().map(|v| v.to_json()).collect();
212                format!("[{}]", items.join(","))
213            }
214            JsonValue::Object(fields) => {
215                let items: Vec<String> = fields
216                    .iter()
217                    .map(|(k, v)| format!("\"{}\":{}", json_escape(k), v.to_json()))
218                    .collect();
219                format!("{{{}}}", items.join(","))
220            }
221            JsonValue::Null => "null".to_string(),
222        }
223    }
224}
225
226impl DebugEvent {
227    /// Create a new debug event
228    pub fn new(category: Category, event: &'static str, tag: &'static str) -> Self {
229        Self { category, event, tag, text_parts: Vec::new(), json_fields: Vec::new() }
230    }
231
232    /// Add a text message (for human-readable output)
233    pub fn text(mut self, message: impl Into<String>) -> Self {
234        self.text_parts.push(message.into());
235        self
236    }
237
238    /// Add a JSON field (for machine-readable output)
239    pub fn field(mut self, name: impl Into<String>, value: JsonValue) -> Self {
240        self.json_fields.push((name.into(), value));
241        self
242    }
243
244    /// Add a string field
245    pub fn field_str(self, name: impl Into<String>, value: impl Into<String>) -> Self {
246        self.field(name, JsonValue::String(value.into()))
247    }
248
249    /// Add an integer field
250    pub fn field_int(self, name: impl Into<String>, value: i64) -> Self {
251        self.field(name, JsonValue::Int(value))
252    }
253
254    /// Add a float field
255    pub fn field_float(self, name: impl Into<String>, value: f64) -> Self {
256        self.field(name, JsonValue::Number(value))
257    }
258
259    /// Add a boolean field
260    pub fn field_bool(self, name: impl Into<String>, value: bool) -> Self {
261        self.field(name, JsonValue::Bool(value))
262    }
263
264    /// Add duration in microseconds
265    pub fn field_duration_us(self, name: impl Into<String>, duration: std::time::Duration) -> Self {
266        self.field(name, JsonValue::Int(duration.as_micros() as i64))
267    }
268
269    /// Add duration in milliseconds (as float)
270    pub fn field_duration_ms(self, name: impl Into<String>, duration: std::time::Duration) -> Self {
271        self.field(name, JsonValue::Number(duration.as_secs_f64() * 1000.0))
272    }
273
274    /// Add a string array field
275    pub fn field_str_array(self, name: impl Into<String>, values: &[String]) -> Self {
276        let arr: Vec<JsonValue> = values.iter().map(|s| JsonValue::String(s.clone())).collect();
277        self.field(name, JsonValue::Array(arr))
278    }
279
280    /// Emit the debug event to stderr
281    pub fn emit(self) {
282        match get_format() {
283            DebugFormat::Text => {
284                // Traditional text output: [TAG] messages
285                let message = self.text_parts.join(" ");
286                eprintln!("[{}] {}", self.tag, message);
287            }
288            DebugFormat::Json => {
289                // JSON output
290                let timestamp = iso_timestamp();
291                let mut fields = vec![
292                    ("timestamp".to_string(), JsonValue::String(timestamp)),
293                    ("category".to_string(), JsonValue::String(self.category.as_str().to_string())),
294                    ("event".to_string(), JsonValue::String(self.event.to_string())),
295                ];
296
297                // Add data object with all custom fields
298                if !self.json_fields.is_empty() {
299                    fields.push(("data".to_string(), JsonValue::Object(self.json_fields)));
300                }
301
302                let json = JsonValue::Object(fields).to_json();
303                eprintln!("{}", json);
304            }
305        }
306    }
307}
308
309/// Convenience function to create a debug event
310pub fn debug_event(category: Category, event: &'static str, tag: &'static str) -> DebugEvent {
311    DebugEvent::new(category, event, tag)
312}
313
314/// Macro for creating debug events with both text and JSON output
315///
316/// # Example
317///
318/// ```text
319/// debug_emit!(
320///     optimizer, "join_reorder", "JOIN_REORDER",
321///     text: "Optimal order: {:?}", optimal_order,
322///     fields: {
323///         "original_order" => json_str_array(&original_order),
324///         "optimal_order" => json_str_array(&optimal_order),
325///         "optimizer_time_us" => JsonValue::Int(time.as_micros() as i64)
326///     }
327/// );
328/// ```
329#[macro_export]
330macro_rules! debug_emit {
331    (
332        $category:ident, $event:expr, $tag:expr,
333        text: $($text_fmt:expr),* $(,)?
334        $(, fields: { $($field_name:expr => $field_value:expr),* $(,)? })?
335    ) => {{
336        let mut event = $crate::debug_output::debug_event(
337            $crate::debug_output::Category::$category,
338            $event,
339            $tag
340        );
341        event = event.text(format!($($text_fmt),*));
342        $($(
343            event = event.field($field_name, $field_value);
344        )*)?
345        event.emit();
346    }};
347}
348
349// Re-export for use in macros
350pub use crate::debug_emit;
351
352#[cfg(test)]
353mod tests {
354    use super::*;
355
356    #[test]
357    fn test_json_escape() {
358        assert_eq!(json_escape("hello"), "hello");
359        assert_eq!(json_escape("hello\"world"), "hello\\\"world");
360        assert_eq!(json_escape("line\nbreak"), "line\\nbreak");
361        assert_eq!(json_escape("tab\there"), "tab\\there");
362    }
363
364    #[test]
365    fn test_json_value_formatting() {
366        assert_eq!(JsonValue::String("test".to_string()).to_json(), "\"test\"");
367        assert_eq!(JsonValue::Int(42).to_json(), "42");
368        assert_eq!(JsonValue::Number(3.5).to_json(), "3.5");
369        assert_eq!(JsonValue::Bool(true).to_json(), "true");
370        assert_eq!(JsonValue::Null.to_json(), "null");
371
372        let arr = JsonValue::Array(vec![JsonValue::Int(1), JsonValue::Int(2)]);
373        assert_eq!(arr.to_json(), "[1,2]");
374
375        let obj = JsonValue::Object(vec![
376            ("name".to_string(), JsonValue::String("test".to_string())),
377            ("value".to_string(), JsonValue::Int(42)),
378        ]);
379        assert_eq!(obj.to_json(), "{\"name\":\"test\",\"value\":42}");
380    }
381
382    #[test]
383    fn test_debug_event_builder() {
384        // Just test that the builder compiles and doesn't panic
385        let event = DebugEvent::new(Category::Optimizer, "test_event", "TEST")
386            .text("Test message")
387            .field_str("key", "value")
388            .field_int("count", 42)
389            .field_float("ratio", 0.5)
390            .field_bool("enabled", true);
391
392        // Don't emit in tests to avoid polluting output
393        drop(event);
394    }
395
396    #[test]
397    fn test_iso_timestamp_format() {
398        let ts = iso_timestamp();
399        // Should match pattern: YYYY-MM-DDTHH:MM:SS.mmmZ
400        assert!(ts.len() == 24, "Timestamp should be 24 chars: {}", ts);
401        assert!(ts.ends_with('Z'), "Timestamp should end with Z: {}", ts);
402        assert!(ts.contains('T'), "Timestamp should contain T: {}", ts);
403    }
404}
vibesql_executor/debug_output.rs

vibesql_executor/
debug_output.rs
