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
diff --git a/system/bta/dm/bta_dm_act.cc b/system/bta/dm/bta_dm_act.cc
index 5772c8b..4c0b069 100644
--- a/system/bta/dm/bta_dm_act.cc
+++ b/system/bta/dm/bta_dm_act.cc
@@ -867,10 +867,11 @@
/** Bonds with peer device */
void bta_dm_bond(const RawAddress& bd_addr, tBLE_ADDR_TYPE addr_type,
tBT_TRANSPORT transport, tBT_DEVICE_TYPE device_type) {
- LOG_DEBUG("Bonding with peer device:%s type:%s transport:%s type:%s",
- ADDRESS_TO_LOGGABLE_CSTR(bd_addr), AddressTypeText(addr_type).c_str(),
- bt_transport_text(transport).c_str(),
- DeviceTypeText(device_type).c_str());
+ LOG_INFO("Bonding with peer device:%s type:%s transport:%s type:%s",
+ ADDRESS_TO_LOGGABLE_CSTR(bd_addr),
+ AddressTypeText(addr_type).c_str(),
+ bt_transport_text(transport).c_str(),
+ DeviceTypeText(device_type).c_str());
tBTA_DM_SEC sec_event;
const char* p_name;
diff --git a/system/btif/src/btif_dm.cc b/system/btif/src/btif_dm.cc
index 458b651..de64f11 100644
--- a/system/btif/src/btif_dm.cc
+++ b/system/btif/src/btif_dm.cc
@@ -1143,9 +1143,8 @@
bt_bond_state_t state = BT_BOND_STATE_NONE;
bool skip_sdp = false;
- BTIF_TRACE_DEBUG("%s: bond state=%d, success=%d, key_present=%d", __func__,
- pairing_cb.state, p_auth_cmpl->success,
- p_auth_cmpl->key_present);
+ LOG_INFO("%s: bond state=%d, success=%d, key_present=%d", __func__,
+ pairing_cb.state, p_auth_cmpl->success, p_auth_cmpl->key_present);
pairing_cb.fail_reason = p_auth_cmpl->fail_reason;
@@ -1285,6 +1284,8 @@
// Do not call bond_state_changed_cb yet. Wait until remote service
// discovery is complete
} else {
+ LOG_WARN("Bonding failed with failure reason: 0x%02x",
+ p_auth_cmpl->fail_reason);
bool is_bonded_device_removed = false;
// Map the HCI fail reason to bt status
switch (p_auth_cmpl->fail_reason) {
diff --git a/system/stack/btm/btm_sec.cc b/system/stack/btm/btm_sec.cc
index d569bff..2a14cc4 100644
--- a/system/stack/btm/btm_sec.cc
+++ b/system/stack/btm/btm_sec.cc
@@ -760,20 +760,19 @@
uint8_t* p_pin) {
tBTM_SEC_DEV_REC* p_dev_rec;
tBTM_STATUS status;
- VLOG(1) << __func__ << " BDA: " << ADDRESS_TO_LOGGABLE_STR(bd_addr);
-
- BTM_TRACE_DEBUG("%s: Transport used %d, bd_addr=%s", __func__, transport,
- ADDRESS_TO_LOGGABLE_CSTR(bd_addr));
+ LOG_INFO("%s: Transport used %d, bd_addr=%s", __func__, transport,
+ ADDRESS_TO_LOGGABLE_CSTR(bd_addr));
/* Other security process is in progress */
if (btm_cb.pairing_state != BTM_PAIR_STATE_IDLE) {
- BTM_TRACE_ERROR("BTM_SecBond: already busy in state: %s",
- btm_pair_state_descr(btm_cb.pairing_state));
+ LOG_ERROR("BTM_SecBond: already busy in state: %s",
+ btm_pair_state_descr(btm_cb.pairing_state));
return (BTM_WRONG_MODE);
}
p_dev_rec = btm_find_or_alloc_dev(bd_addr);
if (p_dev_rec == NULL) {
+ LOG_ERROR("No memory to allocate new p_dev_rec");
return (BTM_NO_RESOURCES);
}
@@ -796,8 +795,10 @@
}
/* 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);
+ }
/* Save the PIN code if we got a valid one */
if (p_pin && (pin_len <= PIN_CODE_LEN) && (pin_len != 0)) {
@@ -939,6 +940,9 @@
if ((transport == BT_TRANSPORT_LE && (dev_type & BT_DEVICE_TYPE_BLE) == 0) ||
(transport == BT_TRANSPORT_BR_EDR &&
(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_sec_bond_by_transport(bd_addr, addr_type, transport, pin_len,
