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

Commit 674384c6 authored by Yun-Hao Chung's avatar Yun-Hao Chung
Browse files

Floss: Allow set log level from btclient

In some cases we want to ask user to provide verbose logs but this is
impossible if they are not in developer mode.

This implements the commands in btclient to set and get the current log
level via btclient.

Bug: 369506387
Tag: #floss
Test: mmm packages/modules/Bluetooth
Test: Deploy to ciri and verified manually
Flag: EXEMPT, Floss-only changes
Change-Id: I38777d0d66c9f570b944c018389215919e8f0064
parent 535a6b8f
Loading
Loading
Loading
Loading
+47 −0
Original line number Diff line number Diff line
@@ -16,12 +16,14 @@ use bt_topshim::profiles::gatt::{GattStatus, LePhy};
use bt_topshim::profiles::hid_host::BthhReportType;
use bt_topshim::profiles::sdp::{BtSdpMpsRecord, BtSdpRecord};
use bt_topshim::profiles::ProfileConnectionState;
use bt_topshim::syslog::Level;
use btstack::battery_manager::IBatteryManager;
use btstack::bluetooth::{BluetoothDevice, IBluetooth};
use btstack::bluetooth_gatt::{
    BluetoothGattCharacteristic, BluetoothGattDescriptor, BluetoothGattService, GattDbElementType,
    GattWriteType, IBluetoothGatt,
};
use btstack::bluetooth_logging::IBluetoothLogging;
use btstack::bluetooth_media::{IBluetoothMedia, IBluetoothTelephony};
use btstack::bluetooth_qa::IBluetoothQA;
use btstack::socket_manager::{IBluetoothSocketManager, SocketResult};
@@ -397,6 +399,17 @@ fn build_commands() -> HashMap<String, CommandOption> {
            function_pointer: CommandHandler::cmd_dumpsys,
        },
    );
    command_options.insert(
        String::from("log"),
        CommandOption {
            rules: vec![
                String::from("log set-level <info|debug|verbose>"),
                String::from("log get-level"),
            ],
            description: String::from("Get/set log level"),
            function_pointer: CommandHandler::cmd_log,
        },
    );
    command_options
}

@@ -2353,6 +2366,40 @@ impl CommandHandler {

        Ok(())
    }

    fn cmd_log(&mut self, args: &[String]) -> CommandResult {
        if !self.lock_context().adapter_ready {
            return Err(self.adapter_not_ready());
        }

        let command = get_arg(args, 0)?;

        match &command[..] {
            "set-level" => {
                let level = match &get_arg(args, 1)?[..] {
                    "info" => Level::Info,
                    "debug" => Level::Debug,
                    "verbose" => Level::Verbose,
                    _ => {
                        return Err("Failed to parse log level".into());
                    }
                };
                self.lock_context().logging_dbus.as_mut().unwrap().set_log_level(level);
            }

            "get-level" => {
                let level = self.lock_context().logging_dbus.as_ref().unwrap().get_log_level();

                print_info!("log level: {:?}", level);
            }

            other => {
                return Err(format!("Invalid argument '{}'", other).into());
            }
        }

        Ok(())
    }
}

#[cfg(test)]
+57 −0
Original line number Diff line number Diff line
@@ -24,6 +24,7 @@ use bt_topshim::profiles::sdp::{
};
use bt_topshim::profiles::socket::SocketType;
use bt_topshim::profiles::ProfileConnectionState;
use bt_topshim::syslog::Level;

