summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
Diffstat
-rwxr-xr-x[-rw-r--r--]audio_a2dp_hw/audio_a2dp_hw.c157
-rwxr-xr-x[-rw-r--r--]bta/ag/bta_ag_act.c8
-rw-r--r--bta/ag/bta_ag_cmd.c6
-rw-r--r--bta/ag/bta_ag_main.c27
-rw-r--r--bta/ag/bta_ag_rfc.c2
-rw-r--r--bta/ag/bta_ag_sco.c34
-rw-r--r--bta/av/bta_av_act.c9
-rw-r--r--bta/av/bta_av_ssm.c15
-rw-r--r--bta/sys/bta_sys_main.c1
-rw-r--r--btif/co/bta_av_co.c6
-rw-r--r--btif/src/btif_av.c10
-rw-r--r--btif/src/btif_hf.c16
-rw-r--r--btif/src/btif_media_task.c61
-rw-r--r--btif/src/btif_rc.c17
-rw-r--r--btif/src/btif_sock_thread.c3
-rw-r--r--include/bt_target.h5
-rw-r--r--include/bt_trace.h8
-rw-r--r--main/bte_logmsg.c15
-rw-r--r--stack/avct/avct_lcb.c8
-rw-r--r--stack/avdt/avdt_scb_act.c1
-rwxr-xr-xstack/avrc/avrc_api.c5
-rw-r--r--stack/avrc/avrc_pars_tg.c2
22 files changed, 311 insertions, 105 deletions
diff --git a/audio_a2dp_hw/audio_a2dp_hw.c b/audio_a2dp_hw/audio_a2dp_hw.c
index d0b36a0a9..cf84d4325 100644..100755
--- a/audio_a2dp_hw/audio_a2dp_hw.c
+++ b/audio_a2dp_hw/audio_a2dp_hw.c
@@ -23,6 +23,12 @@
* Description: Implements hal for bluedroid a2dp audio device
*
*****************************************************************************/
+//#define BT_AUDIO_SYSTRACE_LOG
+
+#ifdef BT_AUDIO_SYSTRACE_LOG
+#define ATRACE_TAG ATRACE_TAG_ALWAYS
+#define PERF_SYSTRACE 1
+#endif
#include <errno.h>
#include <inttypes.h>
@@ -46,9 +52,21 @@
#include "audio_a2dp_hw.h"
#include "bt_utils.h"
+
#define LOG_TAG "bt_a2dp_hw"
#include "osi/include/log.h"
+#ifdef BT_AUDIO_SYSTRACE_LOG
+#include <cutils/trace.h>
+#endif
+
+//#define BT_AUDIO_SAMPLE_LOG
+
+#ifdef BT_AUDIO_SAMPLE_LOG
+FILE *outputpcmsamplefile;
+char btoutputfilename [50] = "/data/audio/output_sample";
+static int number =0;
+#endif
/*****************************************************************************
** Constants & Macros
******************************************************************************/
@@ -150,6 +168,35 @@ static const char* dump_a2dp_ctrl_event(char event)
}
}
+static int calc_audiotime(struct a2dp_config cfg, int bytes)
+{
+ int chan_count = popcount(cfg.channel_flags);
+
+ ASSERTC(cfg.format == AUDIO_FORMAT_PCM_16_BIT,
+ "unsupported sample sz", cfg.format);
+
+ return bytes*(1000000/(chan_count*2))/cfg.rate;
+}
+
+static void ts_error_log(char *tag, int val, int buff_size, struct a2dp_config cfg)
+{
+ struct timespec now;
+ static struct timespec prev = {0,0};
+ unsigned long long now_us;
+ unsigned long long diff_us;
+
+ clock_gettime(CLOCK_MONOTONIC, &now);
+
+ now_us = now.tv_sec*USEC_PER_SEC + now.tv_nsec/1000;
+
+ diff_us = (now.tv_sec - prev.tv_sec) * USEC_PER_SEC + (now.tv_nsec - prev.tv_nsec)/1000;
+ prev = now;
+ if(diff_us > (calc_audiotime (cfg, buff_size) + 10000L))
+ {
+ ERROR("[%s] ts %08lld, diff %08lld, val %d %d", tag, now_us, diff_us, val, buff_size);
+ }
+}
+
/* logs timestamp with microsec precision
pprev is optional in case a dedicated diff is required */
static void ts_log(char *tag, int val, struct timespec *pprev_opt)
@@ -179,16 +226,21 @@ static void ts_log(char *tag, int val, struct timespec *pprev_opt)
}
}
-static int calc_audiotime(struct a2dp_config cfg, int bytes)
-{
- int chan_count = popcount(cfg.channel_flags);
-
- ASSERTC(cfg.format == AUDIO_FORMAT_PCM_16_BIT,
- "unsupported sample sz", cfg.format);
- return bytes*(1000000/(chan_count*2))/cfg.rate;
+static const char* dump_a2dp_hal_state(int event)
+{
+ switch(event)
+ {
+ CASE_RETURN_STR(AUDIO_A2DP_STATE_STARTING)
+ CASE_RETURN_STR(AUDIO_A2DP_STATE_STARTED)
+ CASE_RETURN_STR(AUDIO_A2DP_STATE_STOPPING)
+ CASE_RETURN_STR(AUDIO_A2DP_STATE_STOPPED)
+ CASE_RETURN_STR(AUDIO_A2DP_STATE_SUSPENDED)
+ CASE_RETURN_STR(AUDIO_A2DP_STATE_STANDBY)
+ default:
+ return "UNKNOWN STATE ID";
+ }
}
-
/*****************************************************************************
**
** bluedroid stack adaptation
@@ -331,7 +383,7 @@ static int a2dp_command(struct a2dp_stream_common *common, char cmd)
{
char ack;
- DEBUG("A2DP COMMAND %s", dump_a2dp_ctrl_event(cmd));
+ INFO("A2DP COMMAND %s", dump_a2dp_ctrl_event(cmd));
/* send command */
if (send(common->ctrl_fd, &cmd, 1, MSG_NOSIGNAL) == -1)
@@ -346,7 +398,7 @@ static int a2dp_command(struct a2dp_stream_common *common, char cmd)
if (a2dp_ctrl_receive(common, &ack, 1) < 0)
return -1;
- DEBUG("A2DP COMMAND %s DONE STATUS %d", dump_a2dp_ctrl_event(cmd), ack);
+ INFO("A2DP COMMAND %s DONE STATUS %d", dump_a2dp_ctrl_event(cmd), ack);
if (ack == A2DP_CTRL_ACK_INCALL_FAILURE)
return ack;
@@ -358,6 +410,7 @@ static int a2dp_command(struct a2dp_stream_common *common, char cmd)
static int check_a2dp_ready(struct a2dp_stream_common *common)
{
+ INFO("state %s", dump_a2dp_hal_state(common->state));
if (a2dp_command(common, A2DP_CTRL_CMD_CHECK_READY) < 0)
{
ERROR("check a2dp ready failed");
@@ -445,6 +498,12 @@ static int start_audio_datapath(struct a2dp_stream_common *common)
{
INFO("state %d", common->state);
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ char trace_buf[512];
+ #endif
+
+ INFO("state %s", dump_a2dp_hal_state(common->state));
+
if (common->ctrl_fd == AUDIO_SKT_DISCONNECTED) {
INFO("%s AUDIO_SKT_DISCONNECTED", __func__);
return -1;
@@ -454,6 +513,21 @@ static int start_audio_datapath(struct a2dp_stream_common *common)
common->state = AUDIO_A2DP_STATE_STARTING;
int a2dp_status = a2dp_command(common, A2DP_CTRL_CMD_START);
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ snprintf(trace_buf, 32, "start_audio_data_path:");
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_BEGIN(trace_buf);
+ }
+ #endif
+
+
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_END();
+ }
+ #endif
if (a2dp_status < 0)
{
ERROR("%s Audiopath start failed (status %d)", __func__, a2dp_status);
@@ -488,7 +562,7 @@ static int stop_audio_datapath(struct a2dp_stream_common *common)
{
int oldstate = common->state;
- INFO("state %d", common->state);
+ INFO("state %s", dump_a2dp_hal_state(common->state));
if (common->ctrl_fd == AUDIO_SKT_DISCONNECTED)
return -1;
@@ -515,7 +589,7 @@ static int stop_audio_datapath(struct a2dp_stream_common *common)
static int suspend_audio_datapath(struct a2dp_stream_common *common, bool standby)
{
- INFO("state %d", common->state);
+ INFO("state %s", dump_a2dp_hal_state(common->state));
if (common->ctrl_fd == AUDIO_SKT_DISCONNECTED)
return -1;
@@ -551,6 +625,9 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
{
struct a2dp_stream_out *out = (struct a2dp_stream_out *)stream;
int sent;
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ char trace_buf[512];
+ #endif
DEBUG("write %zu bytes (fd %d)", bytes, out->common.audio_fd);
@@ -558,7 +635,7 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
if (out->common.state == AUDIO_A2DP_STATE_SUSPENDED)
{
- DEBUG("stream suspended");
+ INFO("stream suspended");
pthread_mutex_unlock(&out->common.lock);
return -1;
}
@@ -574,7 +651,7 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
int us_delay = calc_audiotime(out->common.cfg, bytes);
- DEBUG("emulate a2dp write delay (%d us)", us_delay);
+ ERROR("emulate a2dp write delay (%d us)", us_delay);
usleep(us_delay);
pthread_mutex_unlock(&out->common.lock);
@@ -587,10 +664,34 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
pthread_mutex_unlock(&out->common.lock);
return -1;
}
+ #ifdef BT_AUDIO_SAMPLE_LOG
+ if (outputpcmsamplefile)
+ {
+ fwrite (buffer,1,bytes,outputpcmsamplefile);
+ }
+ #endif
+
+ ts_error_log("a2dp_out_write", bytes, out->common.buffer_sz, out->common.cfg);
pthread_mutex_unlock(&out->common.lock);
+
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ snprintf(trace_buf, 32, "out_write:");
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_BEGIN(trace_buf);
+ }
+ #endif
+
sent = skt_write(out->common.audio_fd, buffer, bytes);
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_END();
+ }
+ #endif
+
if (sent == -1)
{
skt_disconnect(out->common.audio_fd);
@@ -610,7 +711,7 @@ static uint32_t out_get_sample_rate(const struct audio_stream *stream)
{
struct a2dp_stream_out *out = (struct a2dp_stream_out *)stream;
- DEBUG("rate %" PRIu32,out->common.cfg.rate);
+ INFO("rate %" PRIu32,out->common.cfg.rate);
return out->common.cfg.rate;
}
@@ -619,7 +720,7 @@ static int out_set_sample_rate(struct audio_stream *stream, uint32_t rate)
{
struct a2dp_stream_out *out = (struct a2dp_stream_out *)stream;
- DEBUG("out_set_sample_rate : %" PRIu32, rate);
+ INFO("out_set_sample_rate : %" PRIu32, rate);
if (rate != AUDIO_STREAM_DEFAULT_RATE)
{
@@ -636,7 +737,7 @@ static size_t out_get_buffer_size(const struct audio_stream *stream)
{
struct a2dp_stream_out *out = (struct a2dp_stream_out *)stream;
- DEBUG("buffer_size : %zu", out->common.buffer_sz);
+ INFO("buffer_size : %zu", out->common.buffer_sz);
return out->common.buffer_sz;
}
@@ -645,7 +746,7 @@ static uint32_t out_get_channels(const struct audio_stream *stream)
{
struct a2dp_stream_out *out = (struct a2dp_stream_out *)stream;
- DEBUG("channels 0x%" PRIx32, out->common.cfg.channel_flags);
+ INFO("channels 0x%" PRIx32, out->common.cfg.channel_flags);
return out->common.cfg.channel_flags;
}
@@ -653,7 +754,7 @@ static uint32_t out_get_channels(const struct audio_stream *stream)
static audio_format_t out_get_format(const struct audio_stream *stream)
{
struct a2dp_stream_out *out = (struct a2dp_stream_out *)stream;
- DEBUG("format 0x%x", out->common.cfg.format);
+ INFO("format 0x%x", out->common.cfg.format);
return out->common.cfg.format;
}
@@ -661,7 +762,7 @@ static int out_set_format(struct audio_stream *stream, audio_format_t format)
{
UNUSED(format);
struct a2dp_stream_out *out = (struct a2dp_stream_out *)stream;
- DEBUG("setting format not yet supported (0x%x)", format);
+ INFO("setting format not yet supported (0x%x)", format);
return -ENOSYS;
}
@@ -1031,6 +1132,11 @@ static int adev_open_output_stream(struct audio_hw_device *dev,
if (!out)
return -ENOMEM;
+ #ifdef BT_AUDIO_SAMPLE_LOG
+ snprintf(btoutputfilename, sizeof(btoutputfilename), "%s%d%s", btoutputfilename, number,".pcm");
+ outputpcmsamplefile = fopen (btoutputfilename, "ab");
+ number++;
+ #endif
out->stream.common.get_sample_rate = out_get_sample_rate;
out->stream.common.set_sample_rate = out_set_sample_rate;
@@ -1074,7 +1180,7 @@ static int adev_open_output_stream(struct audio_hw_device *dev,
goto err_open;
}
- DEBUG("success");
+ INFO("success");
/* Delay to ensure Headset is in proper state when START is initiated
from DUT immediately after the connection due to ongoing music playback. */
usleep(250000);
@@ -1100,12 +1206,17 @@ static void adev_close_output_stream(struct audio_hw_device *dev,
if ((out->common.state == AUDIO_A2DP_STATE_STARTED) || (out->common.state == AUDIO_A2DP_STATE_STOPPING))
stop_audio_datapath(&out->common);
+ #ifdef BT_AUDIO_SAMPLE_LOG
+ ALOGV("close file output");
+ fclose (outputpcmsamplefile);
+ #endif
+
skt_disconnect(out->common.ctrl_fd);
free(stream);
a2dp_dev->output = NULL;
pthread_mutex_unlock(&out->common.lock);
- DEBUG("done");
+ INFO("done");
}
static int adev_set_parameters(struct audio_hw_device *dev, const char *kvpairs)
@@ -1117,7 +1228,7 @@ static int adev_set_parameters(struct audio_hw_device *dev, const char *kvpairs)
if (out == NULL)
return retval;
- INFO("state %d", out->common.state);
+
retval = out->stream.common.set_parameters((struct audio_stream *)out, kvpairs);
diff --git a/bta/ag/bta_ag_act.c b/bta/ag/bta_ag_act.c
index 4e446a725..81dfa3b78 100644..100755
--- a/bta/ag/bta_ag_act.c
+++ b/bta/ag/bta_ag_act.c
@@ -555,7 +555,7 @@ void bta_ag_rfc_acp_open(tBTA_AG_SCB *p_scb, tBTA_AG_DATA *p_data)
/* set role */
p_scb->role = BTA_AG_ACP;
- APPL_TRACE_DEBUG ("bta_ag_rfc_acp_open: serv_handle0 = %d serv_handle1 = %d",
+ APPL_TRACE_IMP ("bta_ag_rfc_acp_open: serv_handle0 = %d serv_handle1 = %d",
p_scb->serv_handle[0], p_scb->serv_handle[1]);
/* get bd addr of peer */
@@ -612,7 +612,7 @@ void bta_ag_rfc_acp_open(tBTA_AG_SCB *p_scb, tBTA_AG_DATA *p_data)
}
}
- APPL_TRACE_DEBUG ("bta_ag_rfc_acp_open: conn_service = %d conn_handle = %d",
+ APPL_TRACE_IMP ("bta_ag_rfc_acp_open: conn_service = %d conn_handle = %d",
p_scb->conn_service, p_scb->conn_handle);
/* close any unopened server */
@@ -667,7 +667,7 @@ void bta_ag_rfc_data(tBTA_AG_SCB *p_scb, tBTA_AG_DATA *p_data)
bta_ag_at_parse(&p_scb->at_cb, buf, len);
if ((p_scb->sco_idx != BTM_INVALID_SCO_INDEX) && bta_ag_sco_is_open(p_scb))
{
- APPL_TRACE_DEBUG ("bta_ag_rfc_data, change link policy for SCO");
+ APPL_TRACE_IMP("bta_ag_rfc_data, change link policy for SCO");
bta_sys_sco_open(BTA_ID_AG, p_scb->app_id, p_scb->peer_addr);
}
else
@@ -865,7 +865,7 @@ void bta_ag_ci_rx_data(tBTA_AG_SCB *p_scb, tBTA_AG_DATA *p_data)
PORT_WriteData(p_scb->conn_handle, p_data_area, strlen(p_data_area), &len);
if ((p_scb->sco_idx != BTM_INVALID_SCO_INDEX) && bta_ag_sco_is_open(p_scb))
{
- APPL_TRACE_DEBUG ("bta_ag_rfc_data, change link policy for SCO");
+ APPL_TRACE_IMP("bta_ag_rfc_data, change link policy for SCO");
bta_sys_sco_open(BTA_ID_AG, p_scb->app_id, p_scb->peer_addr);
}
else
diff --git a/bta/ag/bta_ag_cmd.c b/bta/ag/bta_ag_cmd.c
index cc162d208..a956422ce 100644
--- a/bta/ag/bta_ag_cmd.c
+++ b/bta/ag/bta_ag_cmd.c
@@ -385,7 +385,7 @@ static void bta_ag_send_result(tBTA_AG_SCB *p_scb, UINT8 code, char *p_arg,
*p++ = '\n';
#if defined(BTA_AG_RESULT_DEBUG) && (BTA_AG_RESULT_DEBUG == TRUE)
- APPL_TRACE_DEBUG("bta_ag_send_result: %s", buf);
+ APPL_TRACE_IMP("bta_ag_send_result: %s", buf);
#endif
/* send to RFCOMM */
@@ -885,7 +885,7 @@ void bta_ag_at_hfp_cback(tBTA_AG_SCB *p_scb, UINT16 cmd, UINT8 arg_type,
return;
}
- APPL_TRACE_DEBUG("HFP AT cmd:%d arg_type:%d arg:%d arg:%s", cmd, arg_type,
+ APPL_TRACE_IMP("HFP AT cmd:%d arg_type:%d arg:%d arg:%s", cmd, arg_type,
int_arg, p_arg);
val.hdr.handle = bta_ag_scb_to_idx(p_scb);
@@ -1460,7 +1460,7 @@ void bta_ag_hfp_result(tBTA_AG_SCB *p_scb, tBTA_AG_API_RESULT *p_result)
{
UINT8 code = bta_ag_trans_result[p_result->result];
- APPL_TRACE_DEBUG("bta_ag_hfp_result : res = %d", p_result->result);
+ APPL_TRACE_IMP("bta_ag_hfp_result : res = %d", p_result->result);
switch(p_result->result)
{
diff --git a/bta/ag/bta_ag_main.c b/bta/ag/bta_ag_main.c
index b5501916d..b74fc4828 100644
--- a/bta/ag/bta_ag_main.c
+++ b/bta/ag/bta_ag_main.c
@@ -805,7 +805,7 @@ static void bta_ag_api_result(tBTA_AG_DATA *p_data)
{
if ((p_scb = bta_ag_scb_by_idx(p_data->hdr.layer_specific)) != NULL)
{
- APPL_TRACE_DEBUG("bta_ag_api_result: p_scb 0x%08x ", p_scb);
+ APPL_TRACE_IMP("bta_ag_api_result: p_scb 0x%08x ", p_scb);
bta_ag_sm_execute(p_scb, BTA_AG_API_RESULT_EVT, p_data);
}
}
@@ -837,23 +837,21 @@ void bta_ag_sm_execute(tBTA_AG_SCB *p_scb, UINT16 event, tBTA_AG_DATA *p_data)
tBTA_AG_ST_TBL state_table;
UINT8 action;
int i;
-
-#if BTA_AG_DEBUG == TRUE
UINT16 in_event = event;
UINT8 in_state = p_scb->state;
- /* Ignore displaying of AT results when not connected (Ignored in state machine) */
if (in_event != BTA_AG_API_RESULT_EVT || p_scb->state == BTA_AG_OPEN_ST)
{
- APPL_TRACE_EVENT("AG evt (hdl 0x%04x): State %d (%s), Event 0x%04x (%s)",
+ #if BTA_AG_DEBUG == TRUE
+ APPL_TRACE_IMP("AG evt (hdl 0x%04x): State %d (%s), Event 0x%04x (%s)",
bta_ag_scb_to_idx(p_scb),
p_scb->state, bta_ag_state_str(p_scb->state),
event, bta_ag_evt_str(event, p_data->api_result.result));
+ #else
+ APPL_TRACE_IMP("AG evt (hdl 0x%04x): State %d, Event 0x%04x",
+ bta_ag_scb_to_idx(p_scb), p_scb->state, event);
+ #endif
}
-#else
- APPL_TRACE_EVENT("AG evt (hdl 0x%04x): State %d, Event 0x%04x",
- bta_ag_scb_to_idx(p_scb), p_scb->state, event);
-#endif
event &= 0x00FF;
if (event >= (BTA_AG_MAX_EVT & 0x00FF))
@@ -880,15 +878,18 @@ void bta_ag_sm_execute(tBTA_AG_SCB *p_scb, UINT16 event, tBTA_AG_DATA *p_data)
break;
}
}
-#if BTA_AG_DEBUG == TRUE
if (p_scb->state != in_state)
{
- APPL_TRACE_EVENT("BTA AG State Change: [%s] -> [%s] after Event [%s]",
+ #if BTA_AG_DEBUG == TRUE
+ APPL_TRACE_IMP("BTA AG State Change: [%s] -> [%s] after Event [%s]",
bta_ag_state_str(in_state),
bta_ag_state_str(p_scb->state),
bta_ag_evt_str(in_event, p_data->api_result.result));
+ #else
+ APPL_TRACE_IMP("BTA AG State Change: [%d] -> [%d]",
+ in_state, p_scb->state);
+ #endif
}
-#endif
}
/*******************************************************************************
@@ -932,7 +933,7 @@ BOOLEAN bta_ag_hdl_event(BT_HDR *p_msg)
default:
if ((p_scb = bta_ag_scb_by_idx(p_msg->layer_specific)) != NULL)
{
- APPL_TRACE_DEBUG("bta_ag_hdl_event: p_scb 0x%08x ", p_scb);
+ APPL_TRACE_IMP("bta_ag_hdl_event: p_scb 0x%08x ", p_scb);
bta_ag_sm_execute(p_scb, p_msg->event, (tBTA_AG_DATA *) p_msg);
}
break;
diff --git a/bta/ag/bta_ag_rfc.c b/bta/ag/bta_ag_rfc.c
index 9018b75e3..eadd559c7 100644
--- a/bta/ag/bta_ag_rfc.c
+++ b/bta/ag/bta_ag_rfc.c
@@ -381,7 +381,7 @@ void bta_ag_rfc_do_open(tBTA_AG_SCB *p_scb, tBTA_AG_DATA *p_data)
bta_ag_mgmt_cback_tbl[bta_ag_scb_to_idx(p_scb) - 1]) == PORT_SUCCESS)
{
bta_ag_setup_port(p_scb, p_scb->conn_handle);
- APPL_TRACE_DEBUG("bta_ag_rfc_do_open : conn_handle = %d", p_scb->conn_handle);
+ APPL_TRACE_IMP("bta_ag_rfc_do_open : conn_handle = %d", p_scb->conn_handle);
}
/* RFCOMM create connection failed; send ourselves RFCOMM close event */
else
diff --git a/bta/ag/bta_ag_sco.c b/bta/ag/bta_ag_sco.c
index e612f7790..6e02efcf9 100644
--- a/bta/ag/bta_ag_sco.c
+++ b/bta/ag/bta_ag_sco.c
@@ -203,7 +203,7 @@ static void bta_ag_sco_disc_cback(UINT16 sco_idx)
BT_HDR *p_buf;
UINT16 handle = 0;
- APPL_TRACE_DEBUG ("bta_ag_sco_disc_cback(): sco_idx: 0x%x p_cur_scb: 0x%08x sco.state: %d", sco_idx, bta_ag_cb.sco.p_curr_scb, bta_ag_cb.sco.state);
+ APPL_TRACE_IMP("bta_ag_sco_disc_cback(): sco_idx: 0x%x p_cur_scb: 0x%08x sco.state: %d", sco_idx, bta_ag_cb.sco.p_curr_scb, bta_ag_cb.sco.state);
APPL_TRACE_DEBUG ("bta_ag_sco_disc_cback(): scb[0] addr: 0x%08x in_use: %u sco_idx: 0x%x sco state: %u",
&bta_ag_cb.scb[0], bta_ag_cb.scb[0].in_use, bta_ag_cb.scb[0].sco_idx, bta_ag_cb.scb[0].state);
@@ -328,7 +328,7 @@ static BOOLEAN bta_ag_remove_sco(tBTA_AG_SCB *p_scb, BOOLEAN only_active)
{
status = BTM_RemoveSco(p_scb->sco_idx);
- APPL_TRACE_DEBUG("ag remove sco: inx 0x%04x, status:0x%x", p_scb->sco_idx, status);
+ APPL_TRACE_IMP("ag remove sco: inx 0x%04x, status:0x%x", p_scb->sco_idx, status);
if (status == BTM_CMD_STARTED)
{
@@ -375,7 +375,7 @@ static void bta_ag_esco_connreq_cback(tBTM_ESCO_EVT event, tBTM_ESCO_EVT_DATA *p
/* If no other SCO active, allow this one */
if (!bta_ag_cb.sco.p_curr_scb)
{
- APPL_TRACE_EVENT("bta_ag_esco_connreq_cback: Accept Conn Request (sco_inx 0x%04x)", sco_inx);
+ APPL_TRACE_IMP("bta_ag_esco_connreq_cback: Accept Conn Request (sco_inx 0x%04x)", sco_inx);
bta_ag_sco_conn_rsp(p_scb, &p_data->conn_evt);
bta_ag_cb.sco.state = BTA_AG_SCO_OPENING_ST;
@@ -384,7 +384,7 @@ static void bta_ag_esco_connreq_cback(tBTM_ESCO_EVT event, tBTM_ESCO_EVT_DATA *p
}
else /* Begin a transfer: Close current SCO before responding */
{
- APPL_TRACE_DEBUG("bta_ag_esco_connreq_cback: Begin XFER");
+ APPL_TRACE_IMP("bta_ag_esco_connreq_cback: Begin XFER");
bta_ag_cb.sco.p_xfer_scb = p_scb;
bta_ag_cb.sco.conn_data = p_data->conn_evt;
bta_ag_cb.sco.state = BTA_AG_SCO_OPEN_XFER_ST;
@@ -622,7 +622,7 @@ static void bta_ag_create_sco(tBTA_AG_SCB *p_scb, BOOLEAN is_orig)
}
}
- APPL_TRACE_API("ag create sco: orig %d, inx 0x%04x, status 0x%x, pkt types 0x%04x",
+ APPL_TRACE_IMP("ag create sco: orig %d, inx 0x%04x, status 0x%x, pkt types 0x%04x",
is_orig, p_scb->sco_idx, status, params.packet_types);
}
@@ -732,15 +732,15 @@ static void bta_ag_sco_event(tBTA_AG_SCB *p_scb, UINT8 event)
#if (BTM_SCO_HCI_INCLUDED == TRUE )
BT_HDR *p_buf;
#endif
-#if BTA_AG_SCO_DEBUG == TRUE
UINT8 in_state = p_sco->state;
- APPL_TRACE_EVENT("BTA ag sco evt (hdl 0x%04x): State %d (%s), Event %d (%s)",
+#if BTA_AG_SCO_DEBUG == TRUE
+ APPL_TRACE_IMP("BTA ag sco evt (hdl 0x%04x): State %d (%s), Event %d (%s)",
p_scb->sco_idx,
p_sco->state, bta_ag_sco_state_str(p_sco->state),
event, bta_ag_sco_evt_str(event));
#else
- APPL_TRACE_EVENT("BTA ag sco evt (hdl 0x%04x): State %d, Event %d",
+ APPL_TRACE_IMP("BTA ag sco evt (hdl 0x%04x): State %d, Event %d",
p_scb->sco_idx, p_sco->state, event);
#endif
@@ -1316,15 +1316,19 @@ static void bta_ag_sco_event(tBTA_AG_SCB *p_scb, UINT8 event)
default:
break;
}
-#if BTA_AG_SCO_DEBUG == TRUE
+
if (p_sco->state != in_state)
{
- APPL_TRACE_EVENT("BTA AG SCO State Change: [%s] -> [%s] after Event [%s]",
- bta_ag_sco_state_str(in_state),
- bta_ag_sco_state_str(p_sco->state),
- bta_ag_sco_evt_str(event));
+ #if BTA_AG_SCO_DEBUG == TRUE
+ APPL_TRACE_IMP("BTA AG SCO State Change: [%s] -> [%s] after Event [%s]",
+ bta_ag_sco_state_str(in_state),
+ bta_ag_sco_state_str(p_sco->state),
+ bta_ag_sco_evt_str(event));
+ #else
+ APPL_TRACE_IMP("BTA AG SCO State Change: [%d] -> [%d] after Event [%d]",
+ in_state, p_sco->state, event);
+ #endif
}
-#endif
#if (BTM_WBS_INCLUDED == TRUE )
if (p_cn_scb)
@@ -1439,7 +1443,7 @@ void bta_ag_sco_close(tBTA_AG_SCB *p_scb, tBTA_AG_DATA *p_data)
if (p_scb->sco_idx != BTM_INVALID_SCO_INDEX)
#endif
{
- APPL_TRACE_DEBUG("bta_ag_sco_close: sco_inx = %d", p_scb->sco_idx);
+ APPL_TRACE_IMP("bta_ag_sco_close: sco_inx = %d", p_scb->sco_idx);
bta_ag_sco_event(p_scb, BTA_AG_SCO_CLOSE_E);
}
}
diff --git a/bta/av/bta_av_act.c b/bta/av/bta_av_act.c
index de1618611..429d00d2a 100644
--- a/bta/av/bta_av_act.c
+++ b/bta/av/bta_av_act.c
@@ -220,7 +220,7 @@ static void bta_av_rc_ctrl_cback(UINT8 handle, UINT8 event, UINT16 result, BD_AD
#if (defined(BTA_AV_MIN_DEBUG_TRACES) && BTA_AV_MIN_DEBUG_TRACES == TRUE)
APPL_TRACE_EVENT("rc_ctrl handle: %d event=0x%x", handle, event);
#else
- APPL_TRACE_EVENT("bta_av_rc_ctrl_cback handle: %d event=0x%x", handle, event);
+ BTIF_TRACE_IMP("bta_av_rc_ctrl_cback handle: %d event=0x%x", handle, event);
#endif
if (event == AVRC_OPEN_IND_EVT)
{
@@ -261,7 +261,7 @@ static void bta_av_rc_msg_cback(UINT8 handle, UINT8 label, UINT8 opcode, tAVRC_M
UINT8 *p_data_src = NULL;
UINT16 data_len = 0;
- APPL_TRACE_DEBUG("%s handle: %u opcode=0x%x", __func__, handle, opcode);
+ BTIF_TRACE_IMP("%s handle: %u opcode=0x%x", __func__, handle, opcode);
/* Determine the size of the buffer we need */
if (opcode == AVRC_OP_VENDOR && p_msg->vendor.p_vendor_data != NULL) {
@@ -863,7 +863,7 @@ tBTA_AV_EVT bta_av_proc_meta_cmd(tAVRC_RESPONSE *p_rc_rsp, tBTA_AV_RC_MSG *p_ms
}
}
#else
- APPL_TRACE_DEBUG("AVRCP 1.3 Metadata not supporteed. Reject command.");
+ BTIF_TRACE_IMP("AVRCP 1.3 Metadata not supporteed. Reject command.");
/* reject invalid message without reporting to app */
evt = 0;
p_rc_rsp->rsp.status = AVRC_STS_BAD_CMD;
@@ -1440,7 +1440,8 @@ void bta_av_sig_chg(tBTA_AV_DATA *p_data)
UINT8 mask;
tBTA_AV_LCB *p_lcb = NULL;
- APPL_TRACE_DEBUG("bta_av_sig_chg event: %d", event);
+ BTIF_TRACE_IMP("%s bta_av_sig_chg event: %d",
+ __FUNCTION__, event);
if(event == AVDT_CONNECT_IND_EVT)
{
p_lcb = bta_av_find_lcb(p_data->str_msg.bd_addr, BTA_AV_LCB_FIND);
diff --git a/bta/av/bta_av_ssm.c b/bta/av/bta_av_ssm.c
index 31ee8b7f3..874f8a39c 100644
--- a/bta/av/bta_av_ssm.c
+++ b/bta/av/bta_av_ssm.c
@@ -435,12 +435,15 @@ void bta_av_ssm_execute(tBTA_AV_SCB *p_scb, UINT16 event, tBTA_AV_DATA *p_data)
}
}
-#if (defined(BTA_AV_DEBUG) && BTA_AV_DEBUG == TRUE)
- APPL_TRACE_VERBOSE("AV Sevent(0x%x)=0x%x(%s) state=%d(%s)",
- p_scb->hndl, event, bta_av_evt_code(event), p_scb->state, bta_av_sst_code(p_scb->state));
-#else
- APPL_TRACE_VERBOSE("AV Sevent=0x%x state=%d", event, p_scb->state);
-#endif
+ if ((event != BTA_AV_STR_WRITE_CFM_EVT) && (event != BTA_AV_SRC_DATA_READY_EVT))
+ {
+ #if (defined(BTA_AV_DEBUG) && BTA_AV_DEBUG == TRUE)
+ APPL_TRACE_IMP("AV Sevent(0x%x)=0x%x(%s) state=%d(%s)",
+ p_scb->hndl, event, bta_av_evt_code(event), p_scb->state, bta_av_sst_code(p_scb->state));
+ #else
+ APPL_TRACE_IMP("AV Sevent=0x%x state=%d", event, p_scb->state);
+ #endif
+ }
/* look up the state table for the current state */
state_table = bta_av_sst_tbl[p_scb->state];
diff --git a/bta/sys/bta_sys_main.c b/bta/sys/bta_sys_main.c
index a5b53b960..62362f40c 100644
--- a/bta/sys/bta_sys_main.c
+++ b/bta/sys/bta_sys_main.c
@@ -59,6 +59,7 @@ extern thread_t *bt_workqueue_thread;
/* TODO Bluedroid - Hard-coded trace levels - Needs to be configurable */
UINT8 appl_trace_level = BT_TRACE_LEVEL_WARNING; //APPL_INITIAL_TRACE_LEVEL;
UINT8 btif_trace_level = BT_TRACE_LEVEL_WARNING;
+UINT8 audio_latency_trace_level = BT_TRACE_LEVEL_WARNING;
// Communication queue between btu_task and bta.
extern fixed_queue_t *btu_bta_msg_queue;
diff --git a/btif/co/bta_av_co.c b/btif/co/bta_av_co.c
index a4716169b..6838dd2bf 100644
--- a/btif/co/bta_av_co.c
+++ b/btif/co/bta_av_co.c
@@ -675,7 +675,7 @@ UINT8 bta_av_co_audio_getconfig(tBTA_AV_HNDL hndl, tBTA_AV_CODEC codec_type,
/* Build the codec configuration for this sink */
if (bta_av_co_audio_codec_build_config(p_sink->codec_caps, codec_cfg))
{
- APPL_TRACE_DEBUG("bta_av_co_audio_getconfig reconfig p_codec_info[%x:%x:%x:%x:%x:%x]",
+ APPL_TRACE_IMP("bta_av_co_audio_getconfig reconfig p_codec_info[%x:%x:%x:%x:%x:%x]",
codec_cfg[1], codec_cfg[2], codec_cfg[3],
codec_cfg[4], codec_cfg[5], codec_cfg[6]);
@@ -750,7 +750,7 @@ void bta_av_co_audio_setconfig(tBTA_AV_HNDL hndl, tBTA_AV_CODEC codec_type,
FUNC_TRACE();
- APPL_TRACE_DEBUG("bta_av_co_audio_setconfig p_codec_info[%x:%x:%x:%x:%x:%x]",
+ APPL_TRACE_IMP("bta_av_co_audio_setconfig p_codec_info[%x:%x:%x:%x:%x:%x]",
p_codec_info[1], p_codec_info[2], p_codec_info[3],
p_codec_info[4], p_codec_info[5], p_codec_info[6]);
APPL_TRACE_DEBUG("num_protect:0x%02x protect_info:0x%02x%02x%02x",
@@ -863,7 +863,7 @@ void bta_av_co_audio_setconfig(tBTA_AV_HNDL hndl, tBTA_AV_CODEC codec_type,
if (status != A2D_SUCCESS)
{
- APPL_TRACE_DEBUG("bta_av_co_audio_setconfig reject s=%d c=%d", status, category);
+ APPL_TRACE_ERROR("bta_av_co_audio_setconfig reject s=%d c=%d", status, category);
/* Call call-in rejecting the configuration */
bta_av_ci_setconfig(hndl, status, category, 0, NULL, FALSE, avdt_handle);
diff --git a/btif/src/btif_av.c b/btif/src/btif_av.c
index f5f9b795c..2448c7be4 100644
--- a/btif/src/btif_av.c
+++ b/btif/src/btif_av.c
@@ -279,7 +279,7 @@ static void btif_report_audio_state(btav_audio_state_t state, bt_bdaddr_t *bd_ad
static BOOLEAN btif_av_state_idle_handler(btif_sm_event_t event, void *p_data)
{
- BTIF_TRACE_DEBUG("%s event:%s flags %x", __FUNCTION__,
+ BTIF_TRACE_IMP("%s event:%s flags %x", __FUNCTION__,
dump_av_sm_event_name(event), btif_av_cb.flags);
switch (event)
@@ -389,7 +389,7 @@ static BOOLEAN btif_av_state_idle_handler(btif_sm_event_t event, void *p_data)
static BOOLEAN btif_av_state_opening_handler(btif_sm_event_t event, void *p_data)
{
- BTIF_TRACE_DEBUG("%s event:%s flags %x", __FUNCTION__,
+ BTIF_TRACE_IMP("%s event:%s flags %x", __FUNCTION__,
dump_av_sm_event_name(event), btif_av_cb.flags);
switch (event)
@@ -551,7 +551,7 @@ static BOOLEAN btif_av_state_opening_handler(btif_sm_event_t event, void *p_data
static BOOLEAN btif_av_state_closing_handler(btif_sm_event_t event, void *p_data)
{
- BTIF_TRACE_DEBUG("%s event:%s flags %x", __FUNCTION__,
+ BTIF_TRACE_IMP("%s event:%s flags %x", __FUNCTION__,
dump_av_sm_event_name(event), btif_av_cb.flags);
switch (event)
@@ -624,7 +624,7 @@ static BOOLEAN btif_av_state_opened_handler(btif_sm_event_t event, void *p_data)
tBTA_AV *p_av = (tBTA_AV*)p_data;
tBTIF_STATUS status = BTIF_SUCCESS;
- BTIF_TRACE_DEBUG("%s event:%s flags %x", __FUNCTION__,
+ BTIF_TRACE_IMP("%s event:%s flags %x", __FUNCTION__,
dump_av_sm_event_name(event), btif_av_cb.flags);
if ( (event == BTA_AV_REMOTE_CMD_EVT) && (btif_av_cb.flags & BTIF_AV_FLAG_REMOTE_SUSPEND) &&
@@ -813,7 +813,7 @@ static BOOLEAN btif_av_state_started_handler(btif_sm_event_t event, void *p_data
{
tBTA_AV *p_av = (tBTA_AV*)p_data;
- BTIF_TRACE_DEBUG("%s event:%s flags %x", __FUNCTION__,
+ BTIF_TRACE_IMP("%s event:%s flags %x", __FUNCTION__,
dump_av_sm_event_name(event), btif_av_cb.flags);
switch (event)
diff --git a/btif/src/btif_hf.c b/btif/src/btif_hf.c
index b4a565f11..0421f801c 100644
--- a/btif/src/btif_hf.c
+++ b/btif/src/btif_hf.c
@@ -119,7 +119,7 @@ static UINT32 btif_features = BTIF_HF_FEATURES;
}\
else\
{\
- BTIF_TRACE_EVENT("BTHF: %s", __FUNCTION__);\
+ BTIF_TRACE_IMP("BTHF: %s", __FUNCTION__);\
}
#define CHECK_BTHF_SLC_CONNECTED() if (bt_hf_callbacks == NULL)\
@@ -382,7 +382,7 @@ static void btif_hf_upstreams_evt(UINT16 event, char* p_param)
bdstr_t bdstr;
int idx = p_data->hdr.handle - 1;
- BTIF_TRACE_DEBUG("%s: event=%s", __FUNCTION__, dump_hf_event(event));
+ BTIF_TRACE_IMP("%s: event=%s", __FUNCTION__, dump_hf_event(event));
if ((idx < 0) || (idx >= BTIF_HF_NUM_CB))
{
@@ -1263,7 +1263,7 @@ static bt_status_t phone_state_change(int num_active, int num_held, bthf_call_st
if (btif_hf_check_if_slc_connected() != BT_STATUS_SUCCESS)
return BT_STATUS_NOT_READY;
- BTIF_TRACE_DEBUG("phone_state_change: num_active=%d [prev: %d] num_held=%d[prev: %d]"
+ BTIF_TRACE_IMP("phone_state_change: num_active=%d [prev: %d] num_held=%d[prev: %d]"
" call_setup=%s [prev: %s]", num_active, btif_hf_cb[idx].num_active,
num_held, btif_hf_cb[idx].num_held, dump_hf_call_state(call_setup_state),
dump_hf_call_state(btif_hf_cb[idx].call_setup_state));
@@ -1325,7 +1325,7 @@ static bt_status_t phone_state_change(int num_active, int num_held, bthf_call_st
/* Ringing call changed? */
if (call_setup_state != btif_hf_cb[idx].call_setup_state)
{
- BTIF_TRACE_DEBUG("%s: Call setup states changed. old: %s new: %s",
+ BTIF_TRACE_IMP("%s: Call setup states changed. old: %s new: %s",
__FUNCTION__, dump_hf_call_state(btif_hf_cb[idx].call_setup_state),
dump_hf_call_state(call_setup_state));
memset(&ag_res, 0, sizeof(tBTA_AG_RES_DATA));
@@ -1399,7 +1399,7 @@ static bt_status_t phone_state_change(int num_active, int num_held, bthf_call_st
status = BT_STATUS_PARM_INVALID;
break;
}
- BTIF_TRACE_DEBUG("%s: Call setup state changed. res=%d, audio_handle=%d", __FUNCTION__, res, ag_res.audio_handle);
+ BTIF_TRACE_IMP("%s: Call setup state changed. res=%d, audio_handle=%d", __FUNCTION__, res, ag_res.audio_handle);
if (res)
BTA_AgResult(BTA_AG_HANDLE_ALL, res, &ag_res);
@@ -1423,7 +1423,7 @@ static bt_status_t phone_state_change(int num_active, int num_held, bthf_call_st
if (!activeCallUpdated && ((num_active + num_held) !=
(btif_hf_cb[idx].num_active + btif_hf_cb[idx].num_held)) )
{
- BTIF_TRACE_DEBUG("%s: Active call states changed. old: %d new: %d", __FUNCTION__, btif_hf_cb[idx].num_active, num_active);
+ BTIF_TRACE_IMP("%s: Active call states changed. old: %d new: %d", __FUNCTION__, btif_hf_cb[idx].num_active, num_active);
send_indicator_update(BTA_AG_IND_CALL, ((num_active + num_held) > 0) ? 1 : 0);
}
@@ -1431,7 +1431,7 @@ static bt_status_t phone_state_change(int num_active, int num_held, bthf_call_st
if (num_held != btif_hf_cb[idx].num_held ||
((num_active == 0) && ((num_held + btif_hf_cb[idx].num_held) > 1)))
{
- BTIF_TRACE_DEBUG("%s: Held call states changed. old: %d new: %d",
+ BTIF_TRACE_IMP("%s: Held call states changed. old: %d new: %d",
__FUNCTION__, btif_hf_cb[idx].num_held, num_held);
send_indicator_update(BTA_AG_IND_CALLHELD, ((num_held == 0) ? 0 : ((num_active == 0) ? 2 : 1)));
}
@@ -1442,7 +1442,7 @@ static bt_status_t phone_state_change(int num_active, int num_held, bthf_call_st
(num_active == btif_hf_cb[idx].num_active) &&
(num_held == btif_hf_cb[idx].num_held) )
{
- BTIF_TRACE_DEBUG("%s: Calls swapped", __FUNCTION__);
+ BTIF_TRACE_IMP("%s: Calls swapped", __FUNCTION__);
send_indicator_update(BTA_AG_IND_CALLHELD, 1);
}
diff --git a/btif/src/btif_media_task.c b/btif/src/btif_media_task.c
index 6851c9cbb..34fd19aa4 100644
--- a/btif/src/btif_media_task.c
+++ b/btif/src/btif_media_task.c
@@ -25,6 +25,10 @@
** audio & video processing
**
******************************************************************************/
+//#define BT_AUDIO_SYSTRACE_LOG
+#ifdef BT_AUDIO_SYSTRACE_LOG
+#define ATRACE_TAG ATRACE_TAG_ALWAYS
+#endif
#define LOG_TAG "bt_btif_media"
@@ -85,6 +89,11 @@ OI_UINT32 contextData[CODEC_DATA_WORDS(2, SBC_CODEC_FAST_FILTER_BUFFERS)];
OI_INT16 pcmData[15*SBC_MAX_SAMPLES_PER_FRAME*SBC_MAX_CHANNELS];
#endif
+#ifdef BT_AUDIO_SYSTRACE_LOG
+#include <cutils/trace.h>
+#define PERF_SYSTRACE 1
+#endif
+
/*****************************************************************************
** Constants
*****************************************************************************/
@@ -328,10 +337,23 @@ static UINT64 time_now_us()
static void log_tstamps_us(char *comment)
{
+ #define USEC_PER_MSEC 1000L
static UINT64 prev_us = 0;
const UINT64 now_us = time_now_us();
- APPL_TRACE_DEBUG("[%s] ts %08llu, diff : %08llu, queue sz %d", comment, now_us, now_us - prev_us,
+ static UINT64 diff_us = 0;
+
+ diff_us = now_us - prev_us;
+ if ((diff_us / USEC_PER_MSEC) > (BTIF_MEDIA_TIME_TICK + 10))
+ {
+ APPL_TRACE_ERROR("[%s] ts %08llu, diff : %08llu, queue sz %d", comment, now_us, diff_us,
GKI_queue_length(&btif_media_cb.TxAaQ));
+ }
+ else
+ {
+ APPL_TRACE_DEBUG("[%s] ts %08llu, diff : %08llu, queue sz %d", comment, now_us, diff_us,
+ GKI_queue_length(&btif_media_cb.TxAaQ));
+ }
+
prev_us = now_us;
}
@@ -1357,7 +1379,9 @@ static void btif_media_task_handle_inc_media(tBT_SBC_HDR*p_msg)
p_msg->len = sbc_frame_len + 1;
}
+
UIPC_Send(UIPC_CH_ID_AV_AUDIO, 0, (UINT8 *)pcmData, (2*sizeof(pcmData) - availPcmBytes));
+
}
#endif
@@ -2366,6 +2390,9 @@ BOOLEAN btif_media_aa_read_feeding(tUIPC_CH_ID channel_id)
INT32 fract_max;
INT32 fract_threshold;
UINT32 nb_byte_read;
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ char trace_buf[512];
+ #endif
/* Get the SBC sampling rate */
switch (btif_media_cb.encoder.s16SamplingFreq)
@@ -2455,6 +2482,19 @@ BOOLEAN btif_media_aa_read_feeding(tUIPC_CH_ID channel_id)
{
APPL_TRACE_WARNING("### UNDERRUN :: ONLY READ %d BYTES OUT OF %d ###",
nb_byte_read, read_size);
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ snprintf(trace_buf, 32, "A2DP UNDERRUN read %ld ", nb_byte_read);
+
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_BEGIN(trace_buf);
+ }
+
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_END();
+ }
+ #endif
if (nb_byte_read == 0)
return FALSE;
@@ -2660,6 +2700,9 @@ static void btif_media_send_aa_frame(void)
{
UINT8 nb_frame_2_send;
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ char trace_buf[1024];
+ #endif
/* get the number of frame to send */
nb_frame_2_send = btif_get_num_aa_frame();
@@ -2671,6 +2714,22 @@ static void btif_media_send_aa_frame(void)
/* send it */
LOG_VERBOSE("btif_media_send_aa_frame : send %d frames", nb_frame_2_send);
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ snprintf(trace_buf, 32, "btif_media_send_aa_frame:");
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_BEGIN(trace_buf);
+ }
+ #endif
+
+ /* send it */
+
+ #ifdef BT_AUDIO_SYSTRACE_LOG
+ if (PERF_SYSTRACE)
+ {
+ ATRACE_END();
+ }
+ #endif
bta_av_ci_src_data_ready(BTA_AV_CHNL_AUDIO);
}
diff --git a/btif/src/btif_rc.c b/btif/src/btif_rc.c
index 3000d819f..93be30f5a 100644
--- a/btif/src/btif_rc.c
+++ b/btif/src/btif_rc.c
@@ -255,7 +255,7 @@ void send_key (int fd, uint16_t key, int pressed)
return;
}
- BTIF_TRACE_DEBUG("AVRCP: Send key %d (%d) fd=%d", key, pressed, fd);
+ BTIF_TRACE_IMP("AVRCP: Send key %d (%d) fd=%d", key, pressed, fd);
send_event(fd, EV_KEY, key, pressed);
send_event(fd, EV_SYN, SYN_REPORT, 0);
}
@@ -356,7 +356,7 @@ void handle_rc_features()
bt_bdaddr_t avdtp_addr;
bdstr_t addr1, addr2;
- bdcpy(rc_addr.address, btif_rc_cb.rc_addr);
+ bdcpy(rc_addr.address, btif_rc_cb.rc_addr);
avdtp_addr = btif_av_get_addr();
BTIF_TRACE_DEBUG("AVDTP Address : %s AVCTP address: %s",
@@ -440,7 +440,7 @@ void handle_rc_features()
***************************************************************************/
void handle_rc_connect (tBTA_AV_RC_OPEN *p_rc_open)
{
- BTIF_TRACE_DEBUG("%s: rc_handle: %d", __FUNCTION__, p_rc_open->rc_handle);
+ BTIF_TRACE_IMP("%s: rc_handle: %d", __FUNCTION__, p_rc_open->rc_handle);
bt_status_t result = BT_STATUS_SUCCESS;
#if (AVRC_CTLR_INCLUDED == TRUE)
bt_bdaddr_t rc_addr;
@@ -514,14 +514,13 @@ void handle_rc_disconnect (tBTA_AV_RC_CLOSE *p_rc_close)
bt_bdaddr_t rc_addr;
tBTA_AV_FEAT features;
#endif
- BTIF_TRACE_DEBUG("%s: rc_handle: %d", __FUNCTION__, p_rc_close->rc_handle);
+ BTIF_TRACE_IMP("%s: rc_handle: %d", __FUNCTION__, p_rc_close->rc_handle);
if ((p_rc_close->rc_handle != btif_rc_cb.rc_handle)
&& (bdcmp(btif_rc_cb.rc_addr, p_rc_close->peer_addr)))
{
BTIF_TRACE_ERROR("Got disconnect of unknown device");
return;
}
-
btif_rc_cb.rc_handle = 0;
btif_rc_cb.rc_connected = FALSE;
memset(btif_rc_cb.rc_addr, 0, sizeof(BD_ADDR));
@@ -811,7 +810,7 @@ void handle_rc_metamsg_cmd (tBTA_AV_META_MSG *pmeta_msg)
***************************************************************************/
void btif_rc_handler(tBTA_AV_EVT event, tBTA_AV *p_data)
{
- BTIF_TRACE_DEBUG ("%s event:%s", __FUNCTION__, dump_rc_event(event));
+ BTIF_TRACE_IMP ("%s event:%s", __FUNCTION__, dump_rc_event(event));
switch (event)
{
case BTA_AV_RC_OPEN_EVT:
@@ -1128,7 +1127,7 @@ static UINT8 opcode_from_pdu(UINT8 pdu)
*******************************************************************************/
static void btif_rc_upstreams_evt(UINT16 event, tAVRC_COMMAND *pavrc_cmd, UINT8 ctype, UINT8 label)
{
- BTIF_TRACE_EVENT("%s pdu: %s handle: 0x%x ctype:%x label:%x", __FUNCTION__,
+ BTIF_TRACE_IMP("%s pdu: %s handle: 0x%x ctype:%x label:%x", __FUNCTION__,
dump_rc_pdu(pavrc_cmd->pdu), btif_rc_cb.rc_handle, ctype, label);
switch (event)
@@ -1259,7 +1258,7 @@ static void btif_rc_upstreams_evt(UINT16 event, tAVRC_COMMAND *pavrc_cmd, UINT8
*******************************************************************************/
static void btif_rc_upstreams_rsp_evt(UINT16 event, tAVRC_RESPONSE *pavrc_resp, UINT8 ctype, UINT8 label)
{
- BTIF_TRACE_EVENT("%s pdu: %s handle: 0x%x ctype:%x label:%x", __FUNCTION__,
+ BTIF_TRACE_IMP("%s pdu: %s handle: 0x%x ctype:%x label:%x", __FUNCTION__,
dump_rc_pdu(pavrc_resp->pdu), btif_rc_cb.rc_handle, ctype, label);
#if (AVRC_ADV_CTRL_INCLUDED == TRUE)
@@ -1434,7 +1433,7 @@ static bt_status_t register_notification_rsp(btrc_event_id_t event_id,
{
tAVRC_RESPONSE avrc_rsp;
CHECK_RC_CONNECTED
- BTIF_TRACE_EVENT("## %s ## event_id:%s", __FUNCTION__, dump_rc_notification_event_id(event_id));
+ BTIF_TRACE_IMP("## %s ## event_id:%s", __FUNCTION__, dump_rc_notification_event_id(event_id));
if (btif_rc_cb.rc_notif[event_id-1].bNotify == FALSE)
{
BTIF_TRACE_ERROR("Avrcp Event id not registered: event_id = %x", event_id);
diff --git a/btif/src/btif_sock_thread.c b/btif/src/btif_sock_thread.c
index 459aebac2..5a0ba45b7 100644
--- a/btif/src/btif_sock_thread.c
+++ b/btif/src/btif_sock_thread.c
@@ -37,6 +37,7 @@
#include <sys/types.h>
#include <sys/socket.h>
#include <sys/un.h>
+#include <sys/prctl.h>
#include <time.h>
#include <fcntl.h>
#include <unistd.h>
@@ -605,6 +606,8 @@ static void *sock_poll_thread(void *arg)
struct pollfd pfds[MAX_POLL];
memset(pfds, 0, sizeof(pfds));
int h = (intptr_t)arg;
+
+ prctl(PR_SET_NAME, (unsigned long)"btif_sock_poll", 0, 0, 0);
for(;;)
{
prepare_poll_fds(h, pfds);
diff --git a/include/bt_target.h b/include/bt_target.h
index 638569b75..7cc4f9e37 100644
--- a/include/bt_target.h
+++ b/include/bt_target.h
@@ -176,6 +176,11 @@
#define BT_TRACE_BTIF TRUE
#endif
+
+#ifndef BT_TRACE_LATENCY_AUDIO
+#define BT_TRACE_LATENCY_AUDIO TRUE
+#endif
+
#ifndef BT_TRACE_VERBOSE
#define BT_TRACE_VERBOSE FALSE
#endif
diff --git a/include/bt_trace.h b/include/bt_trace.h
index aefaea687..2d2db0b05 100644
--- a/include/bt_trace.h
+++ b/include/bt_trace.h
@@ -114,7 +114,8 @@ static const char BTE_LOGMSG_MODULE[] = "bte_logmsg_module";
/* LayerIDs for BT APP */
#define BTTRC_ID_BTAPP 87
-#define BTTRC_ID_BT_PROTOCOL 88 /* this is a temporary solution to allow dynamic
+#define BTTRC_ID_LATENCY_AUDIO 88
+#define BTTRC_ID_BT_PROTOCOL 89 /* this is a temporary solution to allow dynamic
enable/disable of BT_PROTOCOL_TRACE */
#define BTTRC_ID_MAX_ID BTTRC_ID_BT_PROTOCOL
// btla-specific --
@@ -363,8 +364,10 @@ static const char BTE_LOGMSG_MODULE[] = "bte_logmsg_module";
#define SMP_TRACE_DEBUG(...) {if (smp_cb.trace_level >= BT_TRACE_LEVEL_DEBUG) BT_TRACE(TRACE_LAYER_SMP, TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
extern UINT8 btif_trace_level;
+extern UINT8 audio_latency_trace_level;
/* define traces for application */
+#define BTIF_TRACE_IMP(...) {LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
#define BTIF_TRACE_ERROR(...) {if (btif_trace_level >= BT_TRACE_LEVEL_ERROR) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_ERROR, ##__VA_ARGS__);}
#define BTIF_TRACE_WARNING(...) {if (btif_trace_level >= BT_TRACE_LEVEL_WARNING) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_WARNING, ##__VA_ARGS__);}
#define BTIF_TRACE_API(...) {if (btif_trace_level >= BT_TRACE_LEVEL_API) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_API, ##__VA_ARGS__);}
@@ -372,13 +375,16 @@ extern UINT8 btif_trace_level;
#define BTIF_TRACE_DEBUG(...) {if (btif_trace_level >= BT_TRACE_LEVEL_DEBUG) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
#define BTIF_TRACE_VERBOSE(...) {if (btif_trace_level >= BT_TRACE_LEVEL_VERBOSE) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
+
/* define traces for application */
+#define APPL_TRACE_IMP(...) {LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
#define APPL_TRACE_ERROR(...) {if (appl_trace_level >= BT_TRACE_LEVEL_ERROR) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_ERROR, ##__VA_ARGS__);}
#define APPL_TRACE_WARNING(...) {if (appl_trace_level >= BT_TRACE_LEVEL_WARNING) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_WARNING, ##__VA_ARGS__);}
#define APPL_TRACE_API(...) {if (appl_trace_level >= BT_TRACE_LEVEL_API) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_API, ##__VA_ARGS__);}
#define APPL_TRACE_EVENT(...) {if (appl_trace_level >= BT_TRACE_LEVEL_EVENT) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_EVENT, ##__VA_ARGS__);}
#define APPL_TRACE_DEBUG(...) {if (appl_trace_level >= BT_TRACE_LEVEL_DEBUG) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
#define APPL_TRACE_VERBOSE(...) {if (appl_trace_level >= BT_TRACE_LEVEL_VERBOSE) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
+#define APPL_TRACE_LATENCY_AUDIO(...) {if (audio_latency_trace_level >= BT_TRACE_LEVEL_VERBOSE) LogMsg(TRACE_CTRL_GENERAL | TRACE_LAYER_NONE | TRACE_ORG_APPL | TRACE_TYPE_DEBUG, ##__VA_ARGS__);}
/* Simplified Trace Helper Macro
*/
diff --git a/main/bte_logmsg.c b/main/bte_logmsg.c
index c07c0c11e..4456e0900 100644
--- a/main/bte_logmsg.c
+++ b/main/bte_logmsg.c
@@ -137,6 +137,7 @@ static const char * const bt_layer_tags[] = {
static uint8_t BTAPP_SetTraceLevel(uint8_t new_level);
static uint8_t BTIF_SetTraceLevel(uint8_t new_level);
static uint8_t BTU_SetTraceLevel(uint8_t new_level);
+static uint8_t AUDIO_Latency_SetTraceLevel(uint8_t new_level);
/* make sure list is order by increasing layer id!!! */
static tBTTRC_FUNC_MAP bttrc_set_level_map[] = {
@@ -172,6 +173,9 @@ static tBTTRC_FUNC_MAP bttrc_set_level_map[] = {
#if (HID_DEV_INCLUDED==TRUE)
{BTTRC_ID_STK_HIDD, BTTRC_ID_STK_HIDD, HID_DevSetTraceLevel, "TRC_HID_DEV", DEFAULT_CONF_TRACE_LEVEL},
#endif
+#if (BT_TRACE_LATENCY_AUDIO == TRUE)
+ {BTTRC_ID_LATENCY_AUDIO, BTTRC_ID_LATENCY_AUDIO, AUDIO_Latency_SetTraceLevel, "TRC_LATENCY_AUDIO", DEFAULT_CONF_TRACE_LEVEL},
+#endif
/* LayerIDs for BTA, currently everything maps onto appl_trace_level.
*/
@@ -229,10 +233,18 @@ static uint8_t BTIF_SetTraceLevel(uint8_t new_level) {
return btif_trace_level;
}
+static uint8_t AUDIO_Latency_SetTraceLevel( uint8_t new_level )
+{
+ if (new_level != 0xFF)
+ audio_latency_trace_level = new_level;
+
+ return (audio_latency_trace_level);
+}
+
+
static uint8_t BTU_SetTraceLevel(uint8_t new_level) {
if (new_level != 0xFF)
btu_cb.trace_level = new_level;
-
return btu_cb.trace_level;
}
@@ -261,6 +273,7 @@ static future_t *init(void) {
return NULL;
}
+
const module_t bte_logmsg_module = {
.name = BTE_LOGMSG_MODULE,
.init = init,
diff --git a/stack/avct/avct_lcb.c b/stack/avct/avct_lcb.c
index eabb8aa2b..26c03c72e 100644
--- a/stack/avct/avct_lcb.c
+++ b/stack/avct/avct_lcb.c
@@ -198,9 +198,9 @@ void avct_lcb_event(tAVCT_LCB *p_lcb, UINT8 event, tAVCT_LCB_EVT *p_data)
int i;
#if BT_TRACE_VERBOSE == TRUE
- AVCT_TRACE_EVENT("LCB lcb=%d event=%s state=%s", p_lcb->allocated, avct_lcb_evt_str[event], avct_lcb_st_str[p_lcb->state]);
+ BTIF_TRACE_IMP("LCB lcb=%d event=%s state=%s", p_lcb->allocated, avct_lcb_evt_str[event], avct_lcb_st_str[p_lcb->state]);
#else
- AVCT_TRACE_EVENT("LCB lcb=%d event=%d state=%d", p_lcb->allocated, event, p_lcb->state);
+ BTIF_TRACE_IMP("LCB lcb=%d event=%d state=%d", p_lcb->allocated, event, p_lcb->state);
#endif
/* look up the state table for the current state */
@@ -241,9 +241,9 @@ void avct_bcb_event(tAVCT_BCB *p_bcb, UINT8 event, tAVCT_LCB_EVT *p_data)
int i;
#if BT_TRACE_VERBOSE == TRUE
- AVCT_TRACE_EVENT("BCB lcb=%d event=%s state=%s", p_bcb->allocated, avct_lcb_evt_str[event], avct_lcb_st_str[p_bcb->state]);
+ BTIF_TRACE_IMP("BCB lcb=%d event=%s state=%s", p_bcb->allocated, avct_lcb_evt_str[event], avct_lcb_st_str[p_bcb->state]);
#else
- AVCT_TRACE_EVENT("BCB lcb=%d event=%d state=%d", p_bcb->allocated, event, p_bcb->state);
+ BTIF_TRACE_IMP("BCB lcb=%d event=%d state=%d", p_bcb->allocated, event, p_bcb->state);
#endif
/* look up the state table for the current state */
diff --git a/stack/avdt/avdt_scb_act.c b/stack/avdt/avdt_scb_act.c
index 109998cdd..ce25b2eae 100644
--- a/stack/avdt/avdt_scb_act.c
+++ b/stack/avdt/avdt_scb_act.c
@@ -299,6 +299,7 @@ void avdt_scb_hdl_pkt_no_frag(tAVDT_SCB *p_scb, tAVDT_SCB_EVT *p_data)
{
/* report sequence number */
p_data->p_pkt->layer_specific = seq;
+ APPL_TRACE_LATENCY_AUDIO("AVDTP Recv Packet, seq number %d", seq);
(*p_scb->cs.p_data_cback)(avdt_scb_to_hdl(p_scb), p_data->p_pkt,
time_stamp, (UINT8)(m_pt | (marker<<7)));
}
diff --git a/stack/avrc/avrc_api.c b/stack/avrc/avrc_api.c
index 70b6f3897..1b874dc8c 100755
--- a/stack/avrc/avrc_api.c
+++ b/stack/avrc/avrc_api.c
@@ -934,9 +934,8 @@ UINT16 AVRC_Open(UINT8 *p_handle, tAVRC_CONN_CB *p_ccb, BD_ADDR_PTR peer_addr)
memset(&avrc_cb.rcb[*p_handle], 0, sizeof(tAVRC_RASM_CB));
#endif
}
- AVRC_TRACE_DEBUG("AVRC_Open role: %d, control:%d status:%d, handle:%d", cc.role, cc.control,
- status, *p_handle);
-
+ BTIF_TRACE_IMP(" %s AVRC_Open role: %d, control:%d status:%d, handle:%d",
+ __FUNCTION__, cc.role, cc.control, status, *p_handle);
return status;
}
diff --git a/stack/avrc/avrc_pars_tg.c b/stack/avrc/avrc_pars_tg.c
index b709c0f8f..6e39c1c5a 100644
--- a/stack/avrc/avrc_pars_tg.c
+++ b/stack/avrc/avrc_pars_tg.c
@@ -314,7 +314,7 @@ tAVRC_STS AVRC_ParsCommand (tAVRC_MSG *p_msg, tAVRC_COMMAND *p_result, UINT8 *p_
p_result->cmd.opcode = p_msg->hdr.opcode;
p_result->cmd.status = status;
}
- AVRC_TRACE_DEBUG("AVRC_ParsCommand() return status:0x%x", status);
+ BTIF_TRACE_IMP("AVRC_ParsCommand() return status:0x%x", status);
return status;
}
generated by cgit v1.2.3 (git 2.25.1) at 2024-05-13 18:45:00 +0000