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

1 files changed, 56 insertions, 60 deletions

diff --git a/audio_bluetooth_hw/device_port_proxy.cc b/audio_bluetooth_hw/device_port_proxy.cc
index 0bbf1d5cc..6e1fda234 100644
--- a/audio_bluetooth_hw/device_port_proxy.cc
+++ b/audio_bluetooth_hw/device_port_proxy.cc
@@ -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);