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

Commit 0c13d6da authored by Łukasz Rymanowski's avatar Łukasz Rymanowski
Browse files

leaudio: Improve dumpsys logs

LeAudio Manager:
  Active group: 2
    configuration: MEDIA  (0x00000004)
    metadata context type mask: MEDIA, NOTIFICATION
    TBS state: No calls
    Start time: 1015 ms, 900 ms,
 Speaker codec config (audio framework)
        sample rate: 48000,     chan: 2,        bits: 16,       data_interval_us: 10000
 Microphone codec config (audio framework)
        sample rate: 32000,     chan: 2,        bits: 16,       data_interval_us: 10000
 Speaker codec config (Bluetooth)
        audio sender state: STARTED
        sample rate: 48000,     chan: 1,        bits: 16,       data_interval_us: 10000
 Microphone codec config (Bluetooth)
        audio receiver state: IDLE
        sample rate: 0, chan: 0,        bits: 0,        data_interval_us: 0
  ----------------
   LE Audio Groups:

    == Group id: 1 == , Inactive
      state: IDLE (0x00),       target state: IDLE (0x00),      cig state: NONE (0x00)
      active context types: 000000000000000000, current context type: UNINITIALIZED
      active configuration name:  not set
      stream configuration:  unknown
      codec id: 0,      pending_configuration: 0
      num of devices(connected): 2(0)
,     num of sinks(connected): 0(0)
      num of sources(connected): 0(0)
      allocated CISes: 0
      == devices: ==
        Address: XX:XX:XX:XX:XX:XX,     CONNECTING_AUTOCONNECT (0x06), acl_handle: 65535,  Unecrypted,mtu: 0
        number of ases_: 3
          == ASEs ==
          id: 1,        active: false, dir: sink,       cis_id: 255,    state: IDLE (0x00)
          id: 2,        active: false, dir: sink,       cis_id: 255,    state: IDLE (0x00)
          id: 3,        active: false, dir: source,     cis_id: 255,    state: IDLE (0x00)
          ====
        Address: yy:yy:yy:yy:yy:yy,     CONNECTING_AUTOCONNECT (0x06): , acl_handle: 65535, Unencrypted,mtu: 0
        number of ases_: 3
          == ASEs ==
          id: 1,        active: false, dir: sink,       cis_id: 255,    state: IDLE (0x00)
          id: 2,        active: false, dir: sink,       cis_id: 255,    state: IDLE (0x00)
          id: 3,        active: false, dir: source,     cis_id: 255,    state: IDLE (0x00)
          ====
    == Group id: 2 == , Active
      state: STREAMING (0x04),  target state: STREAMING (0x04), cig state: CREATED (0x02)
      active context types: 0x0000000000000f3f, current context type: MEDIA
      active configuration name: DualDev_OneChanStereoSnk_48_4_Server_Preferred
      stream configuration: DualDev_OneChanStereoSnk_48_4_Server_Preferred
      codec id: 0,      pending_configuration: 0
      num of devices(connected): 2(1)
,     num of sinks(connected): 2(1)
      num of sources(connected): 0(0)
      allocated CISes: 2
         == CISes ==
         cis id: 0,     type: 1,        conn_handle: 12,        addr: aa:aa:aa:aa:aa:aa
         cis id: 1,     type: 1,        conn_handle: 13,        addr: bb:bb:bb:bb:bb:bb
         ====
      presentation_delay for sink (speaker): 40000 us
      presentation_delay for source (microphone): 0 us
      == devices: ==
        Address: aa:aa:aa:aa:aa:aa,     CONNECTED (0x02): 267, acl_handle: 9,  Encrypted,mtu: 100
        number of ases_: 3
          == ASEs ==
          id: 1,        active: true, dir: sink,        cis_id: 0,      state: DATA_PATH_ESTABLISHED (0x05)
          id: 2,        active: false, dir: sink,       cis_id: 255,    state: IDLE (0x00)
          id: 3,        active: false, dir: source,     cis_id: 255,    state: IDLE (0x00)
          ====
        Address: bb:bb:bb:bb:bb:bb,     CONNECTED (0x02): 11, acl_handle: 10,  Encrypted,mtu: 100
        number of ases_: 3
          == ASEs ==
          id: 1,        active: true, dir: sink,        cis_id: 1,      state: DATA_PATH_ESTABLISHED (0x05)
          id: 2,        active: false, dir: sink,       cis_id: 255,    state: IDLE (0x00)
          id: 3,        active: false, dir: source,     cis_id: 255,    state: IDLE (0x00)
          ====

