matrix_sdk_ffi/
platform.rs

Help
1use tracing_appender::rolling::{RollingFileAppender, Rotation};
2use tracing_core::Subscriber;
3use tracing_subscriber::{
4    field::RecordFields,
5    fmt::{
6        self,
7        format::{DefaultFields, Writer},
8        time::FormatTime,
9        FormatEvent, FormatFields, FormattedFields,
10    },
11    layer::SubscriberExt,
12    registry::LookupSpan,
13    util::SubscriberInitExt,
14    EnvFilter, Layer,
15};
16
17use crate::tracing::LogLevel;
18
19pub fn log_panics() {
20    std::env::set_var("RUST_BACKTRACE", "1");
21
22    log_panics::init();
23}
24
25fn text_layers<S>(config: TracingConfiguration) -> impl Layer<S>
26where
27    S: Subscriber + for<'a> LookupSpan<'a>,
28{
29    // Adjusted version of tracing_subscriber::fmt::Format
30    struct EventFormatter {
31        display_timestamp: bool,
32        display_level: bool,
33    }
34
35    impl EventFormatter {
36        fn new() -> Self {
37            Self { display_timestamp: true, display_level: true }
38        }
39
40        #[cfg(target_os = "android")]
41        fn for_logcat() -> Self {
42            // Level and time are already captured by logcat separately
43            Self { display_timestamp: false, display_level: false }
44        }
45
46        fn format_timestamp(&self, writer: &mut fmt::format::Writer<'_>) -> std::fmt::Result {
47            if fmt::time::SystemTime.format_time(writer).is_err() {
48                writer.write_str("<unknown time>")?;
49            }
50            Ok(())
51        }
52
53        fn write_filename(
54            &self,
55            writer: &mut fmt::format::Writer<'_>,
56            filename: &str,
57        ) -> std::fmt::Result {
58            const CRATES_IO_PATH_MATCHER: &str = ".cargo/registry/src/index.crates.io";
59            let crates_io_filename = filename
60                .split_once(CRATES_IO_PATH_MATCHER)
61                .and_then(|(_, rest)| rest.split_once('/').map(|(_, rest)| rest));
62
63            if let Some(filename) = crates_io_filename {
64                writer.write_str("<crates.io>/")?;
65                writer.write_str(filename)
66            } else {
67                writer.write_str(filename)
68            }
69        }
70    }
71
72    impl<S, N> FormatEvent<S, N> for EventFormatter
73    where
74        S: Subscriber + for<'a> LookupSpan<'a>,
75        N: for<'a> FormatFields<'a> + 'static,
76    {
77        fn format_event(
78            &self,
79            ctx: &fmt::FmtContext<'_, S, N>,
80            mut writer: fmt::format::Writer<'_>,
81            event: &tracing_core::Event<'_>,
82        ) -> std::fmt::Result {
83            let meta = event.metadata();
84
85            if self.display_timestamp {
86                self.format_timestamp(&mut writer)?;
87                writer.write_char(' ')?;
88            }
89
90            if self.display_level {
91                // For info and warn, add a padding space to the left
92                write!(writer, "{:>5} ", meta.level())?;
93            }
94
95            write!(writer, "{}: ", meta.target())?;
96
97            ctx.format_fields(writer.by_ref(), event)?;
98
99            if let Some(filename) = meta.file() {
100                writer.write_str(" | ")?;
101                self.write_filename(&mut writer, filename)?;
102                if let Some(line_number) = meta.line() {
103                    write!(writer, ":{line_number}")?;
104                }
105            }
106
107            if let Some(scope) = ctx.event_scope() {
108                writer.write_str(" | spans: ")?;
109
110                let mut first = true;
111
112                for span in scope.from_root() {
113                    if !first {
114                        writer.write_str(" > ")?;
115                    }
116
117                    first = false;
118
119                    write!(writer, "{}", span.name())?;
120
121                    if let Some(fields) = &span.extensions().get::<FormattedFields<N>>() {
122                        if !fields.is_empty() {
123                            write!(writer, "{{{fields}}}")?;
124                        }
125                    }
126                }
127            }
128
129            writeln!(writer)
130        }
131    }
132
133    let file_layer = config.write_to_files.map(|c| {
134        let mut builder = RollingFileAppender::builder()
135            .rotation(Rotation::HOURLY)
136            .filename_prefix(&c.file_prefix);
137
138        if let Some(max_files) = c.max_files {
139            builder = builder.max_log_files(max_files as usize)
140        };
141        if let Some(file_suffix) = c.file_suffix {
142            builder = builder.filename_suffix(file_suffix)
143        }
144
145        let writer = builder.build(&c.path).expect("Failed to create a rolling file appender.");
146
147        // Another fields formatter is necessary because of this bug
148        // https://github.com/tokio-rs/tracing/issues/1372. Using a new
149        // formatter for the fields forces to record them in different span
150        // extensions, and thus remove the duplicated fields in the span.
151        #[derive(Default)]
152        struct FieldsFormatterForFiles(DefaultFields);
153
154        impl<'writer> FormatFields<'writer> for FieldsFormatterForFiles {
155            fn format_fields<R: RecordFields>(
156                &self,
157                writer: Writer<'writer>,
158                fields: R,
159            ) -> std::fmt::Result {
160                self.0.format_fields(writer, fields)
161            }
162        }
163
164        fmt::layer()
165            .fmt_fields(FieldsFormatterForFiles::default())
166            .event_format(EventFormatter::new())
167            // EventFormatter doesn't support ANSI colors anyways, but the
168            // default field formatter does, which is unhelpful for iOS +
169            // Android logs, but enabled by default.
170            .with_ansi(false)
171            .with_writer(writer)
172    });
173
174    Layer::and_then(
175        file_layer,
176        config.write_to_stdout_or_system.then(|| {
177            // Another fields formatter is necessary because of this bug
178            // https://github.com/tokio-rs/tracing/issues/1372. Using a new
179            // formatter for the fields forces to record them in different span
180            // extensions, and thus remove the duplicated fields in the span.
181            #[derive(Default)]
182            struct FieldsFormatterFormStdoutOrSystem(DefaultFields);
183
184            impl<'writer> FormatFields<'writer> for FieldsFormatterFormStdoutOrSystem {
185                fn format_fields<R: RecordFields>(
186                    &self,
187                    writer: Writer<'writer>,
188                    fields: R,
189                ) -> std::fmt::Result {
190                    self.0.format_fields(writer, fields)
191                }
192            }
193
194            #[cfg(not(target_os = "android"))]
195            return fmt::layer()
196                .fmt_fields(FieldsFormatterFormStdoutOrSystem::default())
197                .event_format(EventFormatter::new())
198                // See comment above.
199                .with_ansi(false)
200                .with_writer(std::io::stderr);
201
202            #[cfg(target_os = "android")]
203            return fmt::layer()
204                .fmt_fields(FieldsFormatterFormStdoutOrSystem::default())
205                .event_format(EventFormatter::for_logcat())
206                // See comment above.
207                .with_ansi(false)
208                .with_writer(paranoid_android::AndroidLogMakeWriter::new(
209                    "org.matrix.rust.sdk".to_owned(),
210                ));
211        }),
212    )
213}
214
215/// Configuration to save logs to (rotated) log-files.
216#[derive(uniffi::Record)]
217pub struct TracingFileConfiguration {
218    /// Base location for all the log files.
219    path: String,
220
221    /// Prefix for the log files' names.
222    file_prefix: String,
223
224    /// Optional suffix for the log file's names.
225    file_suffix: Option<String>,
226
227    /// Maximum number of rotated files.
228    ///
229    /// If not set, there's no max limit, i.e. the number of log files is
230    /// unlimited.
231    max_files: Option<u64>,
232}
233
234#[derive(PartialEq, PartialOrd)]
235enum LogTarget {
236    // External crates.
237    Hyper,
238
239    // FFI modules.
240    MatrixSdkFfi,
241
242    // SDK base modules.
243    MatrixSdkBaseEventCache,
244    MatrixSdkBaseSlidingSync,
245    MatrixSdkBaseStoreAmbiguityMap,
246
247    // SDK common modules.
248    MatrixSdkCommonStoreLocks,
249
250    // SDK modules.
251    MatrixSdk,
252    MatrixSdkClient,
253    MatrixSdkCrypto,
254    MatrixSdkCryptoAccount,
255    MatrixSdkEventCache,
256    MatrixSdkEventCacheStore,
257    MatrixSdkHttpClient,
258    MatrixSdkOidc,
259    MatrixSdkSendQueue,
260    MatrixSdkSlidingSync,
261
262    // SDK UI modules.
263    MatrixSdkUiTimeline,
264}
265
266impl LogTarget {
267    fn as_str(&self) -> &'static str {
268        match self {
269            LogTarget::Hyper => "hyper",
270            LogTarget::MatrixSdkFfi => "matrix_sdk_ffi",
271            LogTarget::MatrixSdkBaseEventCache => "matrix_sdk_base::event_cache",
272            LogTarget::MatrixSdkBaseSlidingSync => "matrix_sdk_base::sliding_sync",
273            LogTarget::MatrixSdkBaseStoreAmbiguityMap => "matrix_sdk_base::store::ambiguity_map",
274            LogTarget::MatrixSdkCommonStoreLocks => "matrix_sdk_common::store_locks",
275            LogTarget::MatrixSdk => "matrix_sdk",
276            LogTarget::MatrixSdkClient => "matrix_sdk::client",
277            LogTarget::MatrixSdkCrypto => "matrix_sdk_crypto",
278            LogTarget::MatrixSdkCryptoAccount => "matrix_sdk_crypto::olm::account",
279            LogTarget::MatrixSdkOidc => "matrix_sdk::oidc",
280            LogTarget::MatrixSdkHttpClient => "matrix_sdk::http_client",
281            LogTarget::MatrixSdkSlidingSync => "matrix_sdk::sliding_sync",
282            LogTarget::MatrixSdkEventCache => "matrix_sdk::event_cache",
283            LogTarget::MatrixSdkSendQueue => "matrix_sdk::send_queue",
284            LogTarget::MatrixSdkEventCacheStore => "matrix_sdk_sqlite::event_cache_store",
285            LogTarget::MatrixSdkUiTimeline => "matrix_sdk_ui::timeline",
286        }
287    }
288}
289
290const DEFAULT_TARGET_LOG_LEVELS: &[(LogTarget, LogLevel)] = &[
291    (LogTarget::Hyper, LogLevel::Warn),
292    (LogTarget::MatrixSdkFfi, LogLevel::Info),
293    (LogTarget::MatrixSdk, LogLevel::Info),
294    (LogTarget::MatrixSdkClient, LogLevel::Trace),
295    (LogTarget::MatrixSdkCrypto, LogLevel::Debug),
296    (LogTarget::MatrixSdkCryptoAccount, LogLevel::Trace),
297    (LogTarget::MatrixSdkOidc, LogLevel::Trace),
298    (LogTarget::MatrixSdkHttpClient, LogLevel::Debug),
299    (LogTarget::MatrixSdkSlidingSync, LogLevel::Info),
300    (LogTarget::MatrixSdkBaseSlidingSync, LogLevel::Info),
301    (LogTarget::MatrixSdkUiTimeline, LogLevel::Info),
302    (LogTarget::MatrixSdkSendQueue, LogLevel::Info),
303    (LogTarget::MatrixSdkEventCache, LogLevel::Info),
304    (LogTarget::MatrixSdkBaseEventCache, LogLevel::Info),
305    (LogTarget::MatrixSdkEventCacheStore, LogLevel::Info),
306    (LogTarget::MatrixSdkCommonStoreLocks, LogLevel::Warn),
307    (LogTarget::MatrixSdkBaseStoreAmbiguityMap, LogLevel::Warn),
308];
309
310const IMMUTABLE_LOG_TARGETS: &[LogTarget] = &[
311    LogTarget::Hyper,                          // Too verbose
312    LogTarget::MatrixSdk,                      // Too generic
313    LogTarget::MatrixSdkFfi,                   // Too verbose
314    LogTarget::MatrixSdkCommonStoreLocks,      // Too verbose
315    LogTarget::MatrixSdkBaseStoreAmbiguityMap, // Too verbose
316];
317
318/// A log pack can be used to set the trace log level for a group of multiple
319/// log targets at once, for debugging purposes.
320#[derive(uniffi::Enum)]
321pub enum TraceLogPacks {
322    /// Enables all the logs relevant to the event cache.
323    EventCache,
324    /// Enables all the logs relevant to the send queue.
325    SendQueue,
326    /// Enables all the logs relevant to the timeline.
327    Timeline,
328}
329
330impl TraceLogPacks {
331    // Note: all the log targets returned here must be part of
332    // `DEFAULT_TARGET_LOG_LEVELS`.
333    fn targets(&self) -> &[LogTarget] {
334        match self {
335            TraceLogPacks::EventCache => &[
336                LogTarget::MatrixSdkEventCache,
337                LogTarget::MatrixSdkBaseEventCache,
338                LogTarget::MatrixSdkEventCacheStore,
339            ],
340            TraceLogPacks::SendQueue => &[LogTarget::MatrixSdkSendQueue],
341            TraceLogPacks::Timeline => &[LogTarget::MatrixSdkUiTimeline],
342        }
343    }
344}
345
346#[derive(uniffi::Record)]
347pub struct TracingConfiguration {
348    /// The desired log level.
349    log_level: LogLevel,
350
351    /// All the log packs, that will be set to `TRACE` when they're enabled.
352    trace_log_packs: Vec<TraceLogPacks>,
353
354    /// Additional targets that the FFI client would like to use.
355    ///
356    /// This can include, for instance, the target names for created
357    /// [`crate::tracing::Span`]. These targets will use the global log level by
358    /// default.
359    extra_targets: Vec<String>,
360
361    /// Whether to log to stdout, or in the logcat on Android.
362    write_to_stdout_or_system: bool,
363
364    /// If set, configures rotated log files where to write additional logs.
365    write_to_files: Option<TracingFileConfiguration>,
366}
367
368fn build_tracing_filter(config: &TracingConfiguration) -> String {
369    // We are intentionally not setting a global log level because we don't want to
370    // risk third party crates logging sensitive information.
371    // As such we need to make sure that panics will be properly logged.
372    // On 2025-01-08, `log_panics` uses the `panic` target, at the error log level.
373    let mut filters = vec!["panic=error".to_owned()];
374
375    let global_level = config.log_level;
376
377    DEFAULT_TARGET_LOG_LEVELS.iter().for_each(|(target, default_level)| {
378        let level = if IMMUTABLE_LOG_TARGETS.contains(target) {
379            // If the target is immutable, keep the log level.
380            *default_level
381        } else if config.trace_log_packs.iter().any(|pack| pack.targets().contains(target)) {
382            // If a log pack includes that target, set the associated log level to TRACE.
383            LogLevel::Trace
384        } else if *default_level > global_level {
385            // If the default level is more verbose than the global level, keep the default.
386            *default_level
387        } else {
388            // Otherwise, use the global level.
389            global_level
390        };
391
392        filters.push(format!("{}={}", target.as_str(), level.as_str()));
393    });
394
395    // Finally append the extra targets requested by the client.
396    for target in &config.extra_targets {
397        filters.push(format!("{}={}", target, config.log_level.as_str()));
398    }
399
400    filters.join(",")
401}
402
403/// Sets up logs and the tokio runtime for the current application.
404///
405/// If `use_lightweight_tokio_runtime` is set to true, this will set up a
406/// lightweight tokio runtime, for processes that have memory limitations (like
407/// the NSE process on iOS). Otherwise, this can remain false, in which case a
408/// multithreaded tokio runtime will be set up.
409#[matrix_sdk_ffi_macros::export]
410pub fn init_platform(config: TracingConfiguration, use_lightweight_tokio_runtime: bool) {
411    log_panics();
412
413    let env_filter = build_tracing_filter(&config);
414
415    tracing_subscriber::registry()
416        .with(EnvFilter::new(&env_filter))
417        .with(text_layers(config))
418        .init();
419
420    // Log the log levels 🧠.
421    tracing::info!(env_filter, "Logging has been set up");
422
423    if use_lightweight_tokio_runtime {
424        setup_lightweight_tokio_runtime();
425    } else {
426        setup_multithreaded_tokio_runtime();
427    }
428}
429
430fn setup_multithreaded_tokio_runtime() {
431    async_compat::set_runtime_builder(Box::new(|| {
432        eprintln!("spawning a multithreaded tokio runtime");
433
434        let mut builder = tokio::runtime::Builder::new_multi_thread();
435        builder.enable_all();
436        builder
437    }));
438}
439
440fn setup_lightweight_tokio_runtime() {
441    async_compat::set_runtime_builder(Box::new(|| {
442        eprintln!("spawning a lightweight tokio runtime");
443
444        // Get the number of available cores through the system, if possible.
445        let num_available_cores =
446            std::thread::available_parallelism().map(|n| n.get()).unwrap_or(1);
447
448        // The number of worker threads will be either that or 4, whichever is smaller.
449        let num_worker_threads = num_available_cores.min(4);
450
451        // Chosen by a fair dice roll.
452        let num_blocking_threads = 2;
453
454        // 1 MiB of memory per worker thread. Should be enough for everyone™.
455        let max_memory_bytes = 1024 * 1024;
456
457        let mut builder = tokio::runtime::Builder::new_multi_thread();
458
459        builder
460            .enable_all()
461            .worker_threads(num_worker_threads)
462            .thread_stack_size(max_memory_bytes)
463            .max_blocking_threads(num_blocking_threads);
464
465        builder
466    }));
467}
468
469#[cfg(test)]
470mod tests {
471    use super::build_tracing_filter;
472    use crate::platform::TraceLogPacks;
473
474    #[test]
475    fn test_default_tracing_filter() {
476        let config = super::TracingConfiguration {
477            log_level: super::LogLevel::Error,
478            trace_log_packs: Vec::new(),
479            extra_targets: vec!["super_duper_app".to_owned()],
480            write_to_stdout_or_system: true,
481            write_to_files: None,
482        };
483
484        let filter = build_tracing_filter(&config);
485
486        assert_eq!(
487            filter,
488            "panic=error,\
489            hyper=warn,\
490            matrix_sdk_ffi=info,\
491            matrix_sdk=info,\
492            matrix_sdk::client=trace,\
493            matrix_sdk_crypto=debug,\
494            matrix_sdk_crypto::olm::account=trace,\
495            matrix_sdk::oidc=trace,\
496            matrix_sdk::http_client=debug,\
497            matrix_sdk::sliding_sync=info,\
498            matrix_sdk_base::sliding_sync=info,\
499            matrix_sdk_ui::timeline=info,\
500            matrix_sdk::send_queue=info,\
501            matrix_sdk::event_cache=info,\
502            matrix_sdk_base::event_cache=info,\
503            matrix_sdk_sqlite::event_cache_store=info,\
504            matrix_sdk_common::store_locks=warn,\
505            matrix_sdk_base::store::ambiguity_map=warn,\
506            super_duper_app=error"
507        );
508    }
509
510    #[test]
511    fn test_trace_tracing_filter() {
512        let config = super::TracingConfiguration {
513            log_level: super::LogLevel::Trace,
514            trace_log_packs: Vec::new(),
515            extra_targets: vec!["super_duper_app".to_owned(), "some_other_span".to_owned()],
516            write_to_stdout_or_system: true,
517            write_to_files: None,
518        };
519
520        let filter = build_tracing_filter(&config);
521
522        assert_eq!(
523            filter,
524            "panic=error,\
525            hyper=warn,\
526            matrix_sdk_ffi=info,\
527            matrix_sdk=info,\
528            matrix_sdk::client=trace,\
529            matrix_sdk_crypto=trace,\
530            matrix_sdk_crypto::olm::account=trace,\
531            matrix_sdk::oidc=trace,\
532            matrix_sdk::http_client=trace,\
533            matrix_sdk::sliding_sync=trace,\
534            matrix_sdk_base::sliding_sync=trace,\
535            matrix_sdk_ui::timeline=trace,\
536            matrix_sdk::send_queue=trace,\
537            matrix_sdk::event_cache=trace,\
538            matrix_sdk_base::event_cache=trace,\
539            matrix_sdk_sqlite::event_cache_store=trace,\
540            matrix_sdk_common::store_locks=warn,\
541            matrix_sdk_base::store::ambiguity_map=warn,\
542            super_duper_app=trace,\
543            some_other_span=trace"
544        );
545    }
546
547    #[test]
548    fn test_trace_log_packs() {
549        let config = super::TracingConfiguration {
550            log_level: super::LogLevel::Info,
551            trace_log_packs: vec![TraceLogPacks::EventCache, TraceLogPacks::SendQueue],
552            extra_targets: vec!["super_duper_app".to_owned()],
553            write_to_stdout_or_system: true,
554            write_to_files: None,
555        };
556
557        let filter = build_tracing_filter(&config);
558
559        assert_eq!(
560            filter,
561            r#"panic=error,
562            hyper=warn,
563            matrix_sdk_ffi=info,
564            matrix_sdk=info,
565            matrix_sdk::client=trace,
566            matrix_sdk_crypto=debug,
567            matrix_sdk_crypto::olm::account=trace,
568            matrix_sdk::oidc=trace,
569            matrix_sdk::http_client=debug,
570            matrix_sdk::sliding_sync=info,
571            matrix_sdk_base::sliding_sync=info,
572            matrix_sdk_ui::timeline=info,
573            matrix_sdk::send_queue=trace,
574            matrix_sdk::event_cache=trace,
575            matrix_sdk_base::event_cache=trace,
576            matrix_sdk_sqlite::event_cache_store=trace,
577            matrix_sdk_common::store_locks=warn,
578            matrix_sdk_base::store::ambiguity_map=warn,
579            super_duper_app=info"#
580                .split('\n')
581                .map(|s| s.trim())
582                .collect::<Vec<_>>()
583                .join("")
584        );
585    }
586}
matrix_sdk_ffi/platform.rs

matrix_sdk_ffi/
platform.rs
