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