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
135/// How to rotate the log file when [`LogConfig::file`] is set.
136#[derive(Debug, Clone, PartialEq, Eq)]
137pub enum LogRotate {
138    /// Append forever (no rotation).
139    Never,
140    /// Rotate when the active file exceeds `max_bytes`; keep `keep` archived files.
141    Size { max_bytes: usize, keep: usize },
142    /// Rotate once per calendar day; keep `keep` archived files.
143    Daily { keep: usize },
144}
145
146impl Default for LogRotate {
147    fn default() -> Self {
148        Self::Size {
149            max_bytes: 10 * 1024 * 1024,
150            keep: 5,
151        }
152    }
153}
154
155/// Tracing install options (stdout and/or file).
156#[derive(Debug, Clone)]
157pub struct LogConfig {
158    /// `EnvFilter` directive (e.g. `sova=info`, `debug`).
159    pub filter: String,
160    /// Write to stdout (default `true`).
161    pub stdout: bool,
162    /// Optional log file path.
163    pub file: Option<PathBuf>,
164    /// File rotation policy (used when `file` is set).
165    pub rotate: LogRotate,
166}
167
168impl Default for LogConfig {
169    fn default() -> Self {
170        Self {
171            filter: "sova=info".into(),
172            stdout: true,
173            file: None,
174            rotate: LogRotate::default(),
175        }
176    }
177}
178
179impl LogConfig {
180    /// Build from environment variables (see crate / README logging section).
181    pub fn from_env() -> Self {
182        let mut cfg = Self::default();
183        if let Ok(v) = std::env::var("RUST_LOG") {
184            if !v.is_empty() {
185                cfg.filter = v;
186            }
187        }
188        cfg.stdout = env_truthy("SOVA_LOG_STDOUT", true);
189        if let Ok(path) = std::env::var("SOVA_LOG_FILE") {
190            if !path.is_empty() {
191                cfg.file = Some(PathBuf::from(path));
192            }
193        }
194        cfg.rotate = parse_rotate_from_env();
195        cfg
196    }
197
198    /// Install the subscriber (`try_init`). No-op if `SOVA_LOG=off` or a subscriber already exists.
199    pub fn install(&self) {
200        if std::env::var_os("SOVA_LOG").is_some_and(|v| v == "off") {
201            return;
202        }
203        let _ = self.try_install();
204    }
205
206    /// Like [`Self::install`], but returns whether init succeeded.
207    pub fn try_install(&self) -> Result<(), String> {
208        if !self.stdout && self.file.is_none() {
209            return Err("LogConfig: enable stdout and/or set a log file".into());
210        }
211
212        let filter = EnvFilter::try_new(&self.filter)
213            .or_else(|_| EnvFilter::try_new("sova=info"))
214            .unwrap_or_else(|_| EnvFilter::new("info"));
215
216        let stdout_layer = self.stdout.then(|| {
217            fmt::layer()
218                .with_writer(io::stdout)
219                .with_target(false)
220                .with_ansi(true)
221        });
222
223        let file_layer = if let Some(path) = &self.file {
224            let writer = open_rotating_file(path, &self.rotate)
225                .map_err(|e| format!("log file {}: {e}", path.display()))?;
226            let (nb, guard) = tracing_appender::non_blocking(writer);
227            retain_guard(guard);
228            Some(
229                fmt::layer()
230                    .with_writer(nb)
231                    .with_target(false)
232                    .with_ansi(false),
233            )
234        } else {
235            None
236        };
237
238        Registry::default()
239            .with(filter)
240            .with(stdout_layer)
241            .with(file_layer)
242            .with(HookLayer)
243            .try_init()
244            .map_err(|e| e.to_string())
245    }
246}
247
248/// Install a default subscriber unless one is already set or `SOVA_LOG=off`.
249pub fn ensure_tracing() {
250    LogConfig::from_env().install();
251}
252
253fn env_truthy(key: &str, default: bool) -> bool {
254    match std::env::var(key) {
255        Ok(v) => matches!(
256            v.trim().to_ascii_lowercase().as_str(),
257            "1" | "true" | "yes" | "on"
258        ),
259        Err(_) => default,
260    }
261}
262
263fn parse_rotate_from_env() -> LogRotate {
264    let keep = std::env::var("SOVA_LOG_ROTATE_KEEP")
265        .ok()
266        .and_then(|s| s.parse().ok())
267        .unwrap_or(5)
268        .max(1);
269
270    let mode = std::env::var("SOVA_LOG_ROTATE")
271        .unwrap_or_else(|_| "size".into())
272        .to_ascii_lowercase();
273
274    match mode.as_str() {
275        "never" | "none" | "off" => LogRotate::Never,
276        "daily" | "day" => LogRotate::Daily { keep },
277        _ => {
278            let max_bytes = std::env::var("SOVA_LOG_ROTATE_SIZE")
279                .ok()
280                .and_then(|s| parse_bytes(&s).ok())
281                .unwrap_or(10 * 1024 * 1024)
282                .max(1);
283            LogRotate::Size { max_bytes, keep }
284        }
285    }
286}
287
288/// Parse rotate mode string (`size` / `daily` / `never`).
289pub fn parse_log_rotate(
290    mode: &str,
291    size: Option<&str>,
292    keep: Option<usize>,
293) -> Result<LogRotate, String> {
294    let keep = keep.unwrap_or(5).max(1);
295    match mode.trim().to_ascii_lowercase().as_str() {
296        "never" | "none" | "off" => Ok(LogRotate::Never),
297        "daily" | "day" => Ok(LogRotate::Daily { keep }),
298        "size" | "" => {
299            let max_bytes = match size {
300                Some(s) => parse_bytes(s)?,
301                None => 10 * 1024 * 1024,
302            }
303            .max(1);
304            Ok(LogRotate::Size { max_bytes, keep })
305        }
306        other => Err(format!("unknown log rotate mode: {other}")),
307    }
308}
309
310enum RotatingWriter {
311    Count(FileRotate<AppendCount>),
312    Stamp(FileRotate<AppendTimestamp>),
313}
314
315impl Write for RotatingWriter {
316    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
317        match self {
318            Self::Count(w) => w.write(buf),
319            Self::Stamp(w) => w.write(buf),
320        }
321    }
322
323    fn flush(&mut self) -> io::Result<()> {
324        match self {
325            Self::Count(w) => w.flush(),
326            Self::Stamp(w) => w.flush(),
327        }
328    }
329}
330
331fn open_rotating_file(path: &Path, rotate: &LogRotate) -> io::Result<RotatingWriter> {
332    if let Some(parent) = path.parent() {
333        if !parent.as_os_str().is_empty() {
334            std::fs::create_dir_all(parent)?;
335        }
336    }
337
338    Ok(match rotate {
339        LogRotate::Never => RotatingWriter::Count(FileRotate::new(
340            path,
341            AppendCount::new(0),
342            ContentLimit::None,
343            Compression::None,
344            None,
345        )),
346        LogRotate::Size { max_bytes, keep } => RotatingWriter::Count(FileRotate::new(
347            path,
348            AppendCount::new(*keep),
349            ContentLimit::BytesSurpassed(*max_bytes),
350            Compression::None,
351            None,
352        )),
353        LogRotate::Daily { keep } => RotatingWriter::Stamp(FileRotate::new(
354            path,
355            AppendTimestamp::default(FileLimit::MaxFiles(*keep)),
356            ContentLimit::Time(TimeFrequency::Daily),
357            Compression::None,
358            None,
359        )),
360    })
361}
362
363#[cfg(test)]
364mod tests {
365    use super::*;
366
367    #[test]
368    fn parse_rotate_modes() {
369        assert_eq!(
370            parse_log_rotate("never", None, Some(3)).unwrap(),
371            LogRotate::Never
372        );
373        assert_eq!(
374            parse_log_rotate("daily", None, Some(7)).unwrap(),
375            LogRotate::Daily { keep: 7 }
376        );
377        let s = parse_log_rotate("size", Some("2MB"), Some(3)).unwrap();
378        assert_eq!(
379            s,
380            LogRotate::Size {
381                max_bytes: 2 * 1024 * 1024,
382                keep: 3
383            }
384        );
385    }
386
387    #[test]
388    fn from_env_defaults() {
389        let cfg = LogConfig::default();
390        assert!(cfg.stdout);
391        assert!(cfg.file.is_none());
392        assert_eq!(
393            cfg.rotate,
394            LogRotate::Size {
395                max_bytes: 10 * 1024 * 1024,
396                keep: 5
397            }
398        );
399    }
400
401    #[test]
402    fn open_size_rotate_writes() {
403        let dir = tempfile::tempdir().unwrap();
404        let path = dir.path().join("app.log");
405        let mut w = open_rotating_file(
406            &path,
407            &LogRotate::Size {
408                max_bytes: 32,
409                keep: 2,
410            },
411        )
412        .unwrap();
413        writeln!(w, "hello logging").unwrap();
414        w.flush().unwrap();
415        assert!(path.exists());
416    }
417
418    #[test]
419    fn hook_layer_receives_events() {
420        use std::sync::Mutex;
421        use tracing_subscriber::prelude::*;
422
423        let got = Arc::new(Mutex::new(Vec::<LogRecord>::new()));
424        let got2 = Arc::clone(&got);
425        let _ = set_log_event_hook(Arc::new(move |r| {
426            got2.lock().unwrap().push(r);
427        }));
428
429        let _guard = tracing::subscriber::set_default(
430            Registry::default().with(HookLayer).with(
431                EnvFilter::new("info"),
432            ),
433        );
434        tracing::info!(request_id = "abc", "hello es");
435        let records = got.lock().unwrap();
436        assert!(!records.is_empty());
437        assert!(records.iter().any(|r| r.message.contains("hello es") || r.fields.iter().any(|(k,_)| k == "request_id")));
438    }
439}