1 /****************************************************************************** 2 * 3 * Copyright (C) 2016 The Android Open Source Project 4 * Copyright (C) 2009-2012 Broadcom Corporation 5 * 6 * Licensed under the Apache License, Version 2.0 (the "License"); 7 * you may not use this file except in compliance with the License. 8 * You may obtain a copy of the License at: 9 * 10 * http://www.apache.org/licenses/LICENSE-2.0 11 * 12 * Unless required by applicable law or agreed to in writing, software 13 * distributed under the License is distributed on an "AS IS" BASIS, 14 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 15 * See the License for the specific language governing permissions and 16 * limitations under the License. 17 * 18 ******************************************************************************/ 19 20 #define LOG_TAG "bt_btif_a2dp_source" 21 22 #include <base/logging.h> 23 #include <limits.h> 24 #include <string.h> 25 #include <algorithm> 26 27 #include "audio_a2dp_hw/include/audio_a2dp_hw.h" 28 #include "bt_common.h" 29 #include "bta_av_ci.h" 30 #include "btcore/include/bdaddr.h" 31 #include "btif_a2dp.h" 32 #include "btif_a2dp_control.h" 33 #include "btif_a2dp_source.h" 34 #include "btif_av.h" 35 #include "btif_av_co.h" 36 #include "btif_util.h" 37 #include "osi/include/fixed_queue.h" 38 #include "osi/include/log.h" 39 #include "osi/include/metrics.h" 40 #include "osi/include/mutex.h" 41 #include "osi/include/osi.h" 42 #include "osi/include/thread.h" 43 #include "osi/include/time.h" 44 #include "uipc.h" 45 46 using system_bt_osi::BluetoothMetricsLogger; 47 using system_bt_osi::A2dpSessionMetrics; 48 49 /** 50 * The typical runlevel of the tx queue size is ~1 buffer 51 * but due to link flow control or thread preemption in lower 52 * layers we might need to temporarily buffer up data. 53 */ 54 #define MAX_OUTPUT_A2DP_FRAME_QUEUE_SZ (MAX_PCM_FRAME_NUM_PER_TICK * 2) 55 56 enum { 57 BTIF_A2DP_SOURCE_STATE_OFF, 58 BTIF_A2DP_SOURCE_STATE_STARTING_UP, 59 BTIF_A2DP_SOURCE_STATE_RUNNING, 60 BTIF_A2DP_SOURCE_STATE_SHUTTING_DOWN 61 }; 62 63 /* BTIF Media Source event definition */ 64 enum { 65 BTIF_MEDIA_AUDIO_TX_START = 1, 66 BTIF_MEDIA_AUDIO_TX_STOP, 67 BTIF_MEDIA_AUDIO_TX_FLUSH, 68 BTIF_MEDIA_SOURCE_ENCODER_INIT, 69 BTIF_MEDIA_SOURCE_ENCODER_USER_CONFIG_UPDATE, 70 BTIF_MEDIA_AUDIO_FEEDING_UPDATE 71 }; 72 73 /* tBTIF_A2DP_SOURCE_ENCODER_INIT msg structure */ 74 typedef struct { 75 BT_HDR hdr; 76 tA2DP_ENCODER_INIT_PEER_PARAMS peer_params; 77 } tBTIF_A2DP_SOURCE_ENCODER_INIT; 78 79 /* tBTIF_A2DP_SOURCE_ENCODER_USER_CONFIG_UPDATE msg structure */ 80 typedef struct { 81 BT_HDR hdr; 82 btav_a2dp_codec_config_t user_config; 83 } tBTIF_A2DP_SOURCE_ENCODER_USER_CONFIG_UPDATE; 84 85 /* tBTIF_A2DP_AUDIO_FEEDING_UPDATE msg structure */ 86 typedef struct { 87 BT_HDR hdr; 88 btav_a2dp_codec_config_t feeding_params; 89 } tBTIF_A2DP_AUDIO_FEEDING_UPDATE; 90 91 typedef struct { 92 // Counter for total updates 93 size_t total_updates; 94 95 // Last update timestamp (in us) 96 uint64_t last_update_us; 97 98 // Counter for overdue scheduling 99 size_t overdue_scheduling_count; 100 101 // Accumulated overdue scheduling deviations (in us) 102 uint64_t total_overdue_scheduling_delta_us; 103 104 // Max. overdue scheduling delta time (in us) 105 uint64_t max_overdue_scheduling_delta_us; 106 107 // Counter for premature scheduling 108 size_t premature_scheduling_count; 109 110 // Accumulated premature scheduling deviations (in us) 111 uint64_t total_premature_scheduling_delta_us; 112 113 // Max. premature scheduling delta time (in us) 114 uint64_t max_premature_scheduling_delta_us; 115 116 // Counter for exact scheduling 117 size_t exact_scheduling_count; 118 119 // Accumulated and counted scheduling time (in us) 120 uint64_t total_scheduling_time_us; 121 } scheduling_stats_t; 122 123 typedef struct { 124 uint64_t session_start_us; 125 uint64_t session_end_us; 126 127 scheduling_stats_t tx_queue_enqueue_stats; 128 scheduling_stats_t tx_queue_dequeue_stats; 129 130 size_t tx_queue_total_frames; 131 size_t tx_queue_max_frames_per_packet; 132 133 uint64_t tx_queue_total_queueing_time_us; 134 uint64_t tx_queue_max_queueing_time_us; 135 136 size_t tx_queue_total_readbuf_calls; 137 uint64_t tx_queue_last_readbuf_us; 138 139 size_t tx_queue_total_flushed_messages; 140 uint64_t tx_queue_last_flushed_us; 141 142 size_t tx_queue_total_dropped_messages; 143 size_t tx_queue_max_dropped_messages; 144 size_t tx_queue_dropouts; 145 uint64_t tx_queue_last_dropouts_us; 146 147 size_t media_read_total_underflow_bytes; 148 size_t media_read_total_underflow_count; 149 uint64_t media_read_last_underflow_us; 150 } btif_media_stats_t; 151 152 typedef struct { 153 thread_t* worker_thread; 154 fixed_queue_t* cmd_msg_queue; 155 fixed_queue_t* tx_audio_queue; 156 bool tx_flush; /* Discards any outgoing data when true */ 157 alarm_t* media_alarm; 158 const tA2DP_ENCODER_INTERFACE* encoder_interface; 159 period_ms_t encoder_interval_ms; /* Local copy of the encoder interval */ 160 btif_media_stats_t stats; 161 btif_media_stats_t accumulated_stats; 162 } tBTIF_A2DP_SOURCE_CB; 163 164 static tBTIF_A2DP_SOURCE_CB btif_a2dp_source_cb; 165 static int btif_a2dp_source_state = BTIF_A2DP_SOURCE_STATE_OFF; 166 167 static void btif_a2dp_source_command_ready(fixed_queue_t* queue, void* context); 168 static void btif_a2dp_source_startup_delayed(void* context); 169 static void btif_a2dp_source_shutdown_delayed(void* context); 170 static void btif_a2dp_source_audio_tx_start_event(void); 171 static void btif_a2dp_source_audio_tx_stop_event(void); 172 static void btif_a2dp_source_audio_tx_flush_event(BT_HDR* p_msg); 173 static void btif_a2dp_source_encoder_init_event(BT_HDR* p_msg); 174 static void btif_a2dp_source_encoder_user_config_update_event(BT_HDR* p_msg); 175 static void btif_a2dp_source_audio_feeding_update_event(BT_HDR* p_msg); 176 static void btif_a2dp_source_encoder_init(void); 177 static void btif_a2dp_source_encoder_init_req( 178 tBTIF_A2DP_SOURCE_ENCODER_INIT* p_msg); 179 static bool btif_a2dp_source_audio_tx_flush_req(void); 180 static void btif_a2dp_source_alarm_cb(void* context); 181 static void btif_a2dp_source_audio_handle_timer(void* context); 182 static uint32_t btif_a2dp_source_read_callback(uint8_t* p_buf, uint32_t len); 183 static bool btif_a2dp_source_enqueue_callback(BT_HDR* p_buf, size_t frames_n); 184 static void log_tstamps_us(const char* comment, uint64_t timestamp_us); 185 static void update_scheduling_stats(scheduling_stats_t* stats, uint64_t now_us, 186 uint64_t expected_delta); 187 static void btm_read_rssi_cb(void* data); 188 189 UNUSED_ATTR static const char* dump_media_event(uint16_t event) { 190 switch (event) { 191 CASE_RETURN_STR(BTIF_MEDIA_AUDIO_TX_START) 192 CASE_RETURN_STR(BTIF_MEDIA_AUDIO_TX_STOP) 193 CASE_RETURN_STR(BTIF_MEDIA_AUDIO_TX_FLUSH) 194 CASE_RETURN_STR(BTIF_MEDIA_SOURCE_ENCODER_INIT) 195 CASE_RETURN_STR(BTIF_MEDIA_SOURCE_ENCODER_USER_CONFIG_UPDATE) 196 CASE_RETURN_STR(BTIF_MEDIA_AUDIO_FEEDING_UPDATE) 197 default: 198 break; 199 } 200 return "UNKNOWN A2DP SOURCE EVENT"; 201 } 202 203 void btif_a2dp_source_accumulate_scheduling_stats(scheduling_stats_t* src, 204 scheduling_stats_t* dst) { 205 dst->total_updates += src->total_updates; 206 dst->last_update_us = src->last_update_us; 207 dst->overdue_scheduling_count += src->overdue_scheduling_count; 208 dst->total_overdue_scheduling_delta_us += 209 src->total_overdue_scheduling_delta_us; 210 dst->max_overdue_scheduling_delta_us = 211 std::max(dst->max_overdue_scheduling_delta_us, 212 src->max_overdue_scheduling_delta_us); 213 dst->premature_scheduling_count += src->premature_scheduling_count; 214 dst->total_premature_scheduling_delta_us += 215 src->total_premature_scheduling_delta_us; 216 dst->max_premature_scheduling_delta_us = 217 std::max(dst->max_premature_scheduling_delta_us, 218 src->max_premature_scheduling_delta_us); 219 dst->exact_scheduling_count += src->exact_scheduling_count; 220 dst->total_scheduling_time_us += src->total_scheduling_time_us; 221 } 222 223 void btif_a2dp_source_accumulate_stats(btif_media_stats_t* src, 224 btif_media_stats_t* dst) { 225 dst->tx_queue_total_frames += src->tx_queue_total_frames; 226 dst->tx_queue_max_frames_per_packet = std::max( 227 dst->tx_queue_max_frames_per_packet, src->tx_queue_max_frames_per_packet); 228 dst->tx_queue_total_queueing_time_us += src->tx_queue_total_queueing_time_us; 229 dst->tx_queue_max_queueing_time_us = std::max( 230 dst->tx_queue_max_queueing_time_us, src->tx_queue_max_queueing_time_us); 231 dst->tx_queue_total_readbuf_calls += src->tx_queue_total_readbuf_calls; 232 dst->tx_queue_last_readbuf_us = src->tx_queue_last_readbuf_us; 233 dst->tx_queue_total_flushed_messages += src->tx_queue_total_flushed_messages; 234 dst->tx_queue_last_flushed_us = src->tx_queue_last_flushed_us; 235 dst->tx_queue_total_dropped_messages += src->tx_queue_total_dropped_messages; 236 dst->tx_queue_max_dropped_messages = std::max( 237 dst->tx_queue_max_dropped_messages, src->tx_queue_max_dropped_messages); 238 dst->tx_queue_dropouts += src->tx_queue_dropouts; 239 dst->tx_queue_last_dropouts_us = src->tx_queue_last_dropouts_us; 240 dst->media_read_total_underflow_bytes += 241 src->media_read_total_underflow_bytes; 242 dst->media_read_total_underflow_count += 243 src->media_read_total_underflow_count; 244 dst->media_read_last_underflow_us = src->media_read_last_underflow_us; 245 btif_a2dp_source_accumulate_scheduling_stats(&src->tx_queue_enqueue_stats, 246 &dst->tx_queue_enqueue_stats); 247 btif_a2dp_source_accumulate_scheduling_stats(&src->tx_queue_dequeue_stats, 248 &dst->tx_queue_dequeue_stats); 249 memset(src, 0, sizeof(btif_media_stats_t)); 250 } 251 252 bool btif_a2dp_source_startup(void) { 253 if (btif_a2dp_source_state != BTIF_A2DP_SOURCE_STATE_OFF) { 254 APPL_TRACE_ERROR("%s: A2DP Source media task already running", __func__); 255 return false; 256 } 257 258 memset(&btif_a2dp_source_cb, 0, sizeof(btif_a2dp_source_cb)); 259 btif_a2dp_source_state = BTIF_A2DP_SOURCE_STATE_STARTING_UP; 260 261 APPL_TRACE_EVENT("## A2DP SOURCE START MEDIA THREAD ##"); 262 263 /* Start A2DP Source media task */ 264 btif_a2dp_source_cb.worker_thread = 265 thread_new("btif_a2dp_source_worker_thread"); 266 if (btif_a2dp_source_cb.worker_thread == NULL) { 267 APPL_TRACE_ERROR("%s: unable to start up media thread", __func__); 268 btif_a2dp_source_state = BTIF_A2DP_SOURCE_STATE_OFF; 269 return false; 270 } 271 272 btif_a2dp_source_cb.tx_audio_queue = fixed_queue_new(SIZE_MAX); 273 274 btif_a2dp_source_cb.cmd_msg_queue = fixed_queue_new(SIZE_MAX); 275 fixed_queue_register_dequeue( 276 btif_a2dp_source_cb.cmd_msg_queue, 277 thread_get_reactor(btif_a2dp_source_cb.worker_thread), 278 btif_a2dp_source_command_ready, NULL); 279 280 APPL_TRACE_EVENT("## A2DP SOURCE MEDIA THREAD STARTED ##"); 281 282 /* Schedule the rest of the startup operations */ 283 thread_post(btif_a2dp_source_cb.worker_thread, 284 btif_a2dp_source_startup_delayed, NULL); 285 286 return true; 287 } 288 289 static void btif_a2dp_source_startup_delayed(UNUSED_ATTR void* context) { 290 raise_priority_a2dp(TASK_HIGH_MEDIA); 291 btif_a2dp_control_init(); 292 btif_a2dp_source_state = BTIF_A2DP_SOURCE_STATE_RUNNING; 293 BluetoothMetricsLogger::GetInstance()->LogBluetoothSessionStart( 294 system_bt_osi::CONNECTION_TECHNOLOGY_TYPE_BREDR, 0); 295 } 296 297 void btif_a2dp_source_shutdown(void) { 298 if ((btif_a2dp_source_state == BTIF_A2DP_SOURCE_STATE_OFF) || 299 (btif_a2dp_source_state == BTIF_A2DP_SOURCE_STATE_SHUTTING_DOWN)) { 300 return; 301 } 302 303 /* Make sure no channels are restarted while shutting down */ 304 btif_a2dp_source_state = BTIF_A2DP_SOURCE_STATE_SHUTTING_DOWN; 305 306 APPL_TRACE_EVENT("## A2DP SOURCE STOP MEDIA THREAD ##"); 307 308 // Stop the timer 309 alarm_free(btif_a2dp_source_cb.media_alarm); 310 btif_a2dp_source_cb.media_alarm = NULL; 311 312 // Exit the thread 313 fixed_queue_free(btif_a2dp_source_cb.cmd_msg_queue, NULL); 314 btif_a2dp_source_cb.cmd_msg_queue = NULL; 315 thread_post(btif_a2dp_source_cb.worker_thread, 316 btif_a2dp_source_shutdown_delayed, NULL); 317 thread_free(btif_a2dp_source_cb.worker_thread); 318 btif_a2dp_source_cb.worker_thread = NULL; 319 } 320 321 static void btif_a2dp_source_shutdown_delayed(UNUSED_ATTR void* context) { 322 btif_a2dp_control_cleanup(); 323 fixed_queue_free(btif_a2dp_source_cb.tx_audio_queue, NULL); 324 btif_a2dp_source_cb.tx_audio_queue = NULL; 325 326 btif_a2dp_source_state = BTIF_A2DP_SOURCE_STATE_OFF; 327 BluetoothMetricsLogger::GetInstance()->LogBluetoothSessionEnd( 328 system_bt_osi::DISCONNECT_REASON_UNKNOWN, 0); 329 } 330 331 bool btif_a2dp_source_media_task_is_running(void) { 332 return (btif_a2dp_source_state == BTIF_A2DP_SOURCE_STATE_RUNNING); 333 } 334 335 bool btif_a2dp_source_media_task_is_shutting_down(void) { 336 return (btif_a2dp_source_state == BTIF_A2DP_SOURCE_STATE_SHUTTING_DOWN); 337 } 338 339 bool btif_a2dp_source_is_streaming(void) { 340 return alarm_is_scheduled(btif_a2dp_source_cb.media_alarm); 341 } 342 343 static void btif_a2dp_source_command_ready(fixed_queue_t* queue, 344 UNUSED_ATTR void* context) { 345 BT_HDR* p_msg = (BT_HDR*)fixed_queue_dequeue(queue); 346 347 LOG_VERBOSE(LOG_TAG, "%s: event %d %s", __func__, p_msg->event, 348 dump_media_event(p_msg->event)); 349 350 switch (p_msg->event) { 351 case BTIF_MEDIA_AUDIO_TX_START: 352 btif_a2dp_source_audio_tx_start_event(); 353 break; 354 case BTIF_MEDIA_AUDIO_TX_STOP: 355 btif_a2dp_source_audio_tx_stop_event(); 356 break; 357 case BTIF_MEDIA_AUDIO_TX_FLUSH: 358 btif_a2dp_source_audio_tx_flush_event(p_msg); 359 break; 360 case BTIF_MEDIA_SOURCE_ENCODER_INIT: 361 btif_a2dp_source_encoder_init_event(p_msg); 362 break; 363 case BTIF_MEDIA_SOURCE_ENCODER_USER_CONFIG_UPDATE: 364 btif_a2dp_source_encoder_user_config_update_event(p_msg); 365 break; 366 case BTIF_MEDIA_AUDIO_FEEDING_UPDATE: 367 btif_a2dp_source_audio_feeding_update_event(p_msg); 368 break; 369 default: 370 APPL_TRACE_ERROR("ERROR in %s unknown event %d", __func__, p_msg->event); 371 break; 372 } 373 374 osi_free(p_msg); 375 LOG_VERBOSE(LOG_TAG, "%s: %s DONE", __func__, dump_media_event(p_msg->event)); 376 } 377 378 void btif_a2dp_source_setup_codec(void) { 379 APPL_TRACE_EVENT("## A2DP SOURCE SETUP CODEC ##"); 380 381 mutex_global_lock(); 382 383 /* Init the encoding task */ 384 btif_a2dp_source_encoder_init(); 385 386 mutex_global_unlock(); 387 } 388 389 void btif_a2dp_source_start_audio_req(void) { 390 BT_HDR* p_buf = (BT_HDR*)osi_malloc(sizeof(BT_HDR)); 391 392 p_buf->event = BTIF_MEDIA_AUDIO_TX_START; 393 fixed_queue_enqueue(btif_a2dp_source_cb.cmd_msg_queue, p_buf); 394 memset(&btif_a2dp_source_cb.stats, 0, sizeof(btif_media_stats_t)); 395 // Assign session_start_us to 1 when time_get_os_boottime_us() is 0 to 396 // indicate btif_a2dp_source_start_audio_req() has been called 397 btif_a2dp_source_cb.stats.session_start_us = time_get_os_boottime_us(); 398 if (btif_a2dp_source_cb.stats.session_start_us == 0) { 399 btif_a2dp_source_cb.stats.session_start_us = 1; 400 } 401 btif_a2dp_source_cb.stats.session_end_us = 0; 402 } 403 404 void btif_a2dp_source_stop_audio_req(void) { 405 BT_HDR* p_buf = (BT_HDR*)osi_malloc(sizeof(BT_HDR)); 406 407 p_buf->event = BTIF_MEDIA_AUDIO_TX_STOP; 408 409 /* 410 * Explicitly check whether btif_a2dp_source_cb.cmd_msg_queue is not NULL 411 * to avoid a race condition during shutdown of the Bluetooth stack. 412 * This race condition is triggered when A2DP audio is streaming on 413 * shutdown: 414 * "btif_a2dp_source_on_stopped() -> btif_a2dp_source_stop_audio_req()" 415 * is called to stop the particular audio stream, and this happens right 416 * after the "BTIF_AV_CLEANUP_REQ_EVT -> btif_a2dp_source_shutdown()" 417 * processing during the shutdown of the Bluetooth stack. 418 */ 419 if (btif_a2dp_source_cb.cmd_msg_queue != NULL) { 420 fixed_queue_enqueue(btif_a2dp_source_cb.cmd_msg_queue, p_buf); 421 } 422 btif_a2dp_source_cb.stats.session_end_us = time_get_os_boottime_us(); 423 btif_a2dp_source_update_metrics(); 424 btif_a2dp_source_accumulate_stats(&btif_a2dp_source_cb.stats, 425 &btif_a2dp_source_cb.accumulated_stats); 426 } 427 428 static void btif_a2dp_source_encoder_init(void) { 429 tBTIF_A2DP_SOURCE_ENCODER_INIT msg; 430 431 // Check to make sure the platform has 8 bits/byte since 432 // we're using that in frame size calculations now. 433 CHECK(CHAR_BIT == 8); 434 435 APPL_TRACE_DEBUG("%s", __func__); 436 437 bta_av_co_get_peer_params(&msg.peer_params); 438 btif_a2dp_source_encoder_init_req(&msg); 439 } 440 441 static void btif_a2dp_source_encoder_init_req( 442 tBTIF_A2DP_SOURCE_ENCODER_INIT* p_msg) { 443 tBTIF_A2DP_SOURCE_ENCODER_INIT* p_buf = 444 (tBTIF_A2DP_SOURCE_ENCODER_INIT*)osi_malloc( 445 sizeof(tBTIF_A2DP_SOURCE_ENCODER_INIT)); 446 447 memcpy(p_buf, p_msg, sizeof(tBTIF_A2DP_SOURCE_ENCODER_INIT)); 448 p_buf->hdr.event = BTIF_MEDIA_SOURCE_ENCODER_INIT; 449 fixed_queue_enqueue(btif_a2dp_source_cb.cmd_msg_queue, p_buf); 450 } 451 452 static void btif_a2dp_source_encoder_init_event(BT_HDR* p_msg) { 453 tBTIF_A2DP_SOURCE_ENCODER_INIT* p_encoder_init = 454 (tBTIF_A2DP_SOURCE_ENCODER_INIT*)p_msg; 455 456 APPL_TRACE_DEBUG("%s", __func__); 457 458 btif_a2dp_source_cb.encoder_interface = bta_av_co_get_encoder_interface(); 459 if (btif_a2dp_source_cb.encoder_interface == NULL) { 460 APPL_TRACE_ERROR("%s: Cannot stream audio: no source encoder interface", 461 __func__); 462 return; 463 } 464 465 A2dpCodecConfig* a2dp_codec_config = bta_av_get_a2dp_current_codec(); 466 if (a2dp_codec_config == nullptr) { 467 APPL_TRACE_ERROR("%s: Cannot stream audio: current codec is not set", 468 __func__); 469 return; 470 } 471 472 btif_a2dp_source_cb.encoder_interface->encoder_init( 473 &p_encoder_init->peer_params, a2dp_codec_config, 474 btif_a2dp_source_read_callback, btif_a2dp_source_enqueue_callback); 475 476 // Save a local copy of the encoder_interval_ms 477 btif_a2dp_source_cb.encoder_interval_ms = 478 btif_a2dp_source_cb.encoder_interface->get_encoder_interval_ms(); 479 } 480 481 void btif_a2dp_source_encoder_user_config_update_req( 482 const btav_a2dp_codec_config_t& codec_user_config) { 483 tBTIF_A2DP_SOURCE_ENCODER_USER_CONFIG_UPDATE* p_buf = 484 (tBTIF_A2DP_SOURCE_ENCODER_USER_CONFIG_UPDATE*)osi_malloc( 485 sizeof(tBTIF_A2DP_SOURCE_ENCODER_USER_CONFIG_UPDATE)); 486 487 p_buf->user_config = codec_user_config; 488 p_buf->hdr.event = BTIF_MEDIA_SOURCE_ENCODER_USER_CONFIG_UPDATE; 489 fixed_queue_enqueue(btif_a2dp_source_cb.cmd_msg_queue, p_buf); 490 } 491 492 static void btif_a2dp_source_encoder_user_config_update_event(BT_HDR* p_msg) { 493 tBTIF_A2DP_SOURCE_ENCODER_USER_CONFIG_UPDATE* p_user_config = 494 (tBTIF_A2DP_SOURCE_ENCODER_USER_CONFIG_UPDATE*)p_msg; 495 496 APPL_TRACE_DEBUG("%s", __func__); 497 if (!bta_av_co_set_codec_user_config(p_user_config->user_config)) { 498 APPL_TRACE_ERROR("%s: cannot update codec user configuration", __func__); 499 } 500 } 501 502 void btif_a2dp_source_feeding_update_req( 503 const btav_a2dp_codec_config_t& codec_audio_config) { 504 tBTIF_A2DP_AUDIO_FEEDING_UPDATE* p_buf = 505 (tBTIF_A2DP_AUDIO_FEEDING_UPDATE*)osi_malloc( 506 sizeof(tBTIF_A2DP_AUDIO_FEEDING_UPDATE)); 507 508 p_buf->feeding_params = codec_audio_config; 509 p_buf->hdr.event = BTIF_MEDIA_AUDIO_FEEDING_UPDATE; 510 fixed_queue_enqueue(btif_a2dp_source_cb.cmd_msg_queue, p_buf); 511 } 512 513 static void btif_a2dp_source_audio_feeding_update_event(BT_HDR* p_msg) { 514 tBTIF_A2DP_AUDIO_FEEDING_UPDATE* p_feeding = 515 (tBTIF_A2DP_AUDIO_FEEDING_UPDATE*)p_msg; 516 517 APPL_TRACE_DEBUG("%s", __func__); 518 if (!bta_av_co_set_codec_audio_config(p_feeding->feeding_params)) { 519 APPL_TRACE_ERROR("%s: cannot update codec audio feeding parameters", 520 __func__); 521 } 522 } 523 524 void btif_a2dp_source_on_idle(void) { 525 if (btif_a2dp_source_state == BTIF_A2DP_SOURCE_STATE_OFF) return; 526 527 /* Make sure media task is stopped */ 528 btif_a2dp_source_stop_audio_req(); 529 } 530 531 void btif_a2dp_source_on_stopped(tBTA_AV_SUSPEND* p_av_suspend) { 532 APPL_TRACE_EVENT("## ON A2DP SOURCE STOPPED ##"); 533 534 if (btif_a2dp_source_state == BTIF_A2DP_SOURCE_STATE_OFF) return; 535 536 /* allow using this api for other than suspend */ 537 if (p_av_suspend != NULL) { 538 if (p_av_suspend->status != BTA_AV_SUCCESS) { 539 APPL_TRACE_EVENT("AV STOP FAILED (%d)", p_av_suspend->status); 540 if (p_av_suspend->initiator) { 541 APPL_TRACE_WARNING("%s: A2DP stop request failed: status = %d", 542 __func__, p_av_suspend->status); 543 btif_a2dp_command_ack(A2DP_CTRL_ACK_FAILURE); 544 } 545 return; 546 } 547 } 548 549 /* ensure tx frames are immediately suspended */ 550 btif_a2dp_source_cb.tx_flush = true; 551 552 /* request to stop media task */ 553 btif_a2dp_source_audio_tx_flush_req(); 554 btif_a2dp_source_stop_audio_req(); 555 556 /* once stream is fully stopped we will ack back */ 557 } 558 559 void btif_a2dp_source_on_suspended(tBTA_AV_SUSPEND* p_av_suspend) { 560 APPL_TRACE_EVENT("## ON A2DP SOURCE SUSPENDED ##"); 561 562 if (btif_a2dp_source_state == BTIF_A2DP_SOURCE_STATE_OFF) return; 563 564 /* check for status failures */ 565 if (p_av_suspend->status != BTA_AV_SUCCESS) { 566 if (p_av_suspend->initiator) { 567 APPL_TRACE_WARNING("%s: A2DP suspend request failed: status = %d", 568 __func__, p_av_suspend->status); 569 btif_a2dp_command_ack(A2DP_CTRL_ACK_FAILURE); 570 } 571 } 572 573 /* once stream is fully stopped we will ack back */ 574 575 /* ensure tx frames are immediately flushed */ 576 btif_a2dp_source_cb.tx_flush = true; 577 578 /* stop timer tick */ 579 btif_a2dp_source_stop_audio_req(); 580 } 581 582 /* when true media task discards any tx frames */ 583 void btif_a2dp_source_set_tx_flush(bool enable) { 584 APPL_TRACE_EVENT("## DROP TX %d ##", enable); 585 btif_a2dp_source_cb.tx_flush = enable; 586 } 587 588 static void btif_a2dp_source_audio_tx_start_event(void) { 589 APPL_TRACE_DEBUG( 590 "%s media_alarm is %srunning, streaming %s", __func__, 591 alarm_is_scheduled(btif_a2dp_source_cb.media_alarm) ? "" : "not ", 592 btif_a2dp_source_is_streaming() ? "true" : "false"); 593 594 /* Reset the media feeding state */ 595 CHECK(btif_a2dp_source_cb.encoder_interface != NULL); 596 btif_a2dp_source_cb.encoder_interface->feeding_reset(); 597 598 APPL_TRACE_EVENT( 599 "starting timer %dms", 600 btif_a2dp_source_cb.encoder_interface->get_encoder_interval_ms()); 601 602 alarm_free(btif_a2dp_source_cb.media_alarm); 603 btif_a2dp_source_cb.media_alarm = 604 alarm_new_periodic("btif.a2dp_source_media_alarm"); 605 if (btif_a2dp_source_cb.media_alarm == NULL) { 606 LOG_ERROR(LOG_TAG, "%s unable to allocate media alarm", __func__); 607 return; 608 } 609 610 alarm_set(btif_a2dp_source_cb.media_alarm, 611 btif_a2dp_source_cb.encoder_interface->get_encoder_interval_ms(), 612 btif_a2dp_source_alarm_cb, NULL); 613 } 614 615 static void btif_a2dp_source_audio_tx_stop_event(void) { 616 APPL_TRACE_DEBUG( 617 "%s media_alarm is %srunning, streaming %s", __func__, 618 alarm_is_scheduled(btif_a2dp_source_cb.media_alarm) ? "" : "not ", 619 btif_a2dp_source_is_streaming() ? "true" : "false"); 620 621 const bool send_ack = btif_a2dp_source_is_streaming(); 622 623 /* Stop the timer first */ 624 alarm_free(btif_a2dp_source_cb.media_alarm); 625 btif_a2dp_source_cb.media_alarm = NULL; 626 627 UIPC_Close(UIPC_CH_ID_AV_AUDIO); 628 629 /* 630 * Try to send acknowldegment once the media stream is 631 * stopped. This will make sure that the A2DP HAL layer is 632 * un-blocked on wait for acknowledgment for the sent command. 633 * This resolves a corner cases AVDTP SUSPEND collision 634 * when the DUT and the remote device issue SUSPEND simultaneously 635 * and due to the processing of the SUSPEND request from the remote, 636 * the media path is torn down. If the A2DP HAL happens to wait 637 * for ACK for the initiated SUSPEND, it would never receive it casuing 638 * a block/wait. Due to this acknowledgement, the A2DP HAL is guranteed 639 * to get the ACK for any pending command in such cases. 640 */ 641 642 if (send_ack) btif_a2dp_command_ack(A2DP_CTRL_ACK_SUCCESS); 643 644 /* audio engine stopped, reset tx suspended flag */ 645 btif_a2dp_source_cb.tx_flush = false; 646 647 /* Reset the media feeding state */ 648 if (btif_a2dp_source_cb.encoder_interface != NULL) 649 btif_a2dp_source_cb.encoder_interface->feeding_reset(); 650 } 651 652 static void btif_a2dp_source_alarm_cb(UNUSED_ATTR void* context) { 653 thread_post(btif_a2dp_source_cb.worker_thread, 654 btif_a2dp_source_audio_handle_timer, NULL); 655 } 656 657 static void btif_a2dp_source_audio_handle_timer(UNUSED_ATTR void* context) { 658 uint64_t timestamp_us = time_get_os_boottime_us(); 659 log_tstamps_us("A2DP Source tx timer", timestamp_us); 660 661 if (alarm_is_scheduled(btif_a2dp_source_cb.media_alarm)) { 662 CHECK(btif_a2dp_source_cb.encoder_interface != NULL); 663 if (btif_a2dp_source_cb.encoder_interface->set_transmit_queue_length != 664 NULL) { 665 size_t transmit_queue_length = 666 fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue); 667 btif_a2dp_source_cb.encoder_interface->set_transmit_queue_length( 668 transmit_queue_length); 669 } 670 btif_a2dp_source_cb.encoder_interface->send_frames(timestamp_us); 671 bta_av_ci_src_data_ready(BTA_AV_CHNL_AUDIO); 672 update_scheduling_stats(&btif_a2dp_source_cb.stats.tx_queue_enqueue_stats, 673 timestamp_us, 674 btif_a2dp_source_cb.encoder_interval_ms * 1000); 675 } else { 676 APPL_TRACE_ERROR("ERROR Media task Scheduled after Suspend"); 677 } 678 } 679 680 static uint32_t btif_a2dp_source_read_callback(uint8_t* p_buf, uint32_t len) { 681 uint16_t event; 682 uint32_t bytes_read = UIPC_Read(UIPC_CH_ID_AV_AUDIO, &event, p_buf, len); 683 684 if (bytes_read < len) { 685 LOG_WARN(LOG_TAG, "%s: UNDERFLOW: ONLY READ %d BYTES OUT OF %d", __func__, 686 bytes_read, len); 687 btif_a2dp_source_cb.stats.media_read_total_underflow_bytes += 688 (len - bytes_read); 689 btif_a2dp_source_cb.stats.media_read_total_underflow_count++; 690 btif_a2dp_source_cb.stats.media_read_last_underflow_us = 691 time_get_os_boottime_us(); 692 } 693 694 return bytes_read; 695 } 696 697 static bool btif_a2dp_source_enqueue_callback(BT_HDR* p_buf, size_t frames_n) { 698 uint64_t now_us = time_get_os_boottime_us(); 699 700 /* Check if timer was stopped (media task stopped) */ 701 if (!alarm_is_scheduled(btif_a2dp_source_cb.media_alarm)) { 702 osi_free(p_buf); 703 return false; 704 } 705 706 /* Check if the transmission queue has been flushed */ 707 if (btif_a2dp_source_cb.tx_flush) { 708 LOG_VERBOSE(LOG_TAG, "%s: tx suspended, discarded frame", __func__); 709 710 btif_a2dp_source_cb.stats.tx_queue_total_flushed_messages += 711 fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue); 712 btif_a2dp_source_cb.stats.tx_queue_last_flushed_us = now_us; 713 fixed_queue_flush(btif_a2dp_source_cb.tx_audio_queue, osi_free); 714 715 osi_free(p_buf); 716 return false; 717 } 718 719 // Check for TX queue overflow 720 // TODO: Using frames_n here is probably wrong: should be "+ 1" instead. 721 if (fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue) + frames_n > 722 MAX_OUTPUT_A2DP_FRAME_QUEUE_SZ) { 723 LOG_WARN(LOG_TAG, "%s: TX queue buffer size now=%u adding=%u max=%d", 724 __func__, 725 (uint32_t)fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue), 726 (uint32_t)frames_n, MAX_OUTPUT_A2DP_FRAME_QUEUE_SZ); 727 // Keep track of drop-outs 728 btif_a2dp_source_cb.stats.tx_queue_dropouts++; 729 btif_a2dp_source_cb.stats.tx_queue_last_dropouts_us = now_us; 730 731 // Flush all queued buffers 732 size_t drop_n = fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue); 733 btif_a2dp_source_cb.stats.tx_queue_max_dropped_messages = std::max( 734 drop_n, btif_a2dp_source_cb.stats.tx_queue_max_dropped_messages); 735 while (fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue)) { 736 btif_a2dp_source_cb.stats.tx_queue_total_dropped_messages++; 737 osi_free(fixed_queue_try_dequeue(btif_a2dp_source_cb.tx_audio_queue)); 738 } 739 740 // Request RSSI for log purposes if we had to flush buffers 741 bt_bdaddr_t peer_bda = btif_av_get_addr(); 742 BTM_ReadRSSI(peer_bda.address, btm_read_rssi_cb); 743 } 744 745 /* Update the statistics */ 746 btif_a2dp_source_cb.stats.tx_queue_total_frames += frames_n; 747 btif_a2dp_source_cb.stats.tx_queue_max_frames_per_packet = std::max( 748 frames_n, btif_a2dp_source_cb.stats.tx_queue_max_frames_per_packet); 749 CHECK(btif_a2dp_source_cb.encoder_interface != NULL); 750 751 fixed_queue_enqueue(btif_a2dp_source_cb.tx_audio_queue, p_buf); 752 753 return true; 754 } 755 756 static void btif_a2dp_source_audio_tx_flush_event(UNUSED_ATTR BT_HDR* p_msg) { 757 /* Flush all enqueued audio buffers (encoded) */ 758 APPL_TRACE_DEBUG("%s", __func__); 759 760 if (btif_a2dp_source_cb.encoder_interface != NULL) 761 btif_a2dp_source_cb.encoder_interface->feeding_flush(); 762 763 btif_a2dp_source_cb.stats.tx_queue_total_flushed_messages += 764 fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue); 765 btif_a2dp_source_cb.stats.tx_queue_last_flushed_us = 766 time_get_os_boottime_us(); 767 fixed_queue_flush(btif_a2dp_source_cb.tx_audio_queue, osi_free); 768 769 UIPC_Ioctl(UIPC_CH_ID_AV_AUDIO, UIPC_REQ_RX_FLUSH, NULL); 770 } 771 772 static bool btif_a2dp_source_audio_tx_flush_req(void) { 773 BT_HDR* p_buf = (BT_HDR*)osi_malloc(sizeof(BT_HDR)); 774 775 p_buf->event = BTIF_MEDIA_AUDIO_TX_FLUSH; 776 777 /* 778 * Explicitly check whether the btif_a2dp_source_cb.cmd_msg_queue is not 779 * NULL to avoid a race condition during shutdown of the Bluetooth stack. 780 * This race condition is triggered when A2DP audio is streaming on 781 * shutdown: 782 * "btif_a2dp_source_on_stopped() -> btif_a2dp_source_audio_tx_flush_req()" 783 * is called to stop the particular audio stream, and this happens right 784 * after the "BTIF_AV_CLEANUP_REQ_EVT -> btif_a2dp_source_shutdown()" 785 * processing during the shutdown of the Bluetooth stack. 786 */ 787 if (btif_a2dp_source_cb.cmd_msg_queue != NULL) 788 fixed_queue_enqueue(btif_a2dp_source_cb.cmd_msg_queue, p_buf); 789 790 return true; 791 } 792 793 BT_HDR* btif_a2dp_source_audio_readbuf(void) { 794 uint64_t now_us = time_get_os_boottime_us(); 795 BT_HDR* p_buf = 796 (BT_HDR*)fixed_queue_try_dequeue(btif_a2dp_source_cb.tx_audio_queue); 797 798 btif_a2dp_source_cb.stats.tx_queue_total_readbuf_calls++; 799 btif_a2dp_source_cb.stats.tx_queue_last_readbuf_us = now_us; 800 if (p_buf != NULL) { 801 // Update the statistics 802 update_scheduling_stats(&btif_a2dp_source_cb.stats.tx_queue_dequeue_stats, 803 now_us, 804 btif_a2dp_source_cb.encoder_interval_ms * 1000); 805 } 806 807 return p_buf; 808 } 809 810 static void log_tstamps_us(const char* comment, uint64_t timestamp_us) { 811 static uint64_t prev_us = 0; 812 APPL_TRACE_DEBUG("[%s] ts %08llu, diff : %08llu, queue sz %d", comment, 813 timestamp_us, timestamp_us - prev_us, 814 fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue)); 815 prev_us = timestamp_us; 816 } 817 818 static void update_scheduling_stats(scheduling_stats_t* stats, uint64_t now_us, 819 uint64_t expected_delta) { 820 uint64_t last_us = stats->last_update_us; 821 822 stats->total_updates++; 823 stats->last_update_us = now_us; 824 825 if (last_us == 0) return; // First update: expected delta doesn't apply 826 827 uint64_t deadline_us = last_us + expected_delta; 828 if (deadline_us < now_us) { 829 // Overdue scheduling 830 uint64_t delta_us = now_us - deadline_us; 831 // Ignore extreme outliers 832 if (delta_us < 10 * expected_delta) { 833 stats->max_overdue_scheduling_delta_us = 834 std::max(delta_us, stats->max_overdue_scheduling_delta_us); 835 stats->total_overdue_scheduling_delta_us += delta_us; 836 stats->overdue_scheduling_count++; 837 stats->total_scheduling_time_us += now_us - last_us; 838 } 839 } else if (deadline_us > now_us) { 840 // Premature scheduling 841 uint64_t delta_us = deadline_us - now_us; 842 // Ignore extreme outliers 843 if (delta_us < 10 * expected_delta) { 844 stats->max_premature_scheduling_delta_us = 845 std::max(delta_us, stats->max_premature_scheduling_delta_us); 846 stats->total_premature_scheduling_delta_us += delta_us; 847 stats->premature_scheduling_count++; 848 stats->total_scheduling_time_us += now_us - last_us; 849 } 850 } else { 851 // On-time scheduling 852 stats->exact_scheduling_count++; 853 stats->total_scheduling_time_us += now_us - last_us; 854 } 855 } 856 857 void btif_a2dp_source_debug_dump(int fd) { 858 btif_a2dp_source_accumulate_stats(&btif_a2dp_source_cb.stats, 859 &btif_a2dp_source_cb.accumulated_stats); 860 uint64_t now_us = time_get_os_boottime_us(); 861 btif_media_stats_t* accumulated_stats = 862 &btif_a2dp_source_cb.accumulated_stats; 863 scheduling_stats_t* enqueue_stats = 864 &accumulated_stats->tx_queue_enqueue_stats; 865 scheduling_stats_t* dequeue_stats = 866 &accumulated_stats->tx_queue_dequeue_stats; 867 size_t ave_size; 868 uint64_t ave_time_us; 869 870 dprintf(fd, "\nA2DP State:\n"); 871 dprintf(fd, " TxQueue:\n"); 872 873 dprintf(fd, 874 " Counts (enqueue/dequeue/readbuf) : %zu / " 875 "%zu / %zu\n", 876 enqueue_stats->total_updates, dequeue_stats->total_updates, 877 accumulated_stats->tx_queue_total_readbuf_calls); 878 879 dprintf( 880 fd, 881 " Last update time ago in ms (enqueue/dequeue/readbuf) : %llu / %llu " 882 "/ %llu\n", 883 (enqueue_stats->last_update_us > 0) 884 ? (unsigned long long)(now_us - enqueue_stats->last_update_us) / 1000 885 : 0, 886 (dequeue_stats->last_update_us > 0) 887 ? (unsigned long long)(now_us - dequeue_stats->last_update_us) / 1000 888 : 0, 889 (accumulated_stats->tx_queue_last_readbuf_us > 0) 890 ? (unsigned long long)(now_us - 891 accumulated_stats->tx_queue_last_readbuf_us) / 892 1000 893 : 0); 894 895 ave_size = 0; 896 if (enqueue_stats->total_updates != 0) 897 ave_size = 898 accumulated_stats->tx_queue_total_frames / enqueue_stats->total_updates; 899 dprintf(fd, 900 " Frames per packet (total/max/ave) : %zu / " 901 "%zu / %zu\n", 902 accumulated_stats->tx_queue_total_frames, 903 accumulated_stats->tx_queue_max_frames_per_packet, ave_size); 904 905 dprintf(fd, 906 " Counts (flushed/dropped/dropouts) : %zu / " 907 "%zu / %zu\n", 908 accumulated_stats->tx_queue_total_flushed_messages, 909 accumulated_stats->tx_queue_total_dropped_messages, 910 accumulated_stats->tx_queue_dropouts); 911 912 dprintf(fd, 913 " Counts (max dropped) : %zu\n", 914 accumulated_stats->tx_queue_max_dropped_messages); 915 916 dprintf( 917 fd, 918 " Last update time ago in ms (flushed/dropped) : %llu / " 919 "%llu\n", 920 (accumulated_stats->tx_queue_last_flushed_us > 0) 921 ? (unsigned long long)(now_us - 922 accumulated_stats->tx_queue_last_flushed_us) / 923 1000 924 : 0, 925 (accumulated_stats->tx_queue_last_dropouts_us > 0) 926 ? (unsigned long long)(now_us - 927 accumulated_stats->tx_queue_last_dropouts_us) / 928 1000 929 : 0); 930 931 dprintf(fd, 932 " Counts (underflow) : %zu\n", 933 accumulated_stats->media_read_total_underflow_count); 934 935 dprintf(fd, 936 " Bytes (underflow) : %zu\n", 937 accumulated_stats->media_read_total_underflow_bytes); 938 939 dprintf(fd, 940 " Last update time ago in ms (underflow) : %llu\n", 941 (accumulated_stats->media_read_last_underflow_us > 0) 942 ? (unsigned long long)(now_us - 943 accumulated_stats 944 ->media_read_last_underflow_us) / 945 1000 946 : 0); 947 948 // 949 // TxQueue enqueue stats 950 // 951 dprintf( 952 fd, 953 " Enqueue deviation counts (overdue/premature) : %zu / %zu\n", 954 enqueue_stats->overdue_scheduling_count, 955 enqueue_stats->premature_scheduling_count); 956 957 ave_time_us = 0; 958 if (enqueue_stats->overdue_scheduling_count != 0) { 959 ave_time_us = enqueue_stats->total_overdue_scheduling_delta_us / 960 enqueue_stats->overdue_scheduling_count; 961 } 962 dprintf( 963 fd, 964 " Enqueue overdue scheduling time in ms (total/max/ave) : %llu / %llu " 965 "/ %llu\n", 966 (unsigned long long)enqueue_stats->total_overdue_scheduling_delta_us / 967 1000, 968 (unsigned long long)enqueue_stats->max_overdue_scheduling_delta_us / 1000, 969 (unsigned long long)ave_time_us / 1000); 970 971 ave_time_us = 0; 972 if (enqueue_stats->premature_scheduling_count != 0) { 973 ave_time_us = enqueue_stats->total_premature_scheduling_delta_us / 974 enqueue_stats->premature_scheduling_count; 975 } 976 dprintf( 977 fd, 978 " Enqueue premature scheduling time in ms (total/max/ave) : %llu / %llu " 979 "/ %llu\n", 980 (unsigned long long)enqueue_stats->total_premature_scheduling_delta_us / 981 1000, 982 (unsigned long long)enqueue_stats->max_premature_scheduling_delta_us / 983 1000, 984 (unsigned long long)ave_time_us / 1000); 985 986 // 987 // TxQueue dequeue stats 988 // 989 dprintf( 990 fd, 991 " Dequeue deviation counts (overdue/premature) : %zu / %zu\n", 992 dequeue_stats->overdue_scheduling_count, 993 dequeue_stats->premature_scheduling_count); 994 995 ave_time_us = 0; 996 if (dequeue_stats->overdue_scheduling_count != 0) { 997 ave_time_us = dequeue_stats->total_overdue_scheduling_delta_us / 998 dequeue_stats->overdue_scheduling_count; 999 } 1000 dprintf( 1001 fd, 1002 " Dequeue overdue scheduling time in ms (total/max/ave) : %llu / %llu " 1003 "/ %llu\n", 1004 (unsigned long long)dequeue_stats->total_overdue_scheduling_delta_us / 1005 1000, 1006 (unsigned long long)dequeue_stats->max_overdue_scheduling_delta_us / 1000, 1007 (unsigned long long)ave_time_us / 1000); 1008 1009 ave_time_us = 0; 1010 if (dequeue_stats->premature_scheduling_count != 0) { 1011 ave_time_us = dequeue_stats->total_premature_scheduling_delta_us / 1012 dequeue_stats->premature_scheduling_count; 1013 } 1014 dprintf( 1015 fd, 1016 " Dequeue premature scheduling time in ms (total/max/ave) : %llu / %llu " 1017 "/ %llu\n", 1018 (unsigned long long)dequeue_stats->total_premature_scheduling_delta_us / 1019 1000, 1020 (unsigned long long)dequeue_stats->max_premature_scheduling_delta_us / 1021 1000, 1022 (unsigned long long)ave_time_us / 1000); 1023 1024 // 1025 // Codec-specific stats 1026 // 1027 A2dpCodecs* a2dp_codecs = bta_av_get_a2dp_codecs(); 1028 if (a2dp_codecs != nullptr) { 1029 a2dp_codecs->debug_codec_dump(fd); 1030 } 1031 } 1032 1033 void btif_a2dp_source_update_metrics(void) { 1034 btif_media_stats_t* stats = &btif_a2dp_source_cb.stats; 1035 scheduling_stats_t* enqueue_stats = &stats->tx_queue_enqueue_stats; 1036 A2dpSessionMetrics metrics; 1037 // session_start_us is 0 when btif_a2dp_source_start_audio_req() is not called 1038 // mark the metric duration as invalid (-1) in this case 1039 if (stats->session_start_us != 0) { 1040 int64_t session_end_us = stats->session_end_us == 0 1041 ? time_get_os_boottime_us() 1042 : stats->session_end_us; 1043 metrics.audio_duration_ms = 1044 (session_end_us - stats->session_start_us) / 1000; 1045 } 1046 1047 if (enqueue_stats->total_updates > 1) { 1048 metrics.media_timer_min_ms = 1049 btif_a2dp_source_cb.encoder_interval_ms - 1050 (enqueue_stats->max_premature_scheduling_delta_us / 1000); 1051 metrics.media_timer_max_ms = 1052 btif_a2dp_source_cb.encoder_interval_ms + 1053 (enqueue_stats->max_overdue_scheduling_delta_us / 1000); 1054 1055 metrics.total_scheduling_count = enqueue_stats->overdue_scheduling_count + 1056 enqueue_stats->premature_scheduling_count + 1057 enqueue_stats->exact_scheduling_count; 1058 if (metrics.total_scheduling_count > 0) { 1059 metrics.media_timer_avg_ms = enqueue_stats->total_scheduling_time_us / 1060 (1000 * metrics.total_scheduling_count); 1061 } 1062 1063 metrics.buffer_overruns_max_count = stats->tx_queue_max_dropped_messages; 1064 metrics.buffer_overruns_total = stats->tx_queue_total_dropped_messages; 1065 metrics.buffer_underruns_count = stats->media_read_total_underflow_count; 1066 metrics.buffer_underruns_average = 0; 1067 if (metrics.buffer_underruns_count > 0) { 1068 metrics.buffer_underruns_average = 1069 stats->media_read_total_underflow_bytes / 1070 metrics.buffer_underruns_count; 1071 } 1072 } 1073 BluetoothMetricsLogger::GetInstance()->LogA2dpSession(metrics); 1074 } 1075 1076 static void btm_read_rssi_cb(void* data) { 1077 if (data == nullptr) { 1078 LOG_ERROR(LOG_TAG, "%s RSSI request timed out", __func__); 1079 return; 1080 } 1081 1082 tBTM_RSSI_RESULTS* result = (tBTM_RSSI_RESULTS*)data; 1083 if (result->status != BTM_SUCCESS) { 1084 LOG_ERROR(LOG_TAG, "%s unable to read remote RSSI (status %d)", __func__, 1085 result->status); 1086 return; 1087 } 1088 1089 char temp_buffer[20] = {0}; 1090 LOG_WARN(LOG_TAG, "%s device: %s, rssi: %d", __func__, 1091 bdaddr_to_string((bt_bdaddr_t*)result->rem_bda, temp_buffer, 1092 sizeof(temp_buffer)), 1093 result->rssi); 1094 } 1095
