xbp_cli/

logging.rs

//! comprehensive logging system for xbp
//!
//! provides structured logging to /var/log/xbp/ with automatic
//! log rotation different log levels and command specific log files
//! supports async logging with per command tracing and file based storage

use crate::config::global_xbp_paths;
use crate::utils::find_xbp_config_upwards;
use chrono::format::{DelayedFormat, StrftimeItems};
use chrono::{DateTime, Local};
use colored::{ColoredString, Colorize};
use fs::ReadDir;
use serde::{Deserialize, Serialize};
use std::fs::{self, OpenOptions};
use std::io::Write;
use std::path::{Path, PathBuf};
use std::sync::MutexGuard;
use std::sync::{Arc, Mutex, OnceLock};
use std::time::{Duration, Instant};
/// Global logger instance
static LOGGER: OnceLock<Arc<Mutex<Option<Arc<XbpLogger>>>>> = OnceLock::new();

#[derive(Debug, Clone, Serialize, Deserialize)]
pub enum LogLevel {
    Info,
    Warning,
    Error,
    Debug,
    Success,
}

impl LogLevel {
    fn to_string(&self) -> &'static str {
        match self {
            LogLevel::Info => "INFO",
            LogLevel::Warning => "WARN",
            LogLevel::Error => "ERROR",
            LogLevel::Debug => "DEBUG",
            LogLevel::Success => "SUCCESS",
        }
    }
}

#[derive(Debug, Clone, Serialize, Deserialize)]
pub struct LogEntry {
    pub timestamp: DateTime<Local>,
    pub level: LogLevel,
    pub command: String,
    pub message: String,
    pub details: Option<String>,
    pub duration_ms: Option<u64>,
}

pub struct XbpLogger {
    log_dir: PathBuf,
    debug_enabled: bool,
    project_name: Option<String>,
}

impl XbpLogger {
    pub async fn new(debug: bool) -> Result<Self, String> {
        let log_dir: PathBuf = Self::determine_and_ensure_log_directory().await?;
        let project_name: Option<String> = Self::detect_project_name();

        let logger: XbpLogger = XbpLogger {
            log_dir,
            debug_enabled: debug,
            project_name,
        };

        Ok(logger)
    }

    fn detect_project_name() -> Option<String> {
        let current_dir: PathBuf = std::env::current_dir().ok()?;
        let found: crate::utils::FoundXbpConfig = find_xbp_config_upwards(&current_dir)?;
        let content: String = fs::read_to_string(&found.config_path).ok()?;

        let json = if found.kind == "yaml" {
            serde_yaml::from_str::<serde_yaml::Value>(&content)
                .ok()
                .and_then(|v| serde_json::to_value(v).ok())?
        } else {
            serde_json::from_str::<serde_json::Value>(&content).ok()?
        };

        json.get("project_name")
            .and_then(|v| v.as_str())
            .map(|s| s.to_string())
    }

    pub async fn determine_and_ensure_log_directory() -> Result<PathBuf, String> {
        let user_log_dir = global_xbp_paths()?.logs_dir;
        Self::try_create_and_set_permissions(&user_log_dir, 0o700).await?;
        Ok(user_log_dir)
    }

    #[cfg(unix)]
    async fn try_create_and_set_permissions(path: &Path, mode: u32) -> Result<(), String> {
        use std::os::unix::fs::PermissionsExt;

        fs::create_dir_all(path)
            .map_err(|e| format!("Failed to create log directory {}: {}", path.display(), e))?;

        let permissions = std::fs::Permissions::from_mode(mode);
        fs::set_permissions(path, permissions).map_err(|e| {
            format!(
                "Failed to set log directory permissions {}: {}",
                path.display(),
                e
            )
        })?;
        Ok(())
    }

    #[cfg(not(unix))]
    async fn try_create_and_set_permissions(path: &Path, _mode: u32) -> Result<(), String> {
        fs::create_dir_all(path)
            .map_err(|e| format!("Failed to create log directory {}: {}", path.display(), e))?;
        Ok(())
    }

    /// Log an info message
    pub async fn log_info(
        &self,
        command: &str,
        message: &str,
        details: Option<&str>,
    ) -> Result<(), String> {
        self.write_log(LogLevel::Info, command, message, details, None)
            .await
    }

    /// Log a warning message
    pub async fn log_warning(
        &self,
        command: &str,
        message: &str,
        details: Option<&str>,
    ) -> Result<(), String> {
        self.write_log(LogLevel::Warning, command, message, details, None)
            .await
    }

