autocore_std/

logger.rs

//! UDP Logger for Control Programs
//!
//! This module provides a logger implementation that sends log messages via UDP
//! to the autocore-server for display in the console. The logger is designed to
//! be non-blocking and fire-and-forget to avoid impacting the control loop timing.
//!
//! # Overview
//!
//! When you use [`log::info!`], [`log::warn!`], etc. in your control program,
//! the messages are sent to the autocore-server where they appear in the web
//! console's log panel. This allows you to monitor your control program in
//! real-time without needing direct access to stdout.
//!
//! # Architecture
//!
//! ```text
//! ┌─────────────────────────────┐
//! │  Control Program Process    │
//! │  ┌───────────────────────┐  │
//! │  │ UdpLogger             │  │
//! │  │ (implements log::Log) │  │
//! │  └──────────┬────────────┘  │
//! │             │ mpsc channel  │
//! │  ┌──────────▼────────────┐  │
//! │  │ Background thread     │  │
//! │  │ (batches & sends UDP) │  │
//! │  └──────────┬────────────┘  │
//! └─────────────┼───────────────┘
//!               │ UDP (fire-and-forget)
//!               ▼
//! ┌─────────────────────────────┐
//! │  autocore-server            │
//! │  (UDP listener on 39101)    │
//! └─────────────────────────────┘
//! ```
//!
//! # Automatic Initialization
//!
//! When using [`ControlRunner`](crate::ControlRunner), the logger is initialized
//! automatically. You can configure the log level via [`RunnerConfig::log_level`](crate::RunnerConfig::log_level).
//!
//! # Manual Initialization
//!
//! If you need to initialize the logger manually (e.g., for testing):
//!
//! ```ignore
//! use autocore_std::logger;
//! use log::LevelFilter;
//!
//! logger::init_udp_logger("127.0.0.1", 39101, LevelFilter::Debug, "my_app")?;
//!
//! log::debug!("Debug messages now visible!");
//! log::info!("Info messages too!");
//! ```
//!
//! # Performance Considerations
//!
//! - Log calls are non-blocking (messages are queued to a background thread)
//! - If the queue fills up (1000 messages), new messages are dropped silently
//! - Messages are batched and sent every 20ms or when 50 messages accumulate
//! - UDP is fire-and-forget: delivery is not guaranteed

use log::{LevelFilter, Log, Metadata, Record, SetLoggerError};
use serde::{Deserialize, Serialize};
use std::net::{SocketAddr, UdpSocket};
use std::sync::mpsc::{self, Receiver, SyncSender, TrySendError};
use std::thread;
use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH};

/// Default UDP port for log messages
pub const DEFAULT_LOG_UDP_PORT: u16 = 39101;

/// Maximum batch size before forcing a send
const MAX_BATCH_SIZE: usize = 50;

/// Batch timeout in milliseconds
const BATCH_TIMEOUT_MS: u64 = 20;

/// Channel capacity for log entries
const CHANNEL_CAPACITY: usize = 1000;

/// A log entry that will be serialized and sent over UDP
#[derive(Debug, Clone, Serialize, Deserialize)]
pub struct LogEntry {
    /// Timestamp in milliseconds since UNIX epoch
    pub timestamp_ms: u64,
    /// Log level: "TRACE", "DEBUG", "INFO", "WARN", "ERROR"
    pub level: String,
    /// Source identifier (e.g., "control")
    pub source: String,
    /// Log target (module path)
    pub target: String,
    /// The log message
    pub message: String,
}

impl LogEntry {
    /// Create a new log entry from a log::Record
    pub fn from_record(record: &Record, source: &str) -> Self {
        let timestamp_ms = SystemTime::now()
            .duration_since(UNIX_EPOCH)
            .map(|d| d.as_millis() as u64)
            .unwrap_or(0);

        Self {
            timestamp_ms,
            level: record.level().to_string(),
            source: source.to_string(),
            target: record.target().to_string(),
            message: format!("{}", record.args()),
        }
    }
}

/// UDP Logger implementation
///
/// This logger sends log messages to a UDP endpoint (the autocore-server).
/// Messages are sent asynchronously via a background thread to avoid blocking
/// the control loop.
pub struct UdpLogger {
    tx: SyncSender<LogEntry>,
    level: LevelFilter,
    source: String,
}

impl UdpLogger {
    /// Create a new UDP logger
    ///
    /// # Arguments
    /// * `server_addr` - The address of the autocore-server UDP listener
    /// * `level` - Minimum log level to capture
    /// * `source` - Source identifier for log entries (e.g., "control")
    fn new(server_addr: SocketAddr, level: LevelFilter, source: String) -> Self {
        let (tx, rx) = mpsc::sync_channel::<LogEntry>(CHANNEL_CAPACITY);

        // Spawn background thread for batching and sending
        thread::spawn(move || {
            log_sender_thread(rx, server_addr);
        });

        Self { tx, level, source }
    }
}

impl Log for UdpLogger {
    fn enabled(&self, metadata: &Metadata) -> bool {
        metadata.level() <= self.level
    }

