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

ant_quic/logging/
mod.rs
