Skip to content

Commit

Permalink
feat(ffi): move tracing setup from the final client to the ffi layer
Browse files Browse the repository at this point in the history
Having the final clients define the tracing filters / log levels proved to be tricky to keep in check resulting missing logs (e.g. recently introduced modules like the event cache) or unexpected behaviors (e.g. missing panics because we don't set a global filter). As such we decided to move the tracing setup and default definitions over to the rust side and let rust developers have full control over them.

We will now take a general log level and the final client's target name and apply them on top of the rust side defined default. Targets that log more than the requested by default will remain unchanged while the others will increase their log levels to match. Certain targets like `hyper` will be ignored in this step as they're too verbose.
  • Loading branch information
stefanceriu committed Jan 9, 2025
1 parent df4b696 commit dcfc9d0
Show file tree
Hide file tree
Showing 2 changed files with 151 additions and 38 deletions.
179 changes: 141 additions & 38 deletions bindings/matrix-sdk-ffi/src/platform.rs
Original file line number Diff line number Diff line change
Expand Up @@ -14,25 +14,11 @@ use tracing_subscriber::{
EnvFilter, Layer,
};

/// Add panic=error to a filter line, if it's missing from it.
///
/// Doesn't do anything if the directive is already present.
fn add_panic_to_filter(filter: &mut String) {
if filter.split(',').all(|pair| pair.split('=').next().is_none_or(|lhs| lhs != "panic")) {
if !filter.is_empty() {
filter.push(',');
}
filter.push_str("panic=error");
}
}
use crate::tracing::LogLevel;

pub fn log_panics(filter: &mut String) {
pub fn log_panics() {
std::env::set_var("RUST_BACKTRACE", "1");

// Make sure that panics will be properly logged. On 2025-01-08, `log_panics`
// uses the `panic` target, at the error log level.
add_panic_to_filter(filter);

log_panics::init();
}

Expand Down Expand Up @@ -245,12 +231,65 @@ pub struct TracingFileConfiguration {
max_files: Option<u64>,
}

#[derive(PartialEq, PartialOrd)]
enum LogTarget {
Hyper,
MatrixSDKFFI,
MatrixSDKClient,
MatrixSDKCrypto,
MatrixSDKCryptoAccount,
MatrixSDKOIDC,
MatrixSDKHTTPClient,
MatrixSDKSlidingSync,
MatrixSDKBaseSlidingSync,
MatrixSDKUITimeline,
MatrixSDKEventCache,
MatrixSDKEventCacheStore,
}

impl LogTarget {
fn as_str(&self) -> &'static str {
match self {
LogTarget::Hyper => "hyper",
LogTarget::MatrixSDKFFI => "matrix_sdk_ffi",
LogTarget::MatrixSDKClient => "matrix_sdk::client",
LogTarget::MatrixSDKCrypto => "matrix_sdk_crypto",
LogTarget::MatrixSDKCryptoAccount => "matrix_sdk_crypto::olm::account",
LogTarget::MatrixSDKOIDC => "matrix_sdk::oidc",
LogTarget::MatrixSDKHTTPClient => "matrix_sdk::http_client",
LogTarget::MatrixSDKSlidingSync => "matrix_sdk::sliding_sync",
LogTarget::MatrixSDKBaseSlidingSync => "matrix_sdk_base::sliding_sync",
LogTarget::MatrixSDKUITimeline => "matrix_sdk_ui::timeline",
LogTarget::MatrixSDKEventCache => "matrix_sdk::event_cache",
LogTarget::MatrixSDKEventCacheStore => "matrix_sdk_sqlite::event_cache_store",
}
}
}

const DEFAULT_TARGET_LOG_LEVELS: &'static [(LogTarget, LogLevel)] = &[
(LogTarget::Hyper, LogLevel::Warn),
(LogTarget::MatrixSDKFFI, LogLevel::Info),
(LogTarget::MatrixSDKClient, LogLevel::Trace),
(LogTarget::MatrixSDKCrypto, LogLevel::Debug),
(LogTarget::MatrixSDKCryptoAccount, LogLevel::Trace),
(LogTarget::MatrixSDKOIDC, LogLevel::Trace),
(LogTarget::MatrixSDKHTTPClient, LogLevel::Debug),
(LogTarget::MatrixSDKSlidingSync, LogLevel::Info),
(LogTarget::MatrixSDKBaseSlidingSync, LogLevel::Info),
(LogTarget::MatrixSDKUITimeline, LogLevel::Info),
(LogTarget::MatrixSDKEventCache, LogLevel::Info),
(LogTarget::MatrixSDKEventCacheStore, LogLevel::Info),
];

const IMMUTABLE_TARGET_LOG_LEVELS: &'static [LogTarget] = &[LogTarget::Hyper];

