Added logging of average power levels to AudioOutputController.

media/audio/audio_output_controller.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "media/audio/audio_output_controller.h"
 
 #include <stdint.h>
 
 #include <algorithm>
 #include <limits>
 
 #include "base/bind.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/numerics/safe_conversions.h"
 #include "base/strings/stringprintf.h"
 #include "base/task_runner_util.h"
 #include "base/threading/platform_thread.h"
 #include "base/time/time.h"
 #include "base/trace_event/trace_event.h"
 #include "media/base/audio_timestamp_helper.h"
 
 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,
     EventHandler* handler,
     const AudioParameters& params,
     const std::string& output_device_id,
     SyncReader* sync_reader)
     : audio_manager_(audio_manager),
       params_(params),
       handler_(handler),
@@ skipping 123 matching lines @@
 
   // We can start from created or paused state.
   if (state_ != kCreated && state_ != kPaused)
     return;
 
   // Ask for first packet.
   sync_reader_->RequestMoreData(base::TimeDelta(), base::TimeTicks(), 0);
 
   state_ = kPlaying;
 
+  if (will_monitor_audio_levels()) {
+    last_audio_level_log_time_ = base::TimeTicks::Now();

[liberato (no reviews please), 2017/05/30 17:00:53]

i think that this will be default-constructed to 0, which should work fine for
the check @303.

[ossu-chromium, 2017/05/31 11:44:40]

Acknowledged.

[ossu-chromium, 2017/05/31 11:44:40]

It needs to be reset to something in DoPlay, and Now() seems as good a value as
any, to me.

[liberato (no reviews please), 2017/05/31 19:39:22]

ah -- i mis-read the diff.  yeah, you're right.

anyway, one can drop the {} for single-line if, here and elsewhere.

+  }
+
   stream_->Start(this);
 
   // For UMA tracking purposes, start the wedge detection timer.  This allows us
   // to record statistics about the number of wedged playbacks in the field.
   //
   // WedgeCheck() will look to see if |on_more_io_data_called_| is true after
   // the timeout expires.  Care must be taken to ensure the wedge check delay is
   // large enough that the value isn't queried while OnMoreDataIO() is setting
   // it.
   //
@@ skipping 103 matching lines @@
     const base::TimeTicks reference_time = delay_timestamp + delay;
     std::unique_ptr<AudioBus> copy(AudioBus::Create(params_));
     dest->CopyTo(copy.get());
     message_loop_->PostTask(
         FROM_HERE,
         base::BindOnce(
             &AudioOutputController::BroadcastDataToDuplicationTargets, this,
             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) {
+      std::pair<float, bool> power_and_clip =
+          power_monitor_.ReadCurrentPowerAndClip();
+
+      handler_->OnLog(
+          base::StringPrintf("AOC::OnMoreData: average audio level=%.2f dBFS",
+                             power_and_clip.first));
+      last_audio_level_log_time_ = now;
+    }
+  }
+
   return frames;
 }
 
 void AudioOutputController::BroadcastDataToDuplicationTargets(
     std::unique_ptr<AudioBus> audio_bus,
     base::TimeTicks reference_time) {
   DCHECK(message_loop_->BelongsToCurrentThread());
   if (state_ != kPlaying || duplication_targets_.empty())
     return;
 
@@ skipping 186 matching lines @@
   DCHECK(message_loop_->BelongsToCurrentThread());
 
   // If we should be playing and we haven't, that's a wedge.
   if (state_ == kPlaying) {
     UMA_HISTOGRAM_BOOLEAN("Media.AudioOutputControllerPlaybackStartupSuccess",
                           base::AtomicRefCountIsOne(&on_more_io_data_called_));
   }
 }
 
 }  // namespace media