wsforge_core/middleware/

logger.rs

//! Logger middleware for request/response logging.
//!
//! This module provides a built-in logging middleware that automatically logs
//! incoming WebSocket messages, responses, and processing times. It integrates
//! with the `tracing` crate for structured logging.
//!
//! # Overview
//!
//! The [`LoggerMiddleware`] records:
//! - Incoming message type and connection ID
//! - Processing duration
//! - Response status (sent/none/error)
//! - Detailed error information
//!
//! # Log Levels
//!
//! The logger supports three log levels:
//! - [`LogLevel::Debug`] - Most verbose, for development
//! - [`LogLevel::Info`] - Standard logging, for production
//! - [`LogLevel::Warn`] - Only warnings and errors
//!
//! # Examples
//!
//! ## Basic Usage
//!
//! ```
//! use wsforge::prelude::*;
//!
//! async fn echo(msg: Message) -> Result<Message> {
//!     Ok(msg)
//! }
//!
//! # async fn example() -> Result<()> {
//! let router = Router::new()
//!     .layer(LoggerMiddleware::new())
//!     .default_handler(handler(echo));
//!
//! router.listen("127.0.0.1:8080").await?;
//! # Ok(())
//! # }
//! ```
//!
//! ## With Custom Log Level
//!
//! ```
//! use wsforge::prelude::*;
//!
//! # fn example() {
//! // Debug level - very verbose
//! let debug_logger = LoggerMiddleware::with_level(LogLevel::Debug);
//!
//! // Info level - standard
//! let info_logger = LoggerMiddleware::with_level(LogLevel::Info);
//!
//! // Warn level - only warnings/errors
//! let warn_logger = LoggerMiddleware::with_level(LogLevel::Warn);
//! # }
//! ```
//!
//! ## In Production
//!
//! ```
//! use wsforge::prelude::*;
//! use tracing_subscriber;
//!
//! #[tokio::main]
//! async fn main() -> Result<()> {
//!     // Initialize tracing subscriber
//!     tracing_subscriber::fmt()
//!         .with_max_level(tracing::Level::INFO)
//!         .init();
//!
//!     let router = Router::new()
//!         .layer(LoggerMiddleware::new())
//!         .default_handler(handler(my_handler));
//!
//!     router.listen("0.0.0.0:8080").await?;
//!     Ok(())
//! }
//! # async fn my_handler() -> Result<String> { Ok("".to_string()) }
//! ```
//!
//! # Log Output Examples
//!
//! ## Successful Request
//! ```
//! 2025-10-16T10:30:45.123Z INFO Received message, conn_id="conn_42", msg_type=Text
//! 2025-10-16T10:30:45.125Z INFO Sent response in 2ms, conn_id="conn_42"
//! ```
//!
//! ## Error Case
//! ```
//! 2025-10-16T10:30:46.123Z INFO Received message, conn_id="conn_43", msg_type=Text
//! 2025-10-16T10:30:46.124Z ERROR Error in 1ms, conn_id="conn_43", error="Invalid JSON"
//! ```
//!
//! ## No Response
//! ```
//! 2025-10-16T10:30:47.123Z INFO Received message, conn_id="conn_44", msg_type=Binary
//! 2025-10-16T10:30:47.124Z INFO Processed in 1ms, conn_id="conn_44"
//! ```

use std::{sync::Arc, time::Instant};

use async_trait::async_trait;
use tracing::{debug, info};

use crate::{
    AppState, Connection, Extensions, Message, Result,
    middleware::{Middleware, Next},
};

/// Log level for the logger middleware.
///
/// Determines the verbosity of logging output. Higher levels produce less output.
///
/// # Examples
///
/// ```
/// use wsforge::prelude::*;
///
/// # fn example() {
/// // Debug - logs everything with maximum detail
/// let debug = LogLevel::Debug;
///
/// // Info - logs standard information
/// let info = LogLevel::Info;
///
/// // Warn - only logs warnings and errors
/// let warn = LogLevel::Warn;
/// # }
/// ```
#[derive(Debug, Clone, Copy)]
pub enum LogLevel {
    /// Debug level logging - most verbose.
    ///
    /// Logs all messages with detailed information including message content,
    /// processing times, and full error details.
    ///
    /// **Use for**: Development, debugging, troubleshooting
    Debug,

    /// Info level logging - standard verbosity.
    ///
    /// Logs message metadata, processing times, and success/failure status.
    /// This is the recommended level for production.
    ///
    /// **Use for**: Production, monitoring, standard operations
    Info,

    /// Warn level logging - minimal verbosity.
    ///
    /// Only logs warnings and errors. Normal message processing is not logged.
    ///
    /// **Use for**: Production with minimal logging overhead
    Warn,
}

