From 273ffd858ef8ef89c33c7a7d282f298c540d3c2c Mon Sep 17 00:00:00 2001 From: Stanley Tng Date: Thu, 8 Feb 2018 12:26:51 -0800 Subject: [PATCH] Add more details in native Bluetooth debug logs As part of debugging a security/pairing issue, these logs are modified to give better debug information. Test: compiled Bug: 71364658 Change-Id: I742cc7dda0afc6350e881c22d03bdc1c69d37d88 --- btif/src/btif_dm.cc | 7 +++++-- stack/btm/btm_ble.cc | 24 +++++++++++++++--------- stack/btm/btm_dev.cc | 6 +++++- stack/btm/btm_sec.cc | 47 +++++++++++++++++++++++++++++++++-------------- stack/l2cap/l2c_ble.cc | 3 ++- stack/l2cap/l2c_csm.cc | 7 +++++-- stack/l2cap/l2c_link.cc | 3 ++- stack/l2cap/l2c_utils.cc | 5 ++--- stack/smp/smp_act.cc | 4 +++- stack/smp/smp_api.cc | 11 +++++++---- stack/smp/smp_l2c.cc | 12 ++++++++---- stack/smp/smp_utils.cc | 8 ++++++-- 12 files changed, 93 insertions(+), 44 deletions(-) diff --git a/btif/src/btif_dm.cc b/btif/src/btif_dm.cc index 8926670ec..42b58549f 100644 --- a/btif/src/btif_dm.cc +++ b/btif/src/btif_dm.cc @@ -1047,7 +1047,9 @@ static void btif_dm_auth_cmpl_evt(tBTA_DM_AUTH_CMPL* p_auth_cmpl) { bt_bond_state_t state = BT_BOND_STATE_NONE; bool skip_sdp = false; - BTIF_TRACE_DEBUG("%s: bond state=%d", __func__, pairing_cb.state); + 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); RawAddress bd_addr = p_auth_cmpl->bd_addr; if ((p_auth_cmpl->success) && (p_auth_cmpl->key_present)) { @@ -2483,7 +2485,8 @@ bt_status_t btif_dm_get_remote_services(const RawAddress& remote_addr) { ******************************************************************************/ bt_status_t btif_dm_get_remote_services_by_transport(RawAddress* remote_addr, const int transport) { - BTIF_TRACE_EVENT("%s", __func__); + BTIF_TRACE_EVENT("%s: transport=%d, remote_addr=%s", __func__, transport, + remote_addr->ToString().c_str()); /* Set the mask extension */ tBTA_SERVICE_MASK_EXT mask_ext; diff --git a/stack/btm/btm_ble.cc b/stack/btm/btm_ble.cc index f013a0302..1f16c1e42 100644 --- a/stack/btm/btm_ble.cc +++ b/stack/btm/btm_ble.cc @@ -89,8 +89,9 @@ bool BTM_SecAddBleDevice(const RawAddress& bd_addr, BD_NAME bd_name, p_dev_rec->conn_params.supervision_tout = BTM_BLE_CONN_PARAM_UNDEF; p_dev_rec->conn_params.slave_latency = BTM_BLE_CONN_PARAM_UNDEF; - BTM_TRACE_DEBUG("%s: Device added, handle=0x%x ", __func__, - p_dev_rec->ble_hci_handle); + BTM_TRACE_DEBUG("%s: Device added, handle=0x%x, p_dev_rec=%p, bd_addr=%s", + __func__, p_dev_rec->ble_hci_handle, p_dev_rec, + bd_addr.ToString().c_str()); } memset(p_dev_rec->sec_bd_name, 0, sizeof(tBTM_BD_NAME)); @@ -1317,8 +1318,11 @@ void btm_sec_save_le_key(const RawAddress& bd_addr, tBTM_LE_KEY_TYPE key_type, p_rec->ble.static_addr = p_keys->pid_key.static_addr; p_rec->ble.static_addr_type = p_keys->pid_key.addr_type; p_rec->ble.key_type |= BTM_LE_KEY_PID; - BTM_TRACE_DEBUG("BTM_LE_KEY_PID key_type=0x%x save peer IRK", - p_rec->ble.key_type); + BTM_TRACE_DEBUG( + "%s: BTM_LE_KEY_PID key_type=0x%x save peer IRK, change bd_addr=%s " + "to static_addr=%s", + __func__, p_rec->ble.key_type, p_rec->bd_addr.ToString().c_str(), + p_keys->pid_key.static_addr.ToString().c_str()); /* update device record address as static address */ p_rec->bd_addr = p_keys->pid_key.static_addr; /* combine DUMO device security record if needed */ @@ -1380,7 +1384,7 @@ void btm_sec_save_le_key(const RawAddress& bd_addr, tBTM_LE_KEY_TYPE key_type, return; } - VLOG(1) << "BLE key type 0x" << std::hex << key_type + VLOG(1) << "BLE key type 0x" << loghex(key_type) << " updated for BDA: " << bd_addr << " (btm_sec_save_le_key)"; /* Notify the application that one of the BLE keys has been updated @@ -1394,7 +1398,7 @@ void btm_sec_save_le_key(const RawAddress& bd_addr, tBTM_LE_KEY_TYPE key_type, return; } - LOG(WARNING) << "BLE key type 0x" << std::hex << key_type + LOG(WARNING) << "BLE key type 0x" << loghex(key_type) << " called for Unknown BDA or type: " << bd_addr << "(btm_sec_save_le_key)"; @@ -1866,13 +1870,15 @@ void btm_ble_connected(const RawAddress& bda, uint16_t handle, uint8_t enc_mode, */ if (p_dev_rec) { VLOG(1) << __func__ << " Security Manager: handle:" << handle - << " enc_mode:" << enc_mode << " bda: " << bda - << " RName: " << p_dev_rec->sec_bd_name; + << " enc_mode:" << loghex(enc_mode) << " bda: " << bda + << " RName: " << p_dev_rec->sec_bd_name + << " p_dev_rec:" << p_dev_rec; BTM_TRACE_DEBUG("btm_ble_connected sec_flags=0x%x", p_dev_rec->sec_flags); } else { VLOG(1) << __func__ << " Security Manager: handle:" << handle - << " enc_mode:" << enc_mode << " bda: " << bda; + << " enc_mode:" << loghex(enc_mode) << " bda: " << bda + << " p_dev_rec:" << p_dev_rec; } if (!p_dev_rec) { diff --git a/stack/btm/btm_dev.cc b/stack/btm/btm_dev.cc index b024137d7..66382e89f 100644 --- a/stack/btm/btm_dev.cc +++ b/stack/btm/btm_dev.cc @@ -68,6 +68,8 @@ bool BTM_SecAddDevice(const RawAddress& bd_addr, DEV_CLASS dev_class, tBTM_SEC_DEV_REC* p_dev_rec = btm_find_dev(bd_addr); if (!p_dev_rec) { p_dev_rec = btm_sec_allocate_dev_rec(); + BTM_TRACE_API("%s: allocated p_dev_rec=%p, bd_addr=%s", __func__, p_dev_rec, + bd_addr.ToString().c_str()); p_dev_rec->bd_addr = bd_addr; p_dev_rec->hci_handle = BTM_GetHCIConnHandle(bd_addr, BT_TRANSPORT_BR_EDR); @@ -225,10 +227,12 @@ char* BTM_SecReadDevName(const RawAddress& bd_addr) { ******************************************************************************/ tBTM_SEC_DEV_REC* btm_sec_alloc_dev(const RawAddress& bd_addr) { tBTM_INQ_INFO* p_inq_info; - BTM_TRACE_EVENT("btm_sec_alloc_dev"); tBTM_SEC_DEV_REC* p_dev_rec = btm_sec_allocate_dev_rec(); + BTM_TRACE_EVENT("%s: allocated p_dev_rec=%p, bd_addr=%s", __func__, p_dev_rec, + bd_addr.ToString().c_str()); + /* Check with the BT manager if details about remote device are known */ /* outgoing connection */ p_inq_info = BTM_InqDbRead(bd_addr); diff --git a/stack/btm/btm_sec.cc b/stack/btm/btm_sec.cc index c76dad677..bd8805401 100644 --- a/stack/btm/btm_sec.cc +++ b/stack/btm/btm_sec.cc @@ -873,7 +873,8 @@ tBTM_STATUS btm_sec_bond_by_transport(const RawAddress& bd_addr, tACL_CONN* p = btm_bda_to_acl(bd_addr, transport); VLOG(1) << __func__ << " BDA: " << bd_addr; - BTM_TRACE_DEBUG("btm_sec_bond_by_transport: Transport used %d", transport); + BTM_TRACE_DEBUG("%s: Transport used %d, bd_addr=%s", __func__, transport, + bd_addr.ToString().c_str()); /* Other security process is in progress */ if (btm_cb.pairing_state != BTM_PAIR_STATE_IDLE) { @@ -1286,9 +1287,9 @@ tBTM_STATUS BTM_SetEncryption(const RawAddress& bd_addr, BTM_TRACE_API( "Security Manager: BTM_SetEncryption Handle:%d State:%d Flags:0x%x " - "Required:0x%x", + "Required:0x%x, p_dev_rec=%p, p_callback=%p", p_dev_rec->hci_handle, p_dev_rec->sec_state, p_dev_rec->sec_flags, - p_dev_rec->security_required); + p_dev_rec->security_required, p_dev_rec, p_callback); if (transport == BT_TRANSPORT_LE) { tACL_CONN* p = btm_bda_to_acl(bd_addr, transport); @@ -1305,6 +1306,11 @@ tBTM_STATUS BTM_SetEncryption(const RawAddress& bd_addr, if (rc != BTM_CMD_STARTED && rc != BTM_BUSY) { if (p_callback) { + BTM_TRACE_DEBUG( + "%s: clearing p_callback=%p, p_dev_rec=%p, transport=%d, " + "bd_addr=%s", + __func__, p_callback, p_dev_rec, transport, + bd_addr.ToString().c_str()); p_dev_rec->p_callback = NULL; (*p_callback)(&bd_addr, transport, p_dev_rec->p_ref_data, rc); } @@ -1938,8 +1944,8 @@ tBTM_STATUS btm_sec_l2cap_access_req(const RawAddress& bd_addr, uint16_t psm, is_originator = conn_type; - BTM_TRACE_DEBUG("%s() is_originator:%d, 0x%x", __func__, is_originator, - p_ref_data); + BTM_TRACE_DEBUG("%s() is_originator:%d, 0x%x, psm=0x%04x", __func__, + is_originator, p_ref_data, psm); /* Find or get oldest record */ p_dev_rec = btm_find_or_alloc_dev(bd_addr); @@ -2226,6 +2232,8 @@ tBTM_STATUS btm_sec_l2cap_access_req(const RawAddress& bd_addr, uint16_t psm, rc = btm_sec_execute_procedure(p_dev_rec); if (rc != BTM_CMD_STARTED) { + BTM_TRACE_DEBUG("%s: p_dev_rec=%p, clearing callback. old p_callback=%p", + __func__, p_dev_rec, p_dev_rec->p_callback); p_dev_rec->p_callback = NULL; (*p_callback)(&bd_addr, transport, p_dev_rec->p_ref_data, (uint8_t)rc); } @@ -2745,6 +2753,9 @@ void btm_sec_abort_access_req(const RawAddress& bd_addr) { return; p_dev_rec->sec_state = BTM_SEC_STATE_IDLE; + + BTM_TRACE_DEBUG("%s: clearing callback. p_dev_rec=%p, p_callback=%p", + __func__, p_dev_rec, p_dev_rec->p_callback); p_dev_rec->p_callback = NULL; } @@ -3758,14 +3769,14 @@ void btm_sec_auth_complete(uint16_t handle, uint8_t status) { bool are_bonding = false; if (p_dev_rec) { - VLOG(2) << __func__ << "Security Manager: in state: " + VLOG(2) << __func__ << ": Security Manager: in state: " << btm_pair_state_descr(btm_cb.pairing_state) << " handle:" << handle << " status:" << status << "dev->sec_state:" << p_dev_rec->sec_state << " bda:" << p_dev_rec->bd_addr << "RName:" << p_dev_rec->sec_bd_name; } else { - VLOG(2) << __func__ << "Security Manager: in state: " + VLOG(2) << __func__ << ": Security Manager: in state: " << btm_pair_state_descr(btm_cb.pairing_state) << " handle:" << handle << " status:" << status; } @@ -4032,6 +4043,8 @@ void btm_sec_encrypt_change(uint16_t handle, uint8_t status, if (p_dev_rec->sec_state != BTM_SEC_STATE_ENCRYPTING) { if (BTM_SEC_STATE_DELAY_FOR_ENC == p_dev_rec->sec_state) { p_dev_rec->sec_state = BTM_SEC_STATE_IDLE; + BTM_TRACE_DEBUG("%s: clearing callback. p_dev_rec=%p, p_callback=%p", + __func__, p_dev_rec, p_dev_rec->p_callback); p_dev_rec->p_callback = NULL; l2cu_resubmit_pending_sec_req(&p_dev_rec->bd_addr); } @@ -4103,16 +4116,16 @@ void btm_sec_connected(const RawAddress& bda, uint16_t handle, uint8_t status, btm_acl_resubmit_page(); if (p_dev_rec) { - VLOG(2) << __func__ << "Security Manager: in state: " + VLOG(2) << __func__ << ": Security Manager: in state: " << btm_pair_state_descr(btm_cb.pairing_state) - << " handle:" << handle << " status:" << status - << "enc_mode:" << enc_mode << " bda:" << bda - << "RName:" << p_dev_rec->sec_bd_name; + << " handle:" << handle << " status:" << loghex(status) + << " enc_mode:" << loghex(enc_mode) << " bda:" << bda + << " RName:" << p_dev_rec->sec_bd_name; } else { - VLOG(2) << __func__ << "Security Manager: in state: " + VLOG(2) << __func__ << ": Security Manager: in state: " << btm_pair_state_descr(btm_cb.pairing_state) - << " handle:" << handle << " status:" << status - << "enc_mode:" << enc_mode << " bda:" << bda; + << " handle:" << handle << " status:" << loghex(status) + << " enc_mode:" << loghex(enc_mode) << " bda:" << bda; } if (!p_dev_rec) { @@ -4534,6 +4547,8 @@ void btm_sec_disconnected(uint16_t handle, uint8_t reason) { /* if security is pending, send callback to clean up the security state */ if (p_callback) { + BTM_TRACE_DEBUG("%s: clearing callback. p_dev_rec=%p, p_callback=%p", + __func__, p_dev_rec, p_dev_rec->p_callback); p_dev_rec->p_callback = NULL; /* when the peer device time out the authentication before we do, this call back must be reset here */ @@ -5545,6 +5560,10 @@ void btm_sec_dev_rec_cback_event(tBTM_SEC_DEV_REC* p_dev_rec, uint8_t res, bool is_le_transport) { tBTM_SEC_CALLBACK* p_callback = p_dev_rec->p_callback; + BTM_TRACE_DEBUG("%s: p_callback=%p, is_le_transport=%d, res=%d, p_dev_rec=%p", + __func__, p_dev_rec->p_callback, is_le_transport, res, + p_dev_rec); + if (p_dev_rec->p_callback) { p_dev_rec->p_callback = NULL; diff --git a/stack/l2cap/l2c_ble.cc b/stack/l2cap/l2c_ble.cc index ff5ee8178..51f81cfb2 100644 --- a/stack/l2cap/l2c_ble.cc +++ b/stack/l2cap/l2c_ble.cc @@ -1340,7 +1340,8 @@ void l2cble_sec_comp(const RawAddress* bda, tBT_TRANSPORT transport, uint8_t sec_act; if (!p_lcb) { - L2CAP_TRACE_WARNING("%s security complete for unknown device", __func__); + L2CAP_TRACE_WARNING("%s: security complete for unknown device. bda=%s", + __func__, bda->ToString().c_str()); return; } diff --git a/stack/l2cap/l2c_csm.cc b/stack/l2cap/l2c_csm.cc index 97841f246..aa1537b5b 100644 --- a/stack/l2cap/l2c_csm.cc +++ b/stack/l2cap/l2c_csm.cc @@ -299,8 +299,11 @@ static void l2c_csm_orig_w4_sec_comp(tL2C_CCB* p_ccb, uint16_t event, tL2CA_CONNECT_CFM_CB* connect_cfm = p_ccb->p_rcb->api.pL2CA_ConnectCfm_Cb; uint16_t local_cid = p_ccb->local_cid; - L2CAP_TRACE_EVENT("L2CAP - LCID: 0x%04x st: ORIG_W4_SEC_COMP evt: %s", - p_ccb->local_cid, l2c_csm_get_event_name(event)); + L2CAP_TRACE_EVENT( + "%s: %sL2CAP - LCID: 0x%04x st: ORIG_W4_SEC_COMP evt: %s", __func__, + ((p_ccb->p_lcb) && (p_ccb->p_lcb->transport == BT_TRANSPORT_LE)) ? "LE " + : "", + p_ccb->local_cid, l2c_csm_get_event_name(event)); switch (event) { case L2CEVT_LP_DISCONNECT_IND: /* Link was disconnected */ diff --git a/stack/l2cap/l2c_link.cc b/stack/l2cap/l2c_link.cc index b33ba91d3..30cb83049 100644 --- a/stack/l2cap/l2c_link.cc +++ b/stack/l2cap/l2c_link.cc @@ -285,7 +285,8 @@ void l2c_link_sec_comp2(const RawAddress& p_bda, tL2C_CCB* p_next_ccb; uint8_t event; - L2CAP_TRACE_DEBUG("l2c_link_sec_comp: %d, 0x%x", status, p_ref_data); + L2CAP_TRACE_DEBUG("%s: status=%d, p_ref_data=%p, BD_ADDR=%s", __func__, + status, p_ref_data, p_bda.ToString().c_str()); if (status == BTM_SUCCESS_NO_SECURITY) status = BTM_SUCCESS; diff --git a/stack/l2cap/l2c_utils.cc b/stack/l2cap/l2c_utils.cc index 4b17f14e1..337e0764b 100644 --- a/stack/l2cap/l2c_utils.cc +++ b/stack/l2cap/l2c_utils.cc @@ -1182,9 +1182,8 @@ void l2cu_enqueue_ccb(tL2C_CCB* p_ccb) { if (p_ccb->p_lcb != NULL) p_q = &p_ccb->p_lcb->ccb_queue; if ((!p_ccb->in_use) || (p_q == NULL)) { - L2CAP_TRACE_ERROR( - "l2cu_enqueue_ccb CID: 0x%04x ERROR in_use: %u p_lcb: 0x%08x", - p_ccb->local_cid, p_ccb->in_use, p_ccb->p_lcb); + L2CAP_TRACE_ERROR("%s: CID: 0x%04x ERROR in_use: %u p_lcb: %p", __func__, + p_ccb->local_cid, p_ccb->in_use, p_ccb->p_lcb); return; } diff --git a/stack/smp/smp_act.cc b/stack/smp/smp_act.cc index bc2bd7f7d..10f51722c 100644 --- a/stack/smp/smp_act.cc +++ b/stack/smp/smp_act.cc @@ -501,7 +501,9 @@ void smp_proc_pair_cmd(tSMP_CB* p_cb, tSMP_INT_DATA* p_data) { uint8_t* p = p_data->p_data; tBTM_SEC_DEV_REC* p_dev_rec = btm_find_dev(p_cb->pairing_bda); - SMP_TRACE_DEBUG("%s", __func__); + SMP_TRACE_DEBUG("%s: pairing_bda=%s", __func__, + p_cb->pairing_bda.ToString().c_str()); + /* erase all keys if it is slave proc pairing req */ if (p_dev_rec && (p_cb->role == HCI_ROLE_SLAVE)) btm_sec_clear_ble_keys(p_dev_rec); diff --git a/stack/smp/smp_api.cc b/stack/smp/smp_api.cc index 5303acf9d..d096da588 100644 --- a/stack/smp/smp_api.cc +++ b/stack/smp/smp_api.cc @@ -133,8 +133,10 @@ bool SMP_Register(tSMP_CALLBACK* p_cback) { tSMP_STATUS SMP_Pair(const RawAddress& bd_addr) { tSMP_CB* p_cb = &smp_cb; - SMP_TRACE_EVENT("%s state=%d br_state=%d flag=0x%x ", __func__, p_cb->state, - p_cb->br_state, p_cb->flags); + SMP_TRACE_EVENT("%s: state=%d br_state=%d flag=0x%x, bd_addr=%s", __func__, + p_cb->state, p_cb->br_state, p_cb->flags, + bd_addr.ToString().c_str()); + if (p_cb->state != SMP_STATE_IDLE || p_cb->flags & SMP_PAIR_FLAGS_WE_STARTED_DD || p_cb->smp_over_br) { /* pending security on going, reject this one */ @@ -171,8 +173,9 @@ tSMP_STATUS SMP_Pair(const RawAddress& bd_addr) { tSMP_STATUS SMP_BR_PairWith(const RawAddress& bd_addr) { tSMP_CB* p_cb = &smp_cb; - SMP_TRACE_EVENT("%s state=%d br_state=%d flag=0x%x ", __func__, p_cb->state, - p_cb->br_state, p_cb->flags); + SMP_TRACE_EVENT("%s: state=%d br_state=%d flag=0x%x, bd_addr=%s", __func__, + p_cb->state, p_cb->br_state, p_cb->flags, + bd_addr.ToString().c_str()); if (p_cb->state != SMP_STATE_IDLE || p_cb->smp_over_br || p_cb->flags & SMP_PAIR_FLAGS_WE_STARTED_DD) { diff --git a/stack/smp/smp_l2c.cc b/stack/smp/smp_l2c.cc index 528bea818..1e0cb715a 100644 --- a/stack/smp/smp_l2c.cc +++ b/stack/smp/smp_l2c.cc @@ -94,7 +94,9 @@ static void smp_connect_callback(uint16_t channel, const RawAddress& bd_addr, tSMP_CB* p_cb = &smp_cb; tSMP_INT_DATA int_data; - SMP_TRACE_EVENT("SMDBG l2c %s", __func__); + SMP_TRACE_EVENT("%s: SMDBG l2c: bd_addr=%s, p_cb->pairing_bda=%s", __func__, + bd_addr.ToString().c_str(), + p_cb->pairing_bda.ToString().c_str()); if (transport == BT_TRANSPORT_BR_EDR || bd_addr.IsEmpty()) return; @@ -138,10 +140,11 @@ static void smp_data_received(uint16_t channel, const RawAddress& bd_addr, tSMP_CB* p_cb = &smp_cb; uint8_t* p = (uint8_t*)(p_buf + 1) + p_buf->offset; uint8_t cmd; - SMP_TRACE_EVENT("SMDBG l2c %s", __func__); STREAM_TO_UINT8(cmd, p); + SMP_TRACE_EVENT("%s: SMDBG l2c, cmd=0x%x", __func__, cmd); + /* sanity check */ if ((SMP_OPCODE_MAX < cmd) || (SMP_OPCODE_MIN > cmd)) { SMP_TRACE_WARNING("Ignore received command with RESERVED code 0x%02x", cmd); @@ -240,11 +243,12 @@ static void smp_br_connect_callback(uint16_t channel, const RawAddress& bd_addr, return; } - if (bd_addr != p_cb->pairing_bda) return; - VLOG(1) << __func__ << " for pairing BDA: " << bd_addr + << ", pairing_bda:" << p_cb->pairing_bda << " Event: " << ((connected) ? "connected" : "disconnected"); + if (bd_addr != p_cb->pairing_bda) return; + if (connected) { if (!p_cb->connect_initialized) { p_cb->connect_initialized = true; diff --git a/stack/smp/smp_utils.cc b/stack/smp/smp_utils.cc index 6a0e35643..bff564501 100644 --- a/stack/smp/smp_utils.cc +++ b/stack/smp/smp_utils.cc @@ -332,7 +332,10 @@ bool smp_send_msg_to_L2CAP(const RawAddress& rem_bda, BT_HDR* p_toL2CAP) { bool smp_send_cmd(uint8_t cmd_code, tSMP_CB* p_cb) { BT_HDR* p_buf; bool sent = false; - SMP_TRACE_EVENT("smp_send_cmd on l2cap cmd_code=0x%x", cmd_code); + + SMP_TRACE_EVENT("%s: on l2cap cmd_code=0x%x, pairing_bda=%s", __func__, + cmd_code, p_cb->pairing_bda.ToString().c_str()); + if (cmd_code <= (SMP_OPCODE_MAX + 1 /* for SMP_OPCODE_PAIR_COMMITM */) && smp_cmd_build_act[cmd_code] != NULL) { p_buf = (*smp_cmd_build_act[cmd_code])(cmd_code, p_cb); @@ -921,7 +924,8 @@ void smp_proc_pairing_cmpl(tSMP_CB* p_cb) { tSMP_EVT_DATA evt_data = {0}; tSMP_CALLBACK* p_callback = p_cb->p_callback; - SMP_TRACE_DEBUG("smp_proc_pairing_cmpl "); + SMP_TRACE_DEBUG("%s: pairing_bda=%s", __func__, + p_cb->pairing_bda.ToString().c_str()); evt_data.cmplt.reason = p_cb->status; evt_data.cmplt.smp_over_br = p_cb->smp_over_br; -- 2.11.0