    fn log(&self, record: &Record) {
        if !self.enabled(record.metadata()) {
            return;
        }

        let entry = LogEntry::from_record(record, &self.source);

        // Non-blocking send - drops if channel is full
        match self.tx.try_send(entry) {
            Ok(_) => {}
            Err(TrySendError::Full(_)) => {
                // Channel full, drop the message to avoid blocking
            }
            Err(TrySendError::Disconnected(_)) => {
                // Background thread died, nothing we can do
            }
        }
    }

    fn flush(&self) {
        // UDP is fire-and-forget, no flush needed
    }
}

/// Background thread that batches log entries and sends them via UDP
fn log_sender_thread(rx: Receiver<LogEntry>, server_addr: SocketAddr) {
    // Bind to any available port
    let socket = match UdpSocket::bind("0.0.0.0:0") {
        Ok(s) => s,
        Err(e) => {
            eprintln!("Failed to create UDP socket for logging: {}", e);
            return;
        }
    };

    // Set socket to non-blocking for timeout handling
    if let Err(e) = socket.set_read_timeout(Some(Duration::from_millis(BATCH_TIMEOUT_MS))) {
        eprintln!("Failed to set socket timeout: {}", e);
    }

    let mut batch: Vec<LogEntry> = Vec::with_capacity(MAX_BATCH_SIZE);
    let mut last_send = Instant::now();

    loop {
        // Try to receive with timeout
        match rx.recv_timeout(Duration::from_millis(BATCH_TIMEOUT_MS)) {
            Ok(entry) => {
                batch.push(entry);
            }
            Err(mpsc::RecvTimeoutError::Timeout) => {
                // Timeout - check if we should send
            }
            Err(mpsc::RecvTimeoutError::Disconnected) => {
                // Channel closed, send remaining entries and exit
                if !batch.is_empty() {
                    send_batch(&socket, &server_addr, &batch);
                }
                break;
            }
        }

        // Send if batch is full or timeout elapsed
        let timeout_elapsed = last_send.elapsed() >= Duration::from_millis(BATCH_TIMEOUT_MS);
        if !batch.is_empty() && (batch.len() >= MAX_BATCH_SIZE || timeout_elapsed) {
            send_batch(&socket, &server_addr, &batch);
            batch.clear();
            last_send = Instant::now();
        }
    }
}

/// Send a batch of log entries via UDP
fn send_batch(socket: &UdpSocket, server_addr: &SocketAddr, batch: &[LogEntry]) {
    match serde_json::to_vec(batch) {
        Ok(json) => {
            // Fire and forget - ignore send errors
            let _ = socket.send_to(&json, server_addr);
        }
        Err(e) => {
            eprintln!("Failed to serialize log batch: {}", e);
        }
    }
}

/// Initialize the UDP logger as the global logger
///
/// # Arguments
/// * `server_host` - The host address of the autocore-server (e.g., "127.0.0.1")
/// * `port` - The UDP port to send logs to (default: 39101)
/// * `level` - Minimum log level to capture
/// * `source` - Source identifier for log entries (e.g., "control")
///
/// # Example
/// ```ignore
/// use autocore_std::logger;
/// use log::LevelFilter;
///
/// logger::init_udp_logger("127.0.0.1", 39101, LevelFilter::Info, "control")?;
/// log::info!("Logger initialized!");
/// ```
pub fn init_udp_logger(
    server_host: &str,
    port: u16,
    level: LevelFilter,
    source: &str,
) -> Result<(), SetLoggerError> {
    // Parse the server address
    let server_addr: SocketAddr = format!("{}:{}", server_host, port)
        .parse()
        .unwrap_or_else(|_| {
            // Fall back to localhost if parsing fails
            format!("127.0.0.1:{}", port).parse().unwrap()
        });

    let logger = UdpLogger::new(server_addr, level, source.to_string());

    log::set_boxed_logger(Box::new(logger))?;
    log::set_max_level(level);

    Ok(())
}

/// Initialize the UDP logger with default settings
///
/// Uses:
/// - Server: 127.0.0.1:39101
/// - Level: Info
/// - Source: "control"
pub fn init_default_logger() -> Result<(), SetLoggerError> {
    init_udp_logger("127.0.0.1", DEFAULT_LOG_UDP_PORT, LevelFilter::Info, "control")
}

#[cfg(test)]
mod tests {
    use super::*;

    #[test]
    fn test_log_entry_from_record() {
        // Basic test that LogEntry can be created
        let entry = LogEntry {
            timestamp_ms: 1234567890,
            level: "INFO".to_string(),
            source: "test".to_string(),
            target: "test::module".to_string(),
            message: "Test message".to_string(),
        };

        assert_eq!(entry.level, "INFO");
        assert_eq!(entry.source, "test");
    }

    #[test]
    fn test_log_entry_serialization() {
        let entry = LogEntry {
            timestamp_ms: 1234567890,
            level: "DEBUG".to_string(),
            source: "control".to_string(),
            target: "my_program".to_string(),
            message: "Hello world".to_string(),
        };

        let json = serde_json::to_string(&entry).unwrap();
        assert!(json.contains("DEBUG"));
        assert!(json.contains("Hello world"));

        let batch = vec![entry.clone(), entry];
        let batch_json = serde_json::to_string(&batch).unwrap();
        assert!(batch_json.starts_with('['));
    }
}