Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 2d7ddc98 authored by Stanley Tng's avatar Stanley Tng
Browse files

Add Rx RSSI logs for Hearing Aids

When there is a data buffer flush (which indicates data congestion),
the received RSSI will be queried for this connection multiple times and
logged in the dumpsys.

Bug: 124331686
Test: Manual test
Change-Id: I686f4e34bda3f8067b42d6b41ca8bf316a5bf6f1
parent 5cbf0658
Loading
Loading
Loading
Loading
+114 −0
Original line number Diff line number Diff line
@@ -83,6 +83,7 @@ Uuid LE_PSM_UUID = Uuid::FromString("2d410339-82b6-42aa-b34e-e2e01
void hearingaid_gattc_callback(tBTA_GATTC_EVT event, tBTA_GATTC* p_data);
void encryption_callback(const RawAddress*, tGATT_TRANSPORT, void*,
                         tBTM_STATUS);
void read_rssi_cb(void* p_void);

inline BT_HDR* malloc_l2cap_buf(uint16_t len) {
  BT_HDR* msg = (BT_HDR*)osi_malloc(BT_HDR_SIZE + L2CAP_MIN_OFFSET +
@@ -155,6 +156,30 @@ class HearingDevices {
    return false;
  }

  void StartRssiLog() {
    int read_rssi_start_interval_count = 0;

    for (auto& d : devices) {
      VLOG(1) << __func__ << ": device=" << d.address << ", read_rssi_count=" << d.read_rssi_count;

      // Reset the count
      if (d.read_rssi_count <= 0) {
        d.read_rssi_count = READ_RSSI_NUM_TRIES;
        d.num_intervals_since_last_rssi_read = read_rssi_start_interval_count;

        // Spaced apart the Read RSSI commands to the BT controller.
        read_rssi_start_interval_count += PERIOD_TO_READ_RSSI_IN_INTERVALS / 2;
        read_rssi_start_interval_count %= PERIOD_TO_READ_RSSI_IN_INTERVALS;

        std::deque<rssi_log>& rssi_logs = d.audio_stats.rssi_history;
        if (rssi_logs.size() >= MAX_RSSI_HISTORY) {
          rssi_logs.pop_front();
        }
        rssi_logs.emplace_back();
      }
    }
  }

  size_t size() { return (devices.size()); }

  std::vector<HearingDevice> devices;
@@ -461,6 +486,34 @@ class HearingAidImpl : public HearingAid {
    }
  }

  // Completion Callback for the RSSI read operation.
  void OnReadRssiComplete(const RawAddress& address, int8_t rssi_value) {
    HearingDevice* hearingDevice = hearingDevices.FindByAddress(address);
    if (!hearingDevice) {
      LOG(INFO) << "Skipping unknown device" << address;
      return;
    }

    VLOG(1) << __func__ << ": device=" << address << ", rssi=" << (int)rssi_value;

    if (hearingDevice->read_rssi_count <= 0) {
      LOG(ERROR) << __func__ << ": device=" << address
                 << ", invalid read_rssi_count=" << hearingDevice->read_rssi_count;
      return;
    }

    rssi_log& last_log_set = hearingDevice->audio_stats.rssi_history.back();

    if (hearingDevice->read_rssi_count == READ_RSSI_NUM_TRIES) {
      // Store the timestamp only for the first one after packet flush
      clock_gettime(CLOCK_REALTIME, &last_log_set.timestamp);
      LOG(INFO) << __func__ << ": store time. device=" << address << ", rssi=" << (int)rssi_value;
    }

    last_log_set.rssi.emplace_back(rssi_value);
    hearingDevice->read_rssi_count--;
  }

  void OnEncryptionComplete(const RawAddress& address, bool success) {
    HearingDevice* hearingDevice = hearingDevices.FindByAddress(address);
    if (!hearingDevice) {
@@ -1072,9 +1125,11 @@ class HearingAidImpl : public HearingAid {
                << " packets";
        left->audio_stats.packet_flush_count += packets_to_flush;
        left->audio_stats.frame_flush_count++;
        hearingDevices.StartRssiLog();
      }
      // flush all packets stuck in queue
      L2CA_FlushChannel(cid, 0xffff);
      check_and_do_rssi_read(left);
    }

    std::vector<uint8_t> encoded_data_right;
@@ -1094,9 +1149,11 @@ class HearingAidImpl : public HearingAid {
                << " packets";
        right->audio_stats.packet_flush_count += packets_to_flush;
        right->audio_stats.frame_flush_count++;
        hearingDevices.StartRssiLog();
      }
      // flush all packets stuck in queue
      L2CA_FlushChannel(cid, 0xffff);
      check_and_do_rssi_read(right);
    }

    size_t encoded_data_size =
@@ -1235,6 +1292,40 @@ class HearingAidImpl : public HearingAid {
    if (instance) instance->GapCallback(gap_handle, event, data);
  }

  void DumpRssi(int fd, const HearingDevice& device) {
    const struct AudioStats* stats = &device.audio_stats;

    if (stats->rssi_history.size() <= 0) {
      dprintf(fd, "  No RSSI history for %s:\n", device.address.ToString().c_str());
      return;
    }
    dprintf(fd, "  RSSI history for %s:\n", device.address.ToString().c_str());

    dprintf(fd, "    Time of RSSI    0.0  0.1  0.2  0.3  0.4  0.5  0.6  0.7  0.8  0.9\n");
    for (auto& rssi_logs : stats->rssi_history) {
      if (rssi_logs.rssi.size() <= 0) {
        break;
      }

      char eventtime[20];
      char temptime[20];
      struct tm* tstamp = localtime(&rssi_logs.timestamp.tv_sec);
      if (!strftime(temptime, sizeof(temptime), "%H:%M:%S", tstamp)) {
        LOG(ERROR) << __func__ << ": strftime fails. tm_sec=" << tstamp->tm_sec << ", tm_min=" << tstamp->tm_min
                   << ", tm_hour=" << tstamp->tm_hour;
        strlcpy(temptime, "UNKNOWN TIME", sizeof(temptime));
      }
      snprintf(eventtime, sizeof(eventtime), "%s.%03ld", temptime, rssi_logs.timestamp.tv_nsec / 1000000);

      dprintf(fd, "    %s: ", eventtime);

      for (auto rssi_value : rssi_logs.rssi) {
        dprintf(fd, " %04d", rssi_value);
      }
      dprintf(fd, "\n");
    }
  }

  void Dump(int fd) {
    std::stringstream stream;
    for (const auto& device : hearingDevices.devices) {
@@ -1252,6 +1343,8 @@ class HearingAidImpl : public HearingAid {
          << "\n    Frame counts (enqueued/flushed)                         : "
          << device.audio_stats.frame_send_count << " / "
          << device.audio_stats.frame_flush_count << std::endl;

      DumpRssi(fd, device);
    }
    dprintf(fd, "%s", stream.str().c_str());
  }
@@ -1426,8 +1519,29 @@ class HearingAidImpl : public HearingAid {
      send_state_change(&device, payload);
    }
  }

  void check_and_do_rssi_read(HearingDevice* device) {
    if (device->read_rssi_count > 0) {
      device->num_intervals_since_last_rssi_read++;
      if (device->num_intervals_since_last_rssi_read >= PERIOD_TO_READ_RSSI_IN_INTERVALS) {
        device->num_intervals_since_last_rssi_read = 0;
        VLOG(1) << __func__ << ": device=" << device->address;
        BTM_ReadRSSI(device->address, read_rssi_cb);
      }
    }
  }
};

void read_rssi_cb(void* p_void) {
  tBTM_RSSI_RESULT* p_result = (tBTM_RSSI_RESULT*)p_void;

  if (!p_result) return;

  if ((instance) && (p_result->status == BTM_SUCCESS)) {
    instance->OnReadRssiComplete(p_result->rem_bda, p_result->rssi);
  }
}

void hearingaid_gattc_callback(tBTA_GATTC_EVT event, tBTA_GATTC* p_data) {
  VLOG(2) << __func__ << " event = " << +event;

+26 −7
Original line number Diff line number Diff line
@@ -20,7 +20,9 @@

#include <base/callback_forward.h>
#include <hardware/bt_hearing_aid.h>
#include <deque>
#include <future>
#include <vector>

constexpr uint16_t HA_INTERVAL_10_MS = 10;
constexpr uint16_t HA_INTERVAL_20_MS = 20;
@@ -39,11 +41,23 @@ class HearingAidAudioReceiver {
  virtual void OnAudioResume(std::promise<void> do_resume_promise) = 0;
};

// Number of rssi reads to attempt when requested
constexpr int READ_RSSI_NUM_TRIES = 10;
constexpr int PERIOD_TO_READ_RSSI_IN_INTERVALS = 5;
// Depth of RSSI History in DumpSys
constexpr int MAX_RSSI_HISTORY = 15;

struct rssi_log {
  struct timespec timestamp;
  std::vector<int8_t> rssi;
};

struct AudioStats {
  size_t packet_flush_count;
  size_t packet_send_count;
  size_t frame_flush_count;
  size_t frame_send_count;
  std::deque<rssi_log> rssi_history;

  AudioStats() { Reset(); }

@@ -112,11 +126,14 @@ struct HearingDevice {
   * ACKnowledged. */
  bool command_acked;

  HearingDevice(const RawAddress& address, uint16_t psm, uint8_t capabilities,
                uint16_t codecs, uint16_t audio_control_point_handle,
                uint16_t audio_status_handle, uint16_t audio_status_ccc_handle,
                uint16_t volume_handle, uint64_t hiSyncId,
                uint16_t render_delay, uint16_t preparation_delay)
  /* When read_rssi_count is > 0, then read the rssi. The interval between rssi
     reads is tracked by num_intervals_since_last_rssi_read. */
  int read_rssi_count;
  int num_intervals_since_last_rssi_read;

  HearingDevice(const RawAddress& address, uint16_t psm, uint8_t capabilities, uint16_t codecs,
                uint16_t audio_control_point_handle, uint16_t audio_status_handle, uint16_t audio_status_ccc_handle,
                uint16_t volume_handle, uint64_t hiSyncId, uint16_t render_delay, uint16_t preparation_delay)
      : address(address),
        first_connection(false),
        connecting_actively(false),
@@ -135,7 +152,8 @@ struct HearingDevice {
        preparation_delay(preparation_delay),
        codecs(codecs),
        playback_started(false),
        command_acked(false) {}
        command_acked(false),
        read_rssi_count(0) {}

  HearingDevice(const RawAddress& address, bool first_connection)
      : address(address),
@@ -149,7 +167,8 @@ struct HearingDevice {
        audio_status_ccc_handle(0),
        psm(0),
        playback_started(false),
        command_acked(false) {}
        command_acked(false),
        read_rssi_count(0) {}

  HearingDevice() : HearingDevice(RawAddress::kEmpty, false) {}