    /// Log an error message
    pub async fn log_error(
        &self,
        command: &str,
        message: &str,
        details: Option<&str>,
    ) -> Result<(), String> {
        self.write_log(LogLevel::Error, command, message, details, None)
            .await
    }

    /// Log a success message
    pub async fn log_success(
        &self,
        command: &str,
        message: &str,
        details: Option<&str>,
    ) -> Result<(), String> {
        self.write_log(LogLevel::Success, command, message, details, None)
            .await
    }

    /// Log a debug message (only if debug is enabled)
    pub async fn log_debug(
        &self,
        command: &str,
        message: &str,
        details: Option<&str>,
    ) -> Result<(), String> {
        if self.debug_enabled {
            self.write_log(LogLevel::Debug, command, message, details, None)
                .await
        } else {
            Ok(())
        }
    }

    /// Log a timed operation
    pub async fn log_timed(
        &self,
        level: LogLevel,
        command: &str,
        message: &str,
        duration_ms: u64,
    ) -> Result<(), String> {
        self.write_log(level, command, message, None, Some(duration_ms))
            .await
    }

    /// Write log entry to both console and file
    async fn write_log(
        &self,
        level: LogLevel,
        command: &str,
        message: &str,
        details: Option<&str>,
        duration_ms: Option<u64>,
    ) -> Result<(), String> {
        let entry: LogEntry = LogEntry {
            timestamp: Local::now(),
            level: level.clone(),
            command: command.to_string(),
            message: message.to_string(),
            details: details.map(|s| s.to_string()),
            duration_ms,
        };

        // Write to console
        self.write_console(&entry);

        // Write to file
        self.write_file(&entry).await?;

        crate::data::athena::persist_log_entry(&entry).await;

        Ok(())
    }

    fn write_console(&self, entry: &LogEntry) {
        use colored::Colorize;

        let duration_str: String = if let Some(duration) = entry.duration_ms {
            format!(" {}", format!("({}ms)", duration).dimmed())
        } else {
            String::new()
        };

        let level_colored: ColoredString = match entry.level {
            LogLevel::Info => "INFO".cyan(),
            LogLevel::Warning => "WARN".yellow(),
            LogLevel::Error => "ERROR".red(),
            LogLevel::Debug => "DEBUG".magenta(),
            LogLevel::Success => "SUCCESS".green(),
        };

        let command_colored: ColoredString = entry.command.bright_blue();

        let message_line: String = format!(
            "{} {} {}{}",
            level_colored, command_colored, entry.message, duration_str
        );

        match entry.level {
            LogLevel::Warning | LogLevel::Error => eprintln!("{}", message_line),
            _ => println!("{}", message_line),
        }

        if let Some(details) = &entry.details {
            match entry.level {
                LogLevel::Warning | LogLevel::Error => eprintln!("  {}", details.dimmed()),
                _ => println!("  {}", details.dimmed()),
            }
        }
    }

    /// Write log entry to file
    async fn write_file(&self, entry: &LogEntry) -> Result<(), String> {
        // Create log file paths
        let date_str: DelayedFormat<StrftimeItems<'_>> = entry.timestamp.format("%Y-%m-%d");
        let general_log: PathBuf = self.log_dir.join(format!("xbp-{}.log", date_str));
        let command_log: PathBuf = self
            .log_dir
            .join(format!("{}-{}.log", entry.command, date_str));

        // Prepare log line
        let duration_str: String = if let Some(duration) = entry.duration_ms {
            format!(" duration={}ms", duration)
        } else {
            String::new()
        };

        let details_str: String = if let Some(details) = &entry.details {
            format!(" details=\"{}\"", details.replace('"', "'"))
        } else {
            String::new()
        };

        let log_line: String = format!(
            "{} level={} command={} message=\"{}\"{}{}\n",
            entry.timestamp.format("%Y-%m-%d %H:%M:%S%.3f"),
            entry.level.to_string(),
            entry.command,
            entry.message.replace('"', "'"),
            details_str,
            duration_str
        );

        // Write to general log
        self.append_to_file(&general_log, &log_line).await?;
        self.append_to_file(&command_log, &log_line).await?;

        // Rotate logs if necessary
        self.rotate_logs_if_needed(&general_log).await?;
        self.rotate_logs_if_needed(&command_log).await?;

        Ok(())
    }

    /// Append content to a log file
    async fn append_to_file(&self, file_path: &Path, content: &str) -> Result<(), String> {
        let mut file = OpenOptions::new()
            .create(true)
            .append(true)
            .open(file_path)
            .map_err(|e| format!("Failed to open log file {}: {}", file_path.display(), e))?;

        file.write_all(content.as_bytes())
            .map_err(|e| format!("Failed to write to log file: {}", e))?;

        Ok(())
    }

