ant_quic/logging/
mod.rs

1// Copyright 2024 Saorsa Labs Ltd.
2//
3// This Saorsa Network Software is licensed under the General Public License (GPL), version 3.
4// Please see the file LICENSE-GPL, or visit <http://www.gnu.org/licenses/> for the full text.
5//
6// Full details available at https://saorsalabs.com/licenses
7
8/// Comprehensive Logging System for ant-quic
9///
10/// This module provides structured logging capabilities for debugging,
11/// monitoring, and analyzing QUIC connections, NAT traversal, and
12/// protocol-level events.
13use std::collections::HashMap;
14use std::net::SocketAddr;
15use std::sync::atomic::{AtomicU64, Ordering};
16use std::sync::{Arc, Mutex};
17
18use tracing::{Level, Span, debug, error, info, trace, warn};
19use tracing_subscriber::{EnvFilter, layer::SubscriberExt, util::SubscriberInitExt};
20
21use crate::{
22    // v0.13.0: NatTraversalRole removed - all nodes are symmetric P2P nodes
23    ConnectionId,
24    Duration,
25    Instant,
26    Side,
27    frame::FrameType,
28    transport_parameters::TransportParameterId,
29};
30
31#[cfg(test)]
32mod tests;
33
34mod components;
35mod filters;
36mod formatters;
37mod lifecycle;
38/// Metrics collection and reporting utilities
39pub mod metrics;
40mod structured;
41
42pub use components::*;
43pub use filters::*;
44pub use formatters::*;
45pub use lifecycle::*;
46pub use metrics::*;
47pub use structured::*;
48
49/// Global logger instance
50static LOGGER: once_cell::sync::OnceCell<Arc<Logger>> = once_cell::sync::OnceCell::new();
51
52/// Initialize the logging system
53#[allow(clippy::expect_used)]
54pub fn init_logging(config: LoggingConfig) -> Result<(), LoggingError> {
55    let logger = Arc::new(Logger::new(config)?);
56
57    LOGGER
58        .set(logger.clone())
59        .map_err(|_| LoggingError::AlreadyInitialized)?;
60
61    // Initialize tracing subscriber
62    let env_filter = EnvFilter::from_default_env().add_directive(
63        "ant_quic=debug"
64            .parse()
65            .expect("Static directive should always parse"),
66    );
67
68    if logger.use_json() {
69        let fmt_layer = tracing_subscriber::fmt::layer()
70            .json()
71            .with_target(true)
72            .with_thread_ids(true)
73            .with_level(true);
74
75        tracing_subscriber::registry()
76            .with(env_filter)
77            .with(fmt_layer)
78            .init();
79    } else {
80        let fmt_layer = tracing_subscriber::fmt::layer()
81            .with_target(true)
82            .with_thread_ids(true)
83            .with_level(true);
84
85        tracing_subscriber::registry()
86            .with(env_filter)
87            .with(fmt_layer)
88            .init();
89    }
90
91    info!("ant-quic logging system initialized");
92    Ok(())
93}
94
95/// Get the global logger instance
96#[allow(clippy::expect_used)]
97pub fn logger() -> Arc<Logger> {
98    LOGGER.get().cloned().unwrap_or_else(|| {
99        // Create default logger if not initialized
100        let config = LoggingConfig::default();
101        let logger = Arc::new(Logger::new(config).expect("Failed to create default logger"));
102        let _ = LOGGER.set(logger.clone());
103        logger
104    })
105}
106
107/// Main logger struct
108pub struct Logger {
109    config: LoggingConfig,
110    metrics_collector: Arc<MetricsCollector>,
111    event_buffer: Arc<Mutex<Vec<LogEvent>>>,
112    rate_limiter: Arc<RateLimiter>,
113}
114
115impl Logger {
116    /// Create a new logger with the given configuration
117    pub fn new(config: LoggingConfig) -> Result<Self, LoggingError> {
118        let rate_limit = config.rate_limit_per_second;
119        let buffer_size = config.event_buffer_size;
120        Ok(Self {
121            config,
122            metrics_collector: Arc::new(MetricsCollector::new()),
123            event_buffer: Arc::new(Mutex::new(Vec::with_capacity(buffer_size))),
124            rate_limiter: Arc::new(RateLimiter::new(rate_limit, Duration::from_secs(1))),
125        })
126    }
127
128    /// Check if JSON output is enabled
129    fn use_json(&self) -> bool {
130        self.config.json_output
131    }
132
133    /// Log a structured event
134    pub fn log_event(&self, event: LogEvent) {
135        if !self.rate_limiter.should_log(event.level) {
136            return;
137        }
138
139        // Add to buffer for analysis
140        if let Ok(mut buffer) = self.event_buffer.lock() {
141            if buffer.len() < 10000 {
142                buffer.push(event.clone());
143            }
144        }
145
146        // Log using tracing
147        match event.level {
148            Level::ERROR => error!("{} - {}", event.target, event.message),
149            Level::WARN => warn!("{} - {}", event.target, event.message),
150            Level::INFO => info!("{} - {}", event.target, event.message),
151            Level::DEBUG => debug!("{} - {}", event.target, event.message),
152            Level::TRACE => trace!("{} - {}", event.target, event.message),
153        }
154
155        // Update metrics
156        self.metrics_collector.record_event(&event);
157    }
158
159    /// Get recent events for analysis
160    pub fn recent_events(&self, count: usize) -> Vec<LogEvent> {
161        match self.event_buffer.lock() {
162            Ok(buffer) => buffer.iter().rev().take(count).cloned().collect(),
163            _ => Vec::new(),
164        }
165    }
166
167    /// Get metrics summary
168    pub fn metrics_summary(&self) -> MetricsSummary {
169        self.metrics_collector.summary()
170    }
171}
172
173/// Logging configuration
174#[derive(Debug, Clone)]
175pub struct LoggingConfig {
176    /// Enable JSON output format
177    pub json_output: bool,
178    /// Rate limit per second
179    pub rate_limit_per_second: u64,
180    /// Component-specific log levels
181    pub component_levels: HashMap<String, Level>,
182    /// Enable performance metrics collection
183    pub collect_metrics: bool,
184    /// Buffer size for event storage
185    pub event_buffer_size: usize,
186}
187
188impl Default for LoggingConfig {
189    fn default() -> Self {
190        Self {
191            json_output: false,
192            rate_limit_per_second: 1000,
193            component_levels: HashMap::new(),
194            collect_metrics: true,
195            event_buffer_size: 10000,
196        }
197    }
198}
199
200/// Structured log event
201#[derive(Debug, Clone)]
202pub struct LogEvent {
203    /// Time the log was recorded
204    pub timestamp: Instant,
205    /// Severity level of the log
206    pub level: Level,
207    /// Target component/module of the log
208    pub target: String,
209    /// Primary message content
210    pub message: String,
211    /// Arbitrary structured fields
212    pub fields: HashMap<String, String>,
213    /// Optional span identifier for tracing correlation
214    pub span_id: Option<String>,
215}
216
217/// Connection role for logging
218#[derive(Debug, Clone, Copy)]
219pub enum ConnectionRole {
220    /// Client-side role
221    Client,
222    /// Server-side role
223    Server,
224}
225
226/// Connection information for logging
227#[derive(Debug, Clone)]
228pub struct ConnectionInfo {
229    /// Connection identifier
230    pub id: ConnectionId,
231    /// Remote socket address
232    pub remote_addr: SocketAddr,
233    /// Role of the connection
234    pub role: ConnectionRole,
235}
236
237/// Frame information for logging
238#[derive(Debug)]
239pub struct FrameInfo {
240    /// QUIC frame type
241    pub frame_type: FrameType,
242    /// Encoded frame size in bytes
243    pub size: usize,
244    /// Optional packet number the frame was carried in
245    pub packet_number: Option<u64>,
246}
247
248/// Transport parameter information
249#[derive(Debug)]
250pub struct TransportParamInfo {
251    pub(crate) param_id: TransportParameterId,
252    /// Raw value bytes, if present
253    pub value: Option<Vec<u8>>,
254    /// Which side (client/server) provided the parameter
255    pub side: Side,
256}
257
258/// NAT traversal information
259///
260/// v0.13.0: role field removed - all nodes are symmetric P2P nodes.
261#[derive(Debug)]
262pub struct NatTraversalInfo {
263    // v0.13.0: role field removed - all nodes are symmetric P2P nodes
264    /// Remote peer address involved in NAT traversal
265    pub remote_addr: SocketAddr,
266    /// Number of candidate addresses considered
267    pub candidate_count: usize,
268}
269
270/// Error context for detailed logging
271#[derive(Debug, Default)]
272pub struct ErrorContext {
273    /// Component name related to the error
274    pub component: &'static str,
275    /// Operation being performed when the error occurred
276    pub operation: &'static str,
277    /// Optional connection identifier involved
278    pub connection_id: Option<ConnectionId>,
279    /// Additional static key/value fields for context
280    pub additional_fields: Vec<(&'static str, &'static str)>,
281}
282
283/// Warning context
284#[derive(Debug, Default)]
285pub struct WarningContext {
286    /// Component name related to the warning
287    pub component: &'static str,
288    /// Additional static key/value fields for context
289    pub details: Vec<(&'static str, &'static str)>,
290}
291
292/// Info context
293#[derive(Debug, Default)]
294pub struct InfoContext {
295    /// Component name related to the information
296    pub component: &'static str,
297    /// Additional static key/value fields for context
298    pub details: Vec<(&'static str, &'static str)>,
299}
300
301/// Debug context
302#[derive(Debug, Default)]
303pub struct DebugContext {
304    /// Component name related to the debug message
305    pub component: &'static str,
306    /// Additional static key/value fields for context
307    pub details: Vec<(&'static str, &'static str)>,
308}
309
310/// Trace context
311#[derive(Debug, Default)]
312pub struct TraceContext {
313    /// Component name related to the trace message
314    pub component: &'static str,
315    /// Additional static key/value fields for context
316    pub details: Vec<(&'static str, &'static str)>,
317}
318
319/// Logging errors
320#[derive(Debug, thiserror::Error)]
321pub enum LoggingError {
322    /// Attempted to initialize the logging system more than once
323    #[error("Logging system already initialized")]
324    AlreadyInitialized,
325    /// Error returned from tracing subscriber initialization
326    #[error("Failed to initialize tracing subscriber: {0}")]
327    SubscriberError(String),
328}
329
330/// Rate limiter for preventing log spam
331pub struct RateLimiter {
332    /// Maximum events allowed per window
333    max_events: u64,
334    /// Length of the rate-limiting window
335    window: Duration,
336    /// Number of events counted in the current window
337    events_in_window: AtomicU64,
338    /// Start time of the current window
339    window_start: Mutex<Instant>,
340}
341
342impl RateLimiter {
343    /// Create a new rate limiter
344    pub fn new(max_events: u64, window: Duration) -> Self {
345        Self {
346            max_events,
347            window,
348            events_in_window: AtomicU64::new(0),
349            window_start: Mutex::new(Instant::now()),
350        }
351    }
352
353    /// Determine whether an event at the given level should be logged
354    #[allow(clippy::unwrap_used, clippy::expect_used)]
355    pub fn should_log(&self, level: Level) -> bool {
356        // Always allow ERROR level
357        if level == Level::ERROR {
358            return true;
359        }
360
361        let now = Instant::now();
362        let mut window_start = self
363            .window_start
364            .lock()
365            .expect("Mutex poisoning is unexpected in normal operation");
366
367        // Reset window if expired
368        if now.duration_since(*window_start) > self.window {
369            *window_start = now;
370            self.events_in_window.store(0, Ordering::Relaxed);
371        }
372
373        // Check rate limit
374        let current = self.events_in_window.fetch_add(1, Ordering::Relaxed);
375        current < self.max_events
376    }
377}
378
379// Convenience logging functions
380
381/// Log an error with context
382pub fn log_error(message: &str, context: ErrorContext) {
383    let mut fields = HashMap::new();
384    fields.insert("component".to_string(), context.component.to_string());
385    fields.insert("operation".to_string(), context.operation.to_string());
386
387    if let Some(conn_id) = context.connection_id {
388        fields.insert("conn_id".to_string(), format!("{conn_id:?}"));
389    }
390
391    for (key, value) in context.additional_fields {
392        fields.insert(key.to_string(), value.to_string());
393    }
394
395    logger().log_event(LogEvent {
396        timestamp: Instant::now(),
397        level: Level::ERROR,
398        target: format!("ant_quic::{}", context.component),
399        message: message.to_string(),
400        fields,
401        span_id: None,
402    });
403}
404
405/// Log a warning
406pub fn log_warning(message: &str, context: WarningContext) {
407    let mut fields = HashMap::new();
408    fields.insert("component".to_string(), context.component.to_string());
409
410    for (key, value) in context.details {
411        fields.insert(key.to_string(), value.to_string());
412    }
413
414    logger().log_event(LogEvent {
415        timestamp: Instant::now(),
416        level: Level::WARN,
417        target: format!("ant_quic::{}", context.component),
418        message: message.to_string(),
419        fields,
420        span_id: None,
421    });
422}
423
424/// Log info message
425pub fn log_info(message: &str, context: InfoContext) {
426    let mut fields = HashMap::new();
427    fields.insert("component".to_string(), context.component.to_string());
428
429    for (key, value) in context.details {
430        fields.insert(key.to_string(), value.to_string());
431    }
432
433    logger().log_event(LogEvent {
434        timestamp: Instant::now(),
435        level: Level::INFO,
436        target: format!("ant_quic::{}", context.component),
437        message: message.to_string(),
438        fields,
439        span_id: None,
440    });
441}
442
443/// Log debug message
444pub fn log_debug(message: &str, context: DebugContext) {
445    let mut fields = HashMap::new();
446    fields.insert("component".to_string(), context.component.to_string());
447
448    for (key, value) in context.details {
449        fields.insert(key.to_string(), value.to_string());
450    }
451
452    logger().log_event(LogEvent {
453        timestamp: Instant::now(),
454        level: Level::DEBUG,
455        target: format!("ant_quic::{}", context.component),
456        message: message.to_string(),
457        fields,
458        span_id: None,
459    });
460}
461
462/// Log trace message
463pub fn log_trace(message: &str, context: TraceContext) {
464    let mut fields = HashMap::new();
465    fields.insert("component".to_string(), context.component.to_string());
466
467    for (key, value) in context.details {
468        fields.insert(key.to_string(), value.to_string());
469    }
470
471    logger().log_event(LogEvent {
472        timestamp: Instant::now(),
473        level: Level::TRACE,
474        target: format!("ant_quic::{}", context.component),
475        message: message.to_string(),
476        fields,
477        span_id: None,
478    });
479}
480
481/// Create a span for connection operations
482pub fn create_connection_span(conn_id: &ConnectionId) -> Span {
483    tracing::span!(
484        Level::DEBUG,
485        "connection",
486        conn_id = %format!("{:?}", conn_id),
487    )
488}
489
490/// Create a span for frame processing
491pub fn create_frame_span(frame_type: FrameType) -> Span {
492    tracing::span!(
493        Level::TRACE,
494        "frame",
495        frame_type = ?frame_type,
496    )
497}
ant_quic/logging/mod.rs

ant_quic/logging/
mod.rs
