Hearing Aid: Add dumpsys log for audio packet

Add log for audio drops from audio HAL and buffer overflow
Add log for device capabilities and HiSyncId

Sample output:

Hearing Aid Manager:
  <device1> connected
    binaural right 0x...
    Packet counts (enqueued/flushed)                        : 73557 / 773
    Frame counts (enqueued/flushed)                         : 73557 / 773
  <device2> connected
    binaural left 0x...
    Packet counts (enqueued/flushed)                        : 74172 / 886
    Frame counts (enqueued/flushed)                         : 74172 / 886
  Hearing Aid Audio HAL:
    Counts (underflow)                                      : 0
    Bytes (underflow)                                       : 0
    Last update time ago in ms (underflow)                  : 0

Test: manual
Bug: 69623109
Change-Id: I5021b9214828b1846506638000f29af7343a3354
(cherry picked from commit b596bb17140c7fc82c73c7db62308aa057cf9aee)

diff --git a/bta/hearing_aid/hearing_aid.cc b/bta/hearing_aid/hearing_aid.cc
index 268f125..144dc99 100644 (file)
--- a/bta/hearing_aid/hearing_aid.cc
+++ b/bta/hearing_aid/hearing_aid.cc
@@ -88,6 +88,22 @@ inline uint8_t* get_l2cap_sdu_start_ptr(BT_HDR* msg) {
   return (uint8_t*)(msg) + BT_HDR_SIZE + L2CAP_MIN_OFFSET;
 }
 
+struct AudioStats {
+  size_t packet_flush_count;
+  size_t packet_send_count;
+  size_t frame_flush_count;
+  size_t frame_send_count;
+
+  AudioStats() { Reset(); }
+
+  void Reset() {
+    packet_flush_count = 0;
+    packet_send_count = 0;
+    frame_flush_count = 0;
+    frame_send_count = 0;
+  }
+};
+
 class HearingAidImpl;
 HearingAidImpl* instance;
 HearingAidAudioReceiver* audioReceiver;
