From e22f0cca387657ef3949c83cffba07cda330b431 Mon Sep 17 00:00:00 2001 From: Marcin Radomski Date: Tue, 4 Mar 2025 16:09:06 +0000 Subject: [PATCH 1/5] Use __android_log_is_loggable in AndroidLogger::enabled Android's C logging API determines the effective log level based on a combination [1] of a global variable, system-wide properties [2], and call-specific default. log + android_logger crates add another layer of log filtering on top of that, independent from the C API. ``` .-----. | app | '-----' | v .-----------. filter by STATIC_MAX_LEVEL [3] + | log crate | - MAX_LOG_LEVEL_FILTER [4], '-----------' overrideable via log::set_max_level | v .----------------------. | android_logger crate | - filter by Config::max_level [5] '----------------------' | v .--------. | liblog | - filter by global state or system-wide properties [2] '--------' ``` The result is that in mixed C/C++ + Rust applications, logs originating from Rust use the least verbose level configured, which sometimes results in unexpected loss of logs. In addition, adjusting the log level globally via system properties, very useful in work on the AOSP itself, currently works only up to the level android_logger defaults to. This change makes AndroidLogger completely delegate log filtering to the underlying liblog when Config::max_level is unset by using __android_log_is_loggable. Setting Config::max_level, or calling log::set_max_level still keep the existing behavior of filtering the logs before they reach liblog, but the default is now to have the log level consistent between Rust and C/C++ logs. It also removes one TODO from the code :) Tested by: - running a test app that uses Rust logs of all levels on a rooted device, using both Android's liblog C API and android_logger ones - adjusting the log.tag system property [2] via adb shell setprop - verifying the message filtering changes according to log.tag changes consistently for logs from both languages [1] https://cs.android.com/android/platform/superproject/main/+/main:system/logging/liblog/properties.cpp;l=243;drc=b74a506c1b69f5b295a8cdfd7e2da3b16db15934 [2] https://cs.android.com/android/platform/superproject/main/+/main:system/logging/logd/README.property;l=45;drc=99c545d3098018a544cb292e1501daca694bee0f [3] https://github.com/rust-lang/log/blob/0551261bb4588b7f8afc8be05640347c97b67e10/src/lib.rs#L1536 [4] https://github.com/rust-lang/log/blob/0551261bb4588b7f8afc8be05640347c97b67e10/src/lib.rs#L469 [5] https://github.com/rust-mobile/android_logger-rs/blob/d51b7ffdacf20fb09fd36a6b309b50240ef50728/src/lib.rs#L198 --- Cargo.toml | 3 +- src/config.rs | 60 ++++++++++++++++++++++++++++++++++++-- src/lib.rs | 3 +- src/platform_log_writer.rs | 8 +++-- 4 files changed, 67 insertions(+), 7 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 07a4d12..752f6e4 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -25,12 +25,13 @@ targets = [ [features] default = ["regex"] regex = ["env_filter/regex"] +android-api-30 = [] [dependencies.log] version = "0.4" [dependencies.android_log-sys] -version = "0.3" +version = "0.3.2" [dependencies.env_filter] version = "0.1" diff --git a/src/config.rs b/src/config.rs index f4bd657..bd14f58 100644 --- a/src/config.rs +++ b/src/config.rs @@ -31,6 +31,56 @@ impl fmt::Debug for Config { } } +#[cfg(all(target_os = "android", feature = "android-api-30"))] +fn android_log_priority_from_level(level: Level) -> android_log_sys::LogPriority { + match level { + Level::Warn => android_log_sys::LogPriority::WARN, + Level::Info => android_log_sys::LogPriority::INFO, + Level::Debug => android_log_sys::LogPriority::DEBUG, + Level::Error => android_log_sys::LogPriority::ERROR, + Level::Trace => android_log_sys::LogPriority::VERBOSE, + } +} + +/// Asks Android liblog if a message with given `tag` and `priority` should be logged, using +/// `default_prio` as the level filter in case no system- or process-wide overrides are set. +#[cfg(all(target_os = "android", feature = "android-api-30"))] +fn android_is_loggable_len( + prio: log_ffi::LogPriority, + tag: &str, + default_prio: log_ffi::LogPriority, +) -> bool { + // SAFETY: tag points to a valid string tag.len() bytes long. + unsafe { + log_ffi::__android_log_is_loggable_len( + prio as log_ffi::c_int, + tag.as_ptr() as *const log_ffi::c_char, + tag.len() as log_ffi::c_size_t, + default_prio as log_ffi::c_int, + ) != 0 + } +} + +#[cfg(not(all(target_os = "android", feature = "android-api-30")))] +fn default_is_loggable(_tag: &str, record_level: Level, config_level: Option) -> bool { + record_level <= config_level.unwrap_or_else(log::max_level) +} + +#[cfg(all(target_os = "android", feature = "android-api-30"))] +fn android_is_loggable(tag: &str, record_level: Level, config_level: Option) -> bool { + let prio = android_log_priority_from_level(record_level); + // Priority to use in case no system-wide or process-wide overrides are set. + let default_prio = match config_level { + Some(level_filter) => match level_filter.to_level() { + Some(level) => android_log_priority_from_level(level), + // LevelFilter::to_level() returns None only for LevelFilter::Off + None => android_log_sys::LogPriority::SILENT, + }, + None => android_log_sys::LogPriority::INFO, + }; + android_is_loggable_len(prio, tag, default_prio) +} + impl Config { /// Changes the maximum log level. /// @@ -64,9 +114,13 @@ impl Config { } } - pub(crate) fn is_loggable(&self, level: Level) -> bool { - // todo: consider __android_log_is_loggable. - level <= self.log_level.unwrap_or_else(log::max_level) + pub(crate) fn is_loggable(&self, tag: &str, level: Level) -> bool { + #[cfg(all(target_os = "android", feature = "android-api-30"))] + use android_is_loggable as is_loggable; + #[cfg(not(all(target_os = "android", feature = "android-api-30")))] + use default_is_loggable as is_loggable; + + is_loggable(tag, level, self.log_level) } pub fn with_filter(mut self, filter: env_filter::Filter) -> Self { diff --git a/src/lib.rs b/src/lib.rs index a05d23d..063f4ac 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -146,7 +146,8 @@ const LOGGING_MSG_MAX_LEN: usize = 4000; impl Log for AndroidLogger { fn enabled(&self, metadata: &Metadata) -> bool { - self.config().is_loggable(metadata.level()) + self.config() + .is_loggable(metadata.target(), metadata.level()) } fn log(&self, record: &Record) { diff --git a/src/platform_log_writer.rs b/src/platform_log_writer.rs index 85826ca..3065178 100644 --- a/src/platform_log_writer.rs +++ b/src/platform_log_writer.rs @@ -1,5 +1,5 @@ use crate::arrays::slice_assume_init_ref; -use crate::{LOGGING_MSG_MAX_LEN, LogId, android_log, uninit_array}; +use crate::{android_log, uninit_array, LogId, LOGGING_MSG_MAX_LEN}; use log::Level; #[cfg(target_os = "android")] use log_ffi::LogPriority; @@ -153,7 +153,11 @@ impl fmt::Write for PlatformLogWriter<'_> { .enumerate() .fold(None, |acc, (i, (output, input))| { output.write(*input); - if *input == b'\n' { Some(i) } else { acc } + if *input == b'\n' { + Some(i) + } else { + acc + } }); // update last \n index From 3aa2a1236c5c286f3b357114f5815763f1ad7c9f Mon Sep 17 00:00:00 2001 From: Marcin Radomski Date: Tue, 4 Mar 2025 14:58:02 +0000 Subject: [PATCH 2/5] Add feature builds to CI Build with default features, no features and all features enabled. --- .github/workflows/ci.yml | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index b47ccba..da17594 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -26,6 +26,10 @@ jobs: - armv7-linux-androideabi - aarch64-linux-android - i686-linux-android + features: + - "" + - --no-default-features + - --all-features steps: - uses: actions/checkout@v3 @@ -37,9 +41,9 @@ jobs: components: rustfmt, clippy - run: cargo fmt --check - - run: cargo clippy --target=${{ matrix.target }} -- -Dwarnings - - run: cargo build --target=${{ matrix.target }} - - run: cargo doc --target=${{ matrix.target }} + - run: cargo clippy --target=${{ matrix.target }} ${{ matrix.features }} -- -Dwarnings + - run: cargo build --target=${{ matrix.target }} ${{ matrix.features }} + - run: cargo doc --target=${{ matrix.target }} ${{ matrix.features }} env: RUSTDOCFLAGS: -Dwarnings # Temporary test non-target only. From 2581c258b996135dc6aa44f28ca831f198d2b5ec Mon Sep 17 00:00:00 2001 From: Marcin Radomski Date: Wed, 5 Mar 2025 10:39:19 +0000 Subject: [PATCH 3/5] Reformat with 1.85 toolchain --- src/platform_log_writer.rs | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/src/platform_log_writer.rs b/src/platform_log_writer.rs index 3065178..85826ca 100644 --- a/src/platform_log_writer.rs +++ b/src/platform_log_writer.rs @@ -1,5 +1,5 @@ use crate::arrays::slice_assume_init_ref; -use crate::{android_log, uninit_array, LogId, LOGGING_MSG_MAX_LEN}; +use crate::{LOGGING_MSG_MAX_LEN, LogId, android_log, uninit_array}; use log::Level; #[cfg(target_os = "android")] use log_ffi::LogPriority; @@ -153,11 +153,7 @@ impl fmt::Write for PlatformLogWriter<'_> { .enumerate() .fold(None, |acc, (i, (output, input))| { output.write(*input); - if *input == b'\n' { - Some(i) - } else { - acc - } + if *input == b'\n' { Some(i) } else { acc } }); // update last \n index From a14e0c856520236ce279e62e3e84819f89017c0c Mon Sep 17 00:00:00 2001 From: Marcin Radomski Date: Wed, 5 Mar 2025 16:04:32 +0000 Subject: [PATCH 4/5] Document the behavior of `android-api-30` feature --- README.md | 42 ++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 42 insertions(+) diff --git a/README.md b/README.md index 0d97778..c40d555 100644 --- a/README.md +++ b/README.md @@ -65,6 +65,48 @@ Therefore this library will only log a warning for subsequent `init_once` calls. This library ensures that logged messages do not overflow Android log message limits by efficiently splitting messages into chunks. +## Consistent log filtering in mixed Rust/C/C++ apps + +Android's C logging API determines the effective log level based on [a +combination](https://cs.android.com/android/platform/superproject/main/+/main:system/logging/liblog/properties.cpp;l=243;drc=b74a506c1b69f5b295a8cdfd7e2da3b16db15934), +of a process-wide global variable, [system-wide +properties](https://cs.android.com/android/platform/superproject/main/+/main:system/logging/logd/README.property;l=45;drc=99c545d3098018a544cb292e1501daca694bee0f), +and call-specific default. `log` + `android_logger` crates add another layer of +log filtering on top of that, independent from the C API. + +``` + .-----. + | app | + '-----' Rust +C/C++ | '--------------. + | v + | .-----------. filter by log::STATIC_MAX_LEVEL + + | | log crate | - log::MAX_LOG_LEVEL_FILTER, + | '-----------' overrideable via log::set_max_level + | | + | v + | .----------------------. + | | android_logger crate | - filter by Config::max_level + | '----------------------' + | | + | .------------' + v v + .--------. + | liblog | - filter by global state or system-wide properties + '--------' +``` + +`liblog` APIs introduced in Android API 30 let `android_logger` delegate log +filtering decision to `liblog`, making the log level consistent across C, C++ +and Rust calls. + +If you build `android_logger` with `android-api-30` feature enabled, the logger +will consider the process-wide global state (set via +[`__android_log_set_minimum_priority`](https://cs.android.com/android/platform/superproject/main/+/main:prebuilts/runtime/mainline/runtime/sdk/common_os/include/system/logging/liblog/include/android/log.h;l=364;drc=4cf460634134d51dba174f8af60dffb10f703f51) +and Android system properties when deciding if a message should be logged or +not. In this case, the effective log level is the _least verbose_ of the levels +set between those and Rust log facilities. + ## License Licensed under either of From e6931cff0cbd55b265f243601f3b2ee7f306935a Mon Sep 17 00:00:00 2001 From: Marcin Radomski Date: Wed, 5 Mar 2025 16:07:10 +0000 Subject: [PATCH 5/5] Fix typos --- README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index c40d555..8a8159d 100644 --- a/README.md +++ b/README.md @@ -68,7 +68,7 @@ by efficiently splitting messages into chunks. ## Consistent log filtering in mixed Rust/C/C++ apps Android's C logging API determines the effective log level based on [a -combination](https://cs.android.com/android/platform/superproject/main/+/main:system/logging/liblog/properties.cpp;l=243;drc=b74a506c1b69f5b295a8cdfd7e2da3b16db15934), +combination](https://cs.android.com/android/platform/superproject/main/+/main:system/logging/liblog/properties.cpp;l=243;drc=b74a506c1b69f5b295a8cdfd7e2da3b16db15934) of a process-wide global variable, [system-wide properties](https://cs.android.com/android/platform/superproject/main/+/main:system/logging/logd/README.property;l=45;drc=99c545d3098018a544cb292e1501daca694bee0f), and call-specific default. `log` + `android_logger` crates add another layer of @@ -102,7 +102,7 @@ and Rust calls. If you build `android_logger` with `android-api-30` feature enabled, the logger will consider the process-wide global state (set via -[`__android_log_set_minimum_priority`](https://cs.android.com/android/platform/superproject/main/+/main:prebuilts/runtime/mainline/runtime/sdk/common_os/include/system/logging/liblog/include/android/log.h;l=364;drc=4cf460634134d51dba174f8af60dffb10f703f51) +[`__android_log_set_minimum_priority`](https://cs.android.com/android/platform/superproject/main/+/main:prebuilts/runtime/mainline/runtime/sdk/common_os/include/system/logging/liblog/include/android/log.h;l=364;drc=4cf460634134d51dba174f8af60dffb10f703f51)) and Android system properties when deciding if a message should be logged or not. In this case, the effective log level is the _least verbose_ of the levels set between those and Rust log facilities.