Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 0c1b384e authored by Abhishek Pandit-Subedi's avatar Abhishek Pandit-Subedi
Browse files

floss: Expose debug logging to runtime 

In order to improve debugability, we should be able to control the log
level without having to restart the daemon. Add a d-bus method to get
and set debug logging. Persistence will be handled in a subsequent CL
with a similar api in the manager daemon.

NO_IFTTT=no change required on flag dump

Bug: 241963222
Tag: #floss
Test: Manual test on ChromeOS
Change-Id: Ib95c6dd989c20bd5a1f7eba5dab1887865d1f5d5
parent 1f14ac0d

system/gd/rust/common/src/init_flags.rs

+62 −1
Original line number Diff line number Diff line
@@ -69,14 +69,35 @@ 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 {

    (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 InitFlags {

            $($flag : type_expand!($($type)?),)*

            $($dy_flag : type_expand!($($dy_type)?),)*

            $($extra_field : $extra_field_type,)*

        }
@@ -84,6 +105,7 @@ macro_rules! init_flags { 
            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)?),)*

                }

            }
@@ -94,6 +116,7 @@ macro_rules! init_flags { 
        pub fn set_all_for_testing() {

            *FLAGS.lock().unwrap() = InitFlags {

                $($flag: test_value!($($type)?),)*

                $($dy_flag: test_value!($($dy_type)?),)*

                $($extra_field: test_value!($extra_field_type),)*

            };

        }
@@ -114,6 +137,10 @@ macro_rules! init_flags { 
                            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])

                    }
@@ -145,14 +172,19 @@ macro_rules! init_flags { 
            fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {

                write!(f, concat!(

                    concat!($(concat!(stringify!($flag), "={}")),*),

                    concat!($(concat!(stringify!($dy_flag), "={}")),*),

                    $(concat!(stringify!($extra_field), "={}")),*),

                    $(self.$flag),*,

                    $(self.$dy_flag),*,

                    $(self.$extra_field),*)

            }

        }



        $(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::*;
@@ -168,6 +200,19 @@ macro_rules! init_flags { 
                    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)?));

                }

            })*

        }

    }

}
@@ -223,7 +268,6 @@ init_flags!( 
        hci_adapter: i32,

        irk_rotation,

        leaudio_targeted_announcement_reconnection_mode,

        logging_debug_enabled_for_all,

        pass_phy_update_callback = true,

        periodic_advertising_adi = true,

        queue_l2cap_coc_while_encrypting = true,
@@ -234,6 +278,11 @@ init_flags!( 
        subrating = true,

        trigger_advertising_callbacks_on_first_resume_after_pause = true,

    }

    // dynamic flags can be updated at runtime and should be accessed directly

    // to check.

    dynamic_flags: {

        logging_debug_enabled_for_all,

    }

    // extra_fields are not a 1 to 1 match with "INIT_*" flags

    extra_fields: {

        logging_debug_explicit_tag_settings: ExplicitTagSettings,
@@ -341,4 +390,16 @@ 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_btaa_hci=true", "INIT_logging_debug_enabled_for_all=true"]);

        assert!(btaa_hci_is_enabled());

        assert!(logging_debug_enabled_for_all_is_enabled());



        update_logging_debug_enabled_for_all(false);

        assert!(!logging_debug_enabled_for_all_is_enabled());

        update_logging_debug_enabled_for_all(true);

        assert!(logging_debug_enabled_for_all_is_enabled());

    }

}

system/gd/rust/linux/service/Cargo.toml

+0 −2
Original line number Diff line number Diff line
@@ -14,14 +14,12 @@ dbus_macros = { path = "../dbus_projection/dbus_macros" } 
dbus = "0.9.2"

dbus-crossroads = "0.4.0"

dbus-tokio = "0.7.3"

env_logger = "0.8.3"

futures = "0.3.13"

lazy_static = "1.4"

log = "0.4.14"

nix = "0.23"

num-traits = "0.2"

tokio = { version = "1", features = ['bytes', 'fs', 'io-util', 'libc', 'macros', 'memchr', 'mio', 'net', 'num_cpus', 'rt', 'rt-multi-thread', 'sync', 'time', 'tokio-macros'] }

syslog = "4.0"



[build-dependencies]

pkg-config = "0.3.19"

system/gd/rust/linux/service/src/iface_logging.rs

0 → 100644
+20 −0
Original line number Diff line number Diff line 
use crate::dbus_arg::DBusArg;



use btstack::bluetooth_logging::IBluetoothLogging;

use dbus_macros::{dbus_method, generate_dbus_exporter};

use dbus_projection::dbus_generated;



struct IBluetoothLoggingDBus {}



#[generate_dbus_exporter(export_bluetooth_logging_dbus_intf, "org.chromium.bluetooth.Logging")]

impl IBluetoothLogging for IBluetoothLoggingDBus {

    #[dbus_method("IsDebugEnabled")]

    fn is_debug_enabled(&self) -> bool {

        dbus_generated!()

    }



