Skip to main content

ecp_core/
logging.rs

1//! Optional logging to a JSONL file, one JSON object per line.
2
3use std::fs::{self, File, OpenOptions};
4use std::io::Write;
5use std::path::{Path, PathBuf};
6use std::sync::atomic::{AtomicBool, Ordering};
7use std::sync::{Mutex, OnceLock};
8
9use log::{LevelFilter, Log, Metadata, Record};
10use rand::RngExt;
11use time::OffsetDateTime;
12use time::format_description::well_known::Rfc3339;
13use time::macros::format_description;
14
15use crate::error::{Result, ResultExt};
16
17/// The log file's path, or the failure that stopped `init` from setting one
18/// up. Only the first call runs; a failing first call is cached too, so a
19/// later call with a different `log_dir` does not get a second attempt.
20static LOG_PATH: OnceLock<Result<PathBuf>> = OnceLock::new();
21
22/// Writes each log record as one JSON line to `file`.
23struct JsonlLogger {
24    file: Mutex<File>,
25    /// Set after the first write failure, so a full disk gets one line on
26    /// stderr instead of one per record.
27    write_failed: AtomicBool,
28}
29
30impl Log for JsonlLogger {
31    fn enabled(&self, metadata: &Metadata) -> bool {
32        metadata.level() <= log::max_level()
33    }
34
35    fn log(&self, record: &Record) {
36        let entry = format_entry(record);
37        if let Ok(mut file) = self.file.lock()
38            && let Err(e) = writeln!(file, "{entry}")
39            && !self.write_failed.swap(true, Ordering::Relaxed)
40        {
41            eprintln!("ecp_core::logging: failed to write a log line: {e}");
42        }
43    }
44
45    fn flush(&self) {
46        if let Ok(mut file) = self.file.lock() {
47            let _ = file.flush();
48        }
49    }
50}
51
52/// Formats `record` as one JSON object with its timestamp, level, target and
53/// message.
54fn format_entry(record: &Record) -> String {
55    let timestamp = OffsetDateTime::now_utc()
56        .format(&Rfc3339)
57        .unwrap_or_default();
58    serde_json::json!({
59        "timestamp": timestamp,
60        "level": record.level().to_string(),
61        "target": record.target(),
62        "message": record.args().to_string(),
63    })
64    .to_string()
65}
66
67/// Returns 6 random hex digits, so two processes started in the same second
68/// get different log files.
69fn random_suffix() -> String {
70    format!("{:06x}", rand::rng().random::<u32>() & 0xff_ffff)
71}
72
73/// Starts logging this process to a new JSONL file in `log_dir` (default
74/// `ecp_logs/`), keeping records at `level` and above, and returns its path.
75/// Only the first call sets logging up; later calls return the same path.
76pub fn init(log_dir: Option<&Path>, level: LevelFilter) -> Result<PathBuf> {
77    LOG_PATH
78        .get_or_init(|| {
79            let dir = log_dir
80                .map(Path::to_path_buf)
81                .unwrap_or_else(|| PathBuf::from("ecp_logs"));
82            fs::create_dir_all(&dir).store_err("failed to create log directory")?;
83
84            // One file per process, named by its start time plus a random suffix
85            const TIMESTAMP_FORMAT: &[time::format_description::FormatItem] =
86                format_description!("[year][month][day]T[hour][minute][second]Z");
87            let timestamp = OffsetDateTime::now_utc()
88                .format(TIMESTAMP_FORMAT)
89                .store_err("failed to format the log file's timestamp")?;
90            let path = dir.join(format!("{timestamp}-{}.jsonl", random_suffix()));
91
92            let file = OpenOptions::new()
93                .create(true)
94                .append(true)
95                .open(&path)
96                .store_err("failed to open log file")?;
97            match log::set_boxed_logger(Box::new(JsonlLogger {
98                file: Mutex::new(file),
99                write_failed: AtomicBool::new(false),
100            })) {
101                Ok(()) => {
102                    log::set_max_level(level);
103                    log::info!("logging to {} at {level}", path.display());
104                }
105                // A logger was already installed for this process, log's one
106                // slot per program. Say so through it, since ours never ran.
107                Err(_) => log::warn!(
108                    "a logger was already active for this process before \
109                     ecp_core::logging::init ran; records go there, not to \
110                     {} (this file will stay empty)",
111                    path.display()
112                ),
113            }
114            Ok(path)
115        })
116        .clone()
117}
118
119#[cfg(test)]
120#[path = "utests/logging.rs"]
121mod tests;