Skip to main content

breez_sdk_spark/
logger.rs

1use std::fs::OpenOptions;
2use tracing::{Event, Subscriber};
3use tracing_subscriber::{
4    EnvFilter, Layer,
5    fmt::{FormatFields, format::Writer},
6    layer::{Context, SubscriberExt},
7    util::SubscriberInitExt,
8};
9
10use crate::{LogEntry, Logger, SdkError};
11
12/// Default tracing filter: `info` globally, `debug` for first-party crates,
13/// and noisy third-party crates silenced below `warn`. Shared with the WASM
14/// bindings so both default to the same behaviour.
15pub const DEFAULT_FILTER: &str = concat!(
16    "info",
17    // First-party crates: keep debug logging.
18    ",breez_sdk_spark=debug",
19    ",breez_sdk_common=debug",
20    ",breez_sdk_spark_wasm=debug",
21    ",breez_sdk_spark_bindings=debug",
22    ",spark=debug",
23    ",spark_wallet=debug",
24    ",spark_postgres=debug",
25    ",spark_mysql=debug",
26    ",flashnet=debug",
27    ",platform_utils=debug",
28    // Noisy third-party crates: silence below warn.
29    ",h2=warn",
30    ",rustls=warn",
31    ",rustyline=warn",
32    ",hyper=warn",
33    ",hyper_util=warn",
34    ",tower=warn",
35    ",Connection=warn",
36    ",tonic=warn",
37);
38
39pub(crate) struct GlobalSdkLogger {
40    /// Optional external log listener, that can receive a stream of log statements
41    pub(crate) log_listener: Option<Box<dyn Logger>>,
42}
43
44impl<S> Layer<S> for GlobalSdkLogger
45where
46    S: Subscriber,
47{
48    fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
49        if let Some(s) = self.log_listener.as_ref() {
50            let mut buf = String::new();
51            let writer = Writer::new(&mut buf);
52
53            if tracing_subscriber::fmt::format::DefaultFields::new()
54                .format_fields(writer, event)
55                .is_ok()
56            {
57                s.log(LogEntry {
58                    line: buf,
59                    level: event.metadata().level().to_string(),
60                });
61            }
62        }
63    }
64}
65
66pub(super) fn init_logging(
67    log_dir: Option<&str>,
68    app_logger: Option<Box<dyn Logger>>,
69    log_filter: Option<&str>,
70) -> Result<(), SdkError> {
71    let filter = log_filter.unwrap_or(DEFAULT_FILTER);
72
73    let registry = tracing_subscriber::registry().with(
74        GlobalSdkLogger {
75            log_listener: app_logger,
76        }
77        .with_filter(EnvFilter::new(filter)),
78    );
79
80    if let Some(log_dir) = log_dir {
81        let log_file = OpenOptions::new()
82            .create(true)
83            .append(true)
84            .open(format!("{log_dir}/sdk.log"))
85            .map_err(|e| SdkError::Generic(e.to_string()))?;
86        let fmt_layer = tracing_subscriber::fmt::layer()
87            .with_ansi(false)
88            .with_line_number(true)
89            .with_writer(log_file);
90        // Bench-only: render span CLOSE lines (`time.busy` / `time.idle`)
91        // so the breez-bench aggregator can attribute per-RPC latency.
92        // The user's filter (`spark::operator_rpc=info`, etc.) controls
93        // which spans actually emit.
94        #[cfg(feature = "span-trace")]
95        let fmt_layer = fmt_layer.with_span_events(tracing_subscriber::fmt::format::FmtSpan::CLOSE);
96        let fmt_layer = fmt_layer.with_filter(EnvFilter::new(filter));
97        registry.with(fmt_layer).try_init()?;
98    } else {
99        registry.try_init()?;
100    }
101
102    Ok(())
103}
104
105#[cfg(test)]
106mod tests {
107    use std::sync::{Arc, Mutex};
108
109    use tracing::{debug, info, trace};
110
111    use super::{EnvFilter, GlobalSdkLogger, Layer, SubscriberExt};
112    use crate::{LogEntry, Logger};
113
114    /// External logger that records the level of every entry it receives.
115    struct CapturingLogger {
116        levels: Arc<Mutex<Vec<String>>>,
117    }
118
119    impl Logger for CapturingLogger {
120        fn log(&self, l: LogEntry) {
121            self.levels.lock().unwrap().push(l.level);
122        }
123    }
124
125    /// Runs `emit` with a [`GlobalSdkLogger`] filtered by `filter` installed as
126    /// the thread-local default, returning the levels that reached the external
127    /// logger. `emit` must use a literal `target:` (the macros bake it into a
128    /// `static` callsite) matching a directive in `filter`.
129    fn forwarded_levels(filter: &str, emit: impl FnOnce()) -> Vec<String> {
130        let levels = Arc::new(Mutex::new(Vec::new()));
131        let subscriber = tracing_subscriber::registry().with(
132            GlobalSdkLogger {
133                log_listener: Some(Box::new(CapturingLogger {
134                    levels: levels.clone(),
135                })),
136            }
137            .with_filter(EnvFilter::new(filter)),
138        );
139
140        tracing::subscriber::with_default(subscriber, emit);
141
142        levels.lock().unwrap().clone()
143    }
144
145    #[test]
146    fn external_logger_respects_filter_level() {
147        // A `debug` filter forwards debug (and above) but not trace — this is
148        // the behaviour that regressed when the layer hard-capped at INFO.
149        let levels = forwarded_levels("brz_logtest_debug=debug", || {
150            info!(target: "brz_logtest_debug", "info");
151            debug!(target: "brz_logtest_debug", "debug");
152            trace!(target: "brz_logtest_debug", "trace");
153        });
154        assert!(levels.contains(&"INFO".to_string()), "got {levels:?}");
155        assert!(levels.contains(&"DEBUG".to_string()), "got {levels:?}");
156        assert!(!levels.contains(&"TRACE".to_string()), "got {levels:?}");
157
158        // A `trace` filter forwards trace too.
159        let levels = forwarded_levels("brz_logtest_trace=trace", || {
160            debug!(target: "brz_logtest_trace", "debug");
161            trace!(target: "brz_logtest_trace", "trace");
162        });
163        assert!(levels.contains(&"DEBUG".to_string()), "got {levels:?}");
164        assert!(levels.contains(&"TRACE".to_string()), "got {levels:?}");
165    }
166}