Bug: 249303876
Test: Compile
Tag: #feature
Change-Id: Id461e2d43a35ad63f63cb0752a20fb9258b3fd1e
parent df55778d
Loading
Loading
Loading
Loading
+56 −19
Original line number Diff line number Diff line
@@ -18,6 +18,8 @@
#include <base/bind.h>
#include <base/strings/string_number_conversions.h>

#include <deque>

#include "advertise_data_parser.h"
#include "audio_hal_interface/le_audio_software.h"
#include "bta/csis/csis_types.h"
@@ -740,13 +742,15 @@ class LeAudioClientImpl : public LeAudioClient {
      return false;
    }

    if (group->GetState() != AseState::BTA_LE_AUDIO_ASE_STATE_STREAMING) {
      stream_setup_start_timestamp_ =
          bluetooth::common::time_get_os_boottime_us();
    }

    bool result = groupStateMachine_->StartStream(
        group, static_cast<LeAudioContextType>(final_context_type),
        adjusted_metadata_context_type,
        GetAllCcids(adjusted_metadata_context_type));
    if (result)
      stream_setup_start_timestamp_ =
          bluetooth::common::time_get_os_boottime_us();

    return result;
  }
@@ -2255,6 +2259,8 @@ class LeAudioClientImpl : public LeAudioClient {
       * codec configuration */
      group->SetPendingConfiguration();
      groupStateMachine_->StopStream(group);
      stream_setup_start_timestamp_ =
          bluetooth::common::time_get_os_boottime_us();
      return;
    }

@@ -2262,6 +2268,9 @@ class LeAudioClientImpl : public LeAudioClient {
      LOG_WARN("Could not add device %s to the group %d streaming. ",
               leAudioDevice->address_.ToString().c_str(), group->group_id_);
      scheduleAttachDeviceToTheStream(leAudioDevice->address_);
    } else {
      stream_setup_start_timestamp_ =
          bluetooth::common::time_get_os_boottime_us();
    }
  }

@@ -2877,16 +2886,16 @@ class LeAudioClientImpl : public LeAudioClient {
    std::stringstream stream;
    if (print_audio_state) {
      if (sender) {
        stream << "   audio sender state: " << audio_sender_state_ << "\n";
        stream << "\taudio sender state: " << audio_sender_state_ << "\n";
      } else {
        stream << "   audio receiver state: " << audio_receiver_state_ << "\n";
        stream << "\taudio receiver state: " << audio_receiver_state_ << "\n";
      }
    }

    stream << "   num_channels: " << +conf->num_channels << "\n"
           << "   sample rate: " << +conf->sample_rate << "\n"
           << "   bits pers sample: " << +conf->bits_per_sample << "\n"
           << "   data_interval_us: " << +conf->data_interval_us << "\n";
    stream << "\tsample rate: " << +conf->sample_rate
           << ",\tchan: " << +conf->num_channels
           << ",\tbits: " << +conf->bits_per_sample
           << ",\tdata_interval_us: " << +conf->data_interval_us << "\n";

    dprintf(fd, "%s", stream.str().c_str());
  }
