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

Commit 6ad208aa authored by Jakub Pawlowski's avatar Jakub Pawlowski
Browse files

Improve logging around create bond failures 

There are few cases when a failure while starting process would not
leave any trace in logs, which are hard to analyze.
This patch is improving logging, so that it's easier to fix those issues
in future.

Test: analyze logs from bond failure
Bug: 286926022
Change-Id: Ib3c0ac193e69fbfe8c43e82498b44c1756555b82
parent de99ef01

system/bta/dm/bta_dm_act.cc

+5 −4
Original line number Original line Diff line number Diff line
@@ -867,8 +867,9 @@ void bta_dm_close_acl(const RawAddress& bd_addr, bool remove_dev, 
/** Bonds with peer device */

/** Bonds with peer device */

void bta_dm_bond(const RawAddress& bd_addr, tBLE_ADDR_TYPE addr_type,

void bta_dm_bond(const RawAddress& bd_addr, tBLE_ADDR_TYPE addr_type,

                 tBT_TRANSPORT transport, tBT_DEVICE_TYPE device_type) {

                 tBT_TRANSPORT transport, tBT_DEVICE_TYPE device_type) {

  LOG_DEBUG("Bonding with peer device:%s type:%s transport:%s type:%s",

  LOG_INFO("Bonding with peer device:%s type:%s transport:%s type:%s",

            ADDRESS_TO_LOGGABLE_CSTR(bd_addr), AddressTypeText(addr_type).c_str(),

           ADDRESS_TO_LOGGABLE_CSTR(bd_addr),

           AddressTypeText(addr_type).c_str(),

           bt_transport_text(transport).c_str(),

           bt_transport_text(transport).c_str(),

           DeviceTypeText(device_type).c_str());

           DeviceTypeText(device_type).c_str());

system/btif/src/btif_dm.cc

+4 −3
Original line number Original line Diff line number Diff line
@@ -1143,9 +1143,8 @@ static void btif_dm_auth_cmpl_evt(tBTA_DM_AUTH_CMPL* p_auth_cmpl) { 
  bt_bond_state_t state = BT_BOND_STATE_NONE;

  bt_bond_state_t state = BT_BOND_STATE_NONE;

  bool skip_sdp = false;

  bool skip_sdp = false;





  BTIF_TRACE_DEBUG("%s: bond state=%d, success=%d, key_present=%d", __func__,

  LOG_INFO("%s: bond state=%d, success=%d, key_present=%d", __func__,

                   pairing_cb.state, p_auth_cmpl->success,

           pairing_cb.state, p_auth_cmpl->success, p_auth_cmpl->key_present);

                   p_auth_cmpl->key_present);





  pairing_cb.fail_reason = p_auth_cmpl->fail_reason;

  pairing_cb.fail_reason = p_auth_cmpl->fail_reason;
@@ -1285,6 +1284,8 @@ static void btif_dm_auth_cmpl_evt(tBTA_DM_AUTH_CMPL* p_auth_cmpl) { 
    // Do not call bond_state_changed_cb yet. Wait until remote service

    // Do not call bond_state_changed_cb yet. Wait until remote service

    // discovery is complete

    // discovery is complete

  } else {

  } else {

    LOG_WARN("Bonding failed with failure reason: 0x%02x",

             p_auth_cmpl->fail_reason);

    bool is_bonded_device_removed = false;

    bool is_bonded_device_removed = false;

    // Map the HCI fail reason  to  bt status

    // Map the HCI fail reason  to  bt status

    switch (p_auth_cmpl->fail_reason) {

    switch (p_auth_cmpl->fail_reason) {

system/stack/btm/btm_sec.cc

+11 −7
Original line number Original line Diff line number Diff line
@@ -760,20 +760,19 @@ tBTM_STATUS btm_sec_bond_by_transport(const RawAddress& bd_addr, 
                                      uint8_t* p_pin) {

                                      uint8_t* p_pin) {

  tBTM_SEC_DEV_REC* p_dev_rec;

  tBTM_SEC_DEV_REC* p_dev_rec;

  tBTM_STATUS status;

  tBTM_STATUS status;

  VLOG(1) << __func__ << " BDA: " << ADDRESS_TO_LOGGABLE_STR(bd_addr);

  LOG_INFO("%s: Transport used %d, bd_addr=%s", __func__, transport,



  BTM_TRACE_DEBUG("%s: Transport used %d, bd_addr=%s", __func__, transport,

           ADDRESS_TO_LOGGABLE_CSTR(bd_addr));

           ADDRESS_TO_LOGGABLE_CSTR(bd_addr));





  /* Other security process is in progress */

  /* Other security process is in progress */

  if (btm_cb.pairing_state != BTM_PAIR_STATE_IDLE) {

  if (btm_cb.pairing_state != BTM_PAIR_STATE_IDLE) {

    BTM_TRACE_ERROR("BTM_SecBond: already busy in state: %s",

    LOG_ERROR("BTM_SecBond: already busy in state: %s",

              btm_pair_state_descr(btm_cb.pairing_state));

              btm_pair_state_descr(btm_cb.pairing_state));

    return (BTM_WRONG_MODE);

    return (BTM_WRONG_MODE);

  }

  }





  p_dev_rec = btm_find_or_alloc_dev(bd_addr);

  p_dev_rec = btm_find_or_alloc_dev(bd_addr);

  if (p_dev_rec == NULL) {

  if (p_dev_rec == NULL) {

    LOG_ERROR("No memory to allocate new p_dev_rec");

    return (BTM_NO_RESOURCES);

    return (BTM_NO_RESOURCES);

  }

  }
@@ -796,8 +795,10 @@ tBTM_STATUS btm_sec_bond_by_transport(const RawAddress& bd_addr, 
  }

  }





  /* Tell controller to get rid of the link key if it has one stored */

  /* Tell controller to get rid of the link key if it has one stored */

  if ((BTM_DeleteStoredLinkKey(&bd_addr, NULL)) != BTM_SUCCESS)

  if ((BTM_DeleteStoredLinkKey(&bd_addr, NULL)) != BTM_SUCCESS) {

    LOG_ERROR("Failed to delete stored link keys");

    return (BTM_NO_RESOURCES);

    return (BTM_NO_RESOURCES);

  }





  /* Save the PIN code if we got a valid one */

  /* Save the PIN code if we got a valid one */

  if (p_pin && (pin_len <= PIN_CODE_LEN) && (pin_len != 0)) {

  if (p_pin && (pin_len <= PIN_CODE_LEN) && (pin_len != 0)) {
@@ -939,6 +940,9 @@ tBTM_STATUS BTM_SecBond(const RawAddress& bd_addr, tBLE_ADDR_TYPE addr_type, 
  if ((transport == BT_TRANSPORT_LE && (dev_type & BT_DEVICE_TYPE_BLE) == 0) ||

  if ((transport == BT_TRANSPORT_LE && (dev_type & BT_DEVICE_TYPE_BLE) == 0) ||

      (transport == BT_TRANSPORT_BR_EDR &&

      (transport == BT_TRANSPORT_BR_EDR &&

       (dev_type & BT_DEVICE_TYPE_BREDR) == 0)) {

       (dev_type & BT_DEVICE_TYPE_BREDR) == 0)) {

    LOG_WARN(

        "Can't start bonding - requested transport and transport we've seen "

        "device on don't match");

    return BTM_ILLEGAL_ACTION;

    return BTM_ILLEGAL_ACTION;

  }

  }

  return btm_sec_bond_by_transport(bd_addr, addr_type, transport, pin_len,

  return btm_sec_bond_by_transport(bd_addr, addr_type, transport, pin_len,