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

Commit 466a5d8e authored by Henri Chataing's avatar Henri Chataing
Browse files

system/gd/metrics: Migrate to libbluetooth_log

Test: m com.android.btservices
Bug: 305066880
Flag: EXEMPT, mechanical refactor
Change-Id: I2a8e38f4ded567676d4f93df38e735700409949d
parent 6b1c4252
Loading
Loading
Loading
Loading
+33 −27
Original line number Diff line number Diff line
@@ -17,6 +17,7 @@

#include "metrics/metrics.h"

#include <bluetooth/log.h>
#include <metrics/structured_events.h>

#include "common/time_util.h"
@@ -43,7 +44,7 @@ void LogMetricsAdapterStateChanged(uint32_t state) {
  adapter_state = (int64_t)ToAdapterState(state);
  boot_time = bluetooth::common::time_get_os_boottime_us();

  LOG_DEBUG("AdapterStateChanged: %s, %d, %d", boot_id.c_str(), boot_time, adapter_state);
  log::debug("AdapterStateChanged: {}, {}, {}", boot_id, boot_time, adapter_state);

  ::metrics::structured::events::bluetooth::BluetoothAdapterStateChanged()
      .SetBootId(boot_id)
@@ -67,11 +68,11 @@ void LogMetricsBondCreateAttempt(RawAddress* addr, uint32_t device_type) {
  boot_time = bluetooth::common::time_get_os_boottime_us();
  connection_type = ToPairingDeviceType(addr_string, device_type);

  LOG_DEBUG(
      "PairingStateChanged: %s, %d, %s, %d, %d",
      boot_id.c_str(),
  log::debug(
      "PairingStateChanged: {}, {}, {}, {}, {}",
      boot_id,
      (int)boot_time,
      addr_string.c_str(),
      addr_string,
      (int)connection_type,
      (int)PairingState::PAIR_STARTING);

@@ -105,11 +106,11 @@ void LogMetricsBondStateChanged(
  // Ignore absurd state.
  if (pairing_state == PairingState::PAIR_FAIL_END) return;

  LOG_DEBUG(
      "PairingStateChanged: %s, %d, %s, %d, %d",
      boot_id.c_str(),
  log::debug(
      "PairingStateChanged: {}, {}, {}, {}, {}",
      boot_id,
      (int)boot_time,
      addr_string.c_str(),
      addr_string,
      (int)connection_type,
      (int)pairing_state);

@@ -145,11 +146,11 @@ void LogMetricsDeviceInfoReport(
  major_class = (class_of_device & DEVICE_MAJOR_CLASS_MASK) >> DEVICE_MAJOR_CLASS_BIT_OFFSET;
  category = (appearance & DEVICE_CATEGORY_MASK) >> DEVICE_CATEGORY_BIT_OFFSET;

  LOG_DEBUG(
      "DeviceInfoReport %s %d %s %d %d %d %d %d %d %d",
      boot_id.c_str(),
  log::debug(
      "DeviceInfoReport {} {} {} {} {} {} {} {} {} {}",
      boot_id,
      (int)boot_time,
      addr_string.c_str(),
      addr_string,
      (int)device_type,
      (int)major_class,
      (int)category,
@@ -193,11 +194,11 @@ void LogMetricsProfileConnectionStateChanged(RawAddress* addr, uint32_t profile,

  if (Profile::UNKNOWN == (Profile)event.profile) return;

  LOG_DEBUG(
      "ProfileConnectionStateChanged: %s, %d, %s, %d, %d, %d",
      boot_id.c_str(),
  log::debug(
      "ProfileConnectionStateChanged: {}, {}, {}, {}, {}, {}",
      boot_id,
      (int)boot_time,
      addr_string.c_str(),
      addr_string,
      (int)event.type,
      (int)event.profile,
      (int)event.state);
@@ -242,11 +243,11 @@ void LogMetricsAclConnectionStateChanged(
    return;
  }

  LOG_DEBUG(
      "AclConnectionStateChanged: %s, %d, %s, %d, %d, %d, %d, %d",
      boot_id.c_str(),
  log::debug(
      "AclConnectionStateChanged: {}, {}, {}, {}, {}, {}, {}, {}",
      boot_id,
      (int)event.start_time,
      addr_string.c_str(),
      addr_string,
      (int)transport,
      (int)event.direction,
      (int)event.initiator,
@@ -265,11 +266,11 @@ void LogMetricsAclConnectionStateChanged(
      .SetAclConnectionState(event.start_status)
      .Record();

  LOG_DEBUG(
      "AclConnectionStateChanged: %s, %d, %s, %d, %d, %d, %d, %d",
      boot_id.c_str(),
  log::debug(
      "AclConnectionStateChanged: {}, {}, {}, {}, {}, {}, {}, {}",
      boot_id,
      (int)boot_time,
      addr_string.c_str(),
      addr_string,
      (int)transport,
      (int)event.direction,
      (int)event.initiator,
@@ -305,7 +306,12 @@ void LogMetricsChipsetInfoReport() {
    return;
  }

  LOG_DEBUG("ChipsetInfoReport: 0x%x 0x%x %d %s", info->vid, info->pid, info->transport, info->chipset_string.c_str());
  log::debug(
      "ChipsetInfoReport: 0x{:x} 0x{:x} {} {}",
      info->vid,
      info->pid,
      info->transport,
      info->chipset_string);

  if (IsChipsetInfoInAllowList(
          info->vid, info->pid, info->transport, info->chipset_string.c_str(), &chipset_string_hval)) {
@@ -328,7 +334,7 @@ void LogMetricsSuspendIdState(uint32_t state) {
  boot_time = bluetooth::common::time_get_os_boottime_us();

  suspend_id_state = (int64_t)ToSuspendIdState(state);
  LOG_DEBUG("SuspendIdState: %s, %d, %d", boot_id.c_str(), boot_time, suspend_id_state);
  log::debug("SuspendIdState: {}, {}, {}", boot_id, boot_time, suspend_id_state);

  ::metrics::structured::events::bluetooth::BluetoothSuspendIdStateChanged()
      .SetBootId(boot_id)
+17 −12
Original line number Diff line number Diff line
@@ -17,6 +17,8 @@

#include "metrics/counter_metrics.h"

#include <bluetooth/log.h>

#include "common/bind.h"
#include "os/log.h"
#include "os/metrics.h"
@@ -36,7 +38,7 @@ void CounterMetrics::Start() {
      common::Bind(&CounterMetrics::DrainBufferedCounters,
           bluetooth::common::Unretained(this)),
      std::chrono::minutes(COUNTER_METRICS_PERDIOD_MINUTES));
  LOG_INFO("Counter metrics initialized");
  log::info("Counter metrics initialized");
  initialized_ = true;
}

@@ -45,16 +47,16 @@ void CounterMetrics::Stop() {
  initialized_ = false;
  alarm_->Cancel();
  alarm_.reset();
  LOG_INFO("Counter metrics canceled");
  log::info("Counter metrics canceled");
}

bool CounterMetrics::CacheCount(int32_t key, int64_t count) {
  if (!IsInitialized()) {
    LOG_WARN("Counter metrics isn't initialized");
    log::warn("Counter metrics isn't initialized");
    return false;
  }
  if (count <= 0) {
    LOG_WARN("count is not larger than 0. count: %s, key: %d", std::to_string(count).c_str(), key);
    log::warn("count is not larger than 0. count: {}, key: {}", std::to_string(count), key);
    return false;
  }
  int64_t total = 0;
@@ -63,8 +65,11 @@ bool CounterMetrics::CacheCount(int32_t key, int64_t count) {
    total = counters_[key];
  }
  if (LLONG_MAX - total < count) {
      LOG_WARN("Counter metric overflows. count %s current total: %s key: %d",
               std::to_string(count).c_str(), std::to_string(total).c_str(), key);
    log::warn(
        "Counter metric overflows. count {} current total: {} key: {}",
        std::to_string(count),
        std::to_string(total),
        key);
    counters_[key] = LLONG_MAX;
    return false;
  }
@@ -74,11 +79,11 @@ bool CounterMetrics::CacheCount(int32_t key, int64_t count) {

bool CounterMetrics::Count(int32_t key, int64_t count) {
  if (!IsInitialized()) {
    LOG_WARN("Counter metrics isn't initialized");
    log::warn("Counter metrics isn't initialized");
    return false;
  }
  if (count <= 0) {
    LOG_WARN("count is not larger than 0. count: %s, key: %d", std::to_string(count).c_str(), key);
    log::warn("count is not larger than 0. count: {}, key: {}", std::to_string(count), key);
    return false;
  }
  os::LogMetricBluetoothCodePathCounterMetrics(key, count);
@@ -87,11 +92,11 @@ bool CounterMetrics::Count(int32_t key, int64_t count) {

void CounterMetrics::DrainBufferedCounters() {
  if (!IsInitialized()) {
    LOG_WARN("Counter metrics isn't initialized");
    log::warn("Counter metrics isn't initialized");
    return ;
  }
  std::lock_guard<std::mutex> lock(mutex_);
  LOG_INFO("Draining buffered counters");
  log::info("Draining buffered counters");
  for (auto const& pair : counters_) {
    Count(pair.first, pair.second);
  }
+15 −14
Original line number Diff line number Diff line
@@ -16,6 +16,7 @@

#include "metrics_state.h"

#include <bluetooth/log.h>
#include <frameworks/proto_logging/stats/enums/bluetooth/hci/enums.pb.h>
#include <frameworks/proto_logging/stats/enums/bluetooth/le/enums.pb.h>

@@ -74,7 +75,7 @@ void LEConnectionMetricState::AddStateChangedEvent(
      if (connection_type_cid != -1) {
        LeConnectionType connection_type = GetLeConnectionTypeFromCID(connection_type_cid);
        if (connection_type != LeConnectionType::CONNECTION_TYPE_UNSPECIFIED) {
          LOG_INFO("LEConnectionMetricsRemoteDevice: Populating the connection type\n");
          log::info("LEConnectionMetricsRemoteDevice: Populating the connection type");
          input_connection_type = connection_type;
        }
      }
@@ -150,8 +151,8 @@ void LEConnectionMetricsRemoteDevice::UploadLEConnectionSession(const hci::Addre
    session_options.acl_latency = session_options.latency;
    session_options.is_cancelled = it->second->is_cancelled;
    metrics_logger_module->LogMetricBluetoothLESession(session_options);
    LOG_INFO(
        "LEConnectionMetricsRemoteDevice: The session is uploaded for %s\n",
    log::info(
        "LEConnectionMetricsRemoteDevice: The session is uploaded for {}",
        ADDRESS_TO_LOGGABLE_CSTR(address));
    opened_devices.erase(it);
  }
@@ -164,23 +165,23 @@ void LEConnectionMetricsRemoteDevice::AddStateChangedEvent(
    LeConnectionType connection_type,
    LeConnectionState transaction_state,
    std::vector<std::pair<os::ArgumentType, int>> argument_list) {
  LOG_INFO(
        "LEConnectionMetricsRemoteDevice: Transaction State %s, Connection Type %s, Origin Type %s\n",
        common::ToHexString(transaction_state).c_str(),
        common::ToHexString(connection_type).c_str(),
        common::ToHexString(origin_type).c_str());
  log::info(
      "LEConnectionMetricsRemoteDevice: Transaction State {}, Connection Type {}, Origin Type {}",
      common::ToHexString(transaction_state),
      common::ToHexString(connection_type),
      common::ToHexString(origin_type));

  std::unique_lock<std::mutex> lock(le_connection_metrics_remote_device_guard);
  if (address.IsEmpty()) {
    LOG_INFO(
        "LEConnectionMetricsRemoteDevice: Empty Address Cancellation %s, %s, %s\n",
        common::ToHexString(transaction_state).c_str(),
        common::ToHexString(connection_type).c_str(),
        common::ToHexString(transaction_state).c_str());
    log::info(
        "LEConnectionMetricsRemoteDevice: Empty Address Cancellation {}, {}, {}",
        common::ToHexString(transaction_state),
        common::ToHexString(connection_type),
        common::ToHexString(transaction_state));
    for (auto& device_metric : device_metrics) {
      if (device_metric->IsStarted() &&
          transaction_state == LeConnectionState::STATE_LE_ACL_CANCEL) {
        LOG_INFO("LEConnectionMetricsRemoteDevice: Cancellation Begin");
        log::info("LEConnectionMetricsRemoteDevice: Cancellation Begin");
        // cancel the connection
        device_metric->AddStateChangedEvent(
            origin_type, connection_type, transaction_state, argument_list);