@@ -2919,17 +2928,27 @@ class LeAudioClientImpl : public LeAudioClient {

  void Dump(int fd) {
    dprintf(fd, "  Active group: %d\n", active_group_id_);
    dprintf(fd, "    configuration content type: 0x%08hx\n",
    dprintf(fd, "    configuration: %s  (0x%08hx)\n",
            bluetooth::common::ToString(configuration_context_type_).c_str(),
            configuration_context_type_);
    dprintf(fd, "    metadata context type mask: ");

    for (auto ctx : le_audio::types::kLeAudioContextAllTypesArray) {
      if (static_cast<uint16_t>(ctx) & metadata_context_types_.to_ulong()) {
        dprintf(fd, "%s, ", bluetooth::common::ToString(ctx).c_str());
      }
    }
    dprintf(fd, "\n");
    dprintf(fd, "    TBS state: %s\n", in_call_ ? " In call" : "No calls");
    dprintf(
        fd, "    stream setup time if started: %d ms\n",
        (int)((stream_setup_end_timestamp_ - stream_setup_start_timestamp_) /
              1000));
    dprintf(fd, "    Start time: ");
    for (auto t : stream_start_history_queue_) {
      dprintf(fd, ", %d ms", static_cast<int>(t));
    }
    dprintf(fd, "\n");
    printCurrentStreamConfiguration(fd);
    dprintf(fd, "  ----------------\n ");
    dprintf(fd, "  LE Audio Groups:\n");
    aseGroups_.Dump(fd);
    aseGroups_.Dump(fd, active_group_id_);
    dprintf(fd, "\n  Not grouped devices:\n");
    leAudioDevices_.Dump(fd, bluetooth::groups::kGroupUnknown);
  }
@@ -3866,6 +3885,23 @@ class LeAudioClientImpl : public LeAudioClient {
    }
  }

  void take_stream_time(void) {
    if (stream_setup_start_timestamp_ == 0) {
      return;
    }

    if (stream_start_history_queue_.size() == 10) {
      stream_start_history_queue_.pop_back();
    }

    stream_setup_end_timestamp_ = bluetooth::common::time_get_os_boottime_us();
    stream_start_history_queue_.emplace_front(
        (stream_setup_end_timestamp_ - stream_setup_start_timestamp_) / 1000);

    stream_setup_end_timestamp_ = 0;
    stream_setup_start_timestamp_ = 0;
  }

  void StatusReportCb(int group_id, GroupStreamStatus status) {
    LOG_INFO("status: %d , audio_sender_state %s, audio_receiver_state %s",
             static_cast<int>(status),
@@ -3884,8 +3920,8 @@ class LeAudioClientImpl : public LeAudioClient {
        if (audio_receiver_state_ == AudioState::READY_TO_START)
          StartReceivingAudio(group_id);

        stream_setup_end_timestamp_ =
            bluetooth::common::time_get_os_boottime_us();
        take_stream_time();

        le_audio::MetricsCollector::Get()->OnStreamStarted(
            active_group_id_, configuration_context_type_);
        break;
@@ -3923,8 +3959,6 @@ class LeAudioClientImpl : public LeAudioClient {
         */
        FALLTHROUGH;
      case GroupStreamStatus::IDLE: {
        stream_setup_end_timestamp_ = 0;
        stream_setup_start_timestamp_ = 0;
        if (group && group->IsPendingConfiguration()) {
          SuspendedForReconfiguration();
          auto adjusted_metedata_context_type =
@@ -3937,6 +3971,8 @@ class LeAudioClientImpl : public LeAudioClient {
            return;
          }
        }
        stream_setup_end_timestamp_ = 0;
        stream_setup_start_timestamp_ = 0;
        CancelStreamingRequest();
        if (group) {
          NotifyUpperLayerGroupTurnedIdleDuringCall(group->group_id_);
@@ -3972,6 +4008,7 @@ class LeAudioClientImpl : public LeAudioClient {
  AudioContexts metadata_context_types_;
  uint64_t stream_setup_start_timestamp_;
  uint64_t stream_setup_end_timestamp_;
  std::deque<uint64_t> stream_start_history_queue_;

  /* Microphone (s) */
  AudioState audio_receiver_state_;
+58 −50
Original line number Diff line number Diff line
@@ -1907,67 +1907,72 @@ bool LeAudioDeviceGroup::Configure(LeAudioContextType context_type,
}

LeAudioDeviceGroup::~LeAudioDeviceGroup(void) { this->Cleanup(); }
void LeAudioDeviceGroup::Dump(int fd) {
void LeAudioDeviceGroup::Dump(int fd, int active_group_id) {
  bool is_active = (group_id_ == active_group_id);
  std::stringstream stream;
  auto* active_conf = GetActiveConfiguration();
  uint32_t context_type_mask = GetActiveContexts().to_ulong();

  stream << "    == Group id: " << group_id_ << " == \n"
         << "      state: " << GetState() << "\n"
         << "      target state: " << GetTargetState() << "\n"
         << "      cig state: " << cig_state_ << "\n"
         << "      number of devices: " << Size() << "\n"
         << "      number of connected devices: " << NumOfConnected() << "\n"
         << "      active context types: "
         << loghex(GetActiveContexts().to_ulong()) << "\n"
         << "      current context type: "
         << static_cast<int>(GetCurrentContextType()) << "\n"
         << "      active stream configuration name: "
  stream << "\n    == Group id: " << group_id_
         << " == " << (is_active ? ",\tActive\n" : ",\tInactive\n")
         << "      state: " << GetState()
         << ",\ttarget state: " << GetTargetState()
         << ",\tcig state: " << cig_state_ << "\n"
         << "      active context type mask: " << context_type_mask;

  for (auto ctx : types::kLeAudioContextAllTypesArray) {
    if (static_cast<uint16_t>(ctx) & static_cast<uint16_t>(context_type_mask)) {
      stream << ", " << bluetooth::common::ToString(ctx).c_str();
    }
  }

  stream << ",\n      current context type: "
         << bluetooth::common::ToString(GetCurrentContextType()).c_str() << "\n"
         << "      active configuration name: "
         << (active_conf ? active_conf->name : " not set") << "\n"
         << "    Last used stream configuration: \n"
         << "      pending_configuration: " << stream_conf.pending_configuration
         << "      stream configuration: "
         << (stream_conf.conf != nullptr ? stream_conf.conf->name : " unknown ")
         << "\n"
         << "      codec id : " << +(stream_conf.id.coding_format) << "\n"
         << "      name: "
         << (stream_conf.conf != nullptr ? stream_conf.conf->name : " null ")
         << "      codec id: " << +(stream_conf.id.coding_format)
         << ",\tpending_configuration: " << stream_conf.pending_configuration
         << "\n"
         << "      number of sinks in the configuration "
         << stream_conf.sink_num_of_devices << "\n"
         << "      number of sink_streams connected: "
         << stream_conf.sink_streams.size() << "\n"
         << "      number of sources in the configuration "
         << stream_conf.source_num_of_devices << "\n"
         << "      number of source_streams connected: "
         << stream_conf.source_streams.size() << "\n"
         << "      num of devices(connected): " << Size() << "("
         << NumOfConnected() << ")\n"
         << ",     num of sinks(connected): " << stream_conf.sink_num_of_devices
         << "(" << stream_conf.sink_streams.size() << ")\n"
         << "      num of sources(connected): "
         << stream_conf.source_num_of_devices << "("
         << stream_conf.source_streams.size() << ")\n"
         << "      allocated CISes: " << static_cast<int>(cises_.size());

  if (cises_.size() > 0) {
    stream << "\n\t === CISes === ";
    stream << "\n\t == CISes == ";
    for (auto cis : cises_) {
      stream << "\n\t cis id: " << static_cast<int>(cis.id)
             << ", type: " << static_cast<int>(cis.type)
             << ", conn_handle: " << static_cast<int>(cis.conn_handle)
             << ", addr: " << cis.addr;
             << ",\ttype: " << static_cast<int>(cis.type)
             << ",\tconn_handle: " << static_cast<int>(cis.conn_handle)
             << ",\taddr: " << cis.addr;
    }
    stream << "\n\t ====";
  }

  if (GetFirstActiveDevice() != nullptr) {
    uint32_t sink_delay;
    stream << "\n      presentation_delay for sink (speaker): ";
    if (GetPresentationDelay(&sink_delay, le_audio::types::kLeAudioDirectionSink)) {
      stream << sink_delay << " us";
    if (GetPresentationDelay(&sink_delay,
                             le_audio::types::kLeAudioDirectionSink)) {
      stream << "\n      presentation_delay for sink (speaker): " << sink_delay
             << " us";
    }
    stream << "\n      presentation_delay for source (microphone): ";

    uint32_t source_delay;
    if (GetPresentationDelay(&source_delay, le_audio::types::kLeAudioDirectionSource)) {
      stream << source_delay << " us";
    if (GetPresentationDelay(&source_delay,
                             le_audio::types::kLeAudioDirectionSource)) {
      stream << "\n      presentation_delay for source (microphone): "
             << source_delay << " us";
    }
    stream << "\n";
  } else {
    stream << "\n      presentation_delay for sink (speaker):\n"
           << "      presentation_delay for source (microphone): \n";
  }

  stream << "      === devices: ===";
  stream << "\n      == devices: ==";

  dprintf(fd, "%s", stream.str().c_str());

@@ -2400,26 +2405,29 @@ void LeAudioDevice::SetSupportedContexts(AudioContexts snk_contexts,
}

void LeAudioDevice::Dump(int fd) {
  uint16_t acl_handle = BTM_GetHCIConnHandle(address_, BT_TRANSPORT_LE);

  std::stringstream stream;
  stream << std::boolalpha;
  stream << "\n\taddress: " << address_ << ": " << connection_state_ << ": "
         << (conn_id_ == GATT_INVALID_CONN_ID ? "" : std::to_string(conn_id_))
         << "\n\t  set member: " << csis_member_
         << "\n\t  known_service_handles_: " << known_service_handles_
         << "\n\t  notify_connected_after_read_: "
         << notify_connected_after_read_ << "\n\t  encrypted_: " << encrypted_
         << ", acl_handle: " << std::to_string(acl_handle) << ",\t"
         << (encrypted_ ? "Encrypted" : "Unecrypted")
         << ",mtu: " << std::to_string(mtu_)
         << "\n\tnumber of ases_: " << static_cast<int>(ases_.size());

  if (ases_.size() > 0) {
    stream << "\n\t  == ASE == ";
    stream << "\n\t  == ASEs == ";
    for (auto& ase : ases_) {
      stream << "\n\t  id: " << static_cast<int>(ase.id)
             << ", active: " << ase.active << ", direction: "
             << ",\tactive: " << ase.active << ", dir: "
             << (ase.direction == types::kLeAudioDirectionSink ? "sink"
                                                               : "source")
             << ", allocated cis id: " << static_cast<int>(ase.cis_id);
             << ",\tcis_id: " << static_cast<int>(ase.cis_id) << ",\tstate: "
             << bluetooth::common::ToString(ase.data_path_state);
    }
  }
  stream << "\n\t  ====";

  dprintf(fd, "%s", stream.str().c_str());
}
@@ -2557,9 +2565,9 @@ void LeAudioDeviceGroups::Cleanup(void) {
  groups_.clear();
}

void LeAudioDeviceGroups::Dump(int fd) {
void LeAudioDeviceGroups::Dump(int fd, int active_group_id) {
  for (auto& g : groups_) {
    g->Dump(fd);
    g->Dump(fd, active_group_id);
  }
}

+2 −2
Original line number Diff line number Diff line
@@ -357,7 +357,7 @@ class LeAudioDeviceGroup {

  bool IsInTransition(void);
  bool IsReleasing(void);
  void Dump(int fd);
  void Dump(int fd, int active_group_id);

 private:
  uint32_t transport_latency_mtos_us_;
@@ -403,7 +403,7 @@ class LeAudioDeviceGroups {
  size_t Size();
  bool IsAnyInTransition();
  void Cleanup(void);
  void Dump(int fd);
  void Dump(int fd, int active_group_id);

 private:
  std::vector<std::unique_ptr<LeAudioDeviceGroup>> groups_;
+11 −0
Original line number Diff line number Diff line
@@ -578,6 +578,17 @@ uint32_t AdjustAllocationForOffloader(uint32_t allocation) {
}

namespace types {
std::ostream& operator<<(std::ostream& os,
                         const AudioStreamDataPathState& state) {
  static const char* char_value_[6] = {
      "IDLE",        "CIS_DISCONNECTING", "CIS_ASSIGNED",
      "CIS_PENDING", "CIS_ESTABLISHED",   "DATA_PATH_ESTABLISHED"};

  os << char_value_[static_cast<uint8_t>(state)] << " ("
     << "0x" << std::setfill('0') << std::setw(2) << static_cast<int>(state)
     << ")";
  return os;
}
std::ostream& operator<<(std::ostream& os, const types::CigState& state) {
  static const char* char_value_[5] = {"NONE", "CREATING", "CREATED",
                                       "REMOVING", "RECOVERING"};