• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /******************************************************************************
2  *
3  *  Copyright 2016 The Android Open Source Project
4  *  Copyright 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 "bluetooth-a2dp"
21 #define ATRACE_TAG ATRACE_TAG_AUDIO
22 
23 #include "btif_a2dp_source.h"
24 
25 #include <base/functional/bind.h>
26 #include <bluetooth/log.h>
27 #include <com_android_bluetooth_flags.h>
28 #include <stdio.h>
29 
30 #include <algorithm>
31 #include <chrono>
32 #include <cstdint>
33 #include <cstring>
34 #include <future>
35 #include <string>
36 #include <utility>
37 #include <vector>
38 
39 #include "a2dp_api.h"
40 #include "a2dp_codec_api.h"
41 #include "audio_hal_interface/a2dp_encoding.h"
42 #include "avdt_api.h"
43 #include "bta_av_api.h"
44 #include "bta_av_ci.h"
45 #include "btif_av.h"
46 #include "btif_av_co.h"
47 #include "btif_common.h"
48 #include "btif_hf.h"
49 #include "btm_iso_api.h"
50 #include "common/message_loop_thread.h"
51 #include "common/repeating_timer.h"
52 #include "common/time_util.h"
53 #include "hardware/bt_av.h"
54 #include "main/shim/metrics_api.h"
55 #include "osi/include/allocator.h"
56 #include "osi/include/fixed_queue.h"
57 #include "osi/include/wakelock.h"
58 #include "stack/include/a2dp_sbc_constants.h"
59 #include "stack/include/acl_api.h"
60 #include "stack/include/acl_api_types.h"
61 #include "stack/include/bt_hdr.h"
62 #include "stack/include/btm_client_interface.h"
63 #include "stack/include/btm_status.h"
64 #include "stack/include/main_thread.h"
65 #include "types/bt_transport.h"
66 #include "types/raw_address.h"
67 
68 #ifdef __ANDROID__
69 #include <cutils/trace.h>
70 #endif
71 
72 using bluetooth::audio::a2dp::Status;
73 using bluetooth::common::RepeatingTimer;
74 using namespace bluetooth;
75 
76 /**
77  * The typical runlevel of the tx queue size is ~1 buffer
78  * but due to link flow control or thread preemption in lower
79  * layers we might need to temporarily buffer up data.
80  */
81 #define MAX_OUTPUT_A2DP_FRAME_QUEUE_SZ (MAX_PCM_FRAME_NUM_PER_TICK * 2)
82 
83 class SchedulingStats {
84 public:
SchedulingStats()85   SchedulingStats() { Reset(); }
Reset()86   void Reset() {
87     total_updates = 0;
88     last_update_us = 0;
89     overdue_scheduling_count = 0;
90     total_overdue_scheduling_delta_us = 0;
91     max_overdue_scheduling_delta_us = 0;
92     premature_scheduling_count = 0;
93     total_premature_scheduling_delta_us = 0;
94     max_premature_scheduling_delta_us = 0;
95     exact_scheduling_count = 0;
96     total_scheduling_time_us = 0;
97   }
98 
99   // Counter for total updates
100   size_t total_updates;
101 
102   // Last update timestamp (in us)
103   uint64_t last_update_us;
104 
105   // Counter for overdue scheduling
106   size_t overdue_scheduling_count;
107 
108   // Accumulated overdue scheduling deviations (in us)
109   uint64_t total_overdue_scheduling_delta_us;
110 
111   // Max. overdue scheduling delta time (in us)
112   uint64_t max_overdue_scheduling_delta_us;
113 
114   // Counter for premature scheduling
115   size_t premature_scheduling_count;
116 
117   // Accumulated premature scheduling deviations (in us)
118   uint64_t total_premature_scheduling_delta_us;
119 
120   // Max. premature scheduling delta time (in us)
121   uint64_t max_premature_scheduling_delta_us;
122 
123   // Counter for exact scheduling
124   size_t exact_scheduling_count;
125 
126   // Accumulated and counted scheduling time (in us)
127   uint64_t total_scheduling_time_us;
128 };
129 
130 class BtifMediaStats {
131 public:
BtifMediaStats()132   BtifMediaStats() { Reset(); }
Reset()133   void Reset() {
134     session_start_us = 0;
135     session_end_us = 0;
136     tx_queue_enqueue_stats.Reset();
137     tx_queue_dequeue_stats.Reset();
138     tx_queue_total_frames = 0;
139     tx_queue_max_frames_per_packet = 0;
140     tx_queue_total_queueing_time_us = 0;
141     tx_queue_max_queueing_time_us = 0;
142     tx_queue_total_readbuf_calls = 0;
143     tx_queue_last_readbuf_us = 0;
144     tx_queue_total_flushed_messages = 0;
145     tx_queue_last_flushed_us = 0;
146     tx_queue_total_dropped_messages = 0;
147     tx_queue_max_dropped_messages = 0;
148     tx_queue_dropouts = 0;
149     tx_queue_last_dropouts_us = 0;
150     media_read_total_underflow_bytes = 0;
151     media_read_total_underflow_count = 0;
152     media_read_last_underflow_us = 0;
153     codec_index = -1;
154   }
155 
156   uint64_t session_start_us;
157   uint64_t session_end_us;
158 
159   SchedulingStats tx_queue_enqueue_stats;
160   SchedulingStats tx_queue_dequeue_stats;
161 
162   size_t tx_queue_total_frames;
163   size_t tx_queue_max_frames_per_packet;
164 
165   uint64_t tx_queue_total_queueing_time_us;
166   uint64_t tx_queue_max_queueing_time_us;
167 
168   size_t tx_queue_total_readbuf_calls;
169   uint64_t tx_queue_last_readbuf_us;
170 
171   size_t tx_queue_total_flushed_messages;
172   uint64_t tx_queue_last_flushed_us;
173 
174   size_t tx_queue_total_dropped_messages;
175   size_t tx_queue_max_dropped_messages;
176   size_t tx_queue_dropouts;
177   uint64_t tx_queue_last_dropouts_us;
178 
179   size_t media_read_total_underflow_bytes;
180   size_t media_read_total_underflow_count;
181   uint64_t media_read_last_underflow_us;
182 
183   int codec_index = -1;
184 };
185 
186 class BtifA2dpSource {
187 public:
188   enum RunState { kStateOff, kStateStartingUp, kStateRunning, kStateShuttingDown };
189 
BtifA2dpSource()190   BtifA2dpSource()
191       : tx_audio_queue(nullptr),
192         tx_flush(false),
193         sw_audio_is_encoding(false),
194         encoder_interface(nullptr),
195         encoder_interval_ms(0),
196         state_(kStateOff) {}
197 
Reset()198   void Reset() {
199     fixed_queue_free(tx_audio_queue, nullptr);
200     tx_audio_queue = nullptr;
201     tx_flush = false;
202     media_alarm.CancelAndWait();
203     wakelock_release();
204     encoder_interface = nullptr;
205     encoder_interval_ms = 0;
206     stats.Reset();
207     accumulated_stats.Reset();
208     state_ = kStateOff;
209   }
210 
State() const211   BtifA2dpSource::RunState State() const { return state_; }
StateStr() const212   std::string StateStr() const {
213     switch (state_) {
214       case kStateOff:
215         return "STATE_OFF";
216       case kStateStartingUp:
217         return "STATE_STARTING_UP";
218       case kStateRunning:
219         return "STATE_RUNNING";
220       case kStateShuttingDown:
221         return "STATE_SHUTTING_DOWN";
222     }
223   }
224 
SetState(BtifA2dpSource::RunState state)225   void SetState(BtifA2dpSource::RunState state) { state_ = state; }
226 
227   fixed_queue_t* tx_audio_queue;
228   bool tx_flush; /* Discards any outgoing data when true */
229   bool sw_audio_is_encoding;
230   RepeatingTimer media_alarm;
231   const tA2DP_ENCODER_INTERFACE* encoder_interface;
232   uint64_t encoder_interval_ms; /* Local copy of the encoder interval */
233   BtifMediaStats stats;
234   BtifMediaStats accumulated_stats;
235 
236 private:
237   BtifA2dpSource::RunState state_;
238 };
239 
240 /// Source worker thread created to run the CPU heavy encoder calls.
241 /// Exactly three functions are executed on this thread:
242 ///   - btif_a2dp_source_audio_handle_timer
243 ///   - btif_a2dp_source_read_callback
244 ///   - btif_a2dp_source_enqueue_callback
245 static bluetooth::common::MessageLoopThread btif_a2dp_source_thread("bt_a2dp_source_worker_thread");
246 
247 static BtifA2dpSource btif_a2dp_source_cb;
248 static uint8_t btif_a2dp_source_dynamic_audio_buffer_size = MAX_OUTPUT_A2DP_FRAME_QUEUE_SZ;
249 
250 static void btif_a2dp_source_init_delayed(void);
251 static bool btif_a2dp_source_startup(void);
252 static void btif_a2dp_source_startup_delayed(void);
253 static void btif_a2dp_source_start_session_delayed(const RawAddress& peer_address,
254                                                    std::promise<void> start_session_promise);
255 static void btif_a2dp_source_audio_tx_start_event(void);
256 static void btif_a2dp_source_audio_tx_stop_event(void);
257 static void btif_a2dp_source_audio_tx_flush_event(void);
258 // Set up the A2DP Source codec, and prepare the encoder.
259 // The peer address is |peer_addr|.
260 // This function should be called prior to starting A2DP streaming.
261 static void btif_a2dp_source_setup_codec(const RawAddress& peer_addr);
262 static void btif_a2dp_source_cleanup_codec_delayed();
263 static void btif_a2dp_source_encoder_user_config_update_event(
264         const RawAddress& peer_address,
265         const std::vector<btav_a2dp_codec_config_t>& codec_user_preferences,
266         std::promise<void> peer_ready_promise);
267 static void btif_a2dp_source_audio_feeding_update_event(
268         const btav_a2dp_codec_config_t& codec_audio_config);
269 static bool btif_a2dp_source_audio_tx_flush_req(void);
270 static void btif_a2dp_source_audio_handle_timer(void);
271 static uint32_t btif_a2dp_source_read_callback(uint8_t* p_buf, uint32_t len);
272 static bool btif_a2dp_source_enqueue_callback(BT_HDR* p_buf, size_t frames_n, uint32_t bytes_read);
273 static void log_tstamps_us(const char* comment, uint64_t timestamp_us);
274 static void update_scheduling_stats(SchedulingStats* stats, uint64_t now_us,
275                                     uint64_t expected_delta);
276 // Update the A2DP Source related metrics.
277 // This function should be called before collecting the metrics.
278 static void btif_a2dp_source_update_metrics(void);
279 static void btm_read_rssi_cb(void* data);
280 static void btm_read_failed_contact_counter_cb(void* data);
281 static void btm_read_tx_power_cb(void* data);
282 
btif_a2dp_source_accumulate_scheduling_stats(SchedulingStats * src,SchedulingStats * dst)283 static void btif_a2dp_source_accumulate_scheduling_stats(SchedulingStats* src,
284                                                          SchedulingStats* dst) {
285   dst->total_updates += src->total_updates;
286   dst->last_update_us = src->last_update_us;
287   dst->overdue_scheduling_count += src->overdue_scheduling_count;
288   dst->total_overdue_scheduling_delta_us += src->total_overdue_scheduling_delta_us;
289   dst->max_overdue_scheduling_delta_us =
290           std::max(dst->max_overdue_scheduling_delta_us, src->max_overdue_scheduling_delta_us);
291   dst->premature_scheduling_count += src->premature_scheduling_count;
292   dst->total_premature_scheduling_delta_us += src->total_premature_scheduling_delta_us;
293   dst->max_premature_scheduling_delta_us =
294           std::max(dst->max_premature_scheduling_delta_us, src->max_premature_scheduling_delta_us);
295   dst->exact_scheduling_count += src->exact_scheduling_count;
296   dst->total_scheduling_time_us += src->total_scheduling_time_us;
297 }
298 
btif_a2dp_source_accumulate_stats(BtifMediaStats * src,BtifMediaStats * dst)299 static void btif_a2dp_source_accumulate_stats(BtifMediaStats* src, BtifMediaStats* dst) {
300   dst->tx_queue_total_frames += src->tx_queue_total_frames;
301   dst->tx_queue_max_frames_per_packet =
302           std::max(dst->tx_queue_max_frames_per_packet, src->tx_queue_max_frames_per_packet);
303   dst->tx_queue_total_queueing_time_us += src->tx_queue_total_queueing_time_us;
304   dst->tx_queue_max_queueing_time_us =
305           std::max(dst->tx_queue_max_queueing_time_us, src->tx_queue_max_queueing_time_us);
306   dst->tx_queue_total_readbuf_calls += src->tx_queue_total_readbuf_calls;
307   dst->tx_queue_last_readbuf_us = src->tx_queue_last_readbuf_us;
308   dst->tx_queue_total_flushed_messages += src->tx_queue_total_flushed_messages;
309   dst->tx_queue_last_flushed_us = src->tx_queue_last_flushed_us;
310   dst->tx_queue_total_dropped_messages += src->tx_queue_total_dropped_messages;
311   dst->tx_queue_max_dropped_messages =
312           std::max(dst->tx_queue_max_dropped_messages, src->tx_queue_max_dropped_messages);
313   dst->tx_queue_dropouts += src->tx_queue_dropouts;
314   dst->tx_queue_last_dropouts_us = src->tx_queue_last_dropouts_us;
315   dst->media_read_total_underflow_bytes += src->media_read_total_underflow_bytes;
316   dst->media_read_total_underflow_count += src->media_read_total_underflow_count;
317   dst->media_read_last_underflow_us = src->media_read_last_underflow_us;
318   if (dst->codec_index < 0) {
319     dst->codec_index = src->codec_index;
320   }
321   btif_a2dp_source_accumulate_scheduling_stats(&src->tx_queue_enqueue_stats,
322                                                &dst->tx_queue_enqueue_stats);
323   btif_a2dp_source_accumulate_scheduling_stats(&src->tx_queue_dequeue_stats,
324                                                &dst->tx_queue_dequeue_stats);
325   src->Reset();
326 }
327 
btif_a2dp_source_init(void)328 bool btif_a2dp_source_init(void) {
329   log::info("");
330 
331   // Start A2DP Source media task
332   btif_a2dp_source_thread.StartUp();
333 
334   do_in_main_thread(base::BindOnce(&btif_a2dp_source_init_delayed));
335   return true;
336 }
337 
338 class A2dpStreamCallbacks : public bluetooth::audio::a2dp::StreamCallbacks {
StartStream(bool low_latency) const339   Status StartStream(bool low_latency) const override {
340     // Check if a phone call is currently active.
341     if (!bluetooth::headset::IsCallIdle()) {
342       log::error("unable to start stream: call is active");
343       return Status::FAILURE;
344     }
345 
346     // Check if LE Audio is currently active.
347     if (hci::IsoManager::GetInstance()->GetNumberOfActiveIso() > 0) {
348       log::error("unable to start stream: LEA is active");
349       return Status::FAILURE;
350     }
351 
352     // Check if the stream has already been started.
353     if (btif_av_stream_started_ready(A2dpType::kSource)) {
354       log::verbose("stream is already started");
355       return Status::SUCCESS;
356     }
357 
358     // Check if the stream is ready to start.
359     if (!btif_av_stream_ready(A2dpType::kSource)) {
360       log::error("unable to start stream: not ready");
361       return Status::FAILURE;
362     }
363 
364     // Check if codec needs to be switched prior to stream start.
365     invoke_switch_codec_cb(low_latency);
366 
367     // Post start event. The start request is pending, completion will be
368     // notified to bluetooth::audio::a2dp::ack_stream_started.
369     btif_av_stream_start_with_latency(low_latency);
370     return Status::PENDING;
371   }
372 
SuspendStream() const373   Status SuspendStream() const override {
374     // Check if the stream is already suspended.
375     if (!btif_av_stream_started_ready(A2dpType::kSource)) {
376       btif_av_clear_remote_suspend_flag(A2dpType::kSource);
377       log::verbose("stream is already suspended");
378       return Status::SUCCESS;
379     }
380 
381     // Post suspend event. The suspend request is pending, completion will
382     // be notified to bluetooth::audio::a2dp::ack_stream_suspended.
383     btif_av_stream_suspend();
384     return Status::PENDING;
385   }
386 
StopStream() const387   Status StopStream() const override {
388     // Check if the stream is already suspended.
389     if (!btif_av_stream_started_ready(A2dpType::kSource)) {
390       btif_av_clear_remote_suspend_flag(A2dpType::kSource);
391       log::verbose("stream is already stopped");
392       return Status::SUCCESS;
393     }
394 
395     // Post stop event. The stop request is pending, but completion is not
396     // notified to the HAL.
397     btif_av_stream_stop(RawAddress::kEmpty);
398     return Status::PENDING;
399   }
400 
SetLatencyMode(bool low_latency) const401   Status SetLatencyMode(bool low_latency) const override {
402     btif_av_set_low_latency(low_latency);
403     return Status::SUCCESS;
404   }
405 };
406 
407 static const A2dpStreamCallbacks a2dp_stream_callbacks;
408 
btif_a2dp_source_init_delayed(void)409 static void btif_a2dp_source_init_delayed(void) {
410   log::info("");
411   // When codec extensibility is enabled in the audio HAL interface,
412   // the provider needs to be initialized earlier in order to ensure
413   // get_a2dp_configuration and parse_a2dp_configuration can be
414   // invoked before the stream is started.
415   bluetooth::audio::a2dp::init(get_main_thread(), &a2dp_stream_callbacks,
416                                btif_av_is_a2dp_offload_enabled());
417 }
418 
btif_a2dp_source_startup(void)419 static bool btif_a2dp_source_startup(void) {
420   log::info("state={}", btif_a2dp_source_cb.StateStr());
421 
422   if (btif_a2dp_source_cb.State() != BtifA2dpSource::kStateOff) {
423     log::error("A2DP Source media task already running");
424     return false;
425   }
426 
427   btif_a2dp_source_cb.Reset();
428   btif_a2dp_source_cb.SetState(BtifA2dpSource::kStateStartingUp);
429   btif_a2dp_source_cb.tx_audio_queue = fixed_queue_new(SIZE_MAX);
430 
431   // Schedule the rest of the operations
432   do_in_main_thread(base::BindOnce(&btif_a2dp_source_startup_delayed));
433 
434   return true;
435 }
436 
btif_a2dp_source_startup_delayed()437 static void btif_a2dp_source_startup_delayed() {
438   log::info("state={}", btif_a2dp_source_cb.StateStr());
439   if (!btif_a2dp_source_thread.EnableRealTimeScheduling()) {
440 #if defined(__ANDROID__)
441     log::fatal("unable to enable real time scheduling");
442 #endif
443   }
444   if (!bluetooth::audio::a2dp::init(get_main_thread(), &a2dp_stream_callbacks,
445                                     btif_av_is_a2dp_offload_enabled())) {
446     log::warn("Failed to setup the bluetooth audio HAL");
447   }
448   btif_a2dp_source_cb.SetState(BtifA2dpSource::kStateRunning);
449 }
450 
btif_a2dp_source_start_session(const RawAddress & peer_address,std::promise<void> peer_ready_promise)451 bool btif_a2dp_source_start_session(const RawAddress& peer_address,
452                                     std::promise<void> peer_ready_promise) {
453   log::info("peer_address={} state={}", peer_address, btif_a2dp_source_cb.StateStr());
454 
455   btif_a2dp_source_audio_tx_flush_req();
456 
457   if (do_in_main_thread(base::BindOnce(&btif_a2dp_source_start_session_delayed, peer_address,
458                                        std::move(peer_ready_promise))) != BT_STATUS_SUCCESS) {
459     log::fatal("peer_address={} state={} fails to context switch", peer_address,
460                btif_a2dp_source_cb.StateStr());
461     return false;
462   }
463 
464   return true;
465 }
466 
btif_a2dp_source_start_session_delayed(const RawAddress & peer_address,std::promise<void> peer_ready_promise)467 static void btif_a2dp_source_start_session_delayed(const RawAddress& peer_address,
468                                                    std::promise<void> peer_ready_promise) {
469   log::info("peer_address={} state={}", peer_address, btif_a2dp_source_cb.StateStr());
470 
471   btif_a2dp_source_setup_codec(peer_address);
472 
473   if (btif_a2dp_source_cb.State() != BtifA2dpSource::kStateRunning) {
474     log::error("A2DP Source media task is not running");
475     peer_ready_promise.set_value();
476     return;
477   }
478 
479   if (bluetooth::audio::a2dp::is_hal_enabled()) {
480     bluetooth::audio::a2dp::start_session();
481     bluetooth::audio::a2dp::set_remote_delay(btif_av_get_audio_delay(A2dpType::kSource));
482   }
483 
484   peer_ready_promise.set_value();
485 }
486 
btif_a2dp_source_restart_session(const RawAddress & old_peer_address,const RawAddress & new_peer_address,std::promise<void> peer_ready_promise)487 bool btif_a2dp_source_restart_session(const RawAddress& old_peer_address,
488                                       const RawAddress& new_peer_address,
489                                       std::promise<void> peer_ready_promise) {
490   log::info("old_peer_address={} new_peer_address={} state={}", old_peer_address, new_peer_address,
491             btif_a2dp_source_cb.StateStr());
492 
493   log::assert_that(!new_peer_address.IsEmpty(), "assert failed: !new_peer_address.IsEmpty()");
494 
495   // Must stop first the audio streaming.
496   btif_a2dp_source_stop_audio_req();
497 
498   // If the old active peer was valid, end the old session.
499   // Otherwise, time to startup the A2DP Source processing.
500   if (!old_peer_address.IsEmpty()) {
501     btif_a2dp_source_end_session(old_peer_address);
502   } else {
503     btif_a2dp_source_startup();
504   }
505 
506   // Start the session.
507   btif_a2dp_source_start_session(new_peer_address, std::move(peer_ready_promise));
508   // If audio was streaming before, DON'T start audio streaming, but leave the
509   // control to the audio HAL.
510   return true;
511 }
512 
btif_a2dp_source_end_session(const RawAddress & peer_address)513 bool btif_a2dp_source_end_session(const RawAddress& peer_address) {
514   log::info("peer_address={} state={}", peer_address, btif_a2dp_source_cb.StateStr());
515 
516   // Must stop first the audio streaming.
517   btif_a2dp_source_stop_audio_req();
518 
519   do_in_main_thread(base::BindOnce(&btif_a2dp_source_cleanup_codec_delayed));
520 
521   if ((btif_a2dp_source_cb.State() == BtifA2dpSource::kStateRunning) ||
522       (btif_a2dp_source_cb.State() == BtifA2dpSource::kStateShuttingDown)) {
523     btif_av_stream_stop(peer_address);
524   } else {
525     log::error("A2DP Source media task is not running");
526   }
527 
528   if (bluetooth::audio::a2dp::is_hal_enabled()) {
529     bluetooth::audio::a2dp::end_session();
530   }
531 
532   return true;
533 }
534 
btif_a2dp_source_allow_low_latency_audio(bool allowed)535 void btif_a2dp_source_allow_low_latency_audio(bool allowed) {
536   log::info("allowed={}", allowed);
537 
538   do_in_main_thread(
539           base::BindOnce(bluetooth::audio::a2dp::set_audio_low_latency_mode_allowed, allowed));
540 }
541 
btif_a2dp_source_shutdown(std::promise<void> shutdown_complete_promise)542 void btif_a2dp_source_shutdown(std::promise<void> shutdown_complete_promise) {
543   log::info("state={}", btif_a2dp_source_cb.StateStr());
544 
545   if ((btif_a2dp_source_cb.State() == BtifA2dpSource::kStateOff) ||
546       (btif_a2dp_source_cb.State() == BtifA2dpSource::kStateShuttingDown)) {
547     return;
548   }
549 
550   // Make sure no channels are restarted while shutting down.
551   btif_a2dp_source_cb.SetState(BtifA2dpSource::kStateShuttingDown);
552 
553   // Stop the timer.
554   btif_a2dp_source_cb.media_alarm.CancelAndWait();
555   wakelock_release();
556 
557   bluetooth::audio::a2dp::cleanup();
558 
559   fixed_queue_free(btif_a2dp_source_cb.tx_audio_queue, nullptr);
560   btif_a2dp_source_cb.tx_audio_queue = nullptr;
561 
562   btif_a2dp_source_cb.SetState(BtifA2dpSource::kStateOff);
563 
564   shutdown_complete_promise.set_value();
565 }
566 
btif_a2dp_source_cleanup(void)567 void btif_a2dp_source_cleanup(void) {
568   log::info("state={}", btif_a2dp_source_cb.StateStr());
569 
570   // Make sure the source is shutdown
571   std::promise<void> shutdown_complete_promise;
572   btif_a2dp_source_shutdown(std::move(shutdown_complete_promise));
573 
574   // Exit the thread
575   btif_a2dp_source_thread.ShutDown();
576 }
577 
578 // This runs on worker thread
btif_a2dp_source_is_streaming(void)579 bool btif_a2dp_source_is_streaming(void) { return btif_a2dp_source_cb.media_alarm.IsScheduled(); }
580 
581 /// Return the MTU for the active peer audio connection.
btif_a2dp_get_peer_mtu(A2dpCodecConfig * a2dp_config)582 static uint16_t btif_a2dp_get_peer_mtu(A2dpCodecConfig* a2dp_config) {
583   uint8_t codec_info[AVDT_CODEC_SIZE];
584   a2dp_config->copyOutOtaCodecConfig(codec_info);
585 
586   RawAddress peer_addr = btif_av_source_active_peer();
587   tA2DP_ENCODER_INIT_PEER_PARAMS peer_params;
588   bta_av_co_get_peer_params(peer_addr, &peer_params);
589   uint16_t peer_mtu = peer_params.peer_mtu;
590   uint16_t effective_mtu = bta_av_co_get_encoder_effective_frame_size(peer_addr);
591 
592   if (effective_mtu > 0 && effective_mtu < peer_mtu) {
593     peer_mtu = effective_mtu;
594   }
595 
596   // b/188020925
597   // When SBC headsets report middle quality bitpool under a larger MTU, we
598   // reduce the packet size to prevent the hardware encoder from putting too
599   // many frames in one packet.
600   if (a2dp_config->codecIndex() == BTAV_A2DP_CODEC_INDEX_SOURCE_SBC &&
601       codec_info[2] /* maxBitpool */ <= A2DP_SBC_BITPOOL_MIDDLE_QUALITY) {
602     peer_mtu = MAX_2MBPS_AVDTP_MTU;
603   }
604 
605   // b/177205770
606   // Fix the MTU value not to be greater than an AVDTP packet, so the data
607   // encoded by A2DP hardware encoder can be fitted into one AVDTP packet
608   // without fragmented
609   if (peer_mtu > MAX_3MBPS_AVDTP_MTU) {
610     peer_mtu = MAX_3MBPS_AVDTP_MTU;
611   }
612 
613   return peer_mtu;
614 }
615 
btif_a2dp_source_setup_codec(const RawAddress & peer_address)616 static void btif_a2dp_source_setup_codec(const RawAddress& peer_address) {
617   log::info("peer_address={} state={}", peer_address, btif_a2dp_source_cb.StateStr());
618 
619   tA2DP_ENCODER_INIT_PEER_PARAMS peer_params;
620   bta_av_co_get_peer_params(peer_address, &peer_params);
621   if (!bta_av_co_set_active_source_peer(peer_address)) {
622     log::error("Cannot stream audio: cannot set active peer to {}", peer_address);
623     return;
624   }
625 
626   const tA2DP_ENCODER_INTERFACE* encoder_interface = bta_av_co_get_encoder_interface(peer_address);
627   if (encoder_interface == nullptr) {
628     log::error("Cannot stream audio: no source encoder interface");
629     return;
630   }
631 
632   A2dpCodecConfig* a2dp_codec_config = bta_av_get_a2dp_current_codec();
633   if (a2dp_codec_config == nullptr) {
634     log::error("Cannot stream audio: current codec is not set");
635     return;
636   }
637 
638   encoder_interface->encoder_init(&peer_params, a2dp_codec_config, btif_a2dp_source_read_callback,
639                                   btif_a2dp_source_enqueue_callback);
640 
641   // Save a local copy of the encoder_interval_ms
642   btif_a2dp_source_cb.encoder_interface = encoder_interface;
643   btif_a2dp_source_cb.encoder_interval_ms =
644           btif_a2dp_source_cb.encoder_interface->get_encoder_interval_ms();
645 
646   if (bluetooth::audio::a2dp::is_hal_enabled()) {
647     bluetooth::audio::a2dp::setup_codec(a2dp_codec_config,
648                                         btif_a2dp_get_peer_mtu(a2dp_codec_config),
649                                         bta_av_co_get_encoder_preferred_interval_us());
650   }
651 }
652 
btif_a2dp_source_cleanup_codec_delayed()653 static void btif_a2dp_source_cleanup_codec_delayed() {
654   log::info("state={}", btif_a2dp_source_cb.StateStr());
655   if (btif_a2dp_source_cb.encoder_interface != nullptr) {
656     btif_a2dp_source_cb.encoder_interface->encoder_cleanup();
657     btif_a2dp_source_cb.encoder_interface = nullptr;
658   }
659 }
660 
btif_a2dp_source_start_audio_req(void)661 void btif_a2dp_source_start_audio_req(void) {
662   log::info("state={}", btif_a2dp_source_cb.StateStr());
663 
664   do_in_main_thread(base::BindOnce(&btif_a2dp_source_audio_tx_start_event));
665 }
666 
btif_a2dp_source_stop_audio_req(void)667 void btif_a2dp_source_stop_audio_req(void) {
668   log::info("state={}", btif_a2dp_source_cb.StateStr());
669 
670   do_in_main_thread(base::BindOnce(&btif_a2dp_source_audio_tx_stop_event));
671 }
672 
btif_a2dp_source_encoder_user_config_update_req(const RawAddress & peer_address,const std::vector<btav_a2dp_codec_config_t> & codec_user_preferences,std::promise<void> peer_ready_promise)673 void btif_a2dp_source_encoder_user_config_update_req(
674         const RawAddress& peer_address,
675         const std::vector<btav_a2dp_codec_config_t>& codec_user_preferences,
676         std::promise<void> peer_ready_promise) {
677   log::info("peer_address={} state={} {} codec_preference(s)", peer_address,
678             btif_a2dp_source_cb.StateStr(), codec_user_preferences.size());
679 
680   if (do_in_main_thread(base::BindOnce(&btif_a2dp_source_encoder_user_config_update_event,
681                                        peer_address, codec_user_preferences,
682                                        std::move(peer_ready_promise))) != BT_STATUS_SUCCESS) {
683     // cannot set promise but triggers crash
684     log::fatal("peer_address={} state={} fails to context switch", peer_address,
685                btif_a2dp_source_cb.StateStr());
686   }
687 }
688 
btif_a2dp_source_encoder_user_config_update_event(const RawAddress & peer_address,const std::vector<btav_a2dp_codec_config_t> & codec_user_preferences,std::promise<void> peer_ready_promise)689 static void btif_a2dp_source_encoder_user_config_update_event(
690         const RawAddress& peer_address,
691         const std::vector<btav_a2dp_codec_config_t>& codec_user_preferences,
692         std::promise<void> peer_ready_promise) {
693   bool restart_output = false;
694   bool success = false;
695   for (auto codec_user_config : codec_user_preferences) {
696     success = bta_av_co_set_codec_user_config(peer_address, codec_user_config, &restart_output);
697     if (success) {
698       log::info("peer_address={} state={} codec_preference=[{}] restart_output={}", peer_address,
699                 btif_a2dp_source_cb.StateStr(), codec_user_config.ToString(), restart_output);
700       break;
701     }
702   }
703   if (success && restart_output) {
704     // Codec reconfiguration is in progress, and it is safe to unlock since
705     // remaining tasks like starting audio session and reporting new codec
706     // will be handled by BTA_AV_RECONFIG_EVT later.
707     peer_ready_promise.set_value();
708     return;
709   }
710   if (!success) {
711     log::error("cannot update codec user configuration(s)");
712   }
713   if (!peer_address.IsEmpty() && peer_address == btif_av_source_active_peer()) {
714     // No more actions needed with remote, and if succeed, user had changed the
715     // config like the bits per sample only. Let's resume the session now.
716     btif_a2dp_source_start_session(peer_address, std::move(peer_ready_promise));
717   } else {
718     // Unlock for non-active peer
719     peer_ready_promise.set_value();
720   }
721 }
722 
btif_a2dp_source_feeding_update_req(const btav_a2dp_codec_config_t & codec_audio_config)723 void btif_a2dp_source_feeding_update_req(const btav_a2dp_codec_config_t& codec_audio_config) {
724   log::info("state={}", btif_a2dp_source_cb.StateStr());
725   do_in_main_thread(
726           base::BindOnce(&btif_a2dp_source_audio_feeding_update_event, codec_audio_config));
727 }
728 
btif_a2dp_source_audio_feeding_update_event(const btav_a2dp_codec_config_t & codec_audio_config)729 static void btif_a2dp_source_audio_feeding_update_event(
730         const btav_a2dp_codec_config_t& codec_audio_config) {
731   log::info("state={}", btif_a2dp_source_cb.StateStr());
732   if (!bta_av_co_set_codec_audio_config(codec_audio_config)) {
733     log::error("cannot update codec audio feeding parameters");
734   }
735 }
736 
btif_a2dp_source_on_idle(void)737 void btif_a2dp_source_on_idle(void) {
738   log::info("state={}", btif_a2dp_source_cb.StateStr());
739   if (btif_a2dp_source_cb.State() == BtifA2dpSource::kStateOff) {
740     return;
741   }
742 
743   /* Make sure media task is stopped */
744   btif_a2dp_source_stop_audio_req();
745 }
746 
btif_a2dp_source_on_stopped(tBTA_AV_SUSPEND * p_av_suspend)747 void btif_a2dp_source_on_stopped(tBTA_AV_SUSPEND* p_av_suspend) {
748   log::info("state={}", btif_a2dp_source_cb.StateStr());
749 
750   btif_a2dp_source_cb.sw_audio_is_encoding = false;
751 
752   // allow using this API for other (acknowledgement and stopping media task)
753   // than suspend
754   if (p_av_suspend != nullptr && p_av_suspend->status != BTA_AV_SUCCESS) {
755     log::error("A2DP stop failed: status={}, initiator={}", p_av_suspend->status,
756                p_av_suspend->initiator);
757     if (p_av_suspend->initiator) {
758       bluetooth::audio::a2dp::ack_stream_suspended(Status::FAILURE);
759     }
760   } else {
761     bluetooth::audio::a2dp::ack_stream_suspended(Status::SUCCESS);
762   }
763 
764   if (btif_a2dp_source_cb.State() == BtifA2dpSource::kStateOff) {
765     return;
766   }
767 
768   // ensure tx frames are immediately suspended
769   btif_a2dp_source_cb.tx_flush = true;
770   // ensure tx frames are immediately flushed
771   btif_a2dp_source_audio_tx_flush_req();
772 
773   // request to stop media task
774   btif_a2dp_source_stop_audio_req();
775 
776   // once software stream is fully stopped we will ack back
777 }
778 
btif_a2dp_source_on_suspended(tBTA_AV_SUSPEND * p_av_suspend)779 void btif_a2dp_source_on_suspended(tBTA_AV_SUSPEND* p_av_suspend) {
780   log::info("state={}", btif_a2dp_source_cb.StateStr());
781 
782   if (btif_a2dp_source_cb.State() == BtifA2dpSource::kStateOff) {
783     return;
784   }
785 
786   log::assert_that(p_av_suspend != nullptr, "Suspend result could not be nullptr");
787 
788   // check for status failures
789   if (p_av_suspend->status != BTA_AV_SUCCESS) {
790     log::warn("A2DP suspend failed: status={}, initiator={}", p_av_suspend->status,
791               p_av_suspend->initiator);
792     if (p_av_suspend->initiator) {
793       bluetooth::audio::a2dp::ack_stream_suspended(Status::FAILURE);
794     }
795   } else if (btif_av_is_a2dp_offload_running()) {
796     bluetooth::audio::a2dp::ack_stream_suspended(Status::SUCCESS);
797   }
798 
799   // ensure tx frames are immediately suspended
800   btif_a2dp_source_cb.tx_flush = true;
801 
802   // stop timer tick
803   btif_a2dp_source_stop_audio_req();
804 
805   // once software stream is fully stopped we will ack back
806 }
807 
808 /* when true media task discards any tx frames */
btif_a2dp_source_set_tx_flush(bool enable)809 void btif_a2dp_source_set_tx_flush(bool enable) {
810   log::info("enable={} state={}", enable, btif_a2dp_source_cb.StateStr());
811   btif_a2dp_source_cb.tx_flush = enable;
812 }
813 
btif_a2dp_source_audio_tx_start_event(void)814 static void btif_a2dp_source_audio_tx_start_event(void) {
815   log::info("streaming {} state={}", btif_a2dp_source_is_streaming(),
816             btif_a2dp_source_cb.StateStr());
817 
818   btif_a2dp_source_cb.stats.Reset();
819   btif_a2dp_source_cb.stats.session_start_us = bluetooth::common::time_get_os_boottime_us();
820   btif_a2dp_source_cb.stats.session_end_us = 0;
821 
822   A2dpCodecConfig* codec_config = bta_av_get_a2dp_current_codec();
823   if (codec_config != nullptr) {
824     btif_a2dp_source_cb.stats.codec_index = codec_config->codecIndex();
825   }
826 
827   if (btif_av_is_a2dp_offload_running()) {
828     return;
829   }
830 
831   log::assert_that(btif_a2dp_source_cb.encoder_interface != nullptr,
832                    "assert failed: btif_a2dp_source_cb.encoder_interface != nullptr");
833 
834   log::verbose("starting media encoder timer with interval {}ms",
835                btif_a2dp_source_cb.encoder_interface->get_encoder_interval_ms());
836 
837   wakelock_acquire();
838   btif_a2dp_source_cb.encoder_interface->feeding_reset();
839   btif_a2dp_source_cb.tx_flush = false;
840   btif_a2dp_source_cb.sw_audio_is_encoding = true;
841   btif_a2dp_source_cb.media_alarm.SchedulePeriodic(
842           btif_a2dp_source_thread.GetWeakPtr(),
843           base::BindRepeating(&btif_a2dp_source_audio_handle_timer),
844           std::chrono::milliseconds(
845                   btif_a2dp_source_cb.encoder_interface->get_encoder_interval_ms()));
846 }
847 
btif_a2dp_source_audio_tx_stop_event(void)848 static void btif_a2dp_source_audio_tx_stop_event(void) {
849   log::info("streaming {} state={}", btif_a2dp_source_is_streaming(),
850             btif_a2dp_source_cb.StateStr());
851 
852   btif_a2dp_source_cb.stats.session_end_us = bluetooth::common::time_get_os_boottime_us();
853 
854   btif_a2dp_source_update_metrics();
855   btif_a2dp_source_accumulate_stats(&btif_a2dp_source_cb.stats,
856                                     &btif_a2dp_source_cb.accumulated_stats);
857 
858   if (btif_av_is_a2dp_offload_running()) {
859     return;
860   }
861 
862   if (!btif_a2dp_source_is_streaming()) {
863     return;
864   }
865 
866   /* Drain data still left in the queue */
867   static constexpr size_t AUDIO_STREAM_OUTPUT_BUFFER_SZ = 28 * 512;
868   uint8_t p_buf[AUDIO_STREAM_OUTPUT_BUFFER_SZ * 2];
869   bluetooth::audio::a2dp::read(p_buf, sizeof(p_buf));
870 
871   /* Stop the timer first */
872   btif_a2dp_source_cb.media_alarm.CancelAndWait();
873   wakelock_release();
874 
875   bluetooth::audio::a2dp::ack_stream_suspended(Status::SUCCESS);
876 
877   /* audio engine stopped, reset tx suspended flag */
878   btif_a2dp_source_cb.tx_flush = false;
879 
880   /* Reset the media feeding state */
881   if (btif_a2dp_source_cb.encoder_interface != nullptr) {
882     btif_a2dp_source_cb.encoder_interface->feeding_reset();
883   }
884 }
885 
886 /// Periodic task responsible for encoding the audio stream and forwarding
887 /// to the remote device. It will read PCM samples from the HAL provided FMQ,
888 /// encode them into audio frames. Runs on the source worker thread.
889 ///
890 /// The timer driving the periodic task is cancelled before any state cleanup
891 /// when the stream is ended.
btif_a2dp_source_audio_handle_timer(void)892 static void btif_a2dp_source_audio_handle_timer(void) {
893   uint64_t timestamp_us = bluetooth::common::time_get_audio_server_tick_us();
894   uint64_t stats_timestamp_us = bluetooth::common::time_get_os_boottime_us();
895 
896   log_tstamps_us("A2DP Source tx scheduling timer", timestamp_us);
897 
898   log::assert_that(btif_a2dp_source_cb.encoder_interface != nullptr,
899                    "assert failed: btif_a2dp_source_cb.encoder_interface != nullptr");
900 
901   size_t transmit_queue_length = fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue);
902 
903 #ifdef __ANDROID__
904   ATRACE_INT("btif TX queue", transmit_queue_length);
905 #endif
906 
907   if (btif_a2dp_source_cb.encoder_interface->set_transmit_queue_length != nullptr) {
908     btif_a2dp_source_cb.encoder_interface->set_transmit_queue_length(transmit_queue_length);
909   }
910 
911   btif_a2dp_source_cb.encoder_interface->send_frames(timestamp_us);
912 
913   bta_av_ci_src_data_ready(BTA_AV_CHNL_AUDIO);
914   update_scheduling_stats(&btif_a2dp_source_cb.stats.tx_queue_enqueue_stats, stats_timestamp_us,
915                           btif_a2dp_source_cb.encoder_interval_ms * 1000);
916 }
917 
918 /// Callback invoked by the encoder for reading PCM audio data from the
919 /// Bluetooth Audio HAL. Runs on the source worker thread.
btif_a2dp_source_read_callback(uint8_t * p_buf,uint32_t len)920 static uint32_t btif_a2dp_source_read_callback(uint8_t* p_buf, uint32_t len) {
921   if (!btif_a2dp_source_cb.sw_audio_is_encoding) {
922     return 0;
923   }
924 
925   uint32_t bytes_read = bluetooth::audio::a2dp::read(p_buf, len);
926 
927   if (bytes_read < len) {
928     log::warn("UNDERFLOW: ONLY READ {} BYTES OUT OF {}", bytes_read, len);
929     btif_a2dp_source_cb.stats.media_read_total_underflow_bytes += (len - bytes_read);
930     btif_a2dp_source_cb.stats.media_read_total_underflow_count++;
931     btif_a2dp_source_cb.stats.media_read_last_underflow_us =
932             bluetooth::common::time_get_os_boottime_us();
933     bluetooth::shim::LogMetricA2dpAudioUnderrunEvent(btif_av_source_active_peer(),
934                                                      btif_a2dp_source_cb.encoder_interval_ms,
935                                                      len - bytes_read);
936   }
937 
938   return bytes_read;
939 }
940 
941 /// Callback invoked by the encoder for sending encoded audio frames to the
942 /// remote Bluetooth device. Runs on the source worker thread.
btif_a2dp_source_enqueue_callback(BT_HDR * p_buf,size_t frames_n,uint32_t)943 static bool btif_a2dp_source_enqueue_callback(BT_HDR* p_buf, size_t frames_n,
944                                               uint32_t /*bytes_read*/) {
945   uint64_t now_us = bluetooth::common::time_get_os_boottime_us();
946 
947   // Check if the transmission queue has been flushed.
948   if (btif_a2dp_source_cb.tx_flush) {
949     log::verbose("tx suspended, discarded frame");
950 
951     btif_a2dp_source_cb.stats.tx_queue_total_flushed_messages +=
952             fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue);
953     btif_a2dp_source_cb.stats.tx_queue_last_flushed_us = now_us;
954     fixed_queue_flush(btif_a2dp_source_cb.tx_audio_queue, osi_free);
955 
956     osi_free(p_buf);
957     return false;
958   }
959 
960   // Check for TX queue overflow
961   // TODO: Using frames_n here is probably wrong: should be "+ 1" instead.
962   if (fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue) + frames_n >
963       btif_a2dp_source_dynamic_audio_buffer_size) {
964     log::warn("TX queue buffer size now={} adding={} max={}",
965               (uint32_t)fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue), (uint32_t)frames_n,
966               btif_a2dp_source_dynamic_audio_buffer_size);
967     // Keep track of drop-outs
968     btif_a2dp_source_cb.stats.tx_queue_dropouts++;
969     btif_a2dp_source_cb.stats.tx_queue_last_dropouts_us = now_us;
970 
971     // Flush all queued buffers
972     size_t drop_n = fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue);
973     btif_a2dp_source_cb.stats.tx_queue_max_dropped_messages =
974             std::max(drop_n, btif_a2dp_source_cb.stats.tx_queue_max_dropped_messages);
975     int num_dropped_encoded_bytes = 0;
976     int num_dropped_encoded_frames = 0;
977     while (fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue)) {
978       btif_a2dp_source_cb.stats.tx_queue_total_dropped_messages++;
979       void* p_data = fixed_queue_try_dequeue(btif_a2dp_source_cb.tx_audio_queue);
980       if (p_data != nullptr) {
981         auto p_dropped_buf = static_cast<BT_HDR*>(p_data);
982         num_dropped_encoded_bytes += p_dropped_buf->len;
983         num_dropped_encoded_frames += p_dropped_buf->layer_specific;
984         osi_free(p_data);
985       }
986     }
987     bluetooth::shim::LogMetricA2dpAudioOverrunEvent(
988             btif_av_source_active_peer(), btif_a2dp_source_cb.encoder_interval_ms, drop_n,
989             num_dropped_encoded_frames, num_dropped_encoded_bytes);
990 
991     // Request additional debug info if we had to flush buffers
992     RawAddress peer_bda = btif_av_source_active_peer();
993     tBTM_STATUS status =
994             get_btm_client_interface().link_controller.BTM_ReadRSSI(peer_bda, btm_read_rssi_cb);
995     if (status != tBTM_STATUS::BTM_CMD_STARTED) {
996       log::warn("Cannot read RSSI: status {}", status);
997     }
998 
999     status = BTM_ReadFailedContactCounter(peer_bda, btm_read_failed_contact_counter_cb);
1000     if (status != tBTM_STATUS::BTM_CMD_STARTED) {
1001       log::warn("Cannot read Failed Contact Counter: status {}", status);
1002     }
1003 
1004     status = BTM_ReadTxPower(peer_bda, BT_TRANSPORT_BR_EDR, btm_read_tx_power_cb);
1005     if (status != tBTM_STATUS::BTM_CMD_STARTED) {
1006       log::warn("Cannot read Tx Power: status {}", status);
1007     }
1008   }
1009 
1010   // Update the statistics.
1011   btif_a2dp_source_cb.stats.tx_queue_total_frames += frames_n;
1012   btif_a2dp_source_cb.stats.tx_queue_max_frames_per_packet =
1013           std::max(frames_n, btif_a2dp_source_cb.stats.tx_queue_max_frames_per_packet);
1014 
1015   fixed_queue_enqueue(btif_a2dp_source_cb.tx_audio_queue, p_buf);
1016 
1017   return true;
1018 }
1019 
btif_a2dp_source_audio_tx_flush_event(void)1020 static void btif_a2dp_source_audio_tx_flush_event(void) {
1021   /* Flush all enqueued audio buffers (encoded) */
1022   log::info("state={}", btif_a2dp_source_cb.StateStr());
1023   if (btif_av_is_a2dp_offload_running()) {
1024     return;
1025   }
1026 
1027   if (btif_a2dp_source_cb.encoder_interface != nullptr) {
1028     btif_a2dp_source_cb.encoder_interface->feeding_flush();
1029   }
1030 
1031   btif_a2dp_source_cb.stats.tx_queue_total_flushed_messages +=
1032           fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue);
1033   btif_a2dp_source_cb.stats.tx_queue_last_flushed_us = bluetooth::common::time_get_os_boottime_us();
1034   fixed_queue_flush(btif_a2dp_source_cb.tx_audio_queue, osi_free);
1035 }
1036 
btif_a2dp_source_audio_tx_flush_req(void)1037 static bool btif_a2dp_source_audio_tx_flush_req(void) {
1038   log::info("state={}", btif_a2dp_source_cb.StateStr());
1039 
1040   do_in_main_thread(base::BindOnce(&btif_a2dp_source_audio_tx_flush_event));
1041   return true;
1042 }
1043 
btif_a2dp_source_audio_readbuf(void)1044 BT_HDR* btif_a2dp_source_audio_readbuf(void) {
1045   uint64_t now_us = bluetooth::common::time_get_os_boottime_us();
1046   BT_HDR* p_buf = (BT_HDR*)fixed_queue_try_dequeue(btif_a2dp_source_cb.tx_audio_queue);
1047 
1048   btif_a2dp_source_cb.stats.tx_queue_total_readbuf_calls++;
1049   btif_a2dp_source_cb.stats.tx_queue_last_readbuf_us = now_us;
1050   if (p_buf != nullptr) {
1051     // Update the statistics
1052     update_scheduling_stats(&btif_a2dp_source_cb.stats.tx_queue_dequeue_stats, now_us,
1053                             btif_a2dp_source_cb.encoder_interval_ms * 1000);
1054   }
1055 
1056   return p_buf;
1057 }
1058 
log_tstamps_us(const char * comment,uint64_t timestamp_us)1059 static void log_tstamps_us(const char* comment, uint64_t timestamp_us) {
1060   static uint64_t prev_us = 0;
1061   log::verbose("[{}] ts {:08}, diff : {:08}, queue sz {}", comment, timestamp_us,
1062                timestamp_us - prev_us, fixed_queue_length(btif_a2dp_source_cb.tx_audio_queue));
1063   prev_us = timestamp_us;
1064 }
1065 
update_scheduling_stats(SchedulingStats * stats,uint64_t now_us,uint64_t expected_delta)1066 static void update_scheduling_stats(SchedulingStats* stats, uint64_t now_us,
1067                                     uint64_t expected_delta) {
1068   uint64_t last_us = stats->last_update_us;
1069 
1070   stats->total_updates++;
1071   stats->last_update_us = now_us;
1072 
1073   if (last_us == 0) {
1074     return;  // First update: expected delta doesn't apply
1075   }
1076 
1077   uint64_t deadline_us = last_us + expected_delta;
1078   if (deadline_us < now_us) {
1079     // Overdue scheduling
1080     uint64_t delta_us = now_us - deadline_us;
1081     // Ignore extreme outliers
1082     if (delta_us < 10 * expected_delta) {
1083       stats->max_overdue_scheduling_delta_us =
1084               std::max(delta_us, stats->max_overdue_scheduling_delta_us);
1085       stats->total_overdue_scheduling_delta_us += delta_us;
1086       stats->overdue_scheduling_count++;
1087       stats->total_scheduling_time_us += now_us - last_us;
1088     }
1089   } else if (deadline_us > now_us) {
1090     // Premature scheduling
1091     uint64_t delta_us = deadline_us - now_us;
1092     // Ignore extreme outliers
1093     if (delta_us < 10 * expected_delta) {
1094       stats->max_premature_scheduling_delta_us =
1095               std::max(delta_us, stats->max_premature_scheduling_delta_us);
1096       stats->total_premature_scheduling_delta_us += delta_us;
1097       stats->premature_scheduling_count++;
1098       stats->total_scheduling_time_us += now_us - last_us;
1099     }
1100   } else {
1101     // On-time scheduling
1102     stats->exact_scheduling_count++;
1103     stats->total_scheduling_time_us += now_us - last_us;
1104   }
1105 }
1106 
btif_a2dp_source_debug_dump(int fd)1107 void btif_a2dp_source_debug_dump(int fd) {
1108   btif_a2dp_source_accumulate_stats(&btif_a2dp_source_cb.stats,
1109                                     &btif_a2dp_source_cb.accumulated_stats);
1110   uint64_t now_us = bluetooth::common::time_get_os_boottime_us();
1111   BtifMediaStats* accumulated_stats = &btif_a2dp_source_cb.accumulated_stats;
1112   SchedulingStats* enqueue_stats = &accumulated_stats->tx_queue_enqueue_stats;
1113   SchedulingStats* dequeue_stats = &accumulated_stats->tx_queue_dequeue_stats;
1114   size_t ave_size;
1115   uint64_t ave_time_us;
1116 
1117   dprintf(fd, "\nA2DP State:\n");
1118   dprintf(fd, "  TxQueue:\n");
1119 
1120   dprintf(fd, "  Counts (enqueue/dequeue/readbuf)                        : %zu / %zu / %zu\n",
1121           enqueue_stats->total_updates, dequeue_stats->total_updates,
1122           accumulated_stats->tx_queue_total_readbuf_calls);
1123 
1124   dprintf(fd, "  Last update time ago in ms (enqueue/dequeue/readbuf)    : %llu / %llu / %llu\n",
1125           (enqueue_stats->last_update_us > 0)
1126                   ? (unsigned long long)(now_us - enqueue_stats->last_update_us) / 1000
1127                   : 0,
1128           (dequeue_stats->last_update_us > 0)
1129                   ? (unsigned long long)(now_us - dequeue_stats->last_update_us) / 1000
1130                   : 0,
1131           (accumulated_stats->tx_queue_last_readbuf_us > 0)
1132                   ? (unsigned long long)(now_us - accumulated_stats->tx_queue_last_readbuf_us) /
1133                             1000
1134                   : 0);
1135 
1136   ave_size = 0;
1137   if (enqueue_stats->total_updates != 0) {
1138     ave_size = accumulated_stats->tx_queue_total_frames / enqueue_stats->total_updates;
1139   }
1140   dprintf(fd, "  Frames per packet (total/max/ave)                       : %zu / %zu / %zu\n",
1141           accumulated_stats->tx_queue_total_frames,
1142           accumulated_stats->tx_queue_max_frames_per_packet, ave_size);
1143 
1144   dprintf(fd, "  Counts (flushed/dropped/dropouts)                       : %zu / %zu / %zu\n",
1145           accumulated_stats->tx_queue_total_flushed_messages,
1146           accumulated_stats->tx_queue_total_dropped_messages, accumulated_stats->tx_queue_dropouts);
1147 
1148   dprintf(fd, "  Counts (max dropped)                                    : %zu\n",
1149           accumulated_stats->tx_queue_max_dropped_messages);
1150 
1151   dprintf(fd, "  Last update time ago in ms (flushed/dropped)            : %llu / %llu\n",
1152           (accumulated_stats->tx_queue_last_flushed_us > 0)
1153                   ? (unsigned long long)(now_us - accumulated_stats->tx_queue_last_flushed_us) /
1154                             1000
1155                   : 0,
1156           (accumulated_stats->tx_queue_last_dropouts_us > 0)
1157                   ? (unsigned long long)(now_us - accumulated_stats->tx_queue_last_dropouts_us) /
1158                             1000
1159                   : 0);
1160 
1161   dprintf(fd, "  Counts (underflow)                                      : %zu\n",
1162           accumulated_stats->media_read_total_underflow_count);
1163 
1164   dprintf(fd, "  Bytes (underflow)                                       : %zu\n",
1165           accumulated_stats->media_read_total_underflow_bytes);
1166 
1167   dprintf(fd, "  Last update time ago in ms (underflow)                  : %llu\n",
1168           (accumulated_stats->media_read_last_underflow_us > 0)
1169                   ? (unsigned long long)(now_us - accumulated_stats->media_read_last_underflow_us) /
1170                             1000
1171                   : 0);
1172 
1173   //
1174   // TxQueue enqueue stats
1175   //
1176   dprintf(fd, "  Enqueue deviation counts (overdue/premature)            : %zu / %zu\n",
1177           enqueue_stats->overdue_scheduling_count, enqueue_stats->premature_scheduling_count);
1178 
1179   ave_time_us = 0;
1180   if (enqueue_stats->overdue_scheduling_count != 0) {
1181     ave_time_us = enqueue_stats->total_overdue_scheduling_delta_us /
1182                   enqueue_stats->overdue_scheduling_count;
1183   }
1184   dprintf(fd, "  Enqueue overdue scheduling time in ms (total/max/ave)   : %llu / %llu / %llu\n",
1185           (unsigned long long)enqueue_stats->total_overdue_scheduling_delta_us / 1000,
1186           (unsigned long long)enqueue_stats->max_overdue_scheduling_delta_us / 1000,
1187           (unsigned long long)ave_time_us / 1000);
1188 
1189   ave_time_us = 0;
1190   if (enqueue_stats->premature_scheduling_count != 0) {
1191     ave_time_us = enqueue_stats->total_premature_scheduling_delta_us /
1192                   enqueue_stats->premature_scheduling_count;
1193   }
1194   dprintf(fd, "  Enqueue premature scheduling time in ms (total/max/ave) : %llu / %llu / %llu\n",
1195           (unsigned long long)enqueue_stats->total_premature_scheduling_delta_us / 1000,
1196           (unsigned long long)enqueue_stats->max_premature_scheduling_delta_us / 1000,
1197           (unsigned long long)ave_time_us / 1000);
1198 
1199   //
1200   // TxQueue dequeue stats
1201   //
1202   dprintf(fd, "  Dequeue deviation counts (overdue/premature)            : %zu / %zu\n",
1203           dequeue_stats->overdue_scheduling_count, dequeue_stats->premature_scheduling_count);
1204 
1205   ave_time_us = 0;
1206   if (dequeue_stats->overdue_scheduling_count != 0) {
1207     ave_time_us = dequeue_stats->total_overdue_scheduling_delta_us /
1208                   dequeue_stats->overdue_scheduling_count;
1209   }
1210   dprintf(fd, "  Dequeue overdue scheduling time in ms (total/max/ave)   : %llu / %llu / %llu\n",
1211           (unsigned long long)dequeue_stats->total_overdue_scheduling_delta_us / 1000,
1212           (unsigned long long)dequeue_stats->max_overdue_scheduling_delta_us / 1000,
1213           (unsigned long long)ave_time_us / 1000);
1214 
1215   ave_time_us = 0;
1216   if (dequeue_stats->premature_scheduling_count != 0) {
1217     ave_time_us = dequeue_stats->total_premature_scheduling_delta_us /
1218                   dequeue_stats->premature_scheduling_count;
1219   }
1220   dprintf(fd, "  Dequeue premature scheduling time in ms (total/max/ave) : %llu / %llu / %llu\n",
1221           (unsigned long long)dequeue_stats->total_premature_scheduling_delta_us / 1000,
1222           (unsigned long long)dequeue_stats->max_premature_scheduling_delta_us / 1000,
1223           (unsigned long long)ave_time_us / 1000);
1224 }
1225 
1226 struct A2dpSessionMetrics {
1227   int64_t audio_duration_ms = -1;
1228   int32_t media_timer_min_ms = -1;
1229   int32_t media_timer_max_ms = -1;
1230   int32_t media_timer_avg_ms = -1;
1231   int64_t total_scheduling_count = -1;
1232   int32_t buffer_overruns_max_count = -1;
1233   int32_t buffer_overruns_total = -1;
1234   float buffer_underruns_average = -1;
1235   int32_t buffer_underruns_count = -1;
1236   int64_t codec_index = -1;
1237   bool is_a2dp_offload = false;
1238 };
1239 
btif_a2dp_source_update_metrics(void)1240 static void btif_a2dp_source_update_metrics(void) {
1241   BtifMediaStats stats = btif_a2dp_source_cb.stats;
1242   SchedulingStats enqueue_stats = stats.tx_queue_enqueue_stats;
1243 
1244   A2dpSessionMetrics metrics;
1245   metrics.codec_index = stats.codec_index;
1246   metrics.is_a2dp_offload = btif_av_is_a2dp_offload_running();
1247 
1248   // session_start_us is 0 when btif_a2dp_source_start_audio_req() is not called
1249   // mark the metric duration as invalid (-1) in this case
1250   if (stats.session_start_us != 0) {
1251     metrics.audio_duration_ms = (stats.session_end_us - stats.session_start_us) / 1000;
1252   }
1253 
1254   if (enqueue_stats.total_updates > 1) {
1255     metrics.media_timer_min_ms = btif_a2dp_source_cb.encoder_interval_ms -
1256                                  (enqueue_stats.max_premature_scheduling_delta_us / 1000);
1257     metrics.media_timer_max_ms = btif_a2dp_source_cb.encoder_interval_ms +
1258                                  (enqueue_stats.max_overdue_scheduling_delta_us / 1000);
1259 
1260     metrics.total_scheduling_count = enqueue_stats.overdue_scheduling_count +
1261                                      enqueue_stats.premature_scheduling_count +
1262                                      enqueue_stats.exact_scheduling_count;
1263     if (metrics.total_scheduling_count > 0) {
1264       metrics.media_timer_avg_ms =
1265               enqueue_stats.total_scheduling_time_us / (1000 * metrics.total_scheduling_count);
1266     }
1267 
1268     metrics.buffer_overruns_max_count = stats.tx_queue_max_dropped_messages;
1269     metrics.buffer_overruns_total = stats.tx_queue_total_dropped_messages;
1270     metrics.buffer_underruns_count = stats.media_read_total_underflow_count;
1271     metrics.buffer_underruns_average = 0;
1272     if (metrics.buffer_underruns_count > 0) {
1273       metrics.buffer_underruns_average =
1274               (float)stats.media_read_total_underflow_bytes / metrics.buffer_underruns_count;
1275     }
1276   }
1277 
1278   if (metrics.audio_duration_ms != -1) {
1279     bluetooth::shim::LogMetricA2dpSessionMetricsEvent(
1280             btif_av_source_active_peer(), metrics.audio_duration_ms, metrics.media_timer_min_ms,
1281             metrics.media_timer_max_ms, metrics.media_timer_avg_ms, metrics.total_scheduling_count,
1282             metrics.buffer_overruns_max_count, metrics.buffer_overruns_total,
1283             metrics.buffer_underruns_average, metrics.buffer_underruns_count, metrics.codec_index,
1284             metrics.is_a2dp_offload);
1285   }
1286 }
1287 
btif_a2dp_source_set_dynamic_audio_buffer_size(uint8_t dynamic_audio_buffer_size)1288 void btif_a2dp_source_set_dynamic_audio_buffer_size(uint8_t dynamic_audio_buffer_size) {
1289   btif_a2dp_source_dynamic_audio_buffer_size = dynamic_audio_buffer_size;
1290 }
1291 
btm_read_rssi_cb(void * data)1292 static void btm_read_rssi_cb(void* data) {
1293   if (data == nullptr) {
1294     log::error("Read RSSI request timed out");
1295     return;
1296   }
1297 
1298   tBTM_RSSI_RESULT* result = (tBTM_RSSI_RESULT*)data;
1299   if (result->status != tBTM_STATUS::BTM_SUCCESS) {
1300     log::error("unable to read remote RSSI (status {})", result->status);
1301     return;
1302   }
1303 
1304   bluetooth::shim::LogMetricReadRssiResult(result->rem_bda, bluetooth::os::kUnknownConnectionHandle,
1305                                            result->hci_status, result->rssi);
1306 
1307   log::warn("device: {}, rssi: {}", result->rem_bda, result->rssi);
1308 }
1309 
btm_read_failed_contact_counter_cb(void * data)1310 static void btm_read_failed_contact_counter_cb(void* data) {
1311   if (data == nullptr) {
1312     log::error("Read Failed Contact Counter request timed out");
1313     return;
1314   }
1315 
1316   tBTM_FAILED_CONTACT_COUNTER_RESULT* result = (tBTM_FAILED_CONTACT_COUNTER_RESULT*)data;
1317   if (result->status != tBTM_STATUS::BTM_SUCCESS) {
1318     log::error("unable to read Failed Contact Counter (status {})", result->status);
1319     return;
1320   }
1321   bluetooth::shim::LogMetricReadFailedContactCounterResult(
1322           result->rem_bda, bluetooth::os::kUnknownConnectionHandle, result->hci_status,
1323           result->failed_contact_counter);
1324 
1325   log::warn("device: {}, Failed Contact Counter: {}", result->rem_bda,
1326             result->failed_contact_counter);
1327 }
1328 
btm_read_tx_power_cb(void * data)1329 static void btm_read_tx_power_cb(void* data) {
1330   if (data == nullptr) {
1331     log::error("Read Tx Power request timed out");
1332     return;
1333   }
1334 
1335   tBTM_TX_POWER_RESULT* result = (tBTM_TX_POWER_RESULT*)data;
1336   if (result->status != tBTM_STATUS::BTM_SUCCESS) {
1337     log::error("unable to read Tx Power (status {})", result->status);
1338     return;
1339   }
1340   bluetooth::shim::LogMetricReadTxPowerLevelResult(result->rem_bda,
1341                                                    bluetooth::os::kUnknownConnectionHandle,
1342                                                    result->hci_status, result->tx_power);
1343 
1344   log::warn("device: {}, Tx Power: {}", result->rem_bda, result->tx_power);
1345 }
1346