@@ -125,6 +141,8 @@ struct HearingDevice {
   uint16_t preparation_delay;
   uint16_t codecs;
 
+  AudioStats audio_stats;
+
   HearingDevice(const RawAddress& address, uint16_t psm, uint8_t capabilities,
                 uint16_t codecs, uint16_t audio_control_point_handle,
                 uint16_t volume_handle, uint64_t hiSyncId,
@@ -787,12 +805,12 @@ class HearingAidImpl : public HearingAid {
       encoded_data_left.resize(encoded_size);
 
       uint16_t cid = GAP_ConnGetL2CAPCid(left->gap_handle);
-      if (DCHECK_IS_ON() && VLOG_IS_ON(2)) {
-        uint16_t packets_to_flush =
-            L2CA_FlushChannel(cid, L2CAP_FLUSH_CHANS_GET);
-        if (packets_to_flush)
-          VLOG(2) << left->address << " skipping " << packets_to_flush
-                  << " packets";
+      uint16_t packets_to_flush = L2CA_FlushChannel(cid, L2CAP_FLUSH_CHANS_GET);
+      if (packets_to_flush) {
+        VLOG(2) << left->address << " skipping " << packets_to_flush
+                << " packets";
+        left->audio_stats.packet_flush_count += packets_to_flush;
+        left->audio_stats.frame_flush_count++;
       }
       // flush all packets stuck in queue
       L2CA_FlushChannel(cid, 0xffff);
@@ -807,12 +825,12 @@ class HearingAidImpl : public HearingAid {
       encoded_data_right.resize(encoded_size);
 
       uint16_t cid = GAP_ConnGetL2CAPCid(right->gap_handle);
-      if (DCHECK_IS_ON() && VLOG_IS_ON(2)) {
-        uint16_t packets_to_flush =
-            L2CA_FlushChannel(cid, L2CAP_FLUSH_CHANS_GET);
-        if (packets_to_flush)
-          VLOG(2) << right->address << " skipping " << packets_to_flush
-                  << " packets";
+      uint16_t packets_to_flush = L2CA_FlushChannel(cid, L2CAP_FLUSH_CHANS_GET);
+      if (packets_to_flush) {
+        VLOG(2) << right->address << " skipping " << packets_to_flush
+                << " packets";
+        right->audio_stats.packet_flush_count += packets_to_flush;
+        right->audio_stats.frame_flush_count++;
       }
       // flush all packets stuck in queue
       L2CA_FlushChannel(cid, 0xffff);
@@ -832,10 +850,18 @@ class HearingAidImpl : public HearingAid {
     }
 
     for (size_t i = 0; i < encoded_data_size; i += packet_size) {
-      if (left) SendAudio(encoded_data_left.data() + i, packet_size, left);
-      if (right) SendAudio(encoded_data_right.data() + i, packet_size, right);
+      if (left) {
+        left->audio_stats.packet_send_count++;
+        SendAudio(encoded_data_left.data() + i, packet_size, left);
+      }
+      if (right) {
+        right->audio_stats.packet_send_count++;
+        SendAudio(encoded_data_right.data() + i, packet_size, right);
+      }
       seq_counter++;
     }
+    if (left) left->audio_stats.frame_send_count++;
+    if (right) right->audio_stats.frame_send_count++;
   }
 
   void SendAudio(uint8_t* encoded_data, uint16_t packet_size,
@@ -941,6 +967,27 @@ class HearingAidImpl : public HearingAid {
     if (instance) instance->GapCallback(gap_handle, event, data);
   }
 
+  void Dump(int fd) {
+    std::stringstream stream;
+    for (const auto& device : hearingDevices.devices) {
+      bool side = device.capabilities & CAPABILITY_SIDE;
+      bool standalone = device.capabilities & CAPABILITY_BINAURAL;
+      stream << "  " << device.address.ToString() << " "
+             << (device.accepting_audio ? "" : "not ") << "connected"
+             << "\n    " << (standalone ? "binaural" : "monaural") << " "
+             << (side ? "right" : "left") << " " << loghex(device.hi_sync_id)
+             << std::endl;
+      stream
+          << "    Packet counts (enqueued/flushed)                        : "
+          << device.audio_stats.packet_send_count << " / "
+          << device.audio_stats.packet_flush_count
+          << "\n    Frame counts (enqueued/flushed)                         : "
+          << device.audio_stats.frame_send_count << " / "
+          << device.audio_stats.frame_flush_count << std::endl;
+    }
+    dprintf(fd, "%s", stream.str().c_str());
+  }
+
   void Disconnect(const RawAddress& address) override {
     DVLOG(2) << __func__;
     HearingDevice* hearingDevice = hearingDevices.FindByAddress(address);
@@ -1153,3 +1200,9 @@ void HearingAid::CleanUp() {
   instance = nullptr;
   delete ptr;
 };
+
+void HearingAid::DebugDump(int fd) {
+  dprintf(fd, "\nHearing Aid Manager:\n");
+  if (instance) instance->Dump(fd);
+  HearingAidAudioSource::DebugDump(fd);
+}
\ No newline at end of file

diff --git a/bta/hearing_aid/hearing_aid_audio_source.cc b/bta/hearing_aid/hearing_aid_audio_source.cc
index cebb4d8..947caaf 100644 (file)
--- a/bta/hearing_aid/hearing_aid_audio_source.cc
+++ b/bta/hearing_aid/hearing_aid_audio_source.cc
@@ -22,7 +22,6 @@
 #include "uipc.h"
 
 #include <base/files/file_util.h>
-#include <base/strings/string_number_conversions.h>
 #include <include/hardware/bt_av.h>
 
 using base::FilePath;
@@ -38,8 +37,24 @@ alarm_t* audio_timer = nullptr;
 HearingAidAudioReceiver* localAudioReceiver;
 std::unique_ptr<tUIPC_STATE> uipc_hearing_aid;
 
+struct AudioHalStats {
+  size_t media_read_total_underflow_bytes;
+  size_t media_read_total_underflow_count;
+  uint64_t media_read_last_underflow_us;
+
+  AudioHalStats() { Reset(); }
+
+  void Reset() {
+    media_read_total_underflow_bytes = 0;
+    media_read_total_underflow_count = 0;
+    media_read_last_underflow_us = 0;
+  }
+};
+
+AudioHalStats stats;
+
 void send_audio_data(void*) {
-  int bytes_per_tick =
+  uint32_t bytes_per_tick =
       (num_channels * sample_rate * data_interval_ms * (bit_rate / 8)) / 1000;
 
   uint16_t event;
@@ -49,6 +64,11 @@ void send_audio_data(void*) {
                                   &event, p_buf, bytes_per_tick);
 
   VLOG(2) << "bytes_read: " << bytes_read;
+  if (bytes_read < bytes_per_tick) {
+    stats.media_read_total_underflow_bytes += bytes_per_tick - bytes_read;
+    stats.media_read_total_underflow_count++;
+    stats.media_read_last_underflow_us = time_get_os_boottime_us();
+  }
 
   std::vector<uint8_t> data(p_buf, p_buf + bytes_read);
 
@@ -246,6 +266,7 @@ void HearingAidAudioSource::Start(const CodecConfiguration& codecConfiguration,
                                   HearingAidAudioReceiver* audioReceiver) {
   localAudioReceiver = audioReceiver;
   VLOG(2) << "Hearing Aid UIPC Open";
+  stats.Reset();
 }
 
 void HearingAidAudioSource::Stop() {
@@ -263,3 +284,21 @@ void HearingAidAudioSource::Initialize() {
 void HearingAidAudioSource::CleanUp() {
   UIPC_Close(*uipc_hearing_aid, UIPC_CH_ID_ALL);
 }
+
+void HearingAidAudioSource::DebugDump(int fd) {
+  uint64_t now_us = time_get_os_boottime_us();
+  std::stringstream stream;
+  stream << "  Hearing Aid Audio HAL:"
+         << "\n    Counts (underflow)                                      : "
+         << stats.media_read_total_underflow_count
+         << "\n    Bytes (underflow)                                       : "
+         << stats.media_read_total_underflow_bytes
+         << "\n    Last update time ago in ms (underflow)                  : "
+         << (stats.media_read_last_underflow_us > 0
+                 ? (unsigned long long)(now_us -
+                                        stats.media_read_last_underflow_us) /
+                       1000
+                 : 0)
+         << std::endl;
+  dprintf(fd, "%s", stream.str().c_str());
+}

diff --git a/bta/include/bta_hearing_aid_api.h b/bta/include/bta_hearing_aid_api.h
index c3eca1a..6b94722 100644 (file)
--- a/bta/include/bta_hearing_aid_api.h
+++ b/bta/include/bta_hearing_aid_api.h
@@ -40,6 +40,7 @@ class HearingAid {
   static void CleanUp();
   static bool IsInitialized();
   static HearingAid* Get();
+  static void DebugDump(int fd);
 
   static void AddFromStorage(const RawAddress& address, uint16_t psm,
                              uint8_t capabilities, uint16_t codec,
@@ -83,4 +84,5 @@ class HearingAidAudioSource {
   static void Stop();
   static void Initialize();
   static void CleanUp();
+  static void DebugDump(int fd);
 };

diff --git a/btif/src/bluetooth.cc b/btif/src/bluetooth.cc
index b338909..92a4092 100644 (file)
--- a/btif/src/bluetooth.cc
+++ b/btif/src/bluetooth.cc
@@ -49,6 +49,7 @@
 
 #include "avrcp_service.h"
 #include "bt_utils.h"
+#include "bta/include/bta_hearing_aid_api.h"
 #include "bta/include/bta_hf_client_api.h"
 #include "btif_a2dp.h"
 #include "btif_api.h"
@@ -321,6 +322,7 @@ static void dump(int fd, const char** arguments) {
   wakelock_debug_dump(fd);
   osi_allocator_debug_dump(fd);
   alarm_debug_dump(fd);
+  HearingAid::DebugDump(fd);
 #if (BTSNOOP_MEM == TRUE)
   btif_debug_btsnoop_dump(fd);
 #endif