    /// Rotate logs if they exceed size limit (10MB)
    async fn rotate_logs_if_needed(&self, file_path: &Path) -> Result<(), String> {
        if let Ok(metadata) = fs::metadata(file_path) {
            const MAX_SIZE: u64 = 10 * 1024 * 1024; // 10MB

            if metadata.len() > MAX_SIZE {
                let rotated_path: PathBuf =
                    file_path.with_extension(format!("log.{}", Local::now().format("%H%M%S")));

                fs::rename(file_path, &rotated_path)
                    .map_err(|e| format!("Failed to rotate log file: {}", e))?;

                // Log rotation directly to avoid recursion
                let entry: LogEntry = LogEntry {
                    timestamp: Local::now(),
                    level: LogLevel::Info,
                    command: "system".to_string(),
                    message: format!("Rotated log file to {}", rotated_path.display()),
                    details: None,
                    duration_ms: None,
                };
                self.write_console(&entry);
            }
        }

        Ok(())
    }

    /// Log command execution with timing
    pub async fn log_command_execution(
        &self,
        command: &str,
        cmd_args: &[&str],
        start_time: Instant,
    ) -> Result<(), String> {
        let duration: Duration = start_time.elapsed();
        let duration_ms: u64 = duration.as_millis() as u64;

        let full_command: String = format!("{} {}", command, cmd_args.join(" "));

        self.log_timed(
            LogLevel::Info,
            "command",
            &format!("Executed: {}", full_command),
            duration_ms,
        )
        .await
    }

    /// Log process output
    pub async fn log_process_output(
        &self,
        command: &str,
        process_name: &str,
        stdout: &str,
        stderr: &str,
    ) -> Result<(), String> {
        if !stdout.is_empty() {
            self.log_info(command, &format!("{} stdout", process_name), Some(stdout))
                .await?;
        }

        if !stderr.is_empty() {
            self.log_warning(command, &format!("{} stderr", process_name), Some(stderr))
                .await?;
        }

        Ok(())
    }

    /// Get log directory path
    pub fn log_dir(&self) -> &Path {
        &self.log_dir
    }

    pub fn get_project_name(&self) -> Option<String> {
        self.project_name.clone()
    }

    /// List available log files
    pub async fn list_log_files(&self) -> Result<Vec<PathBuf>, String> {
        let mut files: Vec<PathBuf> = Vec::new();

        let entries: ReadDir = fs::read_dir(&self.log_dir)
            .map_err(|e| format!("Failed to read log directory: {}", e))?;

        for entry in entries {
            let entry: fs::DirEntry =
                entry.map_err(|e| format!("Failed to read directory entry: {}", e))?;
            let path = entry.path();

            if path.is_file() && path.extension().is_some_and(|ext| ext == "log") {
                files.push(path);
            }
        }

        files.sort();
        Ok(files)
    }

    /// Read recent log entries from a specific log file
    pub async fn read_recent_logs(
        &self,
        file_path: &Path,
        lines: usize,
    ) -> Result<Vec<String>, String> {
        let content: String =
            fs::read_to_string(file_path).map_err(|e| format!("Failed to read log file: {}", e))?;

        let all_lines: Vec<&str> = content.lines().collect();
        let recent_lines: &[&str] = if all_lines.len() > lines {
            &all_lines[all_lines.len() - lines..]
        } else {
            &all_lines
        };

        Ok(recent_lines.iter().map(|s| s.to_string()).collect())
    }
}

/// Initialize the global logger
pub async fn init_logger(debug: bool) -> Result<(), String> {
    let logger: Arc<XbpLogger> = Arc::new(XbpLogger::new(debug).await?);

    let mutex: &Arc<Mutex<Option<Arc<XbpLogger>>>> =
        LOGGER.get_or_init(|| Arc::new(Mutex::new(None)));
    let mut guard: MutexGuard<'_, Option<Arc<XbpLogger>>> = mutex
        .lock()
        .map_err(|e| format!("Failed to lock logger: {}", e))?;
    *guard = Some(logger);

    Ok(())
}

