Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use __android_log_is_loggable in AndroidLogger::enabled #84

Merged
merged 5 commits into from
Mar 5, 2025

Conversation

dextero
Copy link

@dextero dextero commented Feb 24, 2025

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

This PR depends on bindings being added in rust-mobile/android_log-sys-rs#6

[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]

metadata.level() <= config.log_level.unwrap_or_else(log::max_level)

@Nercury
Copy link
Collaborator

Nercury commented Mar 4, 2025

Merged rust-mobile/android_log-sys-rs#6, please use it as dependency.

@Nercury
Copy link
Collaborator

Nercury commented Mar 4, 2025

One question: are we sure it's safe to call __android_log_is_loggable? Is anyone relying on older NDK version?

We can handle this by bumping major version (leave this to someone publishing the crate), plus, adding a note in readme that this library requires specific NDK.

@MarijnS95
Copy link
Member

MarijnS95 commented Mar 4, 2025

Looks like this requires API level 30 (probably in most recent NDKs, but also requires phones to run Android 11 at runtime):

https://cs.android.com/android/platform/superproject/main/+/main:system/logging/liblog/include/android/log.h;l=336-338;drc=64c4c0403e3bf8eccc843bce2afebf6b2ae5af87

@Nercury
Copy link
Collaborator

Nercury commented Mar 4, 2025

Another way to handle are the cargo features.

@dextero
Copy link
Author

dextero commented Mar 4, 2025

One question: are we sure it's safe to call __android_log_is_loggable? Is anyone relying on older NDK version?

Great point. After double checking, only 2 bindings from android_log-sys that require API level 30 before rust-mobile/android_log-sys-rs#6 - _android_log_is_loggable and __android_log_write_log_message. Neither of those is used in android_logger currently. I'll wrap the new code in a feature.

Or is there a way to check for Android API version at compile time?

@MarijnS95
Copy link
Member

Or is there a way to check for Android API version at compile time?

At runtime: rust-mobile/ndk#479, see how fn device_api_level() is implemented. This requires using weak symbols or linking them via e.g. libloading at runtime.

At compile time crates like the ndk use api-level-NN crate features, but other crates checked if an Android API version was set in the C-only build path via the __ANDROID_API__ define:

gimli-rs/findshlibs#65
rust-lang/backtrace-rs#415

This spiraled into a bunch of bugs when build tools didn't set that:

rust-mobile/xbuild#209
rust-lang/backtrace-rs#656
gimli-rs/findshlibs#82

And in general considering that we're building Rust, assuming a C(++) environment is set up seems flawed (except for the final target-specific linker).

@Nercury
Copy link
Collaborator

Nercury commented Mar 4, 2025

I have landed the PR that splits the project into multiple files, sorry about that. But it should be easier to work with.

@dextero
Copy link
Author

dextero commented Mar 4, 2025

Thank you for the blazing fast feedback, I can barely keep up 😄 I rebased the PR onto current master.

As for the API version 30 discussion - I ended up adding a feature for this, and adding CI builds for default/no/all features.

@Nercury
Copy link
Collaborator

Nercury commented Mar 4, 2025

Ugh, I did it again. Ok, I promise to not merge anything else before this.

Marcin Radomski added 2 commits March 5, 2025 10:33
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
Build with default features, no features and all features enabled.
@dextero
Copy link
Author

dextero commented Mar 5, 2025

Ok, all green now 😄

@Nercury
Copy link
Collaborator

Nercury commented Mar 5, 2025

This requires some documentation: how it is integrated to the android toolchain, and that there is a feature flag to switch it. Nothing much, just enough so that users are aware.

Copy link
Collaborator

@Nercury Nercury left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, it would be great to have some info in the README about this feature

@dextero
Copy link
Author

dextero commented Mar 5, 2025

I added a description of how this integrates with Android logging facilities when the feature is enabled, PTAL 😄

@Nercury
Copy link
Collaborator

Nercury commented Mar 5, 2025

Awesome, thanks! Have you had a chance to test it while running on sim/device?

@Nercury Nercury merged commit d829810 into rust-mobile:master Mar 5, 2025
72 checks passed
@dextero
Copy link
Author

dextero commented Mar 6, 2025

Sorry for the late response, a couple urgent things came up.

Here's the exact code & steps I used to test: https://github.com/dextero/log-test

// LevelFilter::to_level() returns None only for LevelFilter::Off
None => android_log_sys::LogPriority::SILENT,
},
None => android_log_sys::LogPriority::INFO,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't this be log::max_level() to match what default_is_loggable does by default when no config_level is set?

[`__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.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shall we link Rust log facilities to (the documentation for) log::set_max_level() once again?

@MarijnS95
Copy link
Member

@dextero perhaps that test/sample project would be perfect as an example checked in to this repo?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants