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

Commit 59fcee0b authored by Cheney Ni's avatar Cheney Ni
Browse files

Refine the log messages of audio_bluetooth_hal 

This CL follows the review suggestions at aosp/920718 and aosp/925233 to
refine logs.

Bug: none
Test: check logs manually
Change-Id: I3c57afaf6d416752687a7a697a310fe98c8ee495
parent 8f46d647

system/audio_bluetooth_hw/device_port_proxy.cc

+56 −60
Original line number Diff line number Diff line
@@ -32,8 +32,7 @@ namespace android { 
namespace bluetooth {

namespace audio {



using android::base::StringPrintf;



using ::android::base::StringPrintf;

using ::android::bluetooth::audio::BluetoothAudioSessionControl;

using ::android::hardware::bluetooth::audio::V2_0::BitsPerSample;

using ::android::hardware::bluetooth::audio::V2_0::ChannelMode;
@@ -116,7 +115,7 @@ bool BluetoothAudioPortOut::SetUp(audio_devices_t devices) { 
      return;

    }

    if (port->cookie_ != cookie) {

      LOG(ERROR) << "control_result_cb: proxy of device port (cookie=0x" << StringPrintf("%04hx", cookie)

      LOG(ERROR) << "control_result_cb: proxy of device port (cookie=" << StringPrintf("%#hx", cookie)

                 << ") is corrupted";

      return;

    }
@@ -128,7 +127,7 @@ bool BluetoothAudioPortOut::SetUp(audio_devices_t devices) { 
      return;

    }

    if (port->cookie_ != cookie) {

      LOG(ERROR) << "session_changed_cb: proxy of device port (cookie=0x" << StringPrintf("%04hx", cookie)

      LOG(ERROR) << "session_changed_cb: proxy of device port (cookie=" << StringPrintf("%#hx", cookie)

                 << ") is corrupted";

      return;

    }
@@ -139,8 +138,7 @@ bool BluetoothAudioPortOut::SetUp(audio_devices_t devices) { 
      .session_changed_cb_ = session_changed_cb};

  cookie_ = BluetoothAudioSessionControl::RegisterControlResultCback(

      session_type_, cbacks);

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_);

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_);



  return (cookie_ != android::bluetooth::audio::kObserversCookieUndefined);

}
@@ -150,23 +148,23 @@ bool BluetoothAudioPortOut::init_session_type(audio_devices_t device) { 
    case AUDIO_DEVICE_OUT_BLUETOOTH_A2DP:

    case AUDIO_DEVICE_OUT_BLUETOOTH_A2DP_HEADPHONES:

    case AUDIO_DEVICE_OUT_BLUETOOTH_A2DP_SPEAKER:

      LOG(VERBOSE) << __func__ << ": device=AUDIO_DEVICE_OUT_BLUETOOTH_A2DP (HEADPHONES/SPEAKER) (0x"

                   << StringPrintf("%08x", device) << ")";

      LOG(VERBOSE) << __func__ << ": device=AUDIO_DEVICE_OUT_BLUETOOTH_A2DP (HEADPHONES/SPEAKER) ("

                   << StringPrintf("%#x", device) << ")";

      session_type_ = SessionType::A2DP_SOFTWARE_ENCODING_DATAPATH;

      break;

    case AUDIO_DEVICE_OUT_HEARING_AID:

      LOG(VERBOSE) << __func__ << ": device=AUDIO_DEVICE_OUT_HEARING_AID (MEDIA/VOICE) (0x"

                   << StringPrintf("%08x", device) << ")";

      LOG(VERBOSE) << __func__ << ": device=AUDIO_DEVICE_OUT_HEARING_AID (MEDIA/VOICE) (" << StringPrintf("%#x", device)

                   << ")";

      session_type_ = SessionType::HEARING_AID_SOFTWARE_ENCODING_DATAPATH;

      break;

    default:

      LOG(ERROR) << __func__ << ": unknown device=0x" << StringPrintf("%08x", device);

      LOG(ERROR) << __func__ << ": unknown device=" << StringPrintf("%#x", device);

      return false;

  }



  if (!BluetoothAudioSessionControl::IsSessionReady(session_type_)) {

    LOG(ERROR) << __func__ << ": device=0x" << StringPrintf("%08x", device)

               << ", session_type=" << toString(session_type_) << " is not ready";

    LOG(ERROR) << __func__ << ": device=" << StringPrintf("%#x", device) << ", session_type=" << toString(session_type_)

               << " is not ready";

    return false;

  }

  return true;
@@ -174,13 +172,12 @@ bool BluetoothAudioPortOut::init_session_type(audio_devices_t device) { 


void BluetoothAudioPortOut::TearDown() {

  if (!in_use()) {

    LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

               << StringPrintf("%04hx", cookie_) << " unknown monitor";

    LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_)

               << ", cookie=" << StringPrintf("%#hx", cookie_) << " unknown monitor";

    return;

  }



  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_);

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_);

  BluetoothAudioSessionControl::UnregisterControlResultCback(session_type_,

                                                             cookie_);

  cookie_ = android::bluetooth::audio::kObserversCookieUndefined;
@@ -194,8 +191,8 @@ void BluetoothAudioPortOut::ControlResultHandler( 
  }

  std::unique_lock<std::mutex> port_lock(cv_mutex_);

  BluetoothStreamState previous_state = state_;

  LOG(INFO) << "control_result_cb: session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_) << ", previous_state=" << previous_state

  LOG(INFO) << "control_result_cb: session_type=" << toString(session_type_)

            << ", cookie=" << StringPrintf("%#hx", cookie_) << ", previous_state=" << previous_state

            << ", status=" << toString(status);



  switch (previous_state) {
@@ -205,8 +202,8 @@ void BluetoothAudioPortOut::ControlResultHandler( 
      } else {

        // Set to standby since the stack may be busy switching between outputs

        LOG(WARNING) << "control_result_cb: status=" << toString(status)

                     << " failure for session_type=" << toString(session_type_) << ", cookie=0x"

                     << StringPrintf("%04hx", cookie_) << ", previous_state=" << previous_state;

                     << " failure for session_type=" << toString(session_type_)

                     << ", cookie=" << StringPrintf("%#hx", cookie_) << ", previous_state=" << previous_state;

        state_ = BluetoothStreamState::STANDBY;

      }

      break;
@@ -217,14 +214,14 @@ void BluetoothAudioPortOut::ControlResultHandler( 
        // It will be failed if the headset is disconnecting, and set to disable

        // to wait for re-init again

        LOG(WARNING) << "control_result_cb: status=" << toString(status)

                     << " failure for session_type=" << toString(session_type_) << ", cookie=0x"

                     << StringPrintf("%04hx", cookie_) << ", previous_state=" << previous_state;

                     << " failure for session_type=" << toString(session_type_)

                     << ", cookie=" << StringPrintf("%#hx", cookie_) << ", previous_state=" << previous_state;

        state_ = BluetoothStreamState::DISABLED;

      }

      break;

    default:

      LOG(ERROR) << "control_result_cb: unexpected status=" << toString(status)

                 << " for session_type=" << toString(session_type_) << ", cookie=0x" << StringPrintf("%04hx", cookie_)

                 << " for session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_)

                 << ", previous_state=" << previous_state;

      return;

  }
@@ -239,8 +236,8 @@ void BluetoothAudioPortOut::SessionChangedHandler() { 
  }

  std::unique_lock<std::mutex> port_lock(cv_mutex_);

  BluetoothStreamState previous_state = state_;

  LOG(INFO) << "session_changed_cb: session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_) << ", previous_state=" << previous_state;

  LOG(INFO) << "session_changed_cb: session_type=" << toString(session_type_)

            << ", cookie=" << StringPrintf("%#hx", cookie_) << ", previous_state=" << previous_state;

  if (previous_state != BluetoothStreamState::DISABLED) {

    state_ = BluetoothStreamState::DISABLED;

  } else {
@@ -273,8 +270,9 @@ bool BluetoothAudioPortOut::LoadAudioConfig(audio_config_t* audio_cfg) const { 
    return false;

  }

  const PcmParameters& pcm_cfg = hal_audio_cfg.pcmConfig();

  LOG(VERBOSE) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

               << StringPrintf("%04hx", cookie_) << ", state=" << state_ << ", PcmConfig=[" << toString(pcm_cfg) << "]";

  LOG(VERBOSE) << __func__ << ": session_type=" << toString(session_type_)

               << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_ << ", PcmConfig=["

               << toString(pcm_cfg) << "]";

  if (pcm_cfg.sampleRate == SampleRate::RATE_UNKNOWN ||

      pcm_cfg.channelMode == ChannelMode::UNKNOWN ||

      pcm_cfg.bitsPerSample == BitsPerSample::BITS_UNKNOWN) {
@@ -292,24 +290,24 @@ bool BluetoothAudioPortOut::CondwaitState(BluetoothStreamState state) { 
  std::unique_lock<std::mutex> port_lock(cv_mutex_);

  switch (state) {

    case BluetoothStreamState::STARTING:

      LOG(VERBOSE) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

                   << StringPrintf("%04hx", cookie_) << " waiting for STARTED";

      LOG(VERBOSE) << __func__ << ": session_type=" << toString(session_type_)

                   << ", cookie=" << StringPrintf("%#hx", cookie_) << " waiting for STARTED";

      retval = internal_cv_.wait_for(

          port_lock, std::chrono::milliseconds(kMaxWaitingTimeMs),

          [this] { return this->state_ != BluetoothStreamState::STARTING; });

      retval = retval && state_ == BluetoothStreamState::STARTED;

      break;

    case BluetoothStreamState::SUSPENDING:

      LOG(VERBOSE) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

                   << StringPrintf("%04hx", cookie_) << " waiting for SUSPENDED";

      LOG(VERBOSE) << __func__ << ": session_type=" << toString(session_type_)

                   << ", cookie=" << StringPrintf("%#hx", cookie_) << " waiting for SUSPENDED";

      retval = internal_cv_.wait_for(

          port_lock, std::chrono::milliseconds(kMaxWaitingTimeMs),

          [this] { return this->state_ != BluetoothStreamState::SUSPENDING; });

      retval = retval && state_ == BluetoothStreamState::STANDBY;

      break;

    default:

      LOG(WARNING) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

                   << StringPrintf("%04hx", cookie_) << " waiting for KNOWN";

      LOG(WARNING) << __func__ << ": session_type=" << toString(session_type_)

                   << ", cookie=" << StringPrintf("%#hx", cookie_) << " waiting for KNOWN";

      return false;

  }
@@ -322,27 +320,26 @@ bool BluetoothAudioPortOut::Start() { 
    return false;

  }



  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_) << ", state=" << state_

            << ", mono=" << (is_stereo_to_mono_ ? "true" : "false") << " request";

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_)

            << ", state=" << state_ << ", mono=" << (is_stereo_to_mono_ ? "true" : "false") << " request";

  bool retval = false;

  if (state_ == BluetoothStreamState::STANDBY) {

    state_ = BluetoothStreamState::STARTING;

    if (BluetoothAudioSessionControl::StartStream(session_type_)) {

      retval = CondwaitState(BluetoothStreamState::STARTING);

    } else {

      LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

                 << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " Hal fails";

      LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_)

                 << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_ << " Hal fails";

    }

  }



  if (retval) {

    LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

              << StringPrintf("%04hx", cookie_) << ", state=" << state_

    LOG(INFO) << __func__ << ": session_type=" << toString(session_type_)

              << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_

              << ", mono=" << (is_stereo_to_mono_ ? "true" : "false") << " done";

  } else {

    LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

               << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " failure";

    LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_)

               << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_ << " failure";

  }



  return retval;  // false if any failure like timeout
@@ -354,25 +351,25 @@ bool BluetoothAudioPortOut::Suspend() { 
    return false;

  }



  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " request";

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_)

            << ", state=" << state_ << " request";

  bool retval = false;

  if (state_ == BluetoothStreamState::STARTED) {

    state_ = BluetoothStreamState::SUSPENDING;

    if (BluetoothAudioSessionControl::SuspendStream(session_type_)) {

      retval = CondwaitState(BluetoothStreamState::SUSPENDING);

    } else {

      LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

                 << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " Hal fails";

      LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_)

                 << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_ << " Hal fails";

    }

  }



  if (retval) {

    LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

              << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " done";

    LOG(INFO) << __func__ << ": session_type=" << toString(session_type_)

              << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_ << " done";

  } else {

    LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

               << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " failure";

    LOG(ERROR) << __func__ << ": session_type=" << toString(session_type_)

               << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_ << " failure";

  }



  return retval;  // false if any failure like timeout
@@ -383,12 +380,12 @@ void BluetoothAudioPortOut::Stop() { 
    LOG(ERROR) << __func__ << ": BluetoothAudioPortOut is not in use";

    return;

  }

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " request";

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_)

            << ", state=" << state_ << " request";

  state_ = BluetoothStreamState::DISABLED;

  BluetoothAudioSessionControl::StopStream(session_type_);

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

            << StringPrintf("%04hx", cookie_) << ", state=" << state_ << " done";

  LOG(INFO) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_)

            << ", state=" << state_ << " done";

}



size_t BluetoothAudioPortOut::WriteData(const void* buffer, size_t bytes) const {
@@ -416,8 +413,8 @@ bool BluetoothAudioPortOut::GetPresentationPosition(uint64_t* delay_ns, 
  }

  bool retval = BluetoothAudioSessionControl::GetPresentationPosition(

      session_type_, delay_ns, bytes, timestamp);

  LOG(VERBOSE) << __func__ << ": session_type=0x" << StringPrintf("%02hhx", session_type_) << ", cookie=0x"

               << StringPrintf("%04hx", cookie_) << ", state=" << state_ << ", delay=" << *delay_ns

  LOG(VERBOSE) << __func__ << ": session_type=" << StringPrintf("%#hhx", session_type_)

               << ", cookie=" << StringPrintf("%#hx", cookie_) << ", state=" << state_ << ", delay=" << *delay_ns

               << "ns, data=" << *bytes << " bytes, timestamp=" << timestamp->tv_sec << "."

               << StringPrintf("%09ld", timestamp->tv_nsec) << "s";
@@ -430,9 +427,8 @@ void BluetoothAudioPortOut::UpdateMetadata( 
    LOG(ERROR) << __func__ << ": BluetoothAudioPortOut is not in use";

    return;

  }

  LOG(DEBUG) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=0x"

             << StringPrintf("%04hx", cookie_) << ", state=" << state_ << ", " << source_metadata->track_count

             << " track(s)";

  LOG(DEBUG) << __func__ << ": session_type=" << toString(session_type_) << ", cookie=" << StringPrintf("%#hx", cookie_)

             << ", state=" << state_ << ", " << source_metadata->track_count << " track(s)";

  if (source_metadata->track_count == 0) return;

  BluetoothAudioSessionControl::UpdateTracksMetadata(session_type_,

                                                     source_metadata);

system/audio_bluetooth_hw/stream_apis.cc

+17 −29
Original line number Diff line number Diff line
@@ -29,6 +29,7 @@ 
#include "stream_apis.h"

#include "utils.h"



using ::android::base::StringPrintf;

using ::android::bluetooth::audio::BluetoothAudioPortOut;

using ::android::bluetooth::audio::utils::GetAudioParamString;

using ::android::bluetooth::audio::utils::ParseAudioParams;
@@ -41,9 +42,7 @@ constexpr int kExtraAudioSyncMs = 200; 


std::ostream& operator<<(std::ostream& os, const audio_config& config) {

  return os << "audio_config[sample_rate=" << config.sample_rate

            << ", channels=0x"

            << android::base::StringPrintf("%x", config.channel_mask)

            << ", format=" << config.format << "]";

            << ", channels=" << StringPrintf("%#x", config.channel_mask) << ", format=" << config.format << "]";

}



}  // namespace
@@ -63,7 +62,7 @@ std::ostream& operator<<(std::ostream& os, const BluetoothStreamState& state) { 
    case BluetoothStreamState::UNKNOWN:

      return os << "UNKNOWN";

    default:

      return os << "0x" + android::base::StringPrintf("%hhx", state);

      return os << StringPrintf("%#hhx", state);

  }

}
@@ -107,9 +106,7 @@ static audio_channel_mask_t out_get_channels( 
    return audio_cfg.channel_mask;

  } else {

    LOG(WARNING) << __func__ << ": state=" << out->bluetooth_output_.GetState()

                 << ", channels=0x"

                 << android::base::StringPrintf("%x", out->channel_mask_)

                 << " failure";

                 << ", channels=" << StringPrintf("%#x", out->channel_mask_) << " failure";

    return out->channel_mask_;

  }

}
@@ -194,10 +191,8 @@ static int out_set_parameters(struct audio_stream* stream, 
      out->sample_rate_ = audio_cfg.sample_rate;

      out->channel_mask_ = audio_cfg.channel_mask;

      out->format_ = audio_cfg.format;

      LOG(VERBOSE) << "state=" << out->bluetooth_output_.GetState()

                   << ", sample_rate=" << out->sample_rate_ << ", channels=0x"

                   << android::base::StringPrintf("%x", out->channel_mask_)

                   << ", format=" << out->format_;

      LOG(VERBOSE) << "state=" << out->bluetooth_output_.GetState() << ", sample_rate=" << out->sample_rate_

                   << ", channels=" << StringPrintf("%#x", out->channel_mask_) << ", format=" << out->format_;

    } else {

      LOG(WARNING) << __func__

                   << ": state=" << out->bluetooth_output_.GetState()
@@ -554,12 +549,9 @@ static int out_get_presentation_position(const struct audio_stream_out* stream, 
        timestamp->tv_sec += static_cast<int>(timestamp->tv_nsec / 1000000000);

        timestamp->tv_nsec %= 1000000000;

      }

      LOG(VERBOSE) << __func__

                   << ": state=" << out->bluetooth_output_.GetState()

                   << ", frames=" << *frames << " (" << bytes

                   << " bytes), timestamp=" << timestamp->tv_sec << "."

                   << android::base::StringPrintf("%09ld", timestamp->tv_nsec)

                   << "s";

      LOG(VERBOSE) << __func__ << ": state=" << out->bluetooth_output_.GetState() << ", frames=" << *frames << " ("

                   << bytes << " bytes), timestamp=" << timestamp->tv_sec << "."

                   << StringPrintf("%09ld", timestamp->tv_nsec) << "s";

      return 0;

    } else if (delay_report_ns >= kMaximumDelayMs * 1000000) {

      LOG(WARNING) << __func__
@@ -572,11 +564,9 @@ static int out_get_presentation_position(const struct audio_stream_out* stream, 
  if (out->frames_presented_ >= out->frames_count_) {

    clock_gettime(CLOCK_MONOTONIC, timestamp);

    *frames = out->frames_presented_ - out->frames_count_;

    LOG(VERBOSE) << __func__ << ": state=" << out->bluetooth_output_.GetState()

                 << ", frames=" << *frames << " (" << bytes

                 << " bytes), timestamp=" << timestamp->tv_sec << "."

                 << android::base::StringPrintf("%09ld", timestamp->tv_nsec)

                 << "s";

    LOG(VERBOSE) << __func__ << ": state=" << out->bluetooth_output_.GetState() << ", frames=" << *frames << " ("

                 << bytes << " bytes), timestamp=" << timestamp->tv_sec << "."

                 << StringPrintf("%09ld", timestamp->tv_nsec) << "s";

    return 0;

  }
@@ -615,8 +605,7 @@ int adev_open_output_stream(struct audio_hw_device* dev, 
    delete out;

    return -EINVAL;

  }

  LOG(VERBOSE) << __func__ << ": device=0x"

               << android::base::StringPrintf("%08x", devices);

  LOG(VERBOSE) << __func__ << ": device=" << StringPrintf("%#x", devices);



  out->stream_out_.common.get_sample_rate = out_get_sample_rate;

  out->stream_out_.common.set_sample_rate = out_set_sample_rate;
@@ -646,7 +635,7 @@ int adev_open_output_stream(struct audio_hw_device* dev, 
  }

  // WAR to support Mono / 16 bits per sample as the Bluetooth stack required

  if (config->channel_mask == AUDIO_CHANNEL_OUT_MONO && config->format == AUDIO_FORMAT_PCM_16_BIT) {

    LOG(INFO) << __func__ << ": force channels=0x" << android::base::StringPrintf("%x", out->channel_mask_)

    LOG(INFO) << __func__ << ": force channels=" << StringPrintf("%#x", out->channel_mask_)

              << " to be AUDIO_CHANNEL_OUT_STEREO";

    out->bluetooth_output_.ForcePcmStereoToMono(true);

    config->channel_mask = AUDIO_CHANNEL_OUT_STEREO;
@@ -661,10 +650,9 @@ int adev_open_output_stream(struct audio_hw_device* dev, 
  out->frames_presented_ = 0;



  *stream_out = &out->stream_out_;

  LOG(INFO) << __func__ << ": state=" << out->bluetooth_output_.GetState()

            << ", sample_rate=" << out->sample_rate_ << ", channels="

            << android::base::StringPrintf("%x", out->channel_mask_)

            << ", format=" << out->format_ << ", frames=" << out->frames_count_;

  LOG(INFO) << __func__ << ": state=" << out->bluetooth_output_.GetState() << ", sample_rate=" << out->sample_rate_

            << ", channels=" << StringPrintf("%#x", out->channel_mask_) << ", format=" << out->format_

            << ", frames=" << out->frames_count_;

  return 0;

}