lb_rs/service/
logging.rs

1use crate::Config;
2use crate::model::errors::{LbResult, core_err_unexpected};
3use crate::service::debug::{generate_panic_content, generate_panic_filename};
4use std::backtrace::Backtrace;
5use std::fs::OpenOptions;
6use std::io::Write;
7use std::{env, panic};
8use tracing::Subscriber;
9use tracing::metadata::LevelFilter;
10use tracing_subscriber::fmt::format::FmtSpan;
11use tracing_subscriber::prelude::*;
12use tracing_subscriber::registry::LookupSpan;
13use tracing_subscriber::{Layer, filter, fmt};
14
15pub static LOG_FILE: &str = "lockbook.log";
16
17/// Set to `1` to write `{writeable_path}/traces/<timestamp>.pftrace`, or to a
18/// path to write there. Open the result in <https://ui.perfetto.dev>.
19pub static TRACE_ENV_VAR: &str = "LB_TRACE";
20
21fn log_targets(metadata: &tracing::Metadata<'_>) -> bool {
22    let t = metadata.target();
23    t.starts_with("lb_rs")
24        || t.starts_with("dbrs")
25        || t.starts_with("workspace")
26        || t.starts_with("lb_fs")
27}
28
29#[cfg(not(target_family = "wasm"))]
30fn trace_targets(metadata: &tracing::Metadata<'_>) -> bool {
31    log_targets(metadata) || metadata.target().starts_with("lockbook_desktop")
32}
33
34fn fmt_layers<S>(config: &Config) -> Vec<Box<dyn Layer<S> + Send + Sync + 'static>>
35where
36    S: Subscriber + for<'a> LookupSpan<'a>,
37{
38    let lockbook_log_level = env::var("LOG_LEVEL")
39        .ok()
40        .and_then(|s| s.as_str().parse().ok())
41        .unwrap_or(LevelFilter::DEBUG);
42
43    let mut layers = Vec::with_capacity(2);
44
45    #[cfg(not(target_arch = "wasm32"))]
46    layers.push(
47        fmt::Layer::new()
48            .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
49            .with_ansi(config.colored_logs)
50            .with_target(true)
51            .with_writer(tracing_appender::rolling::never(&config.writeable_path, LOG_FILE))
52            .with_filter(lockbook_log_level)
53            .with_filter(filter::filter_fn(log_targets))
54            .boxed(),
55    );
56
57    if config.stdout_logs {
58        #[cfg(not(target_os = "android"))]
59        layers.push(
60            fmt::Layer::new()
61                .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
62                .with_ansi(config.colored_logs)
63                .with_target(true)
64                .with_filter(lockbook_log_level)
65                .with_filter(filter::filter_fn(log_targets))
66                .boxed(),
67        );
68        #[cfg(target_os = "android")]
69        if let Some(writer) =
70            tracing_logcat::LogcatMakeWriter::new(tracing_logcat::LogcatTag::Target).ok()
71        {
72            layers.push(
73                fmt::Layer::new()
74                    .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
75                    .with_ansi(false)
76                    .with_writer(writer)
77                    .with_filter(lockbook_log_level)
78                    .with_filter(filter::filter_fn(|metadata| {
79                        let t = metadata.target();
80                        t.starts_with("lb_rs")
81                            || t.starts_with("workspace")
82                            || t.starts_with("lb_java")
83                    }))
84                    .boxed(),
85            );
86        }
87    }
88
89    layers
90}
91
92#[cfg(not(target_family = "wasm"))]
93static TRACE_GUARD: std::sync::OnceLock<tracing_perfetto_file::FlushGuard> =
94    std::sync::OnceLock::new();
95
96#[cfg(not(target_family = "wasm"))]
97fn trace_path(config: &Config) -> Option<std::path::PathBuf> {
98    let requested = env::var(TRACE_ENV_VAR).ok()?;
99    match requested.as_str() {
100        "" | "0" | "false" => None,
101        "1" | "true" => {
102            let stamp = chrono::Local::now().format("%Y%m%d-%H%M%S");
103            Some(
104                std::path::Path::new(&config.writeable_path)
105                    .join("traces")
106                    .join(format!("{stamp}.pftrace")),
107            )
108        }
109        path => Some(std::path::PathBuf::from(path)),
110    }
111}
112
113#[cfg(not(target_family = "wasm"))]
114fn trace_file(path: &std::path::Path) -> std::io::Result<std::fs::File> {
115    if let Some(dir) = path.parent().filter(|dir| !dir.as_os_str().is_empty()) {
116        std::fs::create_dir_all(dir)?;
117    }
118    std::fs::File::create(path)
119}
120
121#[cfg(not(target_family = "wasm"))]
122fn trace_layer<S>(config: &Config) -> Option<Box<dyn Layer<S> + Send + Sync + 'static>>
123where
124    S: Subscriber + for<'a> LookupSpan<'a>,
125{
126    use tracing_perfetto_file::{PerfettoLayer, SpanMode};
127
128    let path = trace_path(config)?;
129
130    let file = match trace_file(&path) {
131        Ok(file) => file,
132        Err(err) => {
133            eprintln!("{TRACE_ENV_VAR}: failed to open {}: {err}", path.display());
134            return None;
135        }
136    };
137
138    let (layer, guard) = PerfettoLayer::builder(file)
139        .span_mode(SpanMode::Both)
140        .with_debug_annotations()
141        .with_source_locations()
142        .with_counters()
143        .build();
144    let _ = TRACE_GUARD.set(guard);
145
146    eprintln!("{TRACE_ENV_VAR}: writing {} (open in https://ui.perfetto.dev)", path.display());
147
148    Some(
149        layer
150            .with_filter(LevelFilter::TRACE)
151            .with_filter(filter::filter_fn(trace_targets))
152            .boxed(),
153    )
154}
155
156/// True once [`init`] has opened a trace file.
157pub fn traces_enabled() -> bool {
158    #[cfg(not(target_family = "wasm"))]
159    {
160        TRACE_GUARD.get().is_some()
161    }
162    #[cfg(target_family = "wasm")]
163    {
164        false
165    }
166}
167
168/// Write buffered spans to the trace file. A no-op when tracing is off; safe to
169/// call from a process exit hook.
170pub fn flush_traces() {
171    #[cfg(not(target_family = "wasm"))]
172    if let Some(guard) = TRACE_GUARD.get() {
173        let _ = guard.flush();
174    }
175}
176
177/// Install the process subscriber: `lockbook.log`, stdout/logcat, and (with
178/// [`TRACE_ENV_VAR`]) a Perfetto trace file. Called by `Lb::init`; call it
179/// earlier from a process entry point to capture boot.
180pub fn init(config: &Config) -> LbResult<()> {
181    if !config.logs {
182        return Ok(());
183    }
184    if tracing::dispatcher::has_been_set() {
185        return Ok(());
186    }
187    if !config.writeable_path.is_empty() {
188        std::fs::create_dir_all(&config.writeable_path).map_err(core_err_unexpected)?;
189    }
190
191    let subscriber = tracing_subscriber::Registry::default().with(fmt_layers(config));
192
193    #[cfg(not(target_family = "wasm"))]
194    let subscriber = subscriber.with(trace_layer(config));
195
196    tracing::subscriber::set_global_default(subscriber).map_err(core_err_unexpected)?;
197    panic_capture(config);
198    Ok(())
199}
200
201fn panic_capture(config: &Config) {
202    let path = config.writeable_path.clone();
203    panic::set_hook(Box::new(move |error_header| {
204        let bt = Backtrace::force_capture();
205        tracing::error!("panic detected: {error_header} {}", bt);
206        eprintln!("panic detected and logged: {error_header} {bt}");
207        let file_name = generate_panic_filename(&path);
208        let content = generate_panic_content(&error_header.to_string(), &bt.to_string());
209
210        let mut file = OpenOptions::new()
211            .create(true)
212            .append(true)
213            .open(&file_name)
214            .unwrap();
215
216        file.write_all(content.as_bytes()).unwrap();
217
218        flush_traces();
219    }));
220}
221
222#[cfg(all(test, not(target_family = "wasm")))]
223mod tests {
224    use super::*;
225    use crate::model::core_config::ClientType;
226
227    #[test]
228    fn lb_trace_writes_a_pftrace() {
229        let path = std::env::temp_dir().join("lockbook-lb-trace-smoke.pftrace");
230        let _ = std::fs::remove_file(&path);
231        env::set_var(TRACE_ENV_VAR, &path);
232
233        let config = Config {
234            writeable_path: String::new(),
235            background_work: false,
236            logs: true,
237            stdout_logs: false,
238            colored_logs: false,
239            client_type: ClientType::Unknown,
240        };
241        let subscriber = tracing_subscriber::Registry::default().with(trace_layer(&config));
242        env::remove_var(TRACE_ENV_VAR);
243
244        tracing::subscriber::with_default(subscriber, || {
245            let _span = tracing::trace_span!("smoke").entered();
246            tracing::trace!(counter.rss_bytes = 1u64, "sample");
247        });
248        flush_traces();
249
250        let len = std::fs::metadata(&path).expect("stat trace file").len();
251        assert!(len > 0, "expected a non-empty .pftrace");
252        let _ = std::fs::remove_file(&path);
253    }
254}
lb_rs/service/logging.rs

lb_rs/service/
logging.rs
