Added logging of average power levels to AudioOutputController.

BUG=chromium:714119
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_optional_gpu_tests_rel;master.tryserver.chromium.linux:linux_optional_gpu_tests_rel;master.tryserver.chromium.mac:mac_optional_gpu_tests_rel;master.tryserver.chromium.win:win_optional_gpu_tests_rel

Review-Url: https://codereview.chromium.org/2902823005
Cr-Commit-Position: refs/heads/master@{#476259}

media/audio/audio_output_controller.cc

@@ -22,6 +22,10 @@
 using base::TimeDelta;
 
 namespace media {
+namespace {
+// Time in seconds between two successive measurements of audio power levels.
+constexpr int kPowerMonitorLogIntervalSeconds = 15;
+}  // namespace
 
 AudioOutputController::AudioOutputController(
     AudioManager* audio_manager,
@@ -165,6 +169,10 @@ void AudioOutputController::DoPlay() {
 
   state_ = kPlaying;
 
+  if (will_monitor_audio_levels()) {
+    last_audio_level_log_time_ = base::TimeTicks::Now();
+  }
+
   stream_->Start(this);
 
   // For UMA tracking purposes, start the wedge detection timer.  This allows us
@@ -193,6 +201,10 @@ void AudioOutputController::StopStream() {
     wedge_timer_.reset();
     stream_->Stop();
 
+    if (will_monitor_audio_levels()) {
+      LogAudioPowerLevel("StopStream");
+    }
+
     // A stopped stream is silent, and power_montior_.Scan() is no longer being
     // called; so we must reset the power monitor.
     power_monitor_.Reset();
@@ -288,9 +300,17 @@ int AudioOutputController::OnMoreData(base::TimeDelta delay,
             std::move(copy), reference_time));
   }
 
-  if (will_monitor_audio_levels())
+  if (will_monitor_audio_levels()) {
     power_monitor_.Scan(*dest, frames);
 
+    const auto now = base::TimeTicks::Now();
+    if ((now - last_audio_level_log_time_).InSeconds() >
+        kPowerMonitorLogIntervalSeconds) {
+      LogAudioPowerLevel("OnMoreData");
+      last_audio_level_log_time_ = now;
+    }
+  }
+
   return frames;
 }
 
@@ -313,6 +333,13 @@ void AudioOutputController::BroadcastDataToDuplicationTargets(
   (*duplication_targets_.begin())->OnData(std::move(audio_bus), reference_time);
 }
 
+void AudioOutputController::LogAudioPowerLevel(const std::string& call_name) {
+  std::pair<float, bool> power_and_clip =
+      power_monitor_.ReadCurrentPowerAndClip();
+  handler_->OnLog(base::StringPrintf("AOC::%s: average audio level=%.2f dBFS",
+                                     call_name.c_str(), power_and_clip.first));
+}
+
 void AudioOutputController::OnError() {
   {
     base::AutoLock auto_lock(error_lock_);

media/audio/audio_output_controller.h

@@ -222,6 +222,9 @@ class MEDIA_EXPORT AudioOutputController
   void BroadcastDataToDuplicationTargets(std::unique_ptr<AudioBus> audio_bus,
                                          base::TimeTicks reference_time);
 
+  // Log the current average power level measured by power_monitor_.
+  void LogAudioPowerLevel(const std::string& call_name);
+
   AudioManager* const audio_manager_;
   const AudioParameters params_;
   EventHandler* const handler_;
@@ -256,6 +259,9 @@ class MEDIA_EXPORT AudioOutputController
   // Scans audio samples from OnMoreData() as input to compute power levels.
   AudioPowerMonitor power_monitor_;
 
+  // Updated each time a power measurement is logged.
+  base::TimeTicks last_audio_level_log_time_;
+
   // Flags when we've asked for a stream to start but it never did.
   base::AtomicRefCount on_more_io_data_called_;
   std::unique_ptr<base::OneShotTimer> wedge_timer_;