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)) {
******************************************************************************/
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;
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));
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 */
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
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)";
*/
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) {
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);
******************************************************************************/
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);
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) {
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);
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);
}
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);
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);
}
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;
}
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;
}
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);
}
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) {
/* 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 */
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;
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;
}
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 */
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;
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;
}
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);
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 */
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) {
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;
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);
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;
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);
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;