#[derive(uniffi::Record)]
pub struct TracingConfiguration {
/// A filter line following the [RUST_LOG format].
///
/// [RUST_LOG format]: https://rust-lang-nursery.github.io/rust-cookbook/development_tools/debugging/config_log.html
filter: String,
/// The desired LogLevel, corresponding to https://docs.rs/log/latest/log/enum.Level.html
log_level: LogLevel,

/// The target name under which the FFI client will log messages using `tracing::log_event`
app_target: String,

/// Whether to log to stdout, or in the logcat on Android.
write_to_stdout_or_system: bool,
Expand All @@ -259,38 +298,102 @@ pub struct TracingConfiguration {
write_to_files: Option<TracingFileConfiguration>,
}

fn build_tracing_filter(config: &TracingConfiguration) -> String {
// We are intentionally not setting a global log level because we don't want to risk
// 3rd party crates logging sensitive information.
// As such we need to make sure that panics will be properly logged.
// On 2025-01-08, `log_panics` uses the `panic` target, at the error log level.
let mut filters = vec!["panic=error".to_string()];

// We're also need to include the target name that the FII client uses
filters.push(format!("{}={}", config.app_target, config.log_level.as_str()));

DEFAULT_TARGET_LOG_LEVELS.iter().for_each(|(target, level)| {
// Use the default if the log level shouldn't be changed for this target or
// if it's already logging more than requested
let level = if IMMUTABLE_TARGET_LOG_LEVELS.contains(target) || level > &config.log_level {
level.as_str()
} else {
&config.log_level.as_str()
};

filters.push(format!("{}={}", target.as_str(), level));
});

filters.join(",")
}

#[matrix_sdk_ffi_macros::export]
pub fn setup_tracing(mut config: TracingConfiguration) {
log_panics(&mut config.filter);
pub fn setup_tracing(config: TracingConfiguration) {
log_panics();

tracing_subscriber::registry()
.with(EnvFilter::new(&config.filter))
.with(EnvFilter::new(build_tracing_filter(&config)))
.with(text_layers(config))
.init();
}

#[cfg(test)]
mod tests {
use super::add_panic_to_filter;
use super::build_tracing_filter;

#[test]
fn test_add_panic_when_not_provided_empty() {
let mut filter = String::from("");
add_panic_to_filter(&mut filter);
assert_eq!(filter, "panic=error");
}
fn test_default_tracing_filter() {
let config = super::TracingConfiguration {
log_level: super::LogLevel::Error,
app_target: "super_duper_app".to_string(),
write_to_stdout_or_system: true,
write_to_files: None,
};

#[test]
fn test_add_panic_when_not_provided_non_empty() {
let mut filter = String::from("a=b,c=d");
add_panic_to_filter(&mut filter);
assert_eq!(filter, "a=b,c=d,panic=error");
let filter = build_tracing_filter(&config);

assert_eq!(
filter,
"panic=error,\
super_duper_app=error,\
hyper=warn,\
matrix_sdk_ffi=info,\
matrix_sdk::client=trace,\
matrix_sdk_crypto=debug,\
matrix_sdk_crypto::olm::account=trace,\
matrix_sdk::oidc=trace,\
matrix_sdk::http_client=debug,\
matrix_sdk::sliding_sync=info,\
matrix_sdk_base::sliding_sync=info,\
matrix_sdk_ui::timeline=info,\
matrix_sdk::event_cache=info,\
matrix_sdk_sqlite::event_cache_store=info"
);
}

#[test]
fn test_do_nothing_when_provided() {
let mut filter = String::from("a=b,panic=info,c=d");
add_panic_to_filter(&mut filter);
assert_eq!(filter, "a=b,panic=info,c=d");
fn test_trace_tracing_filter() {
let config = super::TracingConfiguration {
log_level: super::LogLevel::Trace,
app_target: "super_duper_app".to_string(),
write_to_stdout_or_system: true,
write_to_files: None,
};

let filter = build_tracing_filter(&config);

assert_eq!(
filter,
"panic=error,\
super_duper_app=trace,\
hyper=warn,\
matrix_sdk_ffi=trace,\
matrix_sdk::client=trace,\
matrix_sdk_crypto=trace,\
matrix_sdk_crypto::olm::account=trace,\
matrix_sdk::oidc=trace,\
matrix_sdk::http_client=trace,\
matrix_sdk::sliding_sync=trace,\
matrix_sdk_base::sliding_sync=trace,\
matrix_sdk_ui::timeline=trace,\
matrix_sdk::event_cache=trace,\
matrix_sdk_sqlite::event_cache_store=trace"
);
}
}
10 changes: 10 additions & 0 deletions bindings/matrix-sdk-ffi/src/tracing.rs
Original file line number Diff line number Diff line change
Expand Up @@ -185,6 +185,16 @@ impl LogLevel {
LogLevel::Trace => tracing::Level::TRACE,
}
}

pub(crate) fn as_str(&self) -> &'static str {
match self {
LogLevel::Error => "error",
LogLevel::Warn => "warn",
LogLevel::Info => "info",
LogLevel::Debug => "debug",
LogLevel::Trace => "trace",
}
}
}

#[derive(PartialEq, Eq, PartialOrd, Ord)]
Expand Down

0 comments on commit dcfc9d0

Please sign in to comment.