A2DP: More clear log messages for both BTA and AVDT SCB handle
There were 2 types of handles for the stream control mapping between BTA
and AVDT, tBTA_AV_HNDL and for AvdtpScb respectively, and the stack used
them to communicate crossing layers. However, both of them were all
named *handle* in logs, and was not easy to read. This CL uses
bta_handle / bta_av_handle for tBTA_AV_HNDL and avdt_handle for
AvdtpScb, and raise the log level to be error if AVDT API failed.
Bug: 135655859
Bug: 145326274
Test: Logs changed only. Disconnecting / Reconnecting by A2DP manually
Change-Id: I780561ff4fbd3be0ed54376346fbdad3efb845ed
diff --git a/bta/av/bta_av_aact.cc b/bta/av/bta_av_aact.cc
index f7867d3..41bd5f8 100644
--- a/bta/av/bta_av_aact.cc
+++ b/bta/av/bta_av_aact.cc
@@ -250,7 +250,7 @@
for (int i = 0; i < BTAV_A2DP_CODEC_INDEX_MAX; i++) {
if (p_scb->seps[i].av_handle == tavdt_handle) return (p_scb->seps[i].tsep);
}
- APPL_TRACE_DEBUG("%s: handle %d not found", __func__, tavdt_handle)
+ APPL_TRACE_DEBUG("%s: avdt_handle %d not found", __func__, tavdt_handle)
return AVDT_TSEP_INVALID;
}
@@ -293,9 +293,9 @@
*
******************************************************************************/
static void notify_start_failed(tBTA_AV_SCB* p_scb) {
- LOG_ERROR(LOG_TAG, "%s: peer %s role:0x%x channel:%d handle:0x%x", __func__,
- p_scb->PeerAddress().ToString().c_str(), p_scb->role, p_scb->chnl,
- p_scb->hndl);
+ LOG_ERROR(LOG_TAG, "%s: peer %s role:0x%x bta_channel:%d bta_handle:0x%x",
+ __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->role,
+ p_scb->chnl, p_scb->hndl);
tBTA_AV_START start;
/* if start failed, clear role */
p_scb->role &= ~BTA_AV_ROLE_START_INT;
@@ -477,7 +477,8 @@
p_msg->initiator = false;
if (event == AVDT_SUSPEND_CFM_EVT) p_msg->initiator = true;
- APPL_TRACE_VERBOSE("%s: hndl:0x%x", __func__, p_scb->hndl);
+ APPL_TRACE_VERBOSE("%s: bta_handle:0x%x avdt_handle:%d", __func__,
+ p_scb->hndl, handle);
p_msg->hdr.layer_specific = p_scb->hndl;
p_msg->handle = handle;
p_msg->avdt_event = event;
@@ -545,7 +546,7 @@
tBTA_AV_SCB* p_scb = bta_av_hndl_to_scb(bta_av_cb.handle);
if (p_scb == NULL) {
- APPL_TRACE_ERROR("%s: no scb found for handle(0x%x)", __func__,
+ APPL_TRACE_ERROR("%s: no scb found for SDP handle(0x%x)", __func__,
bta_av_cb.handle);
return;
}
@@ -601,7 +602,7 @@
APPL_TRACE_DEBUG("%s: codec: %s", __func__,
A2DP_CodecName(p_scb->cfg.codec_info));
for (int i = 0; i < BTAV_A2DP_CODEC_INDEX_MAX; i++) {
- APPL_TRACE_DEBUG("%s: av_handle: %d codec: %s", __func__,
+ APPL_TRACE_DEBUG("%s: avdt_handle: %d codec: %s", __func__,
p_scb->seps[i].av_handle,
A2DP_CodecName(p_scb->seps[i].codec_info));
if (p_scb->seps[i].av_handle && (p_scb->seps[i].av_handle == avdt_handle) &&
@@ -751,7 +752,7 @@
*
******************************************************************************/
void bta_av_delay_co(tBTA_AV_SCB* p_scb, tBTA_AV_DATA* p_data) {
- APPL_TRACE_DEBUG("%s: peer %s handle:%d delay:%d", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle:0x%x delay:%d", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
p_data->str_msg.msg.delay_rpt_cmd.delay);
p_scb->p_cos->delay(p_scb->hndl, p_scb->PeerAddress(),
@@ -976,7 +977,7 @@
local_sep = bta_av_get_scb_sep_type(p_scb, p_msg->handle);
p_scb->avdt_label = p_data->str_msg.msg.hdr.label;
- APPL_TRACE_DEBUG("%s: peer %s handle:%d local_sep:%d", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle:0x%x local_sep:%d", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
local_sep);
APPL_TRACE_DEBUG("%s: codec: %s", __func__,
@@ -1122,9 +1123,11 @@
/* we like this codec_type. find the sep_idx */
local_sep = bta_av_get_scb_sep_type(p_scb, avdt_handle);
bta_av_adjust_seps_idx(p_scb, avdt_handle);
- APPL_TRACE_DEBUG("%s: peer %s handle: sep_idx: %d cur_psc_mask:0x%x",
- __func__, p_scb->PeerAddress().ToString().c_str(),
- p_scb->sep_idx, p_scb->cur_psc_mask);
+ LOG_DEBUG(
+ LOG_TAG,
+ "%s: peer %s bta_handle=0x%x avdt_handle=%d sep_idx=%d cur_psc_mask:0x%x",
+ __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
+ p_scb->avdt_handle, p_scb->sep_idx, p_scb->cur_psc_mask);
if ((AVDT_TSEP_SNK == local_sep) &&
(p_data->ci_setconfig.err_code == AVDT_SUCCESS) &&
@@ -1204,7 +1207,7 @@
tBTA_AV_CONN_CHG msg;
uint8_t* p;
- APPL_TRACE_DEBUG("%s: peer %s handle: %d", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle: 0x%x", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl);
msg.hdr.layer_specific = p_scb->hndl;
@@ -1439,7 +1442,7 @@
/* our uuid in case we initiate connection */
uint16_t uuid_int = p_scb->uuid_int;
- APPL_TRACE_DEBUG("%s: peer %s handle: %d initiator UUID 0x%x", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle: 0x%x initiator UUID 0x%x", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
uuid_int);
@@ -1495,7 +1498,7 @@
void bta_av_disc_res_as_acp(tBTA_AV_SCB* p_scb, tBTA_AV_DATA* p_data) {
uint8_t num_snks = 0, i;
- APPL_TRACE_DEBUG("%s: peer %s handle: %d", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle: 0x%x", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl);
/* store number of stream endpoints returned */
@@ -1546,9 +1549,9 @@
bool getcap_done = false;
APPL_TRACE_DEBUG(
- "%s: peer %s handle:%d num_seps:%d sep_info_idx:%d wait:0x%x", __func__,
- p_scb->PeerAddress().ToString().c_str(), p_scb->hndl, p_scb->num_seps,
- p_scb->sep_info_idx, p_scb->wait);
+ "%s: peer %s bta_handle:0x%x num_seps:%d sep_info_idx:%d wait:0x%x",
+ __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
+ p_scb->num_seps, p_scb->sep_info_idx, p_scb->wait);
APPL_TRACE_DEBUG("%s: codec: %s", __func__,
A2DP_CodecInfoString(p_scb->peer_cap.codec_info).c_str());
@@ -1613,7 +1616,7 @@
*
******************************************************************************/
void bta_av_cco_close(tBTA_AV_SCB* p_scb, UNUSED_ATTR tBTA_AV_DATA* p_data) {
- APPL_TRACE_DEBUG("%s: peer %s handle:%d", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle:0x%x", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl);
p_scb->p_cos->close(p_scb->hndl, p_scb->PeerAddress());
}
@@ -1668,7 +1671,7 @@
APPL_TRACE_ERROR(
"%s: there is already an active connection: peer_addr=%s chnl=%d "
- "hndl=%d status=%d starting=%d edr=%d",
+ "hndl=0x%x status=%d starting=%d edr=%d",
__func__, open.bd_addr.ToString().c_str(), open.chnl, open.hndl,
open.status, open.starting, open.edr);
@@ -1701,9 +1704,9 @@
memcpy(cfg.codec_info, p_scb->peer_cap.codec_info, AVDT_CODEC_SIZE);
memcpy(cfg.protect_info, p_scb->peer_cap.protect_info, AVDT_PROTECT_SIZE);
- APPL_TRACE_DEBUG("%s: peer %s handle:%d num_codec:%d psc_mask=0x%x", __func__,
- p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
- p_scb->peer_cap.num_codec, p_scb->cfg.psc_mask);
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle:0x%x num_codec:%d psc_mask=0x%x",
+ __func__, p_scb->PeerAddress().ToString().c_str(),
+ p_scb->hndl, p_scb->peer_cap.num_codec, p_scb->cfg.psc_mask);
APPL_TRACE_DEBUG("%s: media type 0x%x, 0x%x", __func__, media_type,
p_scb->media_type);
APPL_TRACE_DEBUG("%s: codec: %s", __func__,
@@ -1733,12 +1736,14 @@
else if (uuid_int == UUID_SERVCLASS_AUDIO_SINK)
bta_av_adjust_seps_idx(p_scb,
bta_av_get_scb_handle(p_scb, AVDT_TSEP_SNK));
+ LOG_DEBUG(LOG_TAG, "%s: sep_idx=%d avdt_handle=%d bta_handle=0x%x",
+ __func__, p_scb->sep_idx, p_scb->avdt_handle, p_scb->hndl);
/* use only the services peer supports */
cfg.psc_mask &= p_scb->peer_cap.psc_mask;
p_scb->cur_psc_mask = cfg.psc_mask;
APPL_TRACE_DEBUG(
- "%s: peer %s handle:%d sep_idx:%d sep_info_idx:%d "
+ "%s: peer %s bta_handle:0x%x sep_idx:%d sep_info_idx:%d "
"cur_psc_mask:0x%x",
__func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
p_scb->sep_idx, p_scb->sep_info_idx, p_scb->cur_psc_mask);
@@ -1781,7 +1786,8 @@
uint8_t avdt_handle = p_data->ci_setconfig.avdt_handle;
bta_av_adjust_seps_idx(p_scb, avdt_handle);
- APPL_TRACE_DEBUG("%s: sep_idx: %d", __func__, p_scb->sep_idx);
+ LOG_DEBUG(LOG_TAG, "%s: sep_idx=%d avdt_handle=%d bta_handle=0x%x", __func__,
+ p_scb->sep_idx, p_scb->avdt_handle, p_scb->hndl);
AVDT_ConfigRsp(p_scb->avdt_handle, p_scb->avdt_label, AVDT_ERR_UNSUP_CFG, 0);
reject.bd_addr = p_data->str_msg.bd_addr;
@@ -1921,8 +1927,8 @@
uint8_t set_policy = HCI_ENABLE_SNIFF_MODE;
APPL_TRACE_ERROR(
- "%s: peer %s handle:%d audio_open_cnt:%d, p_data %p start:%d", __func__,
- p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
+ "%s: peer %s bta_handle:0x%x audio_open_cnt:%d, p_data %p start:%d",
+ __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
bta_av_cb.audio_open_cnt, p_data, start);
bta_sys_idle(BTA_ID_AV, bta_av_cb.audio_open_cnt, p_scb->PeerAddress());
@@ -2231,7 +2237,8 @@
uint8_t cur_role;
uint8_t local_tsep = p_scb->seps[p_scb->sep_idx].tsep;
- LOG_INFO(LOG_TAG, "%s: peer %s handle:%d wait:0x%x role:0x%x local_tsep:%d",
+ LOG_INFO(LOG_TAG,
+ "%s: peer %s bta_handle:0x%x wait:0x%x role:0x%x local_tsep:%d",
__func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
p_scb->wait, p_scb->role, local_tsep);
@@ -2261,7 +2268,7 @@
if (p_scb->wait & BTA_AV_WAIT_ROLE_SW_FAILED) {
/* role switch has failed */
APPL_TRACE_ERROR(
- "%s: peer %s role switch failed: handle:%d wait:0x%x, role:0x%x",
+ "%s: peer %s role switch failed: bta_handle:0x%x wait:0x%x, role:0x%x",
__func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
p_scb->wait, p_scb->role);
p_scb->wait &= ~BTA_AV_WAIT_ROLE_SW_FAILED;
@@ -2421,7 +2428,7 @@
uint8_t set_policy = (HCI_ENABLE_SNIFF_MODE | HCI_ENABLE_MASTER_SLAVE_SWITCH);
APPL_TRACE_ERROR(
- "%s: peer %s handle:%d audio_open_cnt:%d started:%s co_started:%d",
+ "%s: peer %s bta_handle:0x%x audio_open_cnt:%d started:%s co_started:%d",
__func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
bta_av_cb.audio_open_cnt, logbool(p_scb->started).c_str(),
p_scb->co_started);
@@ -2450,9 +2457,9 @@
uint8_t set_policy = HCI_ENABLE_SNIFF_MODE;
APPL_TRACE_WARNING(
- "%s: peer %s handle:%d open_status:%d chnl:%d co_started:%d", __func__,
- p_scb->PeerAddress().ToString().c_str(), p_scb->hndl, p_scb->open_status,
- p_scb->chnl, p_scb->co_started);
+ "%s: peer %s bta_handle:0x%x open_status:%d chnl:%d co_started:%d",
+ __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
+ p_scb->open_status, p_scb->chnl, p_scb->co_started);
if ((bta_av_cb.features & BTA_AV_FEAT_MASTER) == 0 ||
bta_av_cb.audio_open_cnt == 1) {
@@ -2531,7 +2538,7 @@
uint8_t err_code = p_data->str_msg.msg.hdr.err_code;
uint8_t set_policy = HCI_ENABLE_SNIFF_MODE;
- APPL_TRACE_DEBUG("%s: peer %s handle:%d audio_open_cnt:%d err_code:%d",
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle:0x%x audio_open_cnt:%d err_code:%d",
__func__, p_scb->PeerAddress().ToString().c_str(),
p_scb->hndl, bta_av_cb.audio_open_cnt, err_code);
@@ -2610,7 +2617,7 @@
******************************************************************************/
void bta_av_rcfg_str_ok(tBTA_AV_SCB* p_scb, tBTA_AV_DATA* p_data) {
p_scb->l2c_cid = AVDT_GetL2CapChannel(p_scb->avdt_handle);
- APPL_TRACE_DEBUG("%s: peer %s handle:%d l2c_cid:%d", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle:0x%x l2c_cid:%d", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
p_scb->l2c_cid);
@@ -2857,7 +2864,7 @@
*
******************************************************************************/
void bta_av_rcfg_open(tBTA_AV_SCB* p_scb, UNUSED_ATTR tBTA_AV_DATA* p_data) {
- APPL_TRACE_DEBUG("%s: peer %s handle:%d num_disc_snks:%d", __func__,
+ APPL_TRACE_DEBUG("%s: peer %s bta_handle:0x%x num_disc_snks:%d", __func__,
p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
p_scb->num_disc_snks);
@@ -2876,6 +2883,8 @@
/* we may choose to use a different SEP at reconfig.
* adjust the sep_idx now */
bta_av_adjust_seps_idx(p_scb, bta_av_get_scb_handle(p_scb, AVDT_TSEP_SRC));
+ LOG_DEBUG(LOG_TAG, "%s: sep_idx=%d avdt_handle=%d bta_handle=0x%x",
+ __func__, p_scb->sep_idx, p_scb->avdt_handle, p_scb->hndl);
/* open the stream with the new config */
p_scb->sep_info_idx = p_scb->rcfg_idx;
diff --git a/bta/av/bta_av_api.cc b/bta/av/bta_av_api.cc
index bb5cca4..aed5b12 100644
--- a/bta/av/bta_av_api.cc
+++ b/bta/av/bta_av_api.cc
@@ -156,7 +156,8 @@
******************************************************************************/
void BTA_AvOpen(const RawAddress& bd_addr, tBTA_AV_HNDL handle, bool use_rc,
tBTA_SEC sec_mask, uint16_t uuid) {
- LOG_INFO(LOG_TAG, "%s: peer %s handle:0x%x use_rc=%s sec_mask=0x%x uuid=0x%x",
+ LOG_INFO(LOG_TAG,
+ "%s: peer %s bta_handle:0x%x use_rc=%s sec_mask=0x%x uuid=0x%x",
__func__, bd_addr.ToString().c_str(), handle,
(use_rc) ? "true" : "false", sec_mask, uuid);
@@ -184,7 +185,7 @@
*
******************************************************************************/
void BTA_AvClose(tBTA_AV_HNDL handle) {
- LOG_INFO(LOG_TAG, "%s: handle:0x%x", __func__, handle);
+ LOG_INFO(LOG_TAG, "%s: bta_handle:0x%x", __func__, handle);
BT_HDR* p_buf = (BT_HDR*)osi_malloc(sizeof(BT_HDR));
@@ -225,7 +226,7 @@
*
******************************************************************************/
void BTA_AvStart(tBTA_AV_HNDL handle) {
- LOG_INFO(LOG_TAG, "%s: handle=%d", __func__, handle);
+ LOG_INFO(LOG_TAG, "%s: bta_handle=0x%x", __func__, handle);
BT_HDR* p_buf = (BT_HDR*)osi_malloc(sizeof(BT_HDR));
@@ -245,7 +246,7 @@
*
******************************************************************************/
void BTA_AvOffloadStart(tBTA_AV_HNDL hndl) {
- LOG_INFO(LOG_TAG, "%s: handle=%d", __func__, hndl);
+ LOG_INFO(LOG_TAG, "%s: bta_handle=0x%x", __func__, hndl);
BT_HDR* p_buf = (BT_HDR*)osi_malloc(sizeof(BT_HDR));
@@ -287,7 +288,7 @@
*
******************************************************************************/
void BTA_AvStop(tBTA_AV_HNDL handle, bool suspend) {
- LOG_INFO(LOG_TAG, "%s: handle=%d suspend=%s", __func__, handle,
+ LOG_INFO(LOG_TAG, "%s: bta_handle=0x%x suspend=%s", __func__, handle,
logbool(suspend).c_str());
tBTA_AV_API_STOP* p_buf =
@@ -318,8 +319,8 @@
void BTA_AvReconfig(tBTA_AV_HNDL hndl, bool suspend, uint8_t sep_info_idx,
uint8_t* p_codec_info, uint8_t num_protect,
const uint8_t* p_protect_info) {
- LOG_INFO(LOG_TAG, "%s: handle=%d suspend=%s sep_info_idx=%d", __func__, hndl,
- logbool(suspend).c_str(), sep_info_idx);
+ LOG_INFO(LOG_TAG, "%s: bta_handle=0x%x suspend=%s sep_info_idx=%d", __func__,
+ hndl, logbool(suspend).c_str(), sep_info_idx);
tBTA_AV_API_RCFG* p_buf =
(tBTA_AV_API_RCFG*)osi_malloc(sizeof(tBTA_AV_API_RCFG) + num_protect);
diff --git a/bta/av/bta_av_ci.cc b/bta/av/bta_av_ci.cc
index a3d552d..e92c8d6 100644
--- a/bta/av/bta_av_ci.cc
+++ b/bta/av/bta_av_ci.cc
@@ -71,7 +71,7 @@
uint8_t category, uint8_t num_seid, uint8_t* p_seid,
bool recfg_needed, uint8_t avdt_handle) {
LOG_DEBUG(LOG_TAG,
- "%s: bta_av_handle=%d err_code=%d category=%d "
+ "%s: bta_av_handle=0x%x err_code=%d category=%d "
"num_seid=%d recfg_needed=%s avdt_handle=%d",
__func__, bta_av_handle, err_code, category, num_seid,
recfg_needed ? "true" : "false", avdt_handle);
diff --git a/bta/av/bta_av_main.cc b/bta/av/bta_av_main.cc
index e33635e..0256d1c 100644
--- a/bta/av/bta_av_main.cc
+++ b/bta/av/bta_av_main.cc
@@ -427,7 +427,7 @@
p_msg->bd_addr = bd_addr;
p_msg->scb_index = scb_index;
if (p_scb) {
- APPL_TRACE_DEBUG("%s: scb hndl x%x, role x%x", __func__, p_scb->hndl,
+ APPL_TRACE_DEBUG("%s: bta_handle x%x, role x%x", __func__, p_scb->hndl,
p_scb->role);
}
LOG_INFO(LOG_TAG, "%s: conn_cback bd_addr: %s", __func__,
@@ -910,8 +910,8 @@
tBTA_AV_ROLE_RES* p_buf =
(tBTA_AV_ROLE_RES*)osi_malloc(sizeof(tBTA_AV_ROLE_RES));
APPL_TRACE_DEBUG(
- "%s: peer %s found: new_role:%d, hci_status:0x%x hndl:0x%x", __func__,
- peer_addr.ToString().c_str(), id, app_id, p_scb->hndl);
+ "%s: peer %s found: new_role:%d, hci_status:0x%x bta_handle:0x%x",
+ __func__, peer_addr.ToString().c_str(), id, app_id, p_scb->hndl);
/*
if ((id != BTM_ROLE_MASTER) && (app_id != HCI_SUCCESS))
{
@@ -943,8 +943,8 @@
p_scb = bta_av_cb.p_scb[bta_av_cb.rs_idx - 1];
}
if (p_scb && p_scb->q_tag == BTA_AV_Q_TAG_OPEN) {
- APPL_TRACE_DEBUG("%s: peer %s rs_idx:%d, hndl:0x%x q_tag:%d", __func__,
- p_scb->PeerAddress().ToString().c_str(),
+ APPL_TRACE_DEBUG("%s: peer %s rs_idx:%d, bta_handle:0x%x q_tag:%d",
+ __func__, p_scb->PeerAddress().ToString().c_str(),
bta_av_cb.rs_idx, p_scb->hndl, p_scb->q_tag);
if (HCI_SUCCESS == app_id || HCI_ERR_NO_CONNECTION == app_id) {
@@ -1094,11 +1094,11 @@
bool is_ok = true;
if (BTM_GetRole(p_scb->PeerAddress(), &role) == BTM_SUCCESS) {
- LOG_INFO(
- LOG_TAG,
- "%s: peer %s hndl:0x%x role:%d conn_audio:0x%x bits:%d features:0x%x",
- __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl, role,
- bta_av_cb.conn_audio, bits, bta_av_cb.features);
+ LOG_INFO(LOG_TAG,
+ "%s: peer %s bta_handle:0x%x role:%d conn_audio:0x%x bits:%d "
+ "features:0x%x",
+ __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl,
+ role, bta_av_cb.conn_audio, bits, bta_av_cb.features);
if (BTM_ROLE_MASTER != role &&
(A2DP_BitsSet(bta_av_cb.conn_audio) > bits ||
(bta_av_cb.features & BTA_AV_FEAT_MASTER))) {
@@ -1226,7 +1226,7 @@
/* state machine events */
bta_av_sm_execute(&bta_av_cb, p_msg->event, (tBTA_AV_DATA*)p_msg);
} else {
- APPL_TRACE_VERBOSE("%s: handle=0x%x", __func__, p_msg->layer_specific);
+ APPL_TRACE_VERBOSE("%s: bta_handle=0x%x", __func__, p_msg->layer_specific);
/* stream state machine events */
bta_av_ssm_execute(bta_av_hndl_to_scb(p_msg->layer_specific), p_msg->event,
(tBTA_AV_DATA*)p_msg);
@@ -1354,6 +1354,10 @@
return "AVDT_DELAY_RPT";
case BTA_AV_ACP_CONNECT_EVT:
return "ACP_CONNECT";
+ case BTA_AV_API_OFFLOAD_START_EVT:
+ return "OFFLOAD_START";
+ case BTA_AV_API_OFFLOAD_START_RSP_EVT:
+ return "OFFLOAD_START_RSP";
case BTA_AV_API_ENABLE_EVT:
return "API_ENABLE";
diff --git a/bta/av/bta_av_ssm.cc b/bta/av/bta_av_ssm.cc
index 80effa3..c9fc37e 100644
--- a/bta/av/bta_av_ssm.cc
+++ b/bta/av/bta_av_ssm.cc
@@ -486,22 +486,32 @@
return;
}
- APPL_TRACE_VERBOSE(
- "%s: peer %s AV event(0x%x)=0x%x(%s) state=%d(%s) p_scb=%p", __func__,
- p_scb->PeerAddress().ToString().c_str(), p_scb->hndl, event,
- bta_av_evt_code(event), p_scb->state, bta_av_sst_code(p_scb->state),
- p_scb);
-
/* look up the state table for the current state */
tBTA_AV_SST_TBL state_table = bta_av_sst_tbl[p_scb->state];
/* set next state */
+ auto new_state =
+ state_table[event - BTA_AV_FIRST_SSM_EVT][BTA_AV_SNEXT_STATE];
+ if (p_scb->state != new_state) {
+ APPL_TRACE_WARNING(
+ "%s: peer %s AV event(0x%x)=0x%x(%s) state=%d(%s) -> %d(%s) p_scb=%p",
+ __func__, p_scb->PeerAddress().ToString().c_str(), p_scb->hndl, event,
+ bta_av_evt_code(event), p_scb->state, bta_av_sst_code(p_scb->state),
+ new_state, bta_av_sst_code(new_state), p_scb);
+ } else {
+ APPL_TRACE_VERBOSE(
+ "%s: peer %s AV event(0x%x)=0x%x(%s) state=%d(%s) p_scb=%p", __func__,
+ p_scb->PeerAddress().ToString().c_str(), p_scb->hndl, event,
+ bta_av_evt_code(event), p_scb->state, bta_av_sst_code(p_scb->state),
+ p_scb);
+ }
event -= BTA_AV_FIRST_SSM_EVT;
p_scb->state = state_table[event][BTA_AV_SNEXT_STATE];
- APPL_TRACE_VERBOSE("%s: peer %s AV next state=%d(%s) p_scb=%p", __func__,
- p_scb->PeerAddress().ToString().c_str(), p_scb->state,
- bta_av_sst_code(p_scb->state), p_scb);
+ APPL_TRACE_VERBOSE("%s: peer %s AV next state=%d(%s) p_scb=%p(0x%x)",
+ __func__, p_scb->PeerAddress().ToString().c_str(),
+ p_scb->state, bta_av_sst_code(p_scb->state), p_scb,
+ p_scb->hndl);
/* execute action functions */
for (int i = 0; i < BTA_AV_SACTIONS; i++) {
diff --git a/btif/src/btif_av.cc b/btif/src/btif_av.cc
index 8ab336a..1795a9b 100644
--- a/btif/src/btif_av.cc
+++ b/btif/src/btif_av.cc
@@ -2379,10 +2379,11 @@
tBTA_AV_HNDL bta_handle,
const BtifAvEvent& btif_av_event) {
BtifAvPeer* peer = nullptr;
- BTIF_TRACE_EVENT("%s: peer_sep=%s (%d) peer_address=%s handle=0x%x event=%s",
- __func__, (peer_sep == AVDT_TSEP_SRC) ? "Source" : "Sink",
- peer_sep, peer_address.ToString().c_str(), bta_handle,
- btif_av_event.ToString().c_str());
+ BTIF_TRACE_EVENT(
+ "%s: peer_sep=%s (%d) peer_address=%s bta_handle=0x%x event=%s", __func__,
+ (peer_sep == AVDT_TSEP_SRC) ? "Source" : "Sink", peer_sep,
+ peer_address.ToString().c_str(), bta_handle,
+ btif_av_event.ToString().c_str());
// Find the peer
if (peer_address != RawAddress::kEmpty) {
@@ -2400,8 +2401,8 @@
}
if (peer == nullptr) {
BTIF_TRACE_ERROR(
- "%s: Cannot find or create %s peer for peer_address=%s handle=0x%x : "
- "event dropped: %s",
+ "%s: Cannot find or create %s peer for peer_address=%s bta_handle=0x%x "
+ ": event dropped: %s",
__func__, (peer_sep == AVDT_TSEP_SRC) ? "Source" : "Sink",
peer_address.ToString().c_str(), bta_handle,
btif_av_event.ToString().c_str());
@@ -2441,7 +2442,7 @@
const tBTA_AV_REGISTER& registr = p_data->registr;
bta_handle = registr.hndl;
uint8_t peer_id = registr.app_id; // The PeerId is used as AppId
- BTIF_TRACE_DEBUG("%s: handle=0x%x app_id=%d", __func__, bta_handle,
+ BTIF_TRACE_DEBUG("%s: bta_handle=0x%x app_id=%d", __func__, bta_handle,
registr.app_id);
if (peer_sep == AVDT_TSEP_SNK) {
btif_av_source.BtaHandleRegistered(peer_id, bta_handle);
@@ -2539,7 +2540,7 @@
break;
}
}
- BTIF_TRACE_DEBUG("%s: peer_address=%s handle=0x%x", __func__,
+ BTIF_TRACE_DEBUG("%s: peer_address=%s bta_handle=0x%x", __func__,
peer_address.ToString().c_str(), bta_handle);
btif_av_handle_event(peer_sep, peer_address, bta_handle, btif_av_event);
diff --git a/stack/avdt/avdt_api.cc b/stack/avdt/avdt_api.cc
index 9350c31..7447941 100644
--- a/stack/avdt/avdt_api.cc
+++ b/stack/avdt/avdt_api.cc
@@ -141,13 +141,14 @@
}
void AVDT_AbortReq(uint8_t handle) {
- AVDT_TRACE_WARNING("%s: handle=%d", __func__, handle);
+ AVDT_TRACE_WARNING("%s: avdt_handle=%d", __func__, handle);
AvdtpScb* p_scb = avdt_scb_by_hdl(handle);
if (p_scb != NULL) {
avdt_scb_event(p_scb, AVDT_SCB_API_ABORT_REQ_EVT, NULL);
} else {
- AVDT_TRACE_ERROR("%s Improper SCB, can not abort the stream", __func__);
+ AVDT_TRACE_ERROR("%s Improper avdp_handle=%d, can not abort the stream",
+ __func__, handle);
}
}
@@ -187,8 +188,10 @@
}
}
- AVDT_TRACE_DEBUG("%s: result=%d handle=%d scb_index=%d", __func__, result,
- *p_handle, avdtp_stream_config.scb_index);
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d peer_id=%d scb_index=%d", __func__, result,
+ peer_id, avdtp_stream_config.scb_index);
+ }
return result;
}
@@ -211,7 +214,7 @@
uint16_t result = AVDT_SUCCESS;
AvdtpScb* p_scb;
- AVDT_TRACE_DEBUG("%s: handle=%d", __func__, handle);
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d", __func__, handle);
/* look up scb */
p_scb = avdt_scb_by_hdl(handle);
@@ -222,7 +225,9 @@
avdt_scb_event(p_scb, AVDT_SCB_API_REMOVE_EVT, NULL);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d", __func__, result, handle);
+ }
return result;
}
@@ -286,8 +291,10 @@
}
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d address=%s", __func__, result,
+ bd_addr.ToString().c_str());
+ }
return result;
}
@@ -337,8 +344,10 @@
}
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d address=%s", __func__, result,
+ bd_addr.ToString().c_str());
+ }
return result;
}
@@ -384,8 +393,10 @@
getcap.p_cback = p_cback;
result = avdt_get_cap_req(bd_addr, channel_index, &getcap);
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d address=%s", __func__, result,
+ bd_addr.ToString().c_str());
+ }
return result;
}
@@ -405,8 +416,8 @@
uint16_t result = AVDT_SUCCESS;
tAVDT_SCB_EVT evt;
- AVDT_TRACE_DEBUG("%s: handle=%d ceid=%d delay=%d", __func__, handle, seid,
- delay);
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d seid=%d delay=%d", __func__, handle,
+ seid, delay);
/* map handle to scb */
p_scb = avdt_scb_by_hdl(handle);
@@ -420,8 +431,10 @@
avdt_scb_event(p_scb, AVDT_SCB_API_DELAY_RPT_REQ_EVT, &evt);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d seid=%d", __func__, result,
+ handle, seid);
+ }
return result;
}
@@ -447,7 +460,8 @@
uint16_t result = AVDT_SUCCESS;
tAVDT_SCB_EVT evt;
- AVDT_TRACE_DEBUG("%s: handle=%d seid=%d", __func__, handle, seid);
+ AVDT_TRACE_API("%s: address=%s avdt_handle=%d seid=%d", __func__,
+ bd_addr.ToString().c_str(), handle, seid);
/* verify SEID */
if ((seid < AVDT_SEID_MIN) || (seid > AVDT_SEID_MAX)) {
@@ -482,10 +496,11 @@
evt.msg.config_cmd.int_seid = handle;
evt.msg.config_cmd.p_cfg = p_cfg;
avdt_scb_event(p_scb, AVDT_SCB_API_SETCONFIG_REQ_EVT, &evt);
+ } else {
+ AVDT_TRACE_ERROR("%s: result=%d address=%s avdt_handle=%d", __func__,
+ result, bd_addr.ToString().c_str(), handle);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
return result;
}
@@ -508,7 +523,7 @@
uint16_t result = AVDT_SUCCESS;
uint8_t event_code;
- AVDT_TRACE_DEBUG("%s: handle=%d label=%d error_code=0x%x category=%d",
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d label=%d error_code=0x%x category=%d",
__func__, handle, label, error_code, category);
/* map handle to scb */
@@ -535,8 +550,9 @@
avdt_scb_event(p_scb, event_code, &evt);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d", __func__, result, handle);
+ }
return result;
}
@@ -587,8 +603,16 @@
}
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ if ((num_handles == 0) || (num_handles > AVDT_NUM_SEPS)) {
+ AVDT_TRACE_ERROR("%s: result=%d num_handles=%d invalid", __func__, result,
+ num_handles);
+ } else {
+ AVDT_TRACE_ERROR(
+ "%s: result=%d avdt_handle=%d", __func__, result,
+ (i < num_handles ? p_handles[i] : p_handles[num_handles - 1]));
+ }
+ }
return result;
}
@@ -639,8 +663,16 @@
}
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ if ((num_handles == 0) || (num_handles > AVDT_NUM_SEPS)) {
+ AVDT_TRACE_ERROR("%s: result=%d num_handles=%d invalid", __func__, result,
+ num_handles);
+ } else {
+ AVDT_TRACE_ERROR(
+ "%s: result=%d avdt_handle=%d", __func__, result,
+ (i < num_handles ? p_handles[i] : p_handles[num_handles - 1]));
+ }
+ }
return result;
}
@@ -662,7 +694,7 @@
AvdtpScb* p_scb;
uint16_t result = AVDT_SUCCESS;
- AVDT_TRACE_DEBUG("%s: handle=%d", __func__, handle);
+ AVDT_TRACE_API("%s: avdt_handle=%d", __func__, handle);
/* map handle to scb */
p_scb = avdt_scb_by_hdl(handle);
@@ -674,8 +706,9 @@
avdt_scb_event(p_scb, AVDT_SCB_API_CLOSE_REQ_EVT, NULL);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d", __func__, result, handle);
+ }
return result;
}
@@ -701,7 +734,7 @@
uint16_t result = AVDT_SUCCESS;
tAVDT_SCB_EVT evt;
- AVDT_TRACE_DEBUG("%s: handle=%d", __func__, handle);
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d", __func__, handle);
/* map handle to scb */
p_scb = avdt_scb_by_hdl(handle);
@@ -716,8 +749,9 @@
avdt_scb_event(p_scb, AVDT_SCB_API_RECONFIG_REQ_EVT, &evt);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d", __func__, result, handle);
+ }
return result;
}
@@ -739,7 +773,7 @@
tAVDT_SCB_EVT evt;
uint16_t result = AVDT_SUCCESS;
- AVDT_TRACE_DEBUG("%s: handle=%d label=%d error_code=0x%x category=%d",
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d label=%d error_code=0x%x category=%d",
__func__, handle, label, error_code, category);
/* map handle to scb */
@@ -755,8 +789,9 @@
avdt_scb_event(p_scb, AVDT_SCB_API_RECONFIG_RSP_EVT, &evt);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d", __func__, result, handle);
+ }
return result;
}
@@ -779,7 +814,7 @@
uint16_t result = AVDT_SUCCESS;
tAVDT_SCB_EVT evt;
- AVDT_TRACE_DEBUG("%s: handle=%d len=%d", __func__, handle, len);
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d len=%d", __func__, handle, len);
/* map handle to scb */
p_scb = avdt_scb_by_hdl(handle);
@@ -793,8 +828,9 @@
avdt_scb_event(p_scb, AVDT_SCB_API_SECURITY_REQ_EVT, &evt);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d", __func__, result, handle);
+ }
return result;
}
@@ -818,8 +854,8 @@
uint16_t result = AVDT_SUCCESS;
tAVDT_SCB_EVT evt;
- AVDT_TRACE_DEBUG("%s: handle=%d label=%d error_code=0x%x len=%d", __func__,
- handle, label, error_code, len);
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d label=%d error_code=0x%x len=%d",
+ __func__, handle, label, error_code, len);
/* map handle to scb */
p_scb = avdt_scb_by_hdl(handle);
@@ -835,8 +871,9 @@
avdt_scb_event(p_scb, AVDT_SCB_API_SECURITY_RSP_EVT, &evt);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_ERROR("%s: result=%d avdt_handle=%d", __func__, result, handle);
+ }
return result;
}
@@ -883,8 +920,8 @@
tAVDT_SCB_EVT evt;
uint16_t result = AVDT_SUCCESS;
- AVDT_TRACE_DEBUG("%s: handle=%d timestamp=%d m_pt=0x%x opt=0x%x", __func__,
- handle, time_stamp, m_pt, opt);
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d timestamp=%d m_pt=0x%x opt=0x%x",
+ __func__, handle, time_stamp, m_pt, opt);
/* map handle to scb */
p_scb = avdt_scb_by_hdl(handle);
@@ -898,8 +935,7 @@
avdt_scb_event(p_scb, AVDT_SCB_API_WRITE_REQ_EVT, &evt);
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
-
+ AVDT_TRACE_DEBUG("%s: result=%d avdt_handle=%d", __func__, result, handle);
return result;
}
@@ -1024,11 +1060,11 @@
/* send event to ccb */
evt.disconnect.p_cback = p_cback;
avdt_ccb_event(p_ccb, AVDT_CCB_API_DISCONNECT_REQ_EVT, &evt);
+ } else {
+ AVDT_TRACE_ERROR("%s: address=%s result=%d", __func__,
+ bd_addr.ToString().c_str(), result);
}
- AVDT_TRACE_DEBUG("%s: address=%s result=%d", __func__,
- bd_addr.ToString().c_str(), result);
-
return result;
}
@@ -1109,7 +1145,7 @@
uint32_t ssrc;
uint16_t len;
- AVDT_TRACE_DEBUG("%s: handle=%d type=%d", __func__, handle, type);
+ AVDT_TRACE_DEBUG("%s: avdt_handle=%d type=%d", __func__, handle, type);
/* map handle to scb && verify parameters */
if (((p_scb = avdt_scb_by_hdl(handle)) != NULL) && (p_scb->p_ccb != NULL) &&
@@ -1180,7 +1216,10 @@
}
}
- AVDT_TRACE_DEBUG("%s: result=%d", __func__, result);
+ if (result != AVDT_SUCCESS) {
+ AVDT_TRACE_WARNING("%s: result=%d avdt_handle=%d", __func__, result,
+ handle);
+ }
return result;
}
@@ -1252,7 +1291,7 @@
dprintf(fd, " SEP type: 0x%x\n", scb.stream_config.tsep);
dprintf(fd, " Media type: 0x%x\n", scb.stream_config.media_type);
dprintf(fd, " MTU: %d\n", scb.stream_config.mtu);
- dprintf(fd, " SCB handle: %d\n", scb.ScbHandle());
+ dprintf(fd, " AVDT SCB handle: %d\n", scb.ScbHandle());
dprintf(fd, " SCB index: %d\n", scb.stream_config.scb_index);
dprintf(fd, " Configured codec: %s\n",
A2DP_CodecName(scb.curr_cfg.codec_info));