asupersync_conformance/
logging.rs

1//! Logging infrastructure for conformance tests.
2//!
3//! Provides structured logging for test execution, with support for
4//! capturing logs during test runs and reporting them in results.
5
6use serde::{Deserialize, Serialize};
7use std::cell::RefCell;
8use std::sync::{Arc, Mutex};
9use std::time::Instant;
10
11/// Log level for conformance test logging.
12#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Serialize, Deserialize)]
13pub enum LogLevel {
14    /// Detailed tracing information.
15    Trace,
16    /// Debug information.
17    Debug,
18    /// Informational messages.
19    Info,
20    /// Warning messages.
21    Warn,
22    /// Error messages.
23    Error,
24}
25
26impl std::fmt::Display for LogLevel {
27    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
28        match self {
29            LogLevel::Trace => write!(f, "TRACE"),
30            LogLevel::Debug => write!(f, "DEBUG"),
31            LogLevel::Info => write!(f, "INFO"),
32            LogLevel::Warn => write!(f, "WARN"),
33            LogLevel::Error => write!(f, "ERROR"),
34        }
35    }
36}
37
38/// A log entry captured during test execution.
39#[derive(Debug, Clone, Serialize, Deserialize)]
40pub struct LogEntry {
41    /// Log level.
42    pub level: LogLevel,
43    /// Message text.
44    pub message: String,
45    /// Target (module/component).
46    pub target: String,
47    /// Timestamp (milliseconds from test start).
48    pub timestamp_ms: u64,
49    /// Optional structured fields.
50    pub fields: std::collections::HashMap<String, serde_json::Value>,
51}
52
53impl LogEntry {
54    /// Create a new log entry.
55    pub fn new(level: LogLevel, message: impl Into<String>) -> Self {
56        Self {
57            level,
58            message: message.into(),
59            target: String::new(),
60            timestamp_ms: 0,
61            fields: std::collections::HashMap::new(),
62        }
63    }
64
65    /// Set the target.
66    pub fn with_target(mut self, target: impl Into<String>) -> Self {
67        self.target = target.into();
68        self
69    }
70
71    /// Set the timestamp.
72    pub fn with_timestamp_ms(mut self, timestamp_ms: u64) -> Self {
73        self.timestamp_ms = timestamp_ms;
74        self
75    }
76
77    /// Add a field.
78    pub fn with_field(mut self, key: impl Into<String>, value: serde_json::Value) -> Self {
79        self.fields.insert(key.into(), value);
80        self
81    }
82}
83
84/// Collector for capturing log entries during test execution.
85///
86/// Thread-safe and can be cloned to share across async boundaries.
87#[derive(Clone)]
88pub struct LogCollector {
89    entries: Arc<Mutex<Vec<LogEntry>>>,
90    start_time: Arc<Mutex<Option<Instant>>>,
91    min_level: LogLevel,
92}
93
94impl LogCollector {
95    /// Create a new log collector.
96    pub fn new(min_level: LogLevel) -> Self {
97        Self {
98            entries: Arc::new(Mutex::new(Vec::new())),
99            start_time: Arc::new(Mutex::new(None)),
100            min_level,
101        }
102    }
103
104    /// Start collecting (resets the timer).
105    pub fn start(&self) {
106        {
107            let mut start = self.start_time.lock().unwrap();
108            *start = Some(Instant::now());
109        }
110        self.entries.lock().unwrap().clear();
111    }
112
113    /// Log an entry if it meets the minimum level.
114    pub fn log(&self, level: LogLevel, message: impl Into<String>) {
115        if level < self.min_level {
116            return;
117        }
118
119        let timestamp_ms = self
120            .start_time
121            .lock()
122            .unwrap()
123            .map(|start| start.elapsed().as_millis().min(u128::from(u64::MAX)) as u64)
124            .unwrap_or(0);
125
126        let entry = LogEntry::new(level, message).with_timestamp_ms(timestamp_ms);
127
128        self.entries.lock().unwrap().push(entry);
129    }
130
131    /// Log with target.
132    pub fn log_with_target(&self, level: LogLevel, target: &str, message: impl Into<String>) {
133        if level < self.min_level {
134            return;
135        }
136
137        let timestamp_ms = self
138            .start_time
139            .lock()
140            .unwrap()
141            .map(|start| start.elapsed().as_millis().min(u128::from(u64::MAX)) as u64)
142            .unwrap_or(0);
143
144        let entry = LogEntry::new(level, message)
145            .with_target(target)
146            .with_timestamp_ms(timestamp_ms);
147
148        self.entries.lock().unwrap().push(entry);
149    }
150
151    /// Drain all collected entries.
152    pub fn drain(&self) -> Vec<LogEntry> {
153        std::mem::take(&mut *self.entries.lock().unwrap())
154    }
155
156    /// Get the number of collected entries.
157    pub fn len(&self) -> usize {
158        self.entries.lock().unwrap().len()
159    }
160
161    /// Check if empty.
162    pub fn is_empty(&self) -> bool {
163        self.entries.lock().unwrap().is_empty()
164    }
165
166    /// Trace-level log.
167    pub fn trace(&self, message: impl Into<String>) {
168        self.log(LogLevel::Trace, message);
169    }
170
171    /// Debug-level log.
172    pub fn debug(&self, message: impl Into<String>) {
173        self.log(LogLevel::Debug, message);
174    }
175
176    /// Info-level log.
177    pub fn info(&self, message: impl Into<String>) {
178        self.log(LogLevel::Info, message);
179    }
180
181    /// Warn-level log.
182    pub fn warn(&self, message: impl Into<String>) {
183        self.log(LogLevel::Warn, message);
184    }
185
186    /// Error-level log.
187    pub fn error(&self, message: impl Into<String>) {
188        self.log(LogLevel::Error, message);
189    }
190}
191
192impl Default for LogCollector {
193    fn default() -> Self {
194        Self::new(LogLevel::Info)
195    }
196}
197
198impl std::fmt::Debug for LogCollector {
199    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
200        f.debug_struct("LogCollector")
201            .field("entries_count", &self.len())
202            .field("min_level", &self.min_level)
203            .finish()
204    }
205}
206
207// ============================================================================
208// Conformance Test Logger
209// ============================================================================
210
211/// Event types recorded during a conformance test.
212#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
213pub enum TestEventKind {
214    /// A named phase transition in the test.
215    Phase,
216    /// An assertion evaluated during the test.
217    Assertion,
218    /// Runtime-level event details captured during the test.
219    RuntimeEvent,
220    /// A warning emitted by the test.
221    Warning,
222    /// A checkpoint marker with structured data.
223    Checkpoint,
224}
225
226/// Structured event recorded during a conformance test run.
227#[derive(Debug, Clone, Serialize, Deserialize)]
228pub struct TestEvent {
229    /// Event kind.
230    pub kind: TestEventKind,
231    /// Event name or description.
232    pub name: String,
233    /// Timestamp in milliseconds since test start.
234    pub timestamp_ms: u64,
235    /// Structured details for the event.
236    pub details: serde_json::Value,
237}
238
239impl TestEvent {
240    /// Create a new test event.
241    pub fn new(
242        kind: TestEventKind,
243        name: impl Into<String>,
244        timestamp_ms: u64,
245        details: serde_json::Value,
246    ) -> Self {
247        Self {
248            kind,
249            name: name.into(),
250            timestamp_ms,
251            details,
252        }
253    }
254}
255
256#[derive(Debug)]
257struct ConformanceTestLogState {
258    test_name: String,
259    spec_section: String,
260    start_time: Instant,
261    events: Vec<TestEvent>,
262}
263
264/// Structured logger for conformance test execution.
265#[derive(Clone)]
266pub struct ConformanceTestLogger {
267    inner: Arc<Mutex<ConformanceTestLogState>>,
268}
269
270impl ConformanceTestLogger {
271    /// Create a new logger for a conformance test.
272    pub fn new(test_name: impl Into<String>, spec_section: impl Into<String>) -> Self {
273        Self {
274            inner: Arc::new(Mutex::new(ConformanceTestLogState {
275                test_name: test_name.into(),
276                spec_section: spec_section.into(),
277                start_time: Instant::now(),
278                events: Vec::new(),
279            })),
280        }
281    }
282
283    /// Record a phase transition.
284    pub fn phase(&self, name: &'static str) {
285        self.record(TestEventKind::Phase, name, serde_json::Value::Null);
286    }
287
288    /// Record an assertion and panic if it fails.
289    #[track_caller]
290    pub fn assert_with_context(&self, condition: bool, description: &str) {
291        let location = std::panic::Location::caller().to_string();
292        let details = serde_json::json!({
293            "passed": condition,
294            "location": location,
295        });
296        self.record(TestEventKind::Assertion, description, details);
297        assert!(condition, "Conformance assertion failed: {}", description);
298    }
299
300    /// Record a runtime event with structured details.
301    pub fn runtime_event(&self, description: &str, details: serde_json::Value) {
302        self.record(TestEventKind::RuntimeEvent, description, details);
303    }
304
305    /// Record a warning event.
306    pub fn warning(&self, message: &str) {
307        self.record(TestEventKind::Warning, message, serde_json::Value::Null);
308    }
309
310    /// Record a checkpoint.
311    pub fn checkpoint(&self, name: &str, data: serde_json::Value) {
312        self.record(TestEventKind::Checkpoint, name, data);
313    }
314
315    /// Return a snapshot of recorded events.
316    pub fn events(&self) -> Vec<TestEvent> {
317        self.inner
318            .lock()
319            .expect("conformance log lock poisoned")
320            .events
321            .clone()
322    }
323
324    /// Get the test name.
325    pub fn test_name(&self) -> String {
326        self.inner
327            .lock()
328            .expect("conformance log lock poisoned")
329            .test_name
330            .clone()
331    }
332
333    /// Get the spec section label.
334    pub fn spec_section(&self) -> String {
335        self.inner
336            .lock()
337            .expect("conformance log lock poisoned")
338            .spec_section
339            .clone()
340    }
341
342    fn record(&self, kind: TestEventKind, name: &str, details: serde_json::Value) {
343        let mut guard = self.inner.lock().expect("conformance log lock poisoned");
344        let timestamp_ms = guard
345            .start_time
346            .elapsed()
347            .as_millis()
348            .min(u128::from(u64::MAX)) as u64;
349        guard
350            .events
351            .push(TestEvent::new(kind, name, timestamp_ms, details));
352    }
353}
354
355thread_local! {
356    static CURRENT_TEST_LOGGER: RefCell<Option<ConformanceTestLogger>> =
357        const { RefCell::new(None) };
358}
359
360/// Execute a closure with a logger installed for checkpoint capture.
361pub fn with_test_logger<T>(logger: &ConformanceTestLogger, f: impl FnOnce() -> T) -> T {
362    struct Guard {
363        prev: Option<ConformanceTestLogger>,
364    }
365
366    impl Drop for Guard {
367        fn drop(&mut self) {
368            let prev = self.prev.take();
369            CURRENT_TEST_LOGGER.with(|slot| {
370                *slot.borrow_mut() = prev;
371            });
372        }
373    }
374
375    let prev = CURRENT_TEST_LOGGER.with(|slot| slot.replace(Some(logger.clone())));
376    let _guard = Guard { prev };
377    f()
378}
379
380/// Record a checkpoint into the current test logger, if one is installed.
381pub fn record_checkpoint(name: &str, data: serde_json::Value) {
382    CURRENT_TEST_LOGGER.with(|slot| {
383        if let Some(logger) = slot.borrow().as_ref() {
384            logger.checkpoint(name, data);
385        }
386    });
387}
388
389/// Configuration for logging output.
390#[derive(Debug, Clone)]
391pub struct LogConfig {
392    /// Minimum log level to display.
393    pub min_level: LogLevel,
394    /// Whether to include timestamps.
395    pub show_timestamps: bool,
396    /// Whether to include targets.
397    pub show_targets: bool,
398    /// Whether to use colors (for terminal output).
399    pub use_colors: bool,
400}
401
402impl Default for LogConfig {
403    fn default() -> Self {
404        Self {
405            min_level: LogLevel::Info,
406            show_timestamps: true,
407            show_targets: true,
408            use_colors: false,
409        }
410    }
411}
412
413impl LogConfig {
414    /// Create a new configuration with default settings.
415    pub fn new() -> Self {
416        Self::default()
417    }
418
419    /// Set minimum log level.
420    pub fn with_min_level(mut self, level: LogLevel) -> Self {
421        self.min_level = level;
422        self
423    }
424
425    /// Set whether to show timestamps.
426    pub fn with_timestamps(mut self, show: bool) -> Self {
427        self.show_timestamps = show;
428        self
429    }
430
431    /// Set whether to show targets.
432    pub fn with_targets(mut self, show: bool) -> Self {
433        self.show_targets = show;
434        self
435    }
436
437    /// Set whether to use colors.
438    pub fn with_colors(mut self, use_colors: bool) -> Self {
439        self.use_colors = use_colors;
440        self
441    }
442}
443
444/// Format a log entry as a string.
445pub fn format_entry(entry: &LogEntry, config: &LogConfig) -> String {
446    let mut parts = Vec::new();
447
448    if config.show_timestamps {
449        parts.push(format!("[{:>8}ms]", entry.timestamp_ms));
450    }
451
452    parts.push(format!("{:5}", entry.level));
453
454    if config.show_targets && !entry.target.is_empty() {
455        parts.push(format!("[{}]", entry.target));
456    }
457
458    parts.push(entry.message.clone());
459
460    if !entry.fields.is_empty() {
461        let fields: Vec<String> = entry
462            .fields
463            .iter()
464            .map(|(k, v)| format!("{}={}", k, v))
465            .collect();
466        parts.push(format!("{{{}}}", fields.join(", ")));
467    }
468
469    parts.join(" ")
470}
471
472/// Print log entries to stdout.
473pub fn print_logs(entries: &[LogEntry], config: &LogConfig) {
474    for entry in entries {
475        if entry.level >= config.min_level {
476            println!("{}", format_entry(entry, config));
477        }
478    }
479}
480
481#[cfg(test)]
482mod tests {
483    use super::*;
484
485    #[test]
486    fn log_level_ordering() {
487        assert!(LogLevel::Trace < LogLevel::Debug);
488        assert!(LogLevel::Debug < LogLevel::Info);
489        assert!(LogLevel::Info < LogLevel::Warn);
490        assert!(LogLevel::Warn < LogLevel::Error);
491    }
492
493    #[test]
494    fn log_collector_basic() {
495        let collector = LogCollector::new(LogLevel::Debug);
496        collector.start();
497
498        collector.trace("trace message"); // Should be filtered
499        collector.debug("debug message");
500        collector.info("info message");
501
502        let entries = collector.drain();
503        assert_eq!(entries.len(), 2);
504        assert_eq!(entries[0].message, "debug message");
505        assert_eq!(entries[1].message, "info message");
506    }
507
508    #[test]
509    fn log_collector_with_target() {
510        let collector = LogCollector::new(LogLevel::Info);
511        collector.start();
512
513        collector.log_with_target(LogLevel::Info, "test::module", "test message");
514
515        let entries = collector.drain();
516        assert_eq!(entries.len(), 1);
517        assert_eq!(entries[0].target, "test::module");
518    }
519
520    #[test]
521    fn log_entry_builder() {
522        let entry = LogEntry::new(LogLevel::Info, "message")
523            .with_target("target")
524            .with_timestamp_ms(100)
525            .with_field("key", serde_json::json!("value"));
526
527        assert_eq!(entry.level, LogLevel::Info);
528        assert_eq!(entry.message, "message");
529        assert_eq!(entry.target, "target");
530        assert_eq!(entry.timestamp_ms, 100);
531        assert_eq!(entry.fields.get("key"), Some(&serde_json::json!("value")));
532    }
533
534    #[test]
535    fn format_entry_basic() {
536        let entry = LogEntry::new(LogLevel::Info, "test message").with_timestamp_ms(42);
537
538        let config = LogConfig::new().with_timestamps(true).with_targets(false);
539
540        let formatted = format_entry(&entry, &config);
541        assert!(formatted.contains("42ms"));
542        assert!(formatted.contains("INFO"));
543        assert!(formatted.contains("test message"));
544    }
545
546    #[test]
547    fn log_collector_drain_clears() {
548        let collector = LogCollector::new(LogLevel::Info);
549        collector.start();
550
551        collector.info("message 1");
552        let entries = collector.drain();
553        assert_eq!(entries.len(), 1);
554
555        collector.info("message 2");
556        let entries = collector.drain();
557        assert_eq!(entries.len(), 1);
558        assert_eq!(entries[0].message, "message 2");
559    }
560
561    #[test]
562    fn log_config_builder() {
563        let config = LogConfig::new()
564            .with_min_level(LogLevel::Debug)
565            .with_timestamps(false)
566            .with_targets(true)
567            .with_colors(true);
568
569        assert_eq!(config.min_level, LogLevel::Debug);
570        assert!(!config.show_timestamps);
571        assert!(config.show_targets);
572        assert!(config.use_colors);
573    }
574}
asupersync_conformance/logging.rs

asupersync_conformance/
logging.rs
