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

Commit fdbe9e35 authored by Archie Pusaka's avatar Archie Pusaka
Browse files

pm: demote several noisy logs to verbose

A lot of logging in pm is noisy, either give excessive information
that is given immediately by the preceding/succeding functions, or
just in high frequency within a short time. Demote those to verbose
level logging.

Additionally, also add BTM_PM_STS_PENDING to the pm status handler
even though it does nothing, because otherwise it would be logged as
an error, but it's just noisy.

Bug: 343276940, 335065189
Test: m -j
Flag: EXEMPT, logging only changes
Change-Id: If10c59a93301934db990b28564f7bd502954e13e
parent b56b24f9
Loading
Loading
Loading
Loading
+14 −12
Original line number Original line Diff line number Diff line
@@ -425,7 +425,7 @@ static void bta_dm_pm_cback(tBTA_SYS_CONN_STATUS status, const tBTA_SYS_ID id,
  tBTA_DM_PEER_DEVICE* p_dev;
  tBTA_DM_PEER_DEVICE* p_dev;
  tBTA_DM_PM_REQ pm_req = BTA_DM_PM_NEW_REQ;
  tBTA_DM_PM_REQ pm_req = BTA_DM_PM_NEW_REQ;


  log::debug("Power management callback status:{}[{}] id:{}[{}], app:{}",
  log::verbose("Power management callback status:{}[{}] id:{}[{}], app:{}",
               bta_sys_conn_status_text(status), status, BtaIdSysText(id), id,
               bta_sys_conn_status_text(status), status, BtaIdSysText(id), id,
               app_id);
               app_id);


@@ -445,13 +445,13 @@ static void bta_dm_pm_cback(tBTA_SYS_CONN_STATUS status, const tBTA_SYS_ID id,
    return;
    return;
  }
  }


  log::debug("Stopped all timers for service to device:{} id:{}[{}]", peer_addr,
  log::verbose("Stopped all timers for service to device:{} id:{}[{}]",
             BtaIdSysText(id), id);
               peer_addr, BtaIdSysText(id), id);
  bta_dm_pm_stop_timer_by_srvc_id(peer_addr, static_cast<uint8_t>(id));
  bta_dm_pm_stop_timer_by_srvc_id(peer_addr, static_cast<uint8_t>(id));


  p_dev = bta_dm_find_peer_device(peer_addr);
  p_dev = bta_dm_find_peer_device(peer_addr);
  if (p_dev) {
  if (p_dev) {
    log::debug("Device info:{}", p_dev->info_text());
    log::verbose("Device info:{}", p_dev->info_text());
  } else {
  } else {
    log::error("Unable to find peer device...yet soldiering on...");
    log::error("Unable to find peer device...yet soldiering on...");
  }
  }