/// Built-in logger middleware for logging WebSocket messages.
///
/// This middleware automatically logs incoming messages, responses, and errors
/// with timing information. It integrates with the `tracing` crate for
/// structured logging.
///
/// # Features
///
/// - **Automatic timing**: Measures and logs processing duration
/// - **Connection tracking**: Logs connection ID with each message
/// - **Message type detection**: Identifies Text/Binary/Ping/Pong/Close messages
/// - **Error logging**: Captures and logs handler errors
/// - **Configurable verbosity**: Three log levels (Debug/Info/Warn)
///
/// # Performance
///
/// The middleware has minimal overhead:
/// - ~1-2µs per message for timing
/// - Zero-copy message passing
/// - Efficient structured logging with `tracing`
///
/// # Examples
///
/// ## Default Configuration
///
/// ```
/// use wsforge::prelude::*;
///
/// # fn example() {
/// let logger = LoggerMiddleware::new();
/// // Uses LogLevel::Info by default
/// # }
/// ```
///
/// ## Custom Log Level
///
/// ```
/// use wsforge::prelude::*;
///
/// # fn example() {
/// // Very verbose logging
/// let debug_logger = LoggerMiddleware::with_level(LogLevel::Debug);
///
/// // Minimal logging
/// let warn_logger = LoggerMiddleware::with_level(LogLevel::Warn);
/// # }
/// ```
///
/// ## In Router
///
/// ```
/// use wsforge::prelude::*;
///
/// async fn handler(msg: Message) -> Result<String> {
///     Ok("processed".to_string())
/// }
///
/// # async fn example() -> Result<()> {
/// let router = Router::new()
///     .layer(LoggerMiddleware::new())
///     .default_handler(handler(handler));
///
/// router.listen("127.0.0.1:8080").await?;
/// # Ok(())
/// # }
/// ```
///
/// ## Multiple Middleware
///
/// ```
/// use wsforge::prelude::*;
///
/// # fn example() {
/// let router = Router::new()
///     .layer(LoggerMiddleware::new())      // First: log incoming
///     .layer(auth_middleware())             // Second: authenticate
///     .layer(rate_limit_middleware());      // Third: rate limit
/// # }
/// # fn auth_middleware() -> Arc<dyn Middleware> { unimplemented!() }
/// # fn rate_limit_middleware() -> Arc<dyn Middleware> { unimplemented!() }
/// ```
pub struct LoggerMiddleware {
    /// The log level for this middleware instance
    log_level: LogLevel,
}

impl LoggerMiddleware {
    /// Creates a new logger middleware with default settings.
    ///
    /// Uses [`LogLevel::Info`] by default, which provides standard logging
    /// suitable for production environments.
    ///
    /// # Examples
    ///
    /// ```
    /// use wsforge::prelude::*;
    ///
    /// # fn example() {
    /// let logger = LoggerMiddleware::new();
    /// # }
    /// ```
    pub fn new() -> Arc<Self> {
        Arc::new(Self {
            log_level: LogLevel::Info,
        })
    }

    /// Creates a logger middleware with a custom log level.
    ///
    /// # Arguments
    ///
    /// * `level` - The log level to use
    ///
    /// # Examples
    ///
    /// ```
    /// use wsforge::prelude::*;
    ///
    /// # fn example() {
    /// // Debug level for development
    /// let debug = LoggerMiddleware::with_level(LogLevel::Debug);
    ///
    /// // Info level for production
    /// let info = LoggerMiddleware::with_level(LogLevel::Info);
    ///
    /// // Warn level for minimal logging
    /// let warn = LoggerMiddleware::with_level(LogLevel::Warn);
    /// # }
    /// ```
    pub fn with_level(level: LogLevel) -> Arc<Self> {
        Arc::new(Self { log_level: level })
    }
}

impl Default for LoggerMiddleware {
    fn default() -> Self {
        Self {
            log_level: LogLevel::Info,
        }
    }
}

#[async_trait]
impl Middleware for LoggerMiddleware {
    async fn handle(
        &self,
        message: Message,
        conn: Connection,
        state: AppState,
        extensions: Extensions,
        next: Next,
    ) -> Result<Option<Message>> {
        let start = Instant::now();
        let msg_type = message.message_type();
        let conn_id = conn.id().clone();

        match self.log_level {
            LogLevel::Debug => debug!("📨 [{}] Received {:?} message", conn_id, msg_type),
            LogLevel::Info => info!("📨 [{}] Received {:?} message", conn_id, msg_type),
            LogLevel::Warn => tracing::warn!("📨 [{}] Received {:?} message", conn_id, msg_type),
        }

        let result = next.run(message, conn, state, extensions).await;
        let duration = start.elapsed();

        match &result {
            Ok(Some(_)) => match self.log_level {
                LogLevel::Debug => debug!("📤 [{}] Sent response in {:?}", conn_id, duration),
                LogLevel::Info => info!("📤 [{}] Sent response in {:?}", conn_id, duration),
                LogLevel::Warn => {
                    tracing::warn!("📤 [{}] Sent response in {:?}", conn_id, duration)
                }
            },
            Ok(None) => match self.log_level {
                LogLevel::Debug => debug!("✓ [{}] Processed in {:?}", conn_id, duration),
                LogLevel::Info => info!("✓ [{}] Processed in {:?}", conn_id, duration),
                LogLevel::Warn => {
                    tracing::warn!("✓ [{}] Processed in {:?}", conn_id, duration)
                }
            },
            Err(e) => {
                tracing::error!("❌ [{}] Error in {:?}: {}", conn_id, duration, e);
            }
        }

        result
    }
}