Add UMA stats for OS input glitches on Mac.

media/audio/mac/audio_low_latency_input_mac.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/mac/audio_low_latency_input_mac.h"
 #include <CoreServices/CoreServices.h>
 #include <mach/mach.h>
 #include <string>
 
 #include "base/logging.h"
@@ skipping 164 matching lines @@
 
 // See "Technical Note TN2091 - Device input using the HAL Output Audio Unit"
 // http://developer.apple.com/library/mac/#technotes/tn2091/_index.html
 // for more details and background regarding this implementation.
 
 AUAudioInputStream::AUAudioInputStream(AudioManagerMac* manager,
                                        const AudioParameters& input_params,
                                        AudioDeviceID audio_device_id)
     : manager_(manager),
       number_of_frames_(input_params.frames_per_buffer()),
+      number_of_frames_provided_(0),
       io_buffer_frame_size_(0),
       sink_(nullptr),
       audio_unit_(0),
       input_device_id_(audio_device_id),
       hardware_latency_frames_(0),
       number_of_channels_in_frame_(0),
       fifo_(input_params.channels(),
             number_of_frames_,
             kNumberOfBlocksBufferInFifo),
       input_callback_is_active_(false),
       start_was_deferred_(false),
       buffer_size_was_changed_(false),
       audio_unit_render_has_worked_(false),
-      device_listener_is_active_(false) {
+      device_listener_is_active_(false),
+      last_sample_time_(0.0),
+      last_number_of_frames_(0),
+      total_lost_frames_(0),
+      largest_glitch_frames_(0),
+      glitches_detected_(0) {
   DCHECK(manager_);
 
   // Set up the desired (output) format specified by the client.
   format_.mSampleRate = input_params.sample_rate();
   format_.mFormatID = kAudioFormatLinearPCM;
   format_.mFormatFlags = kLinearPCMFormatFlagIsPacked |
                          kLinearPCMFormatFlagIsSignedInteger;
   DCHECK(FormatIsInterleaved(format_.mFormatFlags));
   format_.mBitsPerChannel = input_params.bits_per_sample();
   format_.mChannelsPerFrame = input_params.channels();
@@ skipping 22 matching lines @@
 
   AudioBuffer* audio_buffer = audio_buffer_list_.mBuffers;
   audio_buffer->mNumberChannels = input_params.channels();
   audio_buffer->mDataByteSize = data_byte_size;
   audio_buffer->mData = audio_data_buffer_.get();
 }
 
 AUAudioInputStream::~AUAudioInputStream() {
   DVLOG(1) << "~dtor";
   DCHECK(!device_listener_is_active_);
+  ReportAndResetStats();
 }
 
 // Obtain and open the AUHAL AudioOutputUnit for recording.
 bool AUAudioInputStream::Open() {
   DCHECK(thread_checker_.CalledOnValidThread());
   DVLOG(1) << "Open";
   DCHECK(!audio_unit_);
 
   // Verify that we have a valid device. Send appropriate error code to
   // HandleError() to ensure that the error type is added to UMA stats.
@@ skipping 260 matching lines @@
   // seems to set this state synchronously, hence it should always report false
   // after a successful call.
   DCHECK(!IsRunning()) << "Audio unit is stopped but still running";
 
   // Reset the audio unit’s render state. This function clears memory.
   // It does not allocate or free memory resources.
   result = AudioUnitReset(audio_unit_, kAudioUnitScope_Global, 0);
   DCHECK_EQ(result, noErr);
 
   SetInputCallbackIsActive(false);
+  ReportAndResetStats();
   sink_ = nullptr;
   fifo_.Clear();
   io_buffer_frame_size_ = 0;
   OSSTATUS_DLOG_IF(ERROR, result != noErr, result)
       << "Failed to stop acquiring data";
 }
 
 void AUAudioInputStream::Close() {
   DCHECK(thread_checker_.CalledOnValidThread());
   DVLOG(1) << "Close";
@@ skipping 277 matching lines @@
   // Update time of successful call to AudioUnitRender().
   last_success_time_ = base::TimeTicks::Now();
 
   // Deliver recorded data to the consumer as a callback.
   return Provide(number_of_frames, &audio_buffer_list_, time_stamp);
 }
 
 OSStatus AUAudioInputStream::Provide(UInt32 number_of_frames,
                                      AudioBufferList* io_data,
                                      const AudioTimeStamp* time_stamp) {
+  UpdateCaptureTimestamp(time_stamp);
+  last_number_of_frames_ = number_of_frames;
+
+  // TODO(grunell): We'll only care about the first buffer size change, any
+  // further changes will be ignored. This is in line with output side stats.
+  // It would be nice to have all changes reflected in UMA stats.
+  if (number_of_frames != number_of_frames_ && number_of_frames_provided_ == 0)
+    number_of_frames_provided_ = number_of_frames;
+
   // Update the capture latency.
   double capture_latency_frames = GetCaptureLatency(time_stamp);
 
   // The AGC volume level is updated once every second on a separate thread.
   // Note that, |volume| is also updated each time SetVolume() is called
   // through IPC by the render-side AGC.
   double normalized_volume = 0.0;
   GetAgcVolume(&normalized_volume);
 
   AudioBuffer& buffer = io_data->mBuffers[0];
@@ skipping 399 matching lines @@
         break;
     }
     DVLOG(1) << "property: " << device_property << " ("
              << FourCharFormatCodeToString(device_property) << ")"
              << " changed: " << change_count;
     LogDevicePropertyChange(startup_failed, uma_result);
   }
   device_property_changes_map_.clear();
 }
 