/// Get a cloned reference to the logger for use in async contexts
pub fn get_logger() -> Option<Arc<XbpLogger>> {
    LOGGER.get().and_then(|mutex| {
        mutex
            .lock()
            .ok()
            .and_then(|guard: MutexGuard<'_, Option<Arc<XbpLogger>>>| guard.as_ref().cloned())
    })
}

/// Get the log directory path
pub async fn get_log_directory() -> Result<PathBuf, String> {
    XbpLogger::determine_and_ensure_log_directory().await
}

/// Helper function to log info with the global logger
pub async fn log_info(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
    if let Some(logger) = get_logger() {
        logger.log_info(command, message, details).await
    } else {
        Ok(())
    }
}

/// Helper function to log errors with the global logger
pub async fn log_error(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
    if let Some(logger) = get_logger() {
        logger.log_error(command, message, details).await
    } else {
        Ok(())
    }
}

/// Helper function to log warnings with the global logger
pub async fn log_warn(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
    if let Some(logger) = get_logger() {
        logger.log_warning(command, message, details).await
    } else {
        Ok(())
    }
}

/// Helper function to log success with the global logger
pub async fn log_success(
    command: &str,
    message: &str,
    details: Option<&str>,
) -> Result<(), String> {
    if let Some(logger) = get_logger() {
        logger.log_success(command, message, details).await
    } else {
        Ok(())
    }
}

/// Helper function to log timed events with the global logger
pub async fn log_timed(
    level: LogLevel,
    command: &str,
    message: &str,
    duration_ms: u64,
) -> Result<(), String> {
    if let Some(logger) = get_logger() {
        logger.log_timed(level, command, message, duration_ms).await
    } else {
        Ok(())
    }
}

/// Helper function to log process output with the global logger
pub async fn log_process_output(
    command: &str,
    process_name: &str,
    stdout: &str,
    stderr: &str,
) -> Result<(), String> {
    if let Some(logger) = get_logger() {
        logger
            .log_process_output(command, process_name, stdout, stderr)
            .await
    } else {
        Ok(())
    }
}

/// Helper function to log debug with the global logger
pub async fn log_debug(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
    if let Some(logger) = get_logger() {
        logger.log_debug(command, message, details).await
    } else {
        Ok(())
    }
}

/// Helper function to get the current project name from the logger
pub fn get_project_name() -> Option<String> {
    if let Some(logger) = get_logger() {
        return logger.get_project_name();
    }
    None
}

/// Helper function to get the standardized log prefix
pub fn get_prefix() -> String {
    let xbp_prefix = format!("{} | ", "XBP".bright_magenta().bold());
    if let Some(name) = get_project_name() {
        format!("{}{} | ", xbp_prefix, name.bright_blue())
    } else {
        xbp_prefix
    }
}

/// Execute a closure with the global logger if it exists
pub fn with_logger<F, R>(f: F)
where
    F: FnOnce(&XbpLogger) -> R,
{
    if let Some(logger) = get_logger() {
        f(&logger);
    }
}

/// Convenience macro for logging
#[macro_export]
macro_rules! xbp_log {
    (info, $command:expr, $message:expr) => {
        $crate::logging::with_logger(|logger| {
            tokio::task::block_in_place(|| {
                tokio::runtime::Handle::current().block_on(async {
                    let _ = logger.log_info($command, $message, None).await;
                })
            })
        });
    };
    (info, $command:expr, $message:expr, $details:expr) => {
        $crate::logging::with_logger(|logger| {
            tokio::task::block_in_place(|| {
                tokio::runtime::Handle::current().block_on(async {
                    let _ = logger.log_info($command, $message, Some($details)).await;
                })
            })
        });
    };
    (warning, $command:expr, $message:expr) => {
        $crate::logging::with_logger(|logger| {
            tokio::task::block_in_place(|| {
                tokio::runtime::Handle::current().block_on(async {
                    let _ = logger.log_warning($command, $message, None).await;
                })
            })
        });
    };
    (error, $command:expr, $message:expr) => {
        $crate::logging::with_logger(|logger| {
            tokio::task::block_in_place(|| {
                tokio::runtime::Handle::current().block_on(async {
                    let _ = logger.log_error($command, $message, None).await;
                })
            })
        });
    };
    (success, $command:expr, $message:expr) => {
        $crate::logging::with_logger(|logger| {
            tokio::task::block_in_place(|| {
                tokio::runtime::Handle::current().block_on(async {
                    let _ = logger.log_success($command, $message, None).await;
                })
            })
        });
    };
    (debug, $command:expr, $message:expr) => {
        $crate::logging::with_logger(|logger| {
            tokio::task::block_in_place(|| {
                tokio::runtime::Handle::current().block_on(async {
                    let _ = logger.log_debug($command, $message, None).await;
                })
            })
        });
    };
}