Skip to main content

xbp_cli/
logging.rs

1//! comprehensive logging system for xbp
2//!
3//! provides structured logging to /var/log/xbp/ with automatic
4//! log rotation different log levels and command specific log files
5//! supports async logging with per command tracing and file based storage
6
7use crate::config::global_xbp_paths;
8use crate::utils::find_xbp_config_upwards;
9use chrono::format::{DelayedFormat, StrftimeItems};
10use chrono::{DateTime, Local};
11use colored::{ColoredString, Colorize};
12use fs::ReadDir;
13use serde::{Deserialize, Serialize};
14use std::fs::{self, OpenOptions};
15use std::io::Write;
16use std::path::{Path, PathBuf};
17use std::sync::MutexGuard;
18use std::sync::{Arc, Mutex, OnceLock};
19use std::time::{Duration, Instant};
20/// Global logger instance
21static LOGGER: OnceLock<Arc<Mutex<Option<Arc<XbpLogger>>>>> = OnceLock::new();
22
23#[derive(Debug, Clone, Serialize, Deserialize)]
24pub enum LogLevel {
25    Info,
26    Warning,
27    Error,
28    Debug,
29    Success,
30}
31
32impl LogLevel {
33    fn to_string(&self) -> &'static str {
34        match self {
35            LogLevel::Info => "INFO",
36            LogLevel::Warning => "WARN",
37            LogLevel::Error => "ERROR",
38            LogLevel::Debug => "DEBUG",
39            LogLevel::Success => "SUCCESS",
40        }
41    }
42}
43
44#[derive(Debug, Clone, Serialize, Deserialize)]
45pub struct LogEntry {
46    pub timestamp: DateTime<Local>,
47    pub level: LogLevel,
48    pub command: String,
49    pub message: String,
50    pub details: Option<String>,
51    pub duration_ms: Option<u64>,
52}
53
54pub struct XbpLogger {
55    log_dir: PathBuf,
56    debug_enabled: bool,
57    project_name: Option<String>,
58}
59
60impl XbpLogger {
61    pub async fn new(debug: bool) -> Result<Self, String> {
62        let log_dir: PathBuf = Self::determine_and_ensure_log_directory().await?;
63        let project_name: Option<String> = Self::detect_project_name();
64
65        let logger: XbpLogger = XbpLogger {
66            log_dir,
67            debug_enabled: debug,
68            project_name,
69        };
70
71        Ok(logger)
72    }
73
74    fn detect_project_name() -> Option<String> {
75        let current_dir: PathBuf = std::env::current_dir().ok()?;
76        let found: crate::utils::FoundXbpConfig = find_xbp_config_upwards(&current_dir)?;
77        let content: String = fs::read_to_string(&found.config_path).ok()?;
78
79        let json = if found.kind == "yaml" {
80            serde_yaml::from_str::<serde_yaml::Value>(&content)
81                .ok()
82                .and_then(|v| serde_json::to_value(v).ok())?
83        } else {
84            serde_json::from_str::<serde_json::Value>(&content).ok()?
85        };
86
87        json.get("project_name")
88            .and_then(|v| v.as_str())
89            .map(|s| s.to_string())
90    }
91
92    pub async fn determine_and_ensure_log_directory() -> Result<PathBuf, String> {
93        let user_log_dir = global_xbp_paths()?.logs_dir;
94        Self::try_create_and_set_permissions(&user_log_dir, 0o700).await?;
95        Ok(user_log_dir)
96    }
97
98    #[cfg(unix)]
99    async fn try_create_and_set_permissions(path: &Path, mode: u32) -> Result<(), String> {
100        use std::os::unix::fs::PermissionsExt;
101
102        fs::create_dir_all(path)
103            .map_err(|e| format!("Failed to create log directory {}: {}", path.display(), e))?;
104
105        let permissions = std::fs::Permissions::from_mode(mode);
106        fs::set_permissions(path, permissions).map_err(|e| {
107            format!(
108                "Failed to set log directory permissions {}: {}",
109                path.display(),
110                e
111            )
112        })?;
113        Ok(())
114    }
115
116    #[cfg(not(unix))]
117    async fn try_create_and_set_permissions(path: &Path, _mode: u32) -> Result<(), String> {
118        fs::create_dir_all(path)
119            .map_err(|e| format!("Failed to create log directory {}: {}", path.display(), e))?;
120        Ok(())
121    }
122
123    /// Log an info message
124    pub async fn log_info(
125        &self,
126        command: &str,
127        message: &str,
128        details: Option<&str>,
129    ) -> Result<(), String> {
130        self.write_log(LogLevel::Info, command, message, details, None)
131            .await
132    }
133
134    /// Log a warning message
135    pub async fn log_warning(
136        &self,
137        command: &str,
138        message: &str,
139        details: Option<&str>,
140    ) -> Result<(), String> {
141        self.write_log(LogLevel::Warning, command, message, details, None)
142            .await
143    }
144
145    /// Log an error message
146    pub async fn log_error(
147        &self,
148        command: &str,
149        message: &str,
150        details: Option<&str>,
151    ) -> Result<(), String> {
152        self.write_log(LogLevel::Error, command, message, details, None)
153            .await
154    }
155
156    /// Log a success message
157    pub async fn log_success(
158        &self,
159        command: &str,
160        message: &str,
161        details: Option<&str>,
162    ) -> Result<(), String> {
163        self.write_log(LogLevel::Success, command, message, details, None)
164            .await
165    }
166
167    /// Log a debug message (only if debug is enabled)
168    pub async fn log_debug(
169        &self,
170        command: &str,
171        message: &str,
172        details: Option<&str>,
173    ) -> Result<(), String> {
174        if self.debug_enabled {
175            self.write_log(LogLevel::Debug, command, message, details, None)
176                .await
177        } else {
178            Ok(())
179        }
180    }
181
182    /// Log a timed operation
183    pub async fn log_timed(
184        &self,
185        level: LogLevel,
186        command: &str,
187        message: &str,
188        duration_ms: u64,
189    ) -> Result<(), String> {
190        self.write_log(level, command, message, None, Some(duration_ms))
191            .await
192    }
193
194    async fn write_log_file_only(
195        &self,
196        level: LogLevel,
197        command: &str,
198        message: &str,
199        details: Option<&str>,
200        duration_ms: Option<u64>,
201    ) -> Result<(), String> {
202        let entry: LogEntry = LogEntry {
203            timestamp: Local::now(),
204            level,
205            command: command.to_string(),
206            message: message.to_string(),
207            details: details.map(|s| s.to_string()),
208            duration_ms,
209        };
210
211        self.write_file(&entry).await?;
212        crate::data::athena::persist_log_entry(&entry).await;
213
214        Ok(())
215    }
216
217    /// Write log entry to both console and file
218    async fn write_log(
219        &self,
220        level: LogLevel,
221        command: &str,
222        message: &str,
223        details: Option<&str>,
224        duration_ms: Option<u64>,
225    ) -> Result<(), String> {
226        let entry: LogEntry = LogEntry {
227            timestamp: Local::now(),
228            level: level.clone(),
229            command: command.to_string(),
230            message: message.to_string(),
231            details: details.map(|s| s.to_string()),
232            duration_ms,
233        };
234
235        // Write to console
236        self.write_console(&entry);
237
238        // Write to file
239        self.write_file(&entry).await?;
240
241        crate::data::athena::persist_log_entry(&entry).await;
242
243        Ok(())
244    }
245
246    fn write_console(&self, entry: &LogEntry) {
247        use colored::Colorize;
248
249        let duration_str: String = if let Some(duration) = entry.duration_ms {
250            format!(" {}", format!("({}ms)", duration).dimmed())
251        } else {
252            String::new()
253        };
254
255        let level_colored: ColoredString = match entry.level {
256            LogLevel::Info => "INFO".cyan(),
257            LogLevel::Warning => "WARN".yellow(),
258            LogLevel::Error => "ERROR".red(),
259            LogLevel::Debug => "DEBUG".magenta(),
260            LogLevel::Success => "SUCCESS".green(),
261        };
262
263        let command_colored: ColoredString = entry.command.bright_blue();
264
265        let message_line: String = format!(
266            "{} {} {}{}",
267            level_colored, command_colored, entry.message, duration_str
268        );
269
270        match entry.level {
271            LogLevel::Warning | LogLevel::Error => eprintln!("{}", message_line),
272            _ => println!("{}", message_line),
273        }
274
275        if let Some(details) = &entry.details {
276            match entry.level {
277                LogLevel::Warning | LogLevel::Error => eprintln!("  {}", details.dimmed()),
278                _ => println!("  {}", details.dimmed()),
279            }
280        }
281    }
282
283    /// Write log entry to file
284    async fn write_file(&self, entry: &LogEntry) -> Result<(), String> {
285        // Create log file paths
286        let date_str: DelayedFormat<StrftimeItems<'_>> = entry.timestamp.format("%Y-%m-%d");
287        let general_log: PathBuf = self.log_dir.join(format!("xbp-{}.log", date_str));
288        let command_log: PathBuf = self
289            .log_dir
290            .join(format!("{}-{}.log", entry.command, date_str));
291
292        // Prepare log line
293        let duration_str: String = if let Some(duration) = entry.duration_ms {
294            format!(" duration={}ms", duration)
295        } else {
296            String::new()
297        };
298
299        // Bound details so multi-MB process transcripts (e.g. cargo publish)
300        // do not explode log lines or peak memory during formatting.
301        const MAX_DETAILS_CHARS: usize = 64 * 1024;
302        let details_str: String = if let Some(details) = &entry.details {
303            let truncated = if details.chars().count() > MAX_DETAILS_CHARS {
304                let head: String = details.chars().take(MAX_DETAILS_CHARS / 2).collect();
305                let tail: String = details
306                    .chars()
307                    .rev()
308                    .take(MAX_DETAILS_CHARS / 2)
309                    .collect::<String>()
310                    .chars()
311                    .rev()
312                    .collect();
313                let omitted = details.chars().count().saturating_sub(MAX_DETAILS_CHARS);
314                format!(
315                    "{head}\n… truncated {omitted} characters …\n{tail}"
316                )
317            } else {
318                details.clone()
319            };
320            format!(" details=\"{}\"", truncated.replace('"', "'"))
321        } else {
322            String::new()
323        };
324
325        let log_line: String = format!(
326            "{} level={} command={} message=\"{}\"{}{}\n",
327            entry.timestamp.format("%Y-%m-%d %H:%M:%S%.3f"),
328            entry.level.to_string(),
329            entry.command,
330            entry.message.replace('"', "'"),
331            details_str,
332            duration_str
333        );
334
335        // Write to general log
336        self.append_to_file(&general_log, &log_line).await?;
337        self.append_to_file(&command_log, &log_line).await?;
338
339        // Rotate logs if necessary
340        self.rotate_logs_if_needed(&general_log).await?;
341        self.rotate_logs_if_needed(&command_log).await?;
342
343        Ok(())
344    }
345
346    /// Append content to a log file
347    async fn append_to_file(&self, file_path: &Path, content: &str) -> Result<(), String> {
348        let mut file = OpenOptions::new()
349            .create(true)
350            .append(true)
351            .open(file_path)
352            .map_err(|e| format!("Failed to open log file {}: {}", file_path.display(), e))?;
353
354        file.write_all(content.as_bytes())
355            .map_err(|e| format!("Failed to write to log file: {}", e))?;
356
357        Ok(())
358    }
359
360    /// Rotate logs if they exceed size limit (10MB)
361    async fn rotate_logs_if_needed(&self, file_path: &Path) -> Result<(), String> {
362        if let Ok(metadata) = fs::metadata(file_path) {
363            const MAX_SIZE: u64 = 10 * 1024 * 1024; // 10MB
364
365            if metadata.len() > MAX_SIZE {
366                let rotated_path: PathBuf =
367                    file_path.with_extension(format!("log.{}", Local::now().format("%H%M%S")));
368
369                fs::rename(file_path, &rotated_path)
370                    .map_err(|e| format!("Failed to rotate log file: {}", e))?;
371
372                // Log rotation directly to avoid recursion
373                let entry: LogEntry = LogEntry {
374                    timestamp: Local::now(),
375                    level: LogLevel::Info,
376                    command: "system".to_string(),
377                    message: format!("Rotated log file to {}", rotated_path.display()),
378                    details: None,
379                    duration_ms: None,
380                };
381                self.write_console(&entry);
382            }
383        }
384
385        Ok(())
386    }
387
388    /// Log command execution with timing
389    pub async fn log_command_execution(
390        &self,
391        command: &str,
392        cmd_args: &[&str],
393        start_time: Instant,
394    ) -> Result<(), String> {
395        let duration: Duration = start_time.elapsed();
396        let duration_ms: u64 = duration.as_millis() as u64;
397
398        let full_command: String = format!("{} {}", command, cmd_args.join(" "));
399
400        self.log_timed(
401            LogLevel::Info,
402            "command",
403            &format!("Executed: {}", full_command),
404            duration_ms,
405        )
406        .await
407    }
408
409    /// Log process output
410    pub async fn log_process_output(
411        &self,
412        command: &str,
413        process_name: &str,
414        stdout: &str,
415        stderr: &str,
416    ) -> Result<(), String> {
417        if !stdout.is_empty() {
418            self.log_info(command, &format!("{} stdout", process_name), Some(stdout))
419                .await?;
420        }
421
422        if !stderr.is_empty() {
423            self.log_warning(command, &format!("{} stderr", process_name), Some(stderr))
424                .await?;
425        }
426
427        Ok(())
428    }
429
430    pub async fn log_file_only(
431        &self,
432        level: LogLevel,
433        command: &str,
434        message: &str,
435        details: Option<&str>,
436        duration_ms: Option<u64>,
437    ) -> Result<(), String> {
438        self.write_log_file_only(level, command, message, details, duration_ms)
439            .await
440    }
441
442    pub async fn log_process_output_file_only(
443        &self,
444        command: &str,
445        process_name: &str,
446        stdout: &str,
447        stderr: &str,
448    ) -> Result<(), String> {
449        if !stdout.is_empty() {
450            self.write_log_file_only(
451                LogLevel::Info,
452                command,
453                &format!("{} stdout", process_name),
454                Some(stdout),
455                None,
456            )
457            .await?;
458        }
459
460        if !stderr.is_empty() {
461            self.write_log_file_only(
462                LogLevel::Warning,
463                command,
464                &format!("{} stderr", process_name),
465                Some(stderr),
466                None,
467            )
468            .await?;
469        }
470
471        Ok(())
472    }
473
474    /// Get log directory path
475    pub fn log_dir(&self) -> &Path {
476        &self.log_dir
477    }
478
479    pub fn get_project_name(&self) -> Option<String> {
480        self.project_name.clone()
481    }
482
483    /// List available log files
484    pub async fn list_log_files(&self) -> Result<Vec<PathBuf>, String> {
485        let mut files: Vec<PathBuf> = Vec::new();
486
487        let entries: ReadDir = fs::read_dir(&self.log_dir)
488            .map_err(|e| format!("Failed to read log directory: {}", e))?;
489
490        for entry in entries {
491            let entry: fs::DirEntry =
492                entry.map_err(|e| format!("Failed to read directory entry: {}", e))?;
493            let path = entry.path();
494
495            if path.is_file() && path.extension().is_some_and(|ext| ext == "log") {
496                files.push(path);
497            }
498        }
499
500        files.sort();
501        Ok(files)
502    }
503
504    /// Read recent log entries from a specific log file
505    pub async fn read_recent_logs(
506        &self,
507        file_path: &Path,
508        lines: usize,
509    ) -> Result<Vec<String>, String> {
510        let content: String =
511            fs::read_to_string(file_path).map_err(|e| format!("Failed to read log file: {}", e))?;
512
513        let all_lines: Vec<&str> = content.lines().collect();
514        let recent_lines: &[&str] = if all_lines.len() > lines {
515            &all_lines[all_lines.len() - lines..]
516        } else {
517            &all_lines
518        };
519
520        Ok(recent_lines.iter().map(|s| s.to_string()).collect())
521    }
522}
523
524/// Initialize the global logger
525pub async fn init_logger(debug: bool) -> Result<(), String> {
526    let logger: Arc<XbpLogger> = Arc::new(XbpLogger::new(debug).await?);
527
528    let mutex: &Arc<Mutex<Option<Arc<XbpLogger>>>> =
529        LOGGER.get_or_init(|| Arc::new(Mutex::new(None)));
530    let mut guard: MutexGuard<'_, Option<Arc<XbpLogger>>> = mutex
531        .lock()
532        .map_err(|e| format!("Failed to lock logger: {}", e))?;
533    *guard = Some(logger);
534
535    Ok(())
536}
537
538/// Get a cloned reference to the logger for use in async contexts
539pub fn get_logger() -> Option<Arc<XbpLogger>> {
540    LOGGER.get().and_then(|mutex| {
541        mutex
542            .lock()
543            .ok()
544            .and_then(|guard: MutexGuard<'_, Option<Arc<XbpLogger>>>| guard.as_ref().cloned())
545    })
546}
547
548/// Get the log directory path
549pub async fn get_log_directory() -> Result<PathBuf, String> {
550    XbpLogger::determine_and_ensure_log_directory().await
551}
552
553/// Helper function to log info with the global logger
554pub async fn log_info(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
555    if let Some(logger) = get_logger() {
556        logger.log_info(command, message, details).await
557    } else {
558        Ok(())
559    }
560}
561
562/// Helper function to log errors with the global logger
563pub async fn log_error(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
564    if let Some(logger) = get_logger() {
565        logger.log_error(command, message, details).await
566    } else {
567        Ok(())
568    }
569}
570
571/// Helper function to log warnings with the global logger
572pub async fn log_warn(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
573    if let Some(logger) = get_logger() {
574        logger.log_warning(command, message, details).await
575    } else {
576        Ok(())
577    }
578}
579
580/// Helper function to log success with the global logger
581pub async fn log_success(
582    command: &str,
583    message: &str,
584    details: Option<&str>,
585) -> Result<(), String> {
586    if let Some(logger) = get_logger() {
587        logger.log_success(command, message, details).await
588    } else {
589        Ok(())
590    }
591}
592
593/// Helper function to log timed events with the global logger
594pub async fn log_timed(
595    level: LogLevel,
596    command: &str,
597    message: &str,
598    duration_ms: u64,
599) -> Result<(), String> {
600    if let Some(logger) = get_logger() {
601        logger.log_timed(level, command, message, duration_ms).await
602    } else {
603        Ok(())
604    }
605}
606
607/// Helper function to log process output with the global logger
608pub async fn log_process_output(
609    command: &str,
610    process_name: &str,
611    stdout: &str,
612    stderr: &str,
613) -> Result<(), String> {
614    if let Some(logger) = get_logger() {
615        logger
616            .log_process_output(command, process_name, stdout, stderr)
617            .await
618    } else {
619        Ok(())
620    }
621}
622
623pub async fn log_file_only(
624    level: LogLevel,
625    command: &str,
626    message: &str,
627    details: Option<&str>,
628    duration_ms: Option<u64>,
629) -> Result<(), String> {
630    if let Some(logger) = get_logger() {
631        logger
632            .log_file_only(level, command, message, details, duration_ms)
633            .await
634    } else {
635        Ok(())
636    }
637}
638
639pub async fn log_process_output_file_only(
640    command: &str,
641    process_name: &str,
642    stdout: &str,
643    stderr: &str,
644) -> Result<(), String> {
645    if let Some(logger) = get_logger() {
646        logger
647            .log_process_output_file_only(command, process_name, stdout, stderr)
648            .await
649    } else {
650        Ok(())
651    }
652}
653
654/// Helper function to log debug with the global logger
655pub async fn log_debug(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
656    if let Some(logger) = get_logger() {
657        logger.log_debug(command, message, details).await
658    } else {
659        Ok(())
660    }
661}
662
663/// Helper function to get the current project name from the logger
664pub fn get_project_name() -> Option<String> {
665    if let Some(logger) = get_logger() {
666        return logger.get_project_name();
667    }
668    None
669}
670
671/// Helper function to get the standardized log prefix
672pub fn get_prefix() -> String {
673    let xbp_prefix = format!("{} | ", "XBP".bright_magenta().bold());
674    if let Some(name) = get_project_name() {
675        format!("{}{} | ", xbp_prefix, name.bright_blue())
676    } else {
677        xbp_prefix
678    }
679}
680
681/// Execute a closure with the global logger if it exists
682pub fn with_logger<F, R>(f: F)
683where
684    F: FnOnce(&XbpLogger) -> R,
685{
686    if let Some(logger) = get_logger() {
687        f(&logger);
688    }
689}
690
691/// Convenience macro for logging
692#[macro_export]
693macro_rules! xbp_log {
694    (info, $command:expr, $message:expr) => {
695        $crate::logging::with_logger(|logger| {
696            tokio::task::block_in_place(|| {
697                tokio::runtime::Handle::current().block_on(async {
698                    let _ = logger.log_info($command, $message, None).await;
699                })
700            })
701        });
702    };
703    (info, $command:expr, $message:expr, $details:expr) => {
704        $crate::logging::with_logger(|logger| {
705            tokio::task::block_in_place(|| {
706                tokio::runtime::Handle::current().block_on(async {
707                    let _ = logger.log_info($command, $message, Some($details)).await;
708                })
709            })
710        });
711    };
712    (warning, $command:expr, $message:expr) => {
713        $crate::logging::with_logger(|logger| {
714            tokio::task::block_in_place(|| {
715                tokio::runtime::Handle::current().block_on(async {
716                    let _ = logger.log_warning($command, $message, None).await;
717                })
718            })
719        });
720    };
721    (error, $command:expr, $message:expr) => {
722        $crate::logging::with_logger(|logger| {
723            tokio::task::block_in_place(|| {
724                tokio::runtime::Handle::current().block_on(async {
725                    let _ = logger.log_error($command, $message, None).await;
726                })
727            })
728        });
729    };
730    (success, $command:expr, $message:expr) => {
731        $crate::logging::with_logger(|logger| {
732            tokio::task::block_in_place(|| {
733                tokio::runtime::Handle::current().block_on(async {
734                    let _ = logger.log_success($command, $message, None).await;
735                })
736            })
737        });
738    };
739    (debug, $command:expr, $message:expr) => {
740        $crate::logging::with_logger(|logger| {
741            tokio::task::block_in_place(|| {
742                tokio::runtime::Handle::current().block_on(async {
743                    let _ = logger.log_debug($command, $message, None).await;
744                })
745            })
746        });
747    };
748}