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