Merge "Refine the log messages of audio_bluetooth_hal"
diff --git a/audio_bluetooth_hw/device_port_proxy.cc b/audio_bluetooth_hw/device_port_proxy.cc
index 0bbf1d5..6e1fda2 100644
--- a/audio_bluetooth_hw/device_port_proxy.cc
+++ b/audio_bluetooth_hw/device_port_proxy.cc
@@ -32,8 +32,7 @@
 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 @@
       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 @@
       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 @@
       .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 @@
     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 @@
 
 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 @@
   }
   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 @@
       } 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 @@
         // 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 @@
   }
   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 @@
     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 @@
   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 @@
     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 @@
     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 @@
     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 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 @@
     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);
diff --git a/audio_bluetooth_hw/stream_apis.cc b/audio_bluetooth_hw/stream_apis.cc
index be48437..74b6f2a 100644
--- a/audio_bluetooth_hw/stream_apis.cc
+++ b/audio_bluetooth_hw/stream_apis.cc
@@ -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 @@
 
 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 @@
     case BluetoothStreamState::UNKNOWN:
       return os << "UNKNOWN";
     default:
-      return os << "0x" + android::base::StringPrintf("%hhx", state);
+      return os << StringPrintf("%#hhx", state);
   }
 }
 
@@ -107,9 +106,7 @@
     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 @@
       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 @@
         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 @@
   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 @@
     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 @@
   }
   // 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 @@
   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;
 }