@@ -632,7 +632,7 @@ static void bta_dm_pm_set_mode(const RawAddress& peer_addr,
      p_act1 = &p_pm_spec->actn_tbl[p_srvcs->state][1];
      p_act1 = &p_pm_spec->actn_tbl[p_srvcs->state][1];


      allowed_modes |= p_pm_spec->allow_mask;
      allowed_modes |= p_pm_spec->allow_mask;
      log::debug(
      log::verbose(
          "Service:{}[{}] state:{}[{}] allowed_modes:0x{:02x} service_index:{}",
          "Service:{}[{}] state:{}[{}] allowed_modes:0x{:02x} service_index:{}",
          BtaIdSysText(p_srvcs->id), p_srvcs->id,
          BtaIdSysText(p_srvcs->id), p_srvcs->id,
          bta_sys_conn_status_text(p_srvcs->state), p_srvcs->state,
          bta_sys_conn_status_text(p_srvcs->state), p_srvcs->state,
@@ -737,7 +737,7 @@ static void bta_dm_pm_set_mode(const RawAddress& peer_addr,
  } else if (pm_action & BTA_DM_PM_SNIFF) {
  } else if (pm_action & BTA_DM_PM_SNIFF) {
    /* dont initiate SNIFF, if link_policy has it disabled */
    /* dont initiate SNIFF, if link_policy has it disabled */
    if (BTM_is_sniff_allowed_for(peer_addr)) {
    if (BTM_is_sniff_allowed_for(peer_addr)) {
      log::debug("Link policy allows sniff mode so setting mode peer:{}",
      log::verbose("Link policy allows sniff mode so setting mode peer:{}",
                   peer_addr);
                   peer_addr);
      p_peer_device->pm_mode_attempted = BTA_DM_PM_SNIFF;
      p_peer_device->pm_mode_attempted = BTA_DM_PM_SNIFF;
      bta_dm_pm_sniff(p_peer_device, (uint8_t)(pm_action & 0x0F));
      bta_dm_pm_sniff(p_peer_device, (uint8_t)(pm_action & 0x0F));
@@ -746,7 +746,7 @@ static void bta_dm_pm_set_mode(const RawAddress& peer_addr,
                 peer_addr);
                 peer_addr);
    }
    }
  } else if (pm_action == BTA_DM_PM_ACTIVE) {
  } else if (pm_action == BTA_DM_PM_ACTIVE) {
    log::debug("Setting link to active mode peer:{}", peer_addr);
    log::verbose("Setting link to active mode peer:{}", peer_addr);
    bta_dm_pm_active(peer_addr);
    bta_dm_pm_active(peer_addr);
  }
  }
}
}
@@ -1072,7 +1072,7 @@ static void bta_dm_pm_timer_cback(void* data) {
static void bta_dm_pm_btm_status(const RawAddress& bd_addr,
static void bta_dm_pm_btm_status(const RawAddress& bd_addr,
                                 tBTM_PM_STATUS status, uint16_t interval,
                                 tBTM_PM_STATUS status, uint16_t interval,
                                 tHCI_STATUS hci_status) {
                                 tHCI_STATUS hci_status) {
  log::debug(
  log::verbose(
      "Power mode notification event status:{} peer:{} interval:{} "
      "Power mode notification event status:{} peer:{} interval:{} "
      "hci_status:{}",
      "hci_status:{}",
      power_mode_status_text(status), bd_addr, interval,
      power_mode_status_text(status), bd_addr, interval,
@@ -1154,6 +1154,8 @@ static void bta_dm_pm_btm_status(const RawAddress& bd_addr,
    case BTM_PM_STS_ERROR:
    case BTM_PM_STS_ERROR:
      p_dev->reset_sniff_command_sent();
      p_dev->reset_sniff_command_sent();
      break;
      break;
    case BTM_PM_STS_PENDING:
      break;


    default:
    default:
      log::error("Received unknown power mode status event:{}", status);
      log::error("Received unknown power mode status event:{}", status);
+8 −7
Original line number Original line Diff line number Diff line
@@ -521,7 +521,7 @@ static tBTM_STATUS btm_pm_snd_md_req(uint16_t handle, uint8_t pm_id,
  mode = btm_pm_get_set_mode(pm_id, p_cb, p_mode, &md_res);
  mode = btm_pm_get_set_mode(pm_id, p_cb, p_mode, &md_res);
  md_res.mode = mode;
  md_res.mode = mode;


  log::debug("Found controller in mode:{}", power_mode_text(mode));
  log::verbose("Found controller in mode:{}", power_mode_text(mode));


  if (p_cb->state == mode) {
  if (p_cb->state == mode) {
    log::info("Link already in requested mode pm_id:{} link_ind:{} mode:{}[{}]",
    log::info("Link already in requested mode pm_id:{} link_ind:{} mode:{}[{}]",
@@ -671,12 +671,12 @@ void btm_pm_proc_cmd_status(tHCI_STATUS status) {
  /* notify the caller is appropriate */
  /* notify the caller is appropriate */
  if ((pm_pend_id != BTM_PM_SET_ONLY_ID) && (pm_reg_db.mask & BTM_PM_REG_SET)) {
  if ((pm_pend_id != BTM_PM_SET_ONLY_ID) && (pm_reg_db.mask & BTM_PM_REG_SET)) {
    const RawAddress bd_addr = pm_mode_db[pm_pend_link].bda_;
    const RawAddress bd_addr = pm_mode_db[pm_pend_link].bda_;
    log::debug("Notifying callback that link power mode is complete peer:{}",
    log::verbose("Notifying callback that link power mode is complete peer:{}",
                 bd_addr);
                 bd_addr);
    (*pm_reg_db.cback)(bd_addr, pm_status, 0, status);
    (*pm_reg_db.cback)(bd_addr, pm_status, 0, status);
  }
  }


  log::info("Clearing pending power mode link state:{}",
  log::verbose("Clearing pending power mode link state:{}",
               power_mode_state_text(p_cb->state));
               power_mode_state_text(p_cb->state));
  pm_pend_link = 0;
  pm_pend_link = 0;


@@ -776,10 +776,11 @@ void process_ssr_event(tHCI_STATUS status, uint16_t handle,


  bool use_ssr = true;
  bool use_ssr = true;
  if (p_cb->interval == max_rx_lat) {
  if (p_cb->interval == max_rx_lat) {
    log::debug("Sniff subrating unsupported so dropping to legacy sniff mode");
    log::verbose(
        "Sniff subrating unsupported so dropping to legacy sniff mode");
    use_ssr = false;
    use_ssr = false;
  } else {
  } else {
    log::debug("Sniff subrating enabled");
    log::verbose("Sniff subrating enabled");
  }
  }


  int cnt = 0;
  int cnt = 0;