diff --git a/system/gd/common/init_flags.h b/system/gd/common/init_flags.h
index 9f0f12a1238c96c079fb29dd22cecb48787cdb3d..764ced5797380cfc25af1e29d5ec81ceb7959adb 100644
--- a/system/gd/common/init_flags.h
+++ b/system/gd/common/init_flags.h
@@ -34,14 +34,6 @@ class InitFlags final {
init_flags::load(std::move(rusted_flags));
}
- inline static int GetLogLevelForTag(const std::string& tag) {
- return init_flags::get_log_level_for_tag(tag);
- }
-
- inline static int GetDefaultLogLevel() {
- return init_flags::get_default_log_level();
- }
-
inline static bool IsDeviceIotConfigLoggingEnabled() {
return init_flags::device_iot_config_logging_is_enabled();
}
diff --git a/system/gd/common/init_flags_test.cc b/system/gd/common/init_flags_test.cc
index 8c4e357fcd310264ceed8e68248e6cbdd94cdd05..ea0019fdb433b834348c1f499b0f3316a6266024 100644
--- a/system/gd/common/init_flags_test.cc
+++ b/system/gd/common/init_flags_test.cc
@@ -20,8 +20,6 @@
#include <gtest/gtest.h>
-#include "os/log_tags.h"
-
using bluetooth::common::InitFlags;
TEST(InitFlagsTest, test_enable_btm_flush_discovery_queue_on_search_cancel) {
@@ -36,51 +34,6 @@ TEST(InitFlagsTest, test_leaudio_targeted_announcement_reconnection_mode) {
ASSERT_TRUE(InitFlags::IsTargetedAnnouncementReconnectionMode());
}
-TEST(InitFlagsTest, test_enable_debug_logging_for_all) {
- const char* input[] = {"INIT_default_log_level=5", nullptr};
- InitFlags::Load(input);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("foo"), LOG_TAG_DEBUG);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("bar"), LOG_TAG_DEBUG);
- ASSERT_EQ(InitFlags::GetDefaultLogLevel(), LOG_TAG_DEBUG);
-}
-
-TEST(InitFlagsTest, test_enable_debug_logging_for_tags) {
- const char* input[] = {"INIT_logging_debug_enabled_for_tags=foo,bar,hello", nullptr};
- InitFlags::Load(input);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("foo"), LOG_TAG_VERBOSE);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("bar"), LOG_TAG_VERBOSE);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("hello"), LOG_TAG_VERBOSE);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("Foo"), LOG_TAG_INFO);
- ASSERT_EQ(InitFlags::GetDefaultLogLevel(), LOG_TAG_INFO);
-}
-
-TEST(InitFlagsTest, test_disable_debug_logging_for_tags) {
- const char* input[] = {
- "INIT_logging_debug_disabled_for_tags=foo,bar,hello",
- "INIT_default_log_level_str=LOG_DEBUG",
- nullptr};
- InitFlags::Load(input);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("foo"), LOG_TAG_INFO);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("bar"), LOG_TAG_INFO);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("hello"), LOG_TAG_INFO);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("Foo"), LOG_TAG_DEBUG);
- ASSERT_EQ(InitFlags::GetDefaultLogLevel(), LOG_TAG_DEBUG);
-}
-
-TEST(InitFlagsTest, test_debug_logging_multiple_flags) {
- const char* input[] = {
- "INIT_logging_debug_enabled_for_tags=foo,hello",
- "INIT_logging_debug_disabled_for_tags=foo,bar",
- "INIT_default_log_level_str=LOG_WARN",
- nullptr};
- InitFlags::Load(input);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("foo"), LOG_TAG_INFO);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("bar"), LOG_TAG_INFO);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("hello"), LOG_TAG_VERBOSE);
- ASSERT_EQ(InitFlags::GetLogLevelForTag("Foo"), LOG_TAG_WARN);
- ASSERT_EQ(InitFlags::GetDefaultLogLevel(), LOG_TAG_WARN);
-}
-
TEST(InitFlagsTest, test_device_iot_config_logging_is_enabled) {
const char* input[] = {"INIT_device_iot_config_logging=true", nullptr};
InitFlags::Load(input);
diff --git a/system/gd/os/log.h b/system/gd/os/log.h
index e07ce1c434583698f970128d99355fe1d045d929..437cba5af525c6da7c8c90f6ad8c5713f2c04348 100644
--- a/system/gd/os/log.h
+++ b/system/gd/os/log.h
@@ -57,24 +57,21 @@ static_assert(LOG_TAG != nullptr, "LOG_TAG should never be NULL");
#include <log/log.h>
#include <log/log_event_list.h>
-#if __has_include("src/init_flags.rs.h")
-
-#include "common/init_flags.h"
-
-#define LOG_VERBOSE_INT(fmt, args...) \
- do { \
- if (bluetooth::common::InitFlags::GetLogLevelForTag(LOG_TAG) >= LOG_TAG_VERBOSE) { \
- ALOGV(fmt, ##args); \
- } \
+#define LOG_VERBOSE_INT(fmt, args...) \
+ do { \
+ if (!__android_log_is_loggable(ANDROID_LOG_VERBOSE, LOG_TAG, ANDROID_LOG_INFO) && \
+ !__android_log_is_loggable(ANDROID_LOG_VERBOSE, "bluetooth", ANDROID_LOG_INFO)) { \
+ ALOGV(fmt, ##args); \
+ } \
} while (false)
-#define LOG_DEBUG_INT(fmt, args...) \
- do { \
- if (bluetooth::common::InitFlags::GetLogLevelForTag(LOG_TAG) >= LOG_TAG_DEBUG) { \
- ALOGD(fmt, ##args); \
- } \
+#define LOG_DEBUG_INT(fmt, args...) \
+ do { \
+ if (!__android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG, ANDROID_LOG_INFO) && \
+ !__android_log_is_loggable(ANDROID_LOG_DEBUG, "bluetooth", ANDROID_LOG_INFO)) { \
+ ALOGD(fmt, ##args); \
+ } \
} while (false)
-#endif /* __has_include("src/init_flags.rs.h") */
#define LOG_INFO_INT(fmt, args...) ALOGI(fmt, ##args)
#define LOG_WARN_INT(fmt, args...) ALOGW(fmt, ##args)
@@ -102,25 +99,13 @@ static_assert(LOG_TAG != nullptr, "LOG_TAG should never be NULL");
abort(); \
} while (false)
#elif defined(TARGET_FLOSS) /* end of defined (ANDROID_EMULATOR) */
-#include "common/init_flags.h"
#include "os/syslog.h"
// Prefix the log with tag, file, line and function
-#define LOGWRAPPER(tag, fmt, args...) \
- write_syslog(tag, "%s: " fmt, LOG_TAG, ##args)
-
-#define LOG_VERBOSE_INT(...) \
- do { \
- if (bluetooth::common::InitFlags::GetLogLevelForTag(LOG_TAG) >= LOG_TAG_VERBOSE) { \
- LOGWRAPPER(LOG_TAG_VERBOSE, __VA_ARGS__); \
- } \
- } while (false)
-#define LOG_DEBUG_INT(...) \
- do { \
- if (bluetooth::common::InitFlags::GetLogLevelForTag(LOG_TAG) >= LOG_TAG_DEBUG) { \
- LOGWRAPPER(LOG_TAG_DEBUG, __VA_ARGS__); \
- } \
- } while (false)
+#define LOGWRAPPER(tag, fmt, args...) write_syslog(tag, LOG_TAG, "%s: " fmt, LOG_TAG, ##args)
+
+#define LOG_VERBOSE_INT(...) LOGWRAPPER(LOG_TAG_VERBOSE, __VA_ARGS__)
+#define LOG_DEBUG_INT(...) LOGWRAPPER(LOG_TAG_DEBUG, __VA_ARGS__)
#define LOG_INFO_INT(...) LOGWRAPPER(LOG_TAG_INFO, __VA_ARGS__)
#define LOG_WARN_INT(...) LOGWRAPPER(LOG_TAG_WARN, __VA_ARGS__)
#define LOG_ERROR_INT(...) LOGWRAPPER(LOG_TAG_ERROR, __VA_ARGS__)
diff --git a/system/gd/os/log_tags.h b/system/gd/os/log_tags.h
index ac94a7f8402178c0bfe2ce8d87e848925d1f34e3..437fb120f25efe31df81d22da6e9ee42a5089451 100644
--- a/system/gd/os/log_tags.h
+++ b/system/gd/os/log_tags.h
@@ -15,14 +15,15 @@
*/
#pragma once
+// TODO(b/305066880) - Deprecate once replaced with fmtlib implementation.
// These log levels may need to be mapped to system values. These values are
-// used to control the log level via init flags.
+// used to control the log level and should match
+// `bluetooth::log_internal::Level`.
enum LogLevels {
- LOG_TAG_FATAL = 0,
- LOG_TAG_ERROR,
- LOG_TAG_WARN,
- LOG_TAG_NOTICE,
- LOG_TAG_INFO,
- LOG_TAG_DEBUG,
- LOG_TAG_VERBOSE
+ LOG_TAG_VERBOSE = 2,
+ LOG_TAG_DEBUG = 3,
+ LOG_TAG_INFO = 4,
+ LOG_TAG_WARN = 5,
+ LOG_TAG_ERROR = 6,
+ LOG_TAG_FATAL = 7,
};
diff --git a/system/gd/os/syslog.cc b/system/gd/os/syslog.cc
index f0a4f74d343c5b4bb7f3b08bfc378e5c0c04d22f..1f223dd2ec21737f0a502911280788a51adbb99f 100644
--- a/system/gd/os/syslog.cc
+++ b/system/gd/os/syslog.cc
@@ -23,23 +23,31 @@
#include "os/log_tags.h"
+// TODO(b/305066880) - This implementation will replace this syslog
+// implementation. Remove this file once everything is moved over to the new
+// logging macros.
+#include "bluetooth/log.h"
+
+namespace bluetooth::log_internal {
+extern Level GetLogLevelForTag(char const* tag);
+}
+
namespace {
#define SYSLOG_IDENT "btadapterd"
const char kSyslogIdent[] = SYSLOG_IDENT;
// Map LOG_TAG_* to syslog mappings
-const int kTagMap[] = {
- /*LOG_TAG_FATAL=*/LOG_CRIT,
- /*LOG_TAG_ERROR=*/LOG_ERR,
- /*LOG_TAG_WARN=*/LOG_WARNING,
- /*LOG_TAG_NOTICE=*/LOG_NOTICE,
- /*LOG_TAG_INFO=*/LOG_INFO,
- /*LOG_TAG_DEBUG=*/LOG_DEBUG,
+const int kLevelMap[] = {
/*LOG_TAG_VERBOSE=*/LOG_DEBUG,
+ /*LOG_TAG_DEBUG=*/LOG_DEBUG,
+ /*LOG_TAG_INFO=*/LOG_INFO,
+ /*LOG_TAG_WARN=*/LOG_WARNING,
+ /*LOG_TAG_ERROR=*/LOG_ERR,
+ /*LOG_TAG_FATAL=*/LOG_CRIT,
};
-static_assert(sizeof(kTagMap) / sizeof(kTagMap[0]) == LOG_TAG_VERBOSE + 1);
+static_assert(sizeof(kLevelMap) / sizeof(kLevelMap[0]) == (LOG_TAG_FATAL - LOG_TAG_VERBOSE) + 1);
class SyslogWrapper {
public:
@@ -55,18 +63,28 @@ class SyslogWrapper {
std::unique_ptr<SyslogWrapper> gSyslog;
} // namespace
-void write_syslog(int tag, const char* format, ...) {
+void write_syslog(int level, const char* tag, const char* format, ...) {
if (!gSyslog) {
gSyslog = std::make_unique<SyslogWrapper>();
}
- // I don't expect to see incorrect tags but making the check anyway so we
+ // Filter out logs that don't meet level requirement.
+ bluetooth::log_internal::Level current_level = bluetooth::log_internal::GetLogLevelForTag(tag);
+ if (static_cast<bluetooth::log_internal::Level>(level) < current_level) {
+ return;
+ }
+
+ // I don't expect to see incorrect levels but making the check anyway so we
// don't go out of bounds in the array above.
- tag = tag <= LOG_TAG_VERBOSE ? tag : LOG_TAG_ERROR;
- int level = kTagMap[tag];
+ if (level > LOG_TAG_FATAL) {
+ level = LOG_TAG_ERROR;
+ } else if (level < LOG_TAG_VERBOSE) {
+ level = LOG_TAG_VERBOSE;
+ }
+ int syslog_level = kLevelMap[level - LOG_TAG_VERBOSE];
va_list args;
va_start(args, format);
- vsyslog(level, format, args);
+ vsyslog(syslog_level, format, args);
va_end(args);
}
diff --git a/system/gd/os/syslog.h b/system/gd/os/syslog.h
index 63411a26200a4c026e460d4e06fe23b7404dc088..aed9bc60e772079b8b19e025abe18b1a95d0ce3b 100644
--- a/system/gd/os/syslog.h
+++ b/system/gd/os/syslog.h
@@ -26,4 +26,4 @@
/**
* Write log to syslog.
*/
-void write_syslog(int tag, const char* format, ...);
+void write_syslog(int level, const char* tag, const char* format, ...);
diff --git a/system/gd/rust/common/src/init_flags.rs b/system/gd/rust/common/src/init_flags.rs
index dca345161cb295606a9ce7f7ebc279b608af344a..e1376a4a186c5d98f003d7e18f76e5883822761c 100644
--- a/system/gd/rust/common/src/init_flags.rs
+++ b/system/gd/rust/common/src/init_flags.rs
@@ -2,7 +2,6 @@ use lazy_static::lazy_static;
use log::{error, info};
use paste::paste;
use std::collections::{BTreeMap, HashMap};
-use std::convert::TryFrom;
use std::fmt;
use std::sync::Mutex;
@@ -70,25 +69,6 @@ macro_rules! create_getter_fn {
};
}
-macro_rules! create_setter_fn {
- ($flag:ident) => {
- paste! {
- #[doc = concat!(" Update value of ", stringify!($flag), " at runtime")]
- pub fn [<update_ $flag>](value: bool) {
- FLAGS.lock().unwrap().$flag = value;
- }
- }
- };
- ($flag:ident $type:ty) => {
- paste! {
- #[doc = concat!(" Update value of ", stringify!($flag), " at runtime")]
- pub fn [<update_ $flag>](value: $type) {
- FLAGS.lock().unwrap().$flag = value;
- }
- }
- };
-}
-
macro_rules! init_flags {
(
name: $name:ident
@@ -116,23 +96,17 @@ macro_rules! init_flags_struct {
(
name: $name:ident
flags: { $($flag:ident $(: $type:ty)? $(= $default:tt)?,)* }
- dynamic_flags: { $($dy_flag:ident $(: $dy_type:ty)? $(= $dy_default:tt)?,)* }
- extra_fields: { $($extra_field:ident : $extra_field_type:ty $(= $extra_default:tt)?,)* }
extra_parsed_flags: { $($extra_flag:tt => $extra_flag_fn:ident(_, _ $(,$extra_args:tt)*),)*}
dependencies: { $($parent:ident => $child:ident),* }) => {
struct $name {
$($flag : type_expand!($($type)?),)*
- $($dy_flag : type_expand!($($dy_type)?),)*
- $($extra_field : $extra_field_type,)*
}
impl Default for $name {
fn default() -> Self {
Self {
$($flag : default_value!($($type)? $(= $default)?),)*
- $($dy_flag : default_value!($($dy_type)? $(= $dy_default)?),)*
- $($extra_field : default_value!($extra_field_type $(= $extra_default)?),)*
}
}
}
@@ -141,16 +115,12 @@ macro_rules! init_flags_struct {
fn get_defaults_for_test() -> Self {
Self {
$($flag: test_value!($($type)?),)*
- $($dy_flag: test_value!($($dy_type)?),)*
- $($extra_field: test_value!($extra_field_type),)*
}
}
fn dump(&self) -> BTreeMap<&'static str, String> {
[
$((stringify!($flag), format!("{}", self.$flag)),)*
- $((stringify!($dy_flag), format!("{}", self.$dy_flag)),)*
- $((stringify!($extra_field), format!("{}", self.$extra_field)),)*
].into()
}
@@ -169,10 +139,6 @@ macro_rules! init_flags_struct {
init_flags.$flag = values[1].parse().unwrap_or_else(|e| {
error!("Parse failure on '{}': {}", flag, e);
default_value!($($type)? $(= $default)?)}),)*
- $(concat!("INIT_", stringify!($dy_flag)) =>
- init_flags.$dy_flag = values[1].parse().unwrap_or_else(|e| {
- error!("Parse failure on '{}': {}", flag, e);
- default_value!($($dy_type)? $(= $dy_default)?)}),)*
$($extra_flag => $extra_flag_fn(&mut init_flags, values $(, $extra_args)*),)*
_ => error!("Unsaved flag: {} = {}", values[0], values[1])
}
@@ -197,13 +163,9 @@ macro_rules! init_flags_struct {
impl fmt::Display for $name {
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
- write!(f, concat!(
+ write!(f,
concat!($(concat!(stringify!($flag), "={}")),*),
- concat!($(concat!(stringify!($dy_flag), "={}")),*),
- $(concat!(stringify!($extra_field), "={}")),*),
- $(self.$flag),*,
- $(self.$dy_flag),*,
- $(self.$extra_field),*)
+ $(self.$flag),*)
}
}
@@ -213,16 +175,11 @@ macro_rules! init_flags_struct {
macro_rules! init_flags_getters {
(
flags: { $($flag:ident $(: $type:ty)? $(= $default:tt)?,)* }
- dynamic_flags: { $($dy_flag:ident $(: $dy_type:ty)? $(= $dy_default:tt)?,)* }
- extra_fields: { $($extra_field:ident : $extra_field_type:ty $(= $extra_default:tt)?,)* }
extra_parsed_flags: { $($extra_flag:tt => $extra_flag_fn:ident(_, _ $(,$extra_args:tt)*),)*}
dependencies: { $($parent:ident => $child:ident),* }) => {
$(create_getter_fn!($flag $($type)?);)*
- $(create_getter_fn!($dy_flag $($dy_type)?);)*
- $(create_setter_fn!($dy_flag $($dy_type)?);)*
-
#[cfg(test)]
mod tests_autogenerated {
use super::*;
@@ -238,19 +195,6 @@ macro_rules! init_flags_getters {
assert_eq!(get_value, test_value!($($type)?));
}
})*
-
- $(paste! {
- #[test]
- pub fn [<test_dynamic_get_ $dy_flag>]() {
- let _guard = tests::ASYNC_LOCK.lock().unwrap();
- tests::test_load(vec![
- &*format!(concat!(concat!("INIT_", stringify!($dy_flag)), "={}"), test_value!($($dy_type)?))
- ]);
- let get_value = call_getter_fn!($dy_flag $($dy_type)?);
- drop(_guard); // Prevent poisonning other tests if a panic occurs
- assert_eq!(get_value, test_value!($($dy_type)?));
- }
- })*
}
}
}
@@ -266,95 +210,16 @@ impl fmt::Display for ExplicitTagSettings {
}
}
-struct LogLevel(i32);
-
-impl TryFrom<&str> for LogLevel {
- type Error = &'static str;
-
- fn try_from(tag_value: &str) -> Result<Self, Self::Error> {
- match tag_value {
- "LOG_FATAL" => Ok(LogLevel(LOG_TAG_FATAL)),
- "LOG_ERROR" => Ok(LogLevel(LOG_TAG_ERROR)),
- "LOG_WARN" => Ok(LogLevel(LOG_TAG_WARN)),
- "LOG_NOTICE" => Ok(LogLevel(LOG_TAG_NOTICE)),
- "LOG_INFO" => Ok(LogLevel(LOG_TAG_INFO)),
- "LOG_DEBUG" => Ok(LogLevel(LOG_TAG_DEBUG)),
- "LOG_VERBOSE" => Ok(LogLevel(LOG_TAG_VERBOSE)),
- _ => Err("Invalid tag value"),
- }
- }
-}
-
-fn deprecated_set_debug_logging_enabled_for_all(flags: &mut InitFlags, values: Vec<&str>) {
- let truthy: bool = values[1].parse().unwrap_or(false);
- flags.default_log_level = if truthy { LOG_TAG_VERBOSE } else { LOG_TAG_INFO };
-
- // Leave a note that this flag is deprecated in the logs.
- log::error!(
- "DEPRECATED flag used: INIT_logging_debug_enabled_for_all. Use INIT_default_log_level_str=LOG_VERBOSE instead.",
- );
-}
-
-fn parse_log_level(flags: &mut InitFlags, values: Vec<&str>) {
- if let Ok(v) = LogLevel::try_from(values[1]) {
- flags.default_log_level = v.0;
- }
-}
-
-fn parse_logging_tag(flags: &mut InitFlags, values: Vec<&str>) {
- for tag in values[1].split(',') {
- let tagstr = tag.to_string();
- let pair = tagstr.split(':').collect::<Vec<&str>>();
- if pair.len() == 2 {
- if let Ok(v) = LogLevel::try_from(pair[1]) {
- flags.logging_explicit_tag_settings.map.insert(pair[0].into(), v.0);
- }
- }
- }
-}
-
-fn parse_debug_logging_tag(flags: &mut InitFlags, values: Vec<&str>, enabled: bool) {
- let log_level: i32 = if enabled { LOG_TAG_VERBOSE } else { LOG_TAG_INFO };
-
- for tag in values[1].split(',') {
- flags.logging_explicit_tag_settings.map.insert(tag.to_string(), log_level);
- }
-}
-
fn parse_hci_adapter(flags: &mut InitFlags, values: Vec<&str>) {
flags.hci_adapter = values[1].parse().unwrap_or(0);
}
-/// Returns the log level for given flag.
-pub fn get_log_level_for_tag(tag: &str) -> i32 {
- let guard = FLAGS.lock().unwrap();
- *guard.logging_explicit_tag_settings.map.get(tag).unwrap_or(&guard.default_log_level)
-}
-
/// Sets all bool flags to true
/// Set all other flags and extra fields to their default type value
pub fn set_all_for_testing() {
*FLAGS.lock().unwrap() = InitFlags::get_defaults_for_test();
}
-// Keep these values in sync with the values in gd/os/log_tags.h
-// They are used to control the log level for each tag.
-
-/// Fatal log level.
-pub const LOG_TAG_FATAL: i32 = 0;
-/// Error log level.
-pub const LOG_TAG_ERROR: i32 = 1;
-/// Warning log level.
-pub const LOG_TAG_WARN: i32 = 2;
-/// Notice log level.
-pub const LOG_TAG_NOTICE: i32 = 3;
-/// Info log level. This is usually the default log level on most systems.
-pub const LOG_TAG_INFO: i32 = 4;
-/// Debug log level.
-pub const LOG_TAG_DEBUG: i32 = 5;
-/// Verbose log level.
-pub const LOG_TAG_VERBOSE: i32 = 6;
-
init_flags!(
name: InitFlags
flags: {
@@ -394,21 +259,7 @@ init_flags!(
att_mtu_default: i32 = 517,
encryption_in_busy_state = true,
}
- // dynamic flags can be updated at runtime and should be accessed directly
- // to check.
- dynamic_flags: {
- default_log_level : i32 = LOG_TAG_INFO,
- }
- // extra_fields are not a 1 to 1 match with "INIT_*" flags
- extra_fields: {
- logging_explicit_tag_settings: ExplicitTagSettings,
- }
extra_parsed_flags: {
- "INIT_default_log_level_str" => parse_log_level(_, _),
- "INIT_log_level_for_tags" => parse_logging_tag(_, _),
- "INIT_logging_debug_enabled_for_all" => deprecated_set_debug_logging_enabled_for_all(_, _),
- "INIT_logging_debug_enabled_for_tags" => parse_debug_logging_tag(_, _, true),
- "INIT_logging_debug_disabled_for_tags" => parse_debug_logging_tag(_, _, false),
"--hci" => parse_hci_adapter(_, _),
}
dependencies: {
@@ -433,9 +284,6 @@ pub fn load(raw_flags: Vec<String>) {
let flags = InitFlags::parse(raw_flags);
info!("Flags loaded: {}", flags);
*FLAGS.lock().unwrap() = flags;
-
- // re-init to respect log levels set by flags
- crate::init_logging();
}
/// Dumps all flag K-V pairs, storing values as strings
@@ -486,29 +334,6 @@ mod tests {
assert_eq!(get_hci_adapter(), 2);
}
#[test]
- fn explicit_flag() {
- let _guard = ASYNC_LOCK.lock().unwrap();
- test_load(vec![
- "INIT_default_log_level_str=LOG_VERBOSE",
- "INIT_logging_debug_enabled_for_tags=foo,bar",
- "INIT_logging_debug_disabled_for_tags=foo,bar2,fizz",
- "INIT_logging_debug_enabled_for_tags=bar2",
- "INIT_log_level_for_tags=fizz:LOG_WARN,buzz:LOG_NOTICE",
- ]);
-
- assert!(get_log_level_for_tag("foo") == LOG_TAG_INFO);
- assert!(get_log_level_for_tag("bar") == LOG_TAG_VERBOSE);
- assert!(get_log_level_for_tag("bar2") == LOG_TAG_VERBOSE);
- assert!(get_log_level_for_tag("unknown_flag") == LOG_TAG_VERBOSE);
- assert!(get_default_log_level() == LOG_TAG_VERBOSE);
- FLAGS.lock().unwrap().default_log_level = LOG_TAG_INFO;
- assert!(get_log_level_for_tag("foo") == LOG_TAG_INFO);
- assert!(get_log_level_for_tag("bar") == LOG_TAG_VERBOSE);
- assert!(get_log_level_for_tag("bar2") == LOG_TAG_VERBOSE);
- assert!(get_log_level_for_tag("unknown_flag") == LOG_TAG_INFO);
- assert!(get_default_log_level() == LOG_TAG_INFO);
- }
- #[test]
fn test_redact_logging() {
let _guard = ASYNC_LOCK.lock().unwrap();
assert!(redact_log_is_enabled()); // default is true
@@ -519,63 +344,23 @@ mod tests {
test_load(vec!["INIT_redact_log=true"]);
assert!(redact_log_is_enabled()); // turned on
}
- #[test]
- fn test_runtime_update() {
- let _guard = ASYNC_LOCK.lock().unwrap();
- test_load(vec!["INIT_private_gatt=true", "INIT_default_log_level_str=LOG_WARN"]);
- assert!(private_gatt_is_enabled());
- assert!(get_default_log_level() == LOG_TAG_WARN);
-
- update_default_log_level(LOG_TAG_DEBUG);
- assert!(get_default_log_level() == LOG_TAG_DEBUG);
- update_default_log_level(LOG_TAG_ERROR);
- assert!(get_default_log_level() == LOG_TAG_ERROR);
- }
- #[test]
- fn test_default_log_level() {
- // Default log level can be provided via int value or string.
- // The string version is just for ease-of-use.
- let _guard = ASYNC_LOCK.lock().unwrap();
- test_load(vec!["INIT_default_log_level=1"]);
- assert!(get_default_log_level() == LOG_TAG_ERROR);
- test_load(vec!["INIT_default_log_level_str=LOG_VERBOSE"]);
- assert!(get_default_log_level() == LOG_TAG_VERBOSE);
- test_load(vec!["INIT_default_log_level_str=LOG_VERBOSE", "INIT_default_log_level=0"]);
- assert!(get_default_log_level() == LOG_TAG_FATAL);
- }
- #[test]
- fn test_deprecated_logging_flag() {
- let _guard = ASYNC_LOCK.lock().unwrap();
- test_load(vec!["INIT_default_log_level_str=1", "INIT_logging_debug_enabled_for_all=true"]);
- assert!(get_default_log_level() == LOG_TAG_VERBOSE);
- test_load(vec!["INIT_logging_debug_enabled_for_all=false"]);
- assert!(get_default_log_level() == LOG_TAG_INFO);
- }
init_flags_struct!(
name: InitFlagsForTest
flags: {
cat,
}
- dynamic_flags: {
- dog: i32 = 8,
- }
- extra_fields: {
- elephant: String,
- }
extra_parsed_flags: {}
dependencies: {}
);
#[test]
fn test_dumpsys() {
- let flags = InitFlagsForTest { dog: 3, elephant: "Go bears!".into(), ..Default::default() };
+ let flags = InitFlagsForTest { ..Default::default() };
let out = flags.dump();
- assert_eq!(out.len(), 3);
+ assert_eq!(out.len(), 1);
assert_eq!(out["cat"], "false");
- assert_eq!(out["dog"], "3");
- assert_eq!(out["elephant"], "Go bears!");
}
}
diff --git a/system/gd/rust/common/src/logging.rs b/system/gd/rust/common/src/logging.rs
index 89577de902b8bc7ade7ffc4ef232fddb991bd320..4207114d92ac37fdf1f49928b853dda6c09b2377 100644
--- a/system/gd/rust/common/src/logging.rs
+++ b/system/gd/rust/common/src/logging.rs
@@ -1,33 +1,11 @@
-use crate::init_flags::{
- get_log_level_for_tag, LOG_TAG_DEBUG, LOG_TAG_ERROR, LOG_TAG_FATAL, LOG_TAG_INFO,
- LOG_TAG_NOTICE, LOG_TAG_VERBOSE, LOG_TAG_WARN,
-};
-
-fn get_log_level() -> log::LevelFilter {
- match get_log_level_for_tag("bluetooth_core") {
- LOG_TAG_FATAL => log::LevelFilter::Error,
- LOG_TAG_ERROR => log::LevelFilter::Error,
- LOG_TAG_WARN => log::LevelFilter::Warn,
- LOG_TAG_NOTICE => log::LevelFilter::Info,
- LOG_TAG_INFO => log::LevelFilter::Info,
- LOG_TAG_DEBUG => log::LevelFilter::Debug,
- LOG_TAG_VERBOSE => log::LevelFilter::Trace,
- _ => log::LevelFilter::Info, // default level
- }
-}
-
/// Inits logging for Android
#[cfg(target_os = "android")]
pub fn init_logging() {
- android_logger::init_once(
- android_logger::Config::default().with_tag("bt").with_max_level(get_log_level()),
- );
- log::set_max_level(get_log_level())
+ android_logger::init_once(android_logger::Config::default().with_tag("bt"));
}
/// Inits logging for host
#[cfg(not(target_os = "android"))]
pub fn init_logging() {
- env_logger::Builder::new().filter(None, get_log_level()).parse_default_env().try_init().ok();
- log::set_max_level(get_log_level())
+ env_logger::Builder::new().parse_default_env().try_init().ok();
}
diff --git a/system/gd/rust/linux/service/src/main.rs b/system/gd/rust/linux/service/src/main.rs
index a35f789f98f3fce337557a3cd03a8a6fd9ff77d0..22a49044ece5d24e2cba0fd33bb461efa22f573f 100644
--- a/system/gd/rust/linux/service/src/main.rs
+++ b/system/gd/rust/linux/service/src/main.rs
@@ -50,15 +50,6 @@ const STACK_TURN_OFF_TIMEOUT_MS: Duration = Duration::from_millis(4000);
// Time bt_stack_manager waits for cleanup
const STACK_CLEANUP_TIMEOUT_MS: Duration = Duration::from_millis(1000);
-const VERBOSE_ONLY_LOG_TAGS: &[&str] = &[
- "bt_bta_av", // AV apis
- "btm_sco", // SCO data path logs
- "l2c_csm", // L2CAP state machine
- "l2c_link", // L2CAP link layer logs
- "sco_hci", // SCO over HCI
- "uipc", // Userspace IPC implementation
-];
-
const INIT_LOGGING_MAX_RETRY: u8 = 3;
/// Runs the Bluetooth daemon serving D-Bus IPC.
@@ -111,24 +102,14 @@ fn main() -> Result<(), Box<dyn Error>> {
None => vec![],
};
- // Set GD debug flag if debug is enabled.
- if is_debug {
- // Limit tags if verbose debug logging isn't enabled.
- if !is_verbose_debug {
- init_flags.push(format!(
- "INIT_logging_debug_disabled_for_tags={}",
- VERBOSE_ONLY_LOG_TAGS.join(",")
- ));
- init_flags.push(String::from("INIT_default_log_level_str=LOG_DEBUG"));
- } else {
- init_flags.push(String::from("INIT_default_log_level_str=LOG_VERBOSE"));
- }
- }
-
// Forward --hci to Fluoride.
init_flags.push(format!("--hci={}", hci_index));
- let logging = Arc::new(Mutex::new(Box::new(BluetoothLogging::new(is_debug, log_output))));
+ let logging = Arc::new(Mutex::new(Box::new(BluetoothLogging::new(
+ is_debug,
+ is_verbose_debug,
+ log_output,
+ ))));
// TODO(b/307171804): Investigate why connecting to unix syslog might fail.
// Retry it a few times. Ignore the failure if fails too many times.
for _ in 0..INIT_LOGGING_MAX_RETRY {
diff --git a/system/gd/rust/linux/stack/src/bluetooth_logging.rs b/system/gd/rust/linux/stack/src/bluetooth_logging.rs
index 2fbd181d5e1c83361820f4afdfc314fee235c8f8..aa2a0c0e189b832ca933ff742c9be142f4969a78 100644
--- a/system/gd/rust/linux/stack/src/bluetooth_logging.rs
+++ b/system/gd/rust/linux/stack/src/bluetooth_logging.rs
@@ -1,10 +1,16 @@
-use bt_common::init_flags;
+//! Modify the Bluetooth logging configuration to enable debug logging.
+//!
+//! There are two logging implementations depending on whether the log is
+//! emitted from Rust or C/C++. In order to keep log levels in sync between the
+//! two, the |BluetoothLogging| struct will configure both the Rust logging and
+//! the C/C++ logging (via topshim).
+use bt_topshim::syslog::{set_default_log_level, set_log_level_for_tag, Level};
use log::LevelFilter;
use syslog::{BasicLogger, Error, Facility, Formatter3164};
use log_panics;
-/// API to modify log levels.
+/// API to modify log levels that is exposed via RPC.
pub trait IBluetoothLogging {
/// Check whether debug logging is enabled.
fn is_debug_enabled(&self) -> bool;
@@ -15,15 +21,34 @@ pub trait IBluetoothLogging {
/// Logging related implementation.
pub struct BluetoothLogging {
+ /// Should debug logs be emitted?
is_debug: bool,
+
+ /// If this flag is not set, we will not emit debug logs for all tags.
+ /// `VERBOSE_ONLY_LOG_TAGS` will be set to emit up to `INFO` only. This
+ /// can only be configured in the constructor (not modifiable at runtime).
+ is_verbose_debug: bool,
+
+ /// Log to stderr?
is_stderr: bool,
+
+ /// Is logging already initialized?
is_initialized: bool,
}
+const VERBOSE_ONLY_LOG_TAGS: &[&str] = &[
+ "bt_bta_av", // AV apis
+ "btm_sco", // SCO data path logs
+ "l2c_csm", // L2CAP state machine
+ "l2c_link", // L2CAP link layer logs
+ "sco_hci", // SCO over HCI
+ "uipc", // Userspace IPC implementation
+];
+
impl BluetoothLogging {
- pub fn new(is_debug: bool, log_output: &str) -> Self {
+ pub fn new(is_debug: bool, is_verbose_debug: bool, log_output: &str) -> Self {
let is_stderr = log_output == "stderr";
- Self { is_debug, is_stderr, is_initialized: false }
+ Self { is_debug, is_verbose_debug, is_stderr, is_initialized: false }
}
pub fn initialize(&mut self) -> Result<(), Error> {
@@ -44,9 +69,31 @@ impl BluetoothLogging {
.map(|()| log::set_max_level(level));
log_panics::init();
}
+
+ // Set initial log levels and filter out tags if not verbose debug.
+ set_default_log_level(self.get_libbluetooth_level());
+ if self.is_debug && !self.is_verbose_debug {
+ for tag in VERBOSE_ONLY_LOG_TAGS {
+ set_log_level_for_tag(tag, Level::Info);
+ }
+ }
+
+ // Initialize the underlying system as well.
self.is_initialized = true;
Ok(())
}
+
+ fn get_libbluetooth_level(&self) -> Level {
+ if self.is_debug {
+ if self.is_verbose_debug {
+ Level::Verbose
+ } else {
+ Level::Debug
+ }
+ } else {
+ Level::Info
+ }
+ }
}
impl IBluetoothLogging for BluetoothLogging {
@@ -66,9 +113,8 @@ impl IBluetoothLogging for BluetoothLogging {
log::set_max_level(level);
// Update log level in libbluetooth.
- let level =
- if self.is_debug { init_flags::LOG_TAG_DEBUG } else { init_flags::LOG_TAG_INFO };
- init_flags::update_default_log_level(level);
+ let level = self.get_libbluetooth_level();
+ set_default_log_level(level);
// Mark the start of debug logging with a debug print.
if self.is_debug {
diff --git a/system/gd/rust/shim/src/init_flags.rs b/system/gd/rust/shim/src/init_flags.rs
index 69ce71182b0eded4889986732fd6b6ca437a69dd..4017057fb164c9cd8e9940737e5c229bef0fe026 100644
--- a/system/gd/rust/shim/src/init_flags.rs
+++ b/system/gd/rust/shim/src/init_flags.rs
@@ -25,9 +25,7 @@ mod ffi {
fn dynamic_avrcp_version_enhancement_is_enabled() -> bool;
fn gatt_robust_caching_client_is_enabled() -> bool;
fn gatt_robust_caching_server_is_enabled() -> bool;
- fn get_default_log_level() -> i32;
fn get_hci_adapter() -> i32;
- fn get_log_level_for_tag(tag: &str) -> i32;
fn get_asha_packet_drop_frequency_threshold() -> i32;
fn get_asha_phy_update_retry_limit() -> i32;
fn hfp_dynamic_version_is_enabled() -> bool;
diff --git a/system/gd/rust/topshim/src/lib.rs b/system/gd/rust/topshim/src/lib.rs
index 27772b3eb1e6ab6846c0ca7390e91f9ac142dad4..6d7bb3b5b4b56399367f0077abb19326fed16743 100644
--- a/system/gd/rust/topshim/src/lib.rs
+++ b/system/gd/rust/topshim/src/lib.rs
@@ -20,6 +20,7 @@ pub mod btif;
pub mod controller;
pub mod metrics;
pub mod profiles;
+pub mod syslog;
pub mod sysprop;
pub mod topstack;
diff --git a/system/gd/rust/topshim/src/syslog.rs b/system/gd/rust/topshim/src/syslog.rs
new file mode 100644
index 0000000000000000000000000000000000000000..fd575ba485614fd6f1e5da3224901b7cc20bae06
--- /dev/null
+++ b/system/gd/rust/topshim/src/syslog.rs
@@ -0,0 +1,56 @@
+//! Expose some internal methods to set the log level for system syslog.
+//!
+//! On systems that use syslog (i.e. `vlog_syslog.cc`), there is support
+//! to filter out logs before they go to syslog. This module provides Rust apis
+//! to tune log levels for syslog.
+
+use num_derive::ToPrimitive;
+use num_traits::cast::ToPrimitive;
+use std::ffi::CString;
+use std::os::raw::c_char;
+
+#[derive(ToPrimitive)]
+#[repr(u8)]
+/// Android framework log priority levels.
+/// They are defined in system/logging/liblog/include/android/log.h by
+/// the Android Framework code.
+pub enum Level {
+ Verbose = 2,
+ Debug = 3,
+ Info = 4,
+ Warn = 5,
+ Error = 6,
+ Fatal = 7,
+}
+
+// Defined in syslog linkage. See |vlog_syslog.cc|.
+extern "C" {
+ fn SetLogLevelForTag(tag: *const c_char, level: u8);
+ fn SetDefaultLogLevel(level: u8);
+}
+
+/// Set a default level value for failed |level.to_u8()| of |Level::Info|.
+const DEFAULT_LEVEL: u8 = 4;
+
+/// Set the level of logs which will get printed for the given tag.
+///
+/// Args:
+/// tag - LOG_TAG for the system module that's logging.
+/// level - Minimum log level that will be sent to syslog.
+pub fn set_log_level_for_tag(tag: &str, level: Level) {
+ let cstr: CString = CString::new(tag).expect("CString::new failed on log tag");
+
+ unsafe {
+ SetLogLevelForTag(cstr.as_ptr(), level.to_u8().unwrap_or(DEFAULT_LEVEL));
+ }
+}
+
+/// Set the default log level for log tags. Will be overridden by any tag specific levels.
+///
+/// Args:
+/// level - Minimum log level that will be sent to syslog.
+pub fn set_default_log_level(level: Level) {
+ unsafe {
+ SetDefaultLogLevel(level.to_u8().unwrap_or(DEFAULT_LEVEL));
+ }
+}
diff --git a/system/log/src/vlog_syslog.cc b/system/log/src/vlog_syslog.cc
index 9d7dad1a965c0e1674a8fc0b7c6ee349336cc72c..d119ca13396d5f12ebf3cae21baed73451d4b4a7 100644
--- a/system/log/src/vlog_syslog.cc
+++ b/system/log/src/vlog_syslog.cc
@@ -16,17 +16,47 @@
#include <syslog.h>
+#include <string>
+#include <unordered_map>
+
#include "bluetooth/log.h"
#include "truncating_buffer.h"
namespace bluetooth::log_internal {
+// Map of tags with custom levels.
+std::unordered_map<std::string, Level>& GetTagMap() {
+ static std::unordered_map<std::string, Level> tag_level_map;
+ return tag_level_map;
+}
+
+// Default log level.
+Level gDefaultLogLevel = Level::kInfo;
+
+Level GetLogLevelForTag(char const* tag) {
+ auto tag_map = GetTagMap();
+ auto find = tag_map.find(tag);
+ if (find != tag_map.end()) {
+ return find->second;
+ } else {
+ return gDefaultLogLevel;
+ }
+}
+
+Level GetDefaultLogLevel() { return gDefaultLogLevel; }
+
// Default value for $MaxMessageSize for rsyslog.
static constexpr size_t kBufferSize = 8192;
void vlog(Level level, char const* tag, char const* file_name, int line,
char const* function_name, fmt::string_view fmt,
fmt::format_args vargs) {
+ // Filter out logs that don't meet level requirement.
+ Level current_level = GetLogLevelForTag(tag);
+ if (level < current_level) {
+ return;
+ }
+
// Convert the level to syslog severity.
int severity = LOG_DEBUG;
switch (level) {
@@ -64,3 +94,26 @@ void vlog(Level level, char const* tag, char const* file_name, int line,
}
} // namespace bluetooth::log_internal
+
+// These apis will be exposed in topshim to allow control of syslog log levels.
+extern "C" {
+void SetLogLevelForTag(char const* tag, uint8_t level) {
+ if (level < bluetooth::log_internal::Level::kVerbose ||
+ level > bluetooth::log_internal::Level::kFatal) {
+ level = bluetooth::log_internal::GetDefaultLogLevel();
+ }
+
+ bluetooth::log_internal::GetTagMap().emplace(
+ tag, static_cast<bluetooth::log_internal::Level>(level));
+}
+
+void SetDefaultLogLevel(uint8_t level) {
+ if (level < bluetooth::log_internal::Level::kVerbose ||
+ level > bluetooth::log_internal::Level::kFatal) {
+ return;
+ }
+
+ bluetooth::log_internal::gDefaultLogLevel =
+ static_cast<bluetooth::log_internal::Level>(level);
+}
+}