use btstack::battery_manager::{Battery, BatterySet, IBatteryManager, IBatteryManagerCallback};
use btstack::bluetooth::{
@@ -52,6 +53,7 @@ use btstack::socket_manager::{
};
use btstack::{RPCProxy, SuspendMode};

use btstack::bluetooth_logging::IBluetoothLogging;
use btstack::suspend::{ISuspend, ISuspendCallback, SuspendType};

use dbus::arg::RefArg;
@@ -115,6 +117,7 @@ impl_dbus_arg_enum!(BthhReportType);
impl_dbus_arg_enum!(BtAdapterRole);

impl_dbus_arg_enum!(BtSdpType);
impl_dbus_arg_enum!(Level);

#[dbus_propmap(BtSdpHeaderOverlay)]
struct BtSdpHeaderOverlayDBus {
@@ -3074,3 +3077,57 @@ impl IBatteryManagerCallback for IBatteryManagerCallbackDBus {
    #[dbus_method("OnBatteryInfoUpdated")]
    fn on_battery_info_updated(&mut self, remote_address: RawAddress, battery_set: BatterySet) {}
}

#[allow(dead_code)]
pub(crate) struct BluetoothLoggingDBusRPC {
    client_proxy: ClientDBusProxy,
}

#[allow(dead_code)]
pub(crate) struct BluetoothLoggingDBus {
    client_proxy: ClientDBusProxy,
    pub rpc: BluetoothLoggingDBusRPC,
}

impl BluetoothLoggingDBus {
    fn make_client_proxy(conn: Arc<SyncConnection>, index: i32) -> ClientDBusProxy {
        ClientDBusProxy::new(
            conn.clone(),
            String::from("org.chromium.bluetooth"),
            make_object_path(index, "logging"),
            String::from("org.chromium.bluetooth.Logging"),
        )
    }

    pub(crate) fn new(conn: Arc<SyncConnection>, index: i32) -> BluetoothLoggingDBus {
        BluetoothLoggingDBus {
            client_proxy: Self::make_client_proxy(conn.clone(), index),
            rpc: BluetoothLoggingDBusRPC {
                client_proxy: Self::make_client_proxy(conn.clone(), index),
            },
        }
    }
}

#[generate_dbus_interface_client(BluetoothLoggingDBusRPC)]
impl IBluetoothLogging for BluetoothLoggingDBus {
    #[dbus_method("IsDebugEnabled")]
    fn is_debug_enabled(&self) -> bool {
        dbus_generated!()
    }

    #[dbus_method("SetDebugLogging")]
    fn set_debug_logging(&mut self, enabled: bool) {
        dbus_generated!()
    }

    #[dbus_method("SetLogLevel")]
    fn set_log_level(&mut self, level: Level) {
        dbus_generated!()
    }

    #[dbus_method("GetLogLevel")]
    fn get_log_level(&self) -> Level {
        dbus_generated!()
    }
}
+9 −3
Original line number Diff line number Diff line
@@ -20,9 +20,9 @@ use crate::callbacks::{
};
use crate::command_handler::{CommandHandler, SocketSchedule};
use crate::dbus_iface::{
    BatteryManagerDBus, BluetoothAdminDBus, BluetoothDBus, BluetoothGattDBus, BluetoothManagerDBus,
    BluetoothMediaDBus, BluetoothQADBus, BluetoothQALegacyDBus, BluetoothSocketManagerDBus,
    BluetoothTelephonyDBus, SuspendDBus,
    BatteryManagerDBus, BluetoothAdminDBus, BluetoothDBus, BluetoothGattDBus, BluetoothLoggingDBus,
    BluetoothManagerDBus, BluetoothMediaDBus, BluetoothQADBus, BluetoothQALegacyDBus,
    BluetoothSocketManagerDBus, BluetoothTelephonyDBus, SuspendDBus,
};
use crate::editor::AsyncEditor;
use bt_topshim::{btif::RawAddress, topstack};
@@ -113,6 +113,9 @@ pub(crate) struct ClientContext {
    /// Proxy for battery manager interface.
    pub(crate) battery_manager_dbus: Option<BatteryManagerDBus>,

    /// Proxy for logging interface.
    pub(crate) logging_dbus: Option<BluetoothLoggingDBus>,

    /// Channel to send actions to take in the foreground
    fg: mpsc::Sender<ForegroundActions>,

@@ -201,6 +204,7 @@ impl ClientContext {
            telephony_dbus: None,
            media_dbus: None,
            battery_manager_dbus: None,
            logging_dbus: None,
            fg: tx,
            dbus_connection,
            dbus_crossroads,
@@ -269,6 +273,8 @@ impl ClientContext {

        self.battery_manager_dbus = Some(BatteryManagerDBus::new(conn.clone(), idx));

        self.logging_dbus = Some(BluetoothLoggingDBus::new(conn.clone(), idx));

        // Trigger callback registration in the foreground
        let fg = self.fg.clone();
        tokio::spawn(async move {
+19 −0
Original line number Diff line number Diff line
use crate::dbus_arg::DBusArg;

use bt_topshim::syslog::Level;
use btstack::bluetooth_logging::IBluetoothLogging;
use dbus_macros::{dbus_method, generate_dbus_exporter};
use dbus_projection::prelude::*;

use num_traits::cast::{FromPrimitive, ToPrimitive};

use crate::dbus_arg::DBusArgError;
use dbus::nonblock::SyncConnection;
use std::sync::Arc;

#[allow(dead_code)]
struct IBluetoothLoggingDBus {}

impl_dbus_arg_enum!(Level);

#[generate_dbus_exporter(export_bluetooth_logging_dbus_intf, "org.chromium.bluetooth.Logging")]
impl IBluetoothLogging for IBluetoothLoggingDBus {
    #[dbus_method("IsDebugEnabled")]
@@ -18,4 +27,14 @@ impl IBluetoothLogging for IBluetoothLoggingDBus {
    fn set_debug_logging(&mut self, enabled: bool) {
        dbus_generated!()
    }

    #[dbus_method("SetLogLevel")]
    fn set_log_level(&mut self, level: Level) {
        dbus_generated!()
    }

    #[dbus_method("GetLogLevel")]
    fn get_log_level(&self) -> Level {
        dbus_generated!()
    }
}
+66 −35
Original line number Diff line number Diff line
@@ -17,17 +17,19 @@ pub trait IBluetoothLogging {

    /// Change whether debug logging is enabled.
    fn set_debug_logging(&mut self, enabled: bool);

    /// Set the log level.
    fn set_log_level(&mut self, level: Level);

    /// Get the log level.
    fn get_log_level(&self) -> Level;
}

/// 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,
    /// Current log level
    /// If the level is not verbose, `VERBOSE_ONLY_LOG_TAGS` will be set to emit up to `INFO` only.
    log_level: Level,

    /// Log to stderr?
    is_stderr: bool,
@@ -48,14 +50,19 @@ const VERBOSE_ONLY_LOG_TAGS: &[&str] = &[
impl BluetoothLogging {
    pub fn new(is_debug: bool, is_verbose_debug: bool, log_output: &str) -> Self {
        let is_stderr = log_output == "stderr";
        Self { is_debug, is_verbose_debug, is_stderr, is_initialized: false }

        let log_level = match (is_debug, is_verbose_debug) {
            (true, true) => Level::Verbose,
            (true, false) => Level::Debug,
            _ => Level::Info,
        };

        Self { log_level, is_stderr, is_initialized: false }
    }

    pub fn initialize(&mut self) -> Result<(), Error> {
        let level = if self.is_debug { LevelFilter::Debug } else { LevelFilter::Info };

        if self.is_stderr {
            env_logger::Builder::new().filter(None, level).init();
            env_logger::Builder::new().filter(None, self.get_log_level_filter()).init();
        } else {
            let formatter = Formatter3164 {
                facility: Facility::LOG_USER,
@@ -66,61 +73,85 @@ impl BluetoothLogging {

            let logger = syslog::unix(formatter)?;
            let _ = log::set_boxed_logger(Box::new(BasicLogger::new(logger)))
                .map(|()| log::set_max_level(level));
                .map(|()| self.apply_linux_log_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);
            }
        }
        self.apply_libbluetooth_log_level();

        // 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
    fn get_log_level_filter(&self) -> LevelFilter {
        match self.is_debug_enabled() {
            true => LevelFilter::Debug,
            false => LevelFilter::Info,
        }
        } else {
            Level::Info
    }

    fn apply_linux_log_level(&self) {
        log::set_max_level(self.get_log_level_filter());
    }

    fn apply_libbluetooth_log_level(&self) {
        set_default_log_level(self.log_level);
        // Levels for verbose-only tags.
        let level = match self.log_level {
            Level::Verbose => Level::Verbose,
            _ => Level::Info,
        };
        for tag in VERBOSE_ONLY_LOG_TAGS {
            log::info!("Setting log level for tag {} to {:?}", tag, level);
            set_log_level_for_tag(tag, level);
        }
    }
}

impl IBluetoothLogging for BluetoothLogging {
    fn is_debug_enabled(&self) -> bool {
        self.is_initialized && self.is_debug
        self.is_initialized && (self.log_level == Level::Debug || self.log_level == Level::Verbose)
    }

    fn set_debug_logging(&mut self, enabled: bool) {
        if enabled {
            match self.log_level {
                Level::Verbose => {
                    self.set_log_level(Level::Verbose);
                }
                _ => {
                    self.set_log_level(Level::Debug);
                }
            }
        } else {
            self.set_log_level(Level::Info);
        }
    }

    fn set_log_level(&mut self, level: Level) {
        if !self.is_initialized {
            return;
        }

        self.is_debug = enabled;
        self.log_level = level;

        // Update log level in Linux stack.
        let level = if self.is_debug { LevelFilter::Debug } else { LevelFilter::Info };
        log::set_max_level(level);
        self.apply_linux_log_level();

        // Update log level in libbluetooth.
        let level = self.get_libbluetooth_level();
        set_default_log_level(level);
        self.apply_libbluetooth_log_level();

        // Mark the start of debug logging with a debug print.
        if self.is_debug {
        if self.is_debug_enabled() {
            log::debug!("Debug logging successfully enabled!");
        }

        log::info!("Setting debug logging to {}", self.is_debug);
        log::info!("Setting log level to {:?}", level);
    }

    fn get_log_level(&self) -> Level {
        self.log_level
    }
}
Loading