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        let details_str: String = if let Some(details) = &entry.details {
300            format!(" details=\"{}\"", details.replace('"', "'"))
301        } else {
302            String::new()
303        };
304
305        let log_line: String = format!(
306            "{} level={} command={} message=\"{}\"{}{}\n",
307            entry.timestamp.format("%Y-%m-%d %H:%M:%S%.3f"),
308            entry.level.to_string(),
309            entry.command,
310            entry.message.replace('"', "'"),
311            details_str,
312            duration_str
313        );
314
315        // Write to general log
316        self.append_to_file(&general_log, &log_line).await?;
317        self.append_to_file(&command_log, &log_line).await?;
318
319        // Rotate logs if necessary
320        self.rotate_logs_if_needed(&general_log).await?;
321        self.rotate_logs_if_needed(&command_log).await?;
322
323        Ok(())
324    }
325
326    /// Append content to a log file
327    async fn append_to_file(&self, file_path: &Path, content: &str) -> Result<(), String> {
328        let mut file = OpenOptions::new()
329            .create(true)
330            .append(true)
331            .open(file_path)
332            .map_err(|e| format!("Failed to open log file {}: {}", file_path.display(), e))?;
333
334        file.write_all(content.as_bytes())
335            .map_err(|e| format!("Failed to write to log file: {}", e))?;
336
337        Ok(())
338    }
339
340    /// Rotate logs if they exceed size limit (10MB)
341    async fn rotate_logs_if_needed(&self, file_path: &Path) -> Result<(), String> {
342        if let Ok(metadata) = fs::metadata(file_path) {
343            const MAX_SIZE: u64 = 10 * 1024 * 1024; // 10MB
344
345            if metadata.len() > MAX_SIZE {
346                let rotated_path: PathBuf =
347                    file_path.with_extension(format!("log.{}", Local::now().format("%H%M%S")));
348
349                fs::rename(file_path, &rotated_path)
350                    .map_err(|e| format!("Failed to rotate log file: {}", e))?;
351
352                // Log rotation directly to avoid recursion
353                let entry: LogEntry = LogEntry {
354                    timestamp: Local::now(),
355                    level: LogLevel::Info,
356                    command: "system".to_string(),
357                    message: format!("Rotated log file to {}", rotated_path.display()),
358                    details: None,
359                    duration_ms: None,
360                };
361                self.write_console(&entry);
362            }
363        }
364
365        Ok(())
366    }
367
368    /// Log command execution with timing
369    pub async fn log_command_execution(
370        &self,
371        command: &str,
372        cmd_args: &[&str],
373        start_time: Instant,
374    ) -> Result<(), String> {
375        let duration: Duration = start_time.elapsed();
376        let duration_ms: u64 = duration.as_millis() as u64;
377
378        let full_command: String = format!("{} {}", command, cmd_args.join(" "));
379
380        self.log_timed(
381            LogLevel::Info,
382            "command",
383            &format!("Executed: {}", full_command),
384            duration_ms,
385        )
386        .await
387    }
388
389    /// Log process output
390    pub async fn log_process_output(
391        &self,
392        command: &str,
393        process_name: &str,
394        stdout: &str,
395        stderr: &str,
396    ) -> Result<(), String> {
397        if !stdout.is_empty() {
398            self.log_info(command, &format!("{} stdout", process_name), Some(stdout))
399                .await?;
400        }
401
402        if !stderr.is_empty() {
403            self.log_warning(command, &format!("{} stderr", process_name), Some(stderr))
404                .await?;
405        }
406
407        Ok(())
408    }
409
410    pub async fn log_file_only(
411        &self,
412        level: LogLevel,
413        command: &str,
414        message: &str,
415        details: Option<&str>,
416        duration_ms: Option<u64>,
417    ) -> Result<(), String> {
418        self.write_log_file_only(level, command, message, details, duration_ms)
419            .await
420    }
421
422    pub async fn log_process_output_file_only(
423        &self,
424        command: &str,
425        process_name: &str,
426        stdout: &str,
427        stderr: &str,
428    ) -> Result<(), String> {
429        if !stdout.is_empty() {
430            self.write_log_file_only(
431                LogLevel::Info,
432                command,
433                &format!("{} stdout", process_name),
434                Some(stdout),
435                None,
436            )
437            .await?;
438        }
439
440        if !stderr.is_empty() {
441            self.write_log_file_only(
442                LogLevel::Warning,
443                command,
444                &format!("{} stderr", process_name),
445                Some(stderr),
446                None,
447            )
448            .await?;
449        }
450
451        Ok(())
452    }
453
454    /// Get log directory path
455    pub fn log_dir(&self) -> &Path {
456        &self.log_dir
457    }
458
459    pub fn get_project_name(&self) -> Option<String> {
460        self.project_name.clone()
461    }
462
463    /// List available log files
464    pub async fn list_log_files(&self) -> Result<Vec<PathBuf>, String> {
465        let mut files: Vec<PathBuf> = Vec::new();
466
467        let entries: ReadDir = fs::read_dir(&self.log_dir)
468            .map_err(|e| format!("Failed to read log directory: {}", e))?;
469
470        for entry in entries {
471            let entry: fs::DirEntry =
472                entry.map_err(|e| format!("Failed to read directory entry: {}", e))?;
473            let path = entry.path();
474
475            if path.is_file() && path.extension().is_some_and(|ext| ext == "log") {
476                files.push(path);
477            }
478        }
479
480        files.sort();
481        Ok(files)
482    }
483
484    /// Read recent log entries from a specific log file
485    pub async fn read_recent_logs(
486        &self,
487        file_path: &Path,
488        lines: usize,
489    ) -> Result<Vec<String>, String> {
490        let content: String =
491            fs::read_to_string(file_path).map_err(|e| format!("Failed to read log file: {}", e))?;
492
493        let all_lines: Vec<&str> = content.lines().collect();
494        let recent_lines: &[&str] = if all_lines.len() > lines {
495            &all_lines[all_lines.len() - lines..]
496        } else {
497            &all_lines
498        };
499
500        Ok(recent_lines.iter().map(|s| s.to_string()).collect())
501    }
502}
503
504/// Initialize the global logger
505pub async fn init_logger(debug: bool) -> Result<(), String> {
506    let logger: Arc<XbpLogger> = Arc::new(XbpLogger::new(debug).await?);
507
508    let mutex: &Arc<Mutex<Option<Arc<XbpLogger>>>> =
509        LOGGER.get_or_init(|| Arc::new(Mutex::new(None)));
510    let mut guard: MutexGuard<'_, Option<Arc<XbpLogger>>> = mutex
511        .lock()
512        .map_err(|e| format!("Failed to lock logger: {}", e))?;
513    *guard = Some(logger);
514
515    Ok(())
516}
517
518/// Get a cloned reference to the logger for use in async contexts
519pub fn get_logger() -> Option<Arc<XbpLogger>> {
520    LOGGER.get().and_then(|mutex| {
521        mutex
522            .lock()
523            .ok()
524            .and_then(|guard: MutexGuard<'_, Option<Arc<XbpLogger>>>| guard.as_ref().cloned())
525    })
526}
527
528/// Get the log directory path
529pub async fn get_log_directory() -> Result<PathBuf, String> {
530    XbpLogger::determine_and_ensure_log_directory().await
531}
532
533/// Helper function to log info with the global logger
534pub async fn log_info(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
535    if let Some(logger) = get_logger() {
536        logger.log_info(command, message, details).await
537    } else {
538        Ok(())
539    }
540}
541
542/// Helper function to log errors with the global logger
543pub async fn log_error(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
544    if let Some(logger) = get_logger() {
545        logger.log_error(command, message, details).await
546    } else {
547        Ok(())
548    }
549}
550
551/// Helper function to log warnings with the global logger
552pub async fn log_warn(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
553    if let Some(logger) = get_logger() {
554        logger.log_warning(command, message, details).await
555    } else {
556        Ok(())
557    }
558}
559
560/// Helper function to log success with the global logger
561pub async fn log_success(
562    command: &str,
563    message: &str,
564    details: Option<&str>,
565) -> Result<(), String> {
566    if let Some(logger) = get_logger() {
567        logger.log_success(command, message, details).await
568    } else {
569        Ok(())
570    }
571}
572
573/// Helper function to log timed events with the global logger
574pub async fn log_timed(
575    level: LogLevel,
576    command: &str,
577    message: &str,
578    duration_ms: u64,
579) -> Result<(), String> {
580    if let Some(logger) = get_logger() {
581        logger.log_timed(level, command, message, duration_ms).await
582    } else {
583        Ok(())
584    }
585}
586
587/// Helper function to log process output with the global logger
588pub async fn log_process_output(
589    command: &str,
590    process_name: &str,
591    stdout: &str,
592    stderr: &str,
593) -> Result<(), String> {
594    if let Some(logger) = get_logger() {
595        logger
596            .log_process_output(command, process_name, stdout, stderr)
597            .await
598    } else {
599        Ok(())
600    }
601}
602
603pub async fn log_file_only(
604    level: LogLevel,
605    command: &str,
606    message: &str,
607    details: Option<&str>,
608    duration_ms: Option<u64>,
609) -> Result<(), String> {
610    if let Some(logger) = get_logger() {
611        logger
612            .log_file_only(level, command, message, details, duration_ms)
613            .await
614    } else {
615        Ok(())
616    }
617}
618
619pub async fn log_process_output_file_only(
620    command: &str,
621    process_name: &str,
622    stdout: &str,
623    stderr: &str,
624) -> Result<(), String> {
625    if let Some(logger) = get_logger() {
626        logger
627            .log_process_output_file_only(command, process_name, stdout, stderr)
628            .await
629    } else {
630        Ok(())
631    }
632}
633
634/// Helper function to log debug with the global logger
635pub async fn log_debug(command: &str, message: &str, details: Option<&str>) -> Result<(), String> {
636    if let Some(logger) = get_logger() {
637        logger.log_debug(command, message, details).await
638    } else {
639        Ok(())
640    }
641}
642
643/// Helper function to get the current project name from the logger
644pub fn get_project_name() -> Option<String> {
645    if let Some(logger) = get_logger() {
646        return logger.get_project_name();
647    }
648    None
649}
650
651/// Helper function to get the standardized log prefix
652pub fn get_prefix() -> String {
653    let xbp_prefix = format!("{} | ", "XBP".bright_magenta().bold());
654    if let Some(name) = get_project_name() {
655        format!("{}{} | ", xbp_prefix, name.bright_blue())
656    } else {
657        xbp_prefix
658    }
659}
660
661/// Execute a closure with the global logger if it exists
662pub fn with_logger<F, R>(f: F)
663where
664    F: FnOnce(&XbpLogger) -> R,
665{
666    if let Some(logger) = get_logger() {
667        f(&logger);
668    }
669}
670
671/// Convenience macro for logging
672#[macro_export]
673macro_rules! xbp_log {
674    (info, $command:expr, $message:expr) => {
675        $crate::logging::with_logger(|logger| {
676            tokio::task::block_in_place(|| {
677                tokio::runtime::Handle::current().block_on(async {
678                    let _ = logger.log_info($command, $message, None).await;
679                })
680            })
681        });
682    };
683    (info, $command:expr, $message:expr, $details:expr) => {
684        $crate::logging::with_logger(|logger| {
685            tokio::task::block_in_place(|| {
686                tokio::runtime::Handle::current().block_on(async {
687                    let _ = logger.log_info($command, $message, Some($details)).await;
688                })
689            })
690        });
691    };
692    (warning, $command:expr, $message:expr) => {
693        $crate::logging::with_logger(|logger| {
694            tokio::task::block_in_place(|| {
695                tokio::runtime::Handle::current().block_on(async {
696                    let _ = logger.log_warning($command, $message, None).await;
697                })
698            })
699        });
700    };
701    (error, $command:expr, $message:expr) => {
702        $crate::logging::with_logger(|logger| {
703            tokio::task::block_in_place(|| {
704                tokio::runtime::Handle::current().block_on(async {
705                    let _ = logger.log_error($command, $message, None).await;
706                })
707            })
708        });
709    };
710    (success, $command:expr, $message:expr) => {
711        $crate::logging::with_logger(|logger| {
712            tokio::task::block_in_place(|| {
713                tokio::runtime::Handle::current().block_on(async {
714                    let _ = logger.log_success($command, $message, None).await;
715                })
716            })
717        });
718    };
719    (debug, $command:expr, $message:expr) => {
720        $crate::logging::with_logger(|logger| {
721            tokio::task::block_in_place(|| {
722                tokio::runtime::Handle::current().block_on(async {
723                    let _ = logger.log_debug($command, $message, None).await;
724                })
725            })
726        });
727    };
728}