+void AUAudioInputStream::UpdateCaptureTimestamp(
+    const AudioTimeStamp* timestamp) {
+  if ((timestamp->mFlags & kAudioTimeStampSampleTimeValid) == 0)
+    return;
+
+  if (last_sample_time_) {
+    DCHECK_NE(0U, last_number_of_frames_);
+    UInt32 diff =
+        static_cast<UInt32>(timestamp->mSampleTime - last_sample_time_);
+    if (diff != last_number_of_frames_) {
+      DCHECK_GT(diff, last_number_of_frames_);
+      // We were given samples post what we expected. Update the glitch count
+      // etc. and keep a record of the largest glitch.
+      auto lost_frames = diff - last_number_of_frames_;
+      total_lost_frames_ += lost_frames;
+      if (lost_frames > largest_glitch_frames_)
+        largest_glitch_frames_ = lost_frames;
+      ++glitches_detected_;
+    }
+  }
+
+  // Store the last sample time for use next time we get called back.
+  last_sample_time_ = timestamp->mSampleTime;
+}
+
+void AUAudioInputStream::ReportAndResetStats() {
+  if (last_sample_time_ == 0)
+    return;  // No stats gathered to report.
+
+  // A value of 0 indicates that we got the buffer size we asked for.
+  UMA_HISTOGRAM_COUNTS_10000("Media.Audio.Capture.FramesProvided",
+                             number_of_frames_provided_);
+  // Even if there aren't any glitches, we want to record it to get a feel for
+  // how often we get no glitches vs the alternative.
+  UMA_HISTOGRAM_COUNTS("Media.Audio.Capture.Glitches", glitches_detected_);
+
+  if (glitches_detected_ != 0) {
+    auto lost_frames_ms = (total_lost_frames_ * 1000) / format_.mSampleRate;
+    UMA_HISTOGRAM_LONG_TIMES("Media.Audio.Capture.LostFramesInMs",
+                             base::TimeDelta::FromMilliseconds(lost_frames_ms));
+    auto largest_glitch_ms =
+        (largest_glitch_frames_ * 1000) / format_.mSampleRate;
+    UMA_HISTOGRAM_CUSTOM_TIMES(
+        "Media.Audio.Capture.LargestGlitchMs",
+        base::TimeDelta::FromMilliseconds(largest_glitch_ms),
+        base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromMinutes(1),
+        50);
+    DLOG(WARNING) << "Total glitches=" << glitches_detected_
+                  << ". Total frames lost=" << total_lost_frames_ << " ("
+                  << lost_frames_ms;
+  }
+
+  number_of_frames_provided_ = 0;
+  glitches_detected_ = 0;
+  last_sample_time_ = 0;
+  last_number_of_frames_ = 0;
+  total_lost_frames_ = 0;
+  largest_glitch_frames_ = 0;
+}
+
 }  // namespace media