    #[dbus_method("SetDebugLogging")]

    fn set_debug_logging(&mut self, enabled: bool) {

        dbus_generated!()

    }

}

system/gd/rust/linux/service/src/main.rs

+14 −20
Original line number Diff line number Diff line
@@ -4,12 +4,10 @@ use dbus_crossroads::Crossroads; 
use dbus_tokio::connection;

use futures::future;

use lazy_static::lazy_static;

use log::LevelFilter;

use nix::sys::signal;

use std::error::Error;

use std::sync::{Arc, Condvar, Mutex};

use std::time::Duration;

use syslog::{BasicLogger, Facility, Formatter3164};

use tokio::time;



// Necessary to link right entries.
@@ -24,6 +22,7 @@ use btstack::{ 
    bluetooth::{get_bt_dispatcher, Bluetooth, IBluetooth},

    bluetooth_admin::BluetoothAdmin,

    bluetooth_gatt::BluetoothGatt,

    bluetooth_logging::BluetoothLogging,

    bluetooth_media::BluetoothMedia,

    socket_manager::BluetoothSocketManager,

    suspend::Suspend,
@@ -39,6 +38,7 @@ mod iface_bluetooth; 
mod iface_bluetooth_admin;

mod iface_bluetooth_gatt;

mod iface_bluetooth_media;

mod iface_logging;



const DBUS_SERVICE_NAME: &str = "org.chromium.bluetooth";

const ADMIN_SETTINGS_FILE_PATH: &str = "/var/lib/bluetooth/admin_policy.json";
@@ -101,23 +101,6 @@ fn main() -> Result<(), Box<dyn Error>> { 
    // Forward --hci to Fluoride.

    init_flags.push(format!("--hci={}", hci_index));



    let level_filter = if is_debug { LevelFilter::Debug } else { LevelFilter::Info };



    if log_output == "stderr" {

        env_logger::Builder::new().filter(None, level_filter).init();

    } else {

        let formatter = Formatter3164 {

            facility: Facility::LOG_USER,

            hostname: None,

            process: "btadapterd".into(),

            pid: 0,

        };



        let logger = syslog::unix(formatter).expect("could not connect to syslog");

        let _ = log::set_boxed_logger(Box::new(BasicLogger::new(logger)))

            .map(|()| log::set_max_level(level_filter));

    }



    let (tx, rx) = Stack::create_channel();

    let sig_notifier = Arc::new((Mutex::new(false), Condvar::new()));
@@ -157,7 +140,7 @@ fn main() -> Result<(), Box<dyn Error>> { 
        bluetooth_gatt.clone(),

        tx.clone(),

    ))));



    let logging = Arc::new(Mutex::new(Box::new(BluetoothLogging::new(is_debug, log_output))));

    let bt_sock_mgr = Arc::new(Mutex::new(Box::new(BluetoothSocketManager::new(tx.clone()))));



    topstack::get_runtime().block_on(async {
@@ -240,6 +223,11 @@ fn main() -> Result<(), Box<dyn Error>> { 
            &mut cr.lock().unwrap(),

            disconnect_watcher.clone(),

        );

        let logging_iface = iface_logging::export_bluetooth_logging_dbus_intf(

            conn.clone(),

            &mut cr.lock().unwrap(),

            disconnect_watcher.clone(),

        );



        // Register D-Bus method handlers of IBluetoothGatt.

        let gatt_iface = iface_bluetooth_gatt::export_bluetooth_gatt_dbus_intf(
@@ -315,6 +303,12 @@ fn main() -> Result<(), Box<dyn Error>> { 
            bluetooth_admin.clone(),

        );



        cr.lock().unwrap().insert(

            make_object_name(adapter_index, "logging"),

            &[logging_iface],

            logging.clone(),

        );



        // Hold locks and initialize all interfaces. This must be done AFTER DBus is

        // initialized so DBus can properly enforce user policies.

        {

system/gd/rust/linux/stack/Cargo.toml

+3 −0
Original line number Diff line number Diff line
@@ -4,6 +4,7 @@ version = "0.1.0" 
edition = "2018"



[dependencies]

bt_common = { path = "../../common" }

bt_topshim = { path = "../../topshim" }

bt_shim = { path = "../../shim" }

bt_utils = { path = "../utils" }
@@ -11,6 +12,7 @@ bt_utils = { path = "../utils" } 
btif_macros = { path = "btif_macros" }



dbus = "0.9.2"

env_logger = "0.8.3"

itertools = "0.10.5"

lazy_static = "1.4"

log = "0.4.14"
@@ -19,6 +21,7 @@ num-derive = "0.3" 
num-traits = "0.2"

rand = { version = "0.8.3", features = ["small_rng"] }

serde_json = "1.0"

syslog = "4.0"

tokio = { version = "1", features = ['bytes', 'fs', 'io-util', 'libc', 'macros', 'memchr', 'mio', 'net', 'num_cpus', 'rt', 'rt-multi-thread', 'sync', 'time', 'tokio-macros'] }



[lib]