Skip to main content

sova_core/
tracing_init.rs

1//! Default tracing subscriber for `listen` / `run` / `serve`.
2//!
3//! Supports stdout and/or a rotating log file. Configure via env (`LogConfig::from_env`)
4//! or build [`LogConfig`] in code / CLI.
5//!
6//! Optional [`set_log_event_hook`] lets plugins (e.g. Elasticsearch sink) observe events
7//! without replacing the subscriber.
8
9use crate::human::parse_bytes;
10use file_rotate::{
11    compression::Compression,
12    suffix::{AppendCount, AppendTimestamp, FileLimit},
13    ContentLimit, FileRotate, TimeFrequency,
14};
15use std::io::{self, Write};
16use std::path::{Path, PathBuf};
17use std::sync::{Arc, Mutex, OnceLock};
18use tracing::field::{Field, Visit};
19use tracing::{Event, Subscriber};
20use tracing_appender::non_blocking::WorkerGuard;
21use tracing_subscriber::layer::{Context, Layer};
22use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter, Registry};
23
24/// Keep non-blocking worker guards alive for the process lifetime.
25static FILE_GUARDS: OnceLock<Mutex<Vec<WorkerGuard>>> = OnceLock::new();
26
27fn retain_guard(guard: WorkerGuard) {
28    FILE_GUARDS
29        .get_or_init(|| Mutex::new(Vec::new()))
30        .lock()
31        .unwrap()
32        .push(guard);
33}
34
35/// Structured log event for external sinks (Elasticsearch, …).
36#[derive(Debug, Clone)]
37pub struct LogRecord {
38    pub level: String,
39    pub target: String,
40    pub message: String,
41    pub fields: Vec<(String, String)>,
42}
43
44/// Callback invoked for every tracing event (after the local fmt layers).
45pub type LogEventHook = Arc<dyn Fn(LogRecord) + Send + Sync>;
46
47static LOG_EVENT_HOOKS: OnceLock<Mutex<Vec<LogEventHook>>> = OnceLock::new();
48
49fn hooks() -> &'static Mutex<Vec<LogEventHook>> {
50    LOG_EVENT_HOOKS.get_or_init(|| Mutex::new(Vec::new()))
51}
52
53/// Append a global log sink (DevTools, Elasticsearch, …). Multiple hooks are supported.
54pub fn add_log_event_hook(hook: LogEventHook) {
55    hooks().lock().unwrap().push(hook);
56}
57
58/// Register a global log sink hook. Prefer [`add_log_event_hook`] when multiple sinks
59/// may coexist. Returns `Err(hook)` only if an older single-hook API path reserved the
60/// slot — with the multi-hook registry this always succeeds via [`add_log_event_hook`].
61pub fn set_log_event_hook(hook: LogEventHook) -> Result<(), LogEventHook> {
62    add_log_event_hook(hook);
63    Ok(())
64}
65
66struct HookLayer;
67
68impl<S> Layer<S> for HookLayer
69where
70    S: Subscriber,
71{
72    fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
73        let list = hooks().lock().unwrap();
74        if list.is_empty() {
75            return;
76        }
77        let mut visitor = FieldVisitor::default();
78        event.record(&mut visitor);
79        let meta = event.metadata();
80        let record = LogRecord {
81            level: meta.level().to_string(),
82            target: meta.target().to_string(),
83            message: visitor.message.unwrap_or_default(),
84            fields: visitor.fields,
85        };
86        for hook in list.iter() {
87            hook(record.clone());
88        }
89    }
90}
91
92#[derive(Default)]
93struct FieldVisitor {
94    message: Option<String>,
95    fields: Vec<(String, String)>,
96}
97
98impl Visit for FieldVisitor {
99    fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
100        let s = format!("{value:?}");
101        // tracing often wraps Display as Debug with quotes — keep raw for message.
102        if field.name() == "message" {
103            let trimmed = s.trim_matches('"').to_string();
104            self.message = Some(trimmed);
105        } else {
106            self.fields.push((field.name().to_string(), s));
107        }
108    }
109
110    fn record_str(&mut self, field: &Field, value: &str) {
111        if field.name() == "message" {
112            self.message = Some(value.to_string());
113        } else {
114            self.fields
115                .push((field.name().to_string(), value.to_string()));
116        }
117    }
118
119    fn record_i64(&mut self, field: &Field, value: i64) {
120        self.fields
121            .push((field.name().to_string(), value.to_string()));
122    }
123
124    fn record_u64(&mut self, field: &Field, value: u64) {
125        self.fields
126            .push((field.name().to_string(), value.to_string()));
127    }
128
129    fn record_f64(&mut self, field: &Field, value: f64) {
130        self.fields
131            .push((field.name().to_string(), value.to_string()));
132    }
133
134    fn record_bool(&mut self, field: &Field, value: bool) {
135        self.fields
136            .push((field.name().to_string(), value.to_string()));
137    }
138}
139
140/// How to rotate the log file when [`LogConfig::file`] is set.
141#[derive(Debug, Clone, PartialEq, Eq)]
142pub enum LogRotate {
143    /// Append forever (no rotation).
144    Never,
145    /// Rotate when the active file exceeds `max_bytes`; keep `keep` archived files.
146    Size { max_bytes: usize, keep: usize },
147    /// Rotate once per calendar day; keep `keep` archived files.
148    Daily { keep: usize },
149}
150
151impl Default for LogRotate {
152    fn default() -> Self {
153        Self::Size {
154            max_bytes: 10 * 1024 * 1024,
155            keep: 5,
156        }
157    }
158}
159
160/// Tracing install options (stdout and/or file).
161#[derive(Debug, Clone)]
162pub struct LogConfig {
163    /// `EnvFilter` directive (e.g. `sova=info`, `debug`).
164    pub filter: String,
165    /// Write to stdout (default `true`).
166    pub stdout: bool,
167    /// Optional log file path.
168    pub file: Option<PathBuf>,
169    /// File rotation policy (used when `file` is set).
170    pub rotate: LogRotate,
171}
172
173impl Default for LogConfig {
174    fn default() -> Self {
175        Self {
176            filter: "sova=info".into(),
177            stdout: true,
178            file: None,
179            rotate: LogRotate::default(),
180        }
181    }
182}
183
184impl LogConfig {
185    /// Build from environment variables (see crate / README logging section).
186    pub fn from_env() -> Self {
187        let mut cfg = Self::default();
188        if let Ok(v) = std::env::var("RUST_LOG") {
189            if !v.is_empty() {
190                cfg.filter = v;
191            }
192        }
193        cfg.stdout = env_truthy("SOVA_LOG_STDOUT", true);
194        if let Ok(path) = std::env::var("SOVA_LOG_FILE") {
195            if !path.is_empty() {
196                cfg.file = Some(PathBuf::from(path));
197            }
198        }
199        cfg.rotate = parse_rotate_from_env();
200        cfg
201    }
202
203    /// Install the subscriber (`try_init`). No-op if `SOVA_LOG=off` or a subscriber already exists.
204    pub fn install(&self) {
205        if std::env::var_os("SOVA_LOG").is_some_and(|v| v == "off") {
206            return;
207        }
208        let _ = self.try_install();
209    }
210
211    /// Like [`Self::install`], but returns whether init succeeded.
212    pub fn try_install(&self) -> Result<(), String> {
213        if !self.stdout && self.file.is_none() {
214            return Err("LogConfig: enable stdout and/or set a log file".into());
215        }
216
217        let filter = EnvFilter::try_new(&self.filter)
218            .or_else(|_| EnvFilter::try_new("sova=info"))
219            .unwrap_or_else(|_| EnvFilter::new("info"));
220
221        let stdout_layer = self.stdout.then(|| {
222            fmt::layer()
223                .with_writer(io::stdout)
224                .with_target(false)
225                .with_ansi(true)
226        });
227
228        let file_layer = if let Some(path) = &self.file {
229            let writer = open_rotating_file(path, &self.rotate)
230                .map_err(|e| format!("log file {}: {e}", path.display()))?;
231            let (nb, guard) = tracing_appender::non_blocking(writer);
232            retain_guard(guard);
233            Some(
234                fmt::layer()
235                    .with_writer(nb)
236                    .with_target(false)
237                    .with_ansi(false),
238            )
239        } else {
240            None
241        };
242
243        Registry::default()
244            .with(filter)
245            .with(stdout_layer)
246            .with(file_layer)
247            .with(HookLayer)
248            .try_init()
249            .map_err(|e| e.to_string())
250    }
251}
252
253/// Install a default subscriber unless one is already set or `SOVA_LOG=off`.
254pub fn ensure_tracing() {
255    LogConfig::from_env().install();
256}
257
258fn env_truthy(key: &str, default: bool) -> bool {
259    match std::env::var(key) {
260        Ok(v) => matches!(
261            v.trim().to_ascii_lowercase().as_str(),
262            "1" | "true" | "yes" | "on"
263        ),
264        Err(_) => default,
265    }
266}
267
268fn parse_rotate_from_env() -> LogRotate {
269    let keep = std::env::var("SOVA_LOG_ROTATE_KEEP")
270        .ok()
271        .and_then(|s| s.parse().ok())
272        .unwrap_or(5)
273        .max(1);
274
275    let mode = std::env::var("SOVA_LOG_ROTATE")
276        .unwrap_or_else(|_| "size".into())
277        .to_ascii_lowercase();
278
279    match mode.as_str() {
280        "never" | "none" | "off" => LogRotate::Never,
281        "daily" | "day" => LogRotate::Daily { keep },
282        _ => {
283            let max_bytes = std::env::var("SOVA_LOG_ROTATE_SIZE")
284                .ok()
285                .and_then(|s| parse_bytes(&s).ok())
286                .unwrap_or(10 * 1024 * 1024)
287                .max(1);
288            LogRotate::Size { max_bytes, keep }
289        }
290    }
291}
292
293/// Parse rotate mode string (`size` / `daily` / `never`).
294pub fn parse_log_rotate(
295    mode: &str,
296    size: Option<&str>,
297    keep: Option<usize>,
298) -> Result<LogRotate, String> {
299    let keep = keep.unwrap_or(5).max(1);
300    match mode.trim().to_ascii_lowercase().as_str() {
301        "never" | "none" | "off" => Ok(LogRotate::Never),
302        "daily" | "day" => Ok(LogRotate::Daily { keep }),
303        "size" | "" => {
304            let max_bytes = match size {
305                Some(s) => parse_bytes(s)?,
306                None => 10 * 1024 * 1024,
307            }
308            .max(1);
309            Ok(LogRotate::Size { max_bytes, keep })
310        }
311        other => Err(format!("unknown log rotate mode: {other}")),
312    }
313}
314
315enum RotatingWriter {
316    Count(FileRotate<AppendCount>),
317    Stamp(FileRotate<AppendTimestamp>),
318}
319
320impl Write for RotatingWriter {
321    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
322        match self {
323            Self::Count(w) => w.write(buf),
324            Self::Stamp(w) => w.write(buf),
325        }
326    }
327
328    fn flush(&mut self) -> io::Result<()> {
329        match self {
330            Self::Count(w) => w.flush(),
331            Self::Stamp(w) => w.flush(),
332        }
333    }
334}
335
336fn open_rotating_file(path: &Path, rotate: &LogRotate) -> io::Result<RotatingWriter> {
337    if let Some(parent) = path.parent() {
338        if !parent.as_os_str().is_empty() {
339            std::fs::create_dir_all(parent)?;
340        }
341    }
342
343    Ok(match rotate {
344        LogRotate::Never => RotatingWriter::Count(FileRotate::new(
345            path,
346            AppendCount::new(0),
347            ContentLimit::None,
348            Compression::None,
349            None,
350        )),
351        LogRotate::Size { max_bytes, keep } => RotatingWriter::Count(FileRotate::new(
352            path,
353            AppendCount::new(*keep),
354            ContentLimit::BytesSurpassed(*max_bytes),
355            Compression::None,
356            None,
357        )),
358        LogRotate::Daily { keep } => RotatingWriter::Stamp(FileRotate::new(
359            path,
360            AppendTimestamp::default(FileLimit::MaxFiles(*keep)),
361            ContentLimit::Time(TimeFrequency::Daily),
362            Compression::None,
363            None,
364        )),
365    })
366}
367
368#[cfg(test)]
369mod tests {
370    use super::*;
371
372    #[test]
373    fn parse_rotate_modes() {
374        assert_eq!(
375            parse_log_rotate("never", None, Some(3)).unwrap(),
376            LogRotate::Never
377        );
378        assert_eq!(
379            parse_log_rotate("daily", None, Some(7)).unwrap(),
380            LogRotate::Daily { keep: 7 }
381        );
382        let s = parse_log_rotate("size", Some("2MB"), Some(3)).unwrap();
383        assert_eq!(
384            s,
385            LogRotate::Size {
386                max_bytes: 2 * 1024 * 1024,
387                keep: 3
388            }
389        );
390    }
391
392    #[test]
393    fn from_env_defaults() {
394        let cfg = LogConfig::default();
395        assert!(cfg.stdout);
396        assert!(cfg.file.is_none());
397        assert_eq!(
398            cfg.rotate,
399            LogRotate::Size {
400                max_bytes: 10 * 1024 * 1024,
401                keep: 5
402            }
403        );
404    }
405
406    #[test]
407    fn open_size_rotate_writes() {
408        let dir = tempfile::tempdir().unwrap();
409        let path = dir.path().join("app.log");
410        let mut w = open_rotating_file(
411            &path,
412            &LogRotate::Size {
413                max_bytes: 32,
414                keep: 2,
415            },
416        )
417        .unwrap();
418        writeln!(w, "hello logging").unwrap();
419        w.flush().unwrap();
420        assert!(path.exists());
421    }
422
423    #[test]
424    fn hook_layer_receives_events() {
425        use std::sync::Mutex;
426        use tracing_subscriber::prelude::*;
427
428        let got = Arc::new(Mutex::new(Vec::<LogRecord>::new()));
429        let got2 = Arc::clone(&got);
430        let _ = set_log_event_hook(Arc::new(move |r| {
431            got2.lock().unwrap().push(r);
432        }));
433
434        let _guard = tracing::subscriber::set_default(
435            Registry::default().with(HookLayer).with(
436                EnvFilter::new("info"),
437            ),
438        );
439        tracing::info!(request_id = "abc", "hello es");
440        let records = got.lock().unwrap();
441        assert!(!records.is_empty());
442        assert!(records.iter().any(|r| r.message.contains("hello es") || r.fields.iter().any(|(k,_)| k == "request_id")));
443    }
444}