Adds Media.Audio.InputStartupSuccessMac UMA stat for Mac OS X

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 "base/basictypes.h"
 #include "base/logging.h"
 #include "base/mac/mac_logging.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/metrics/sparse_histogram.h"
+#include "base/time/time.h"
 #include "media/audio/mac/audio_manager_mac.h"
 #include "media/base/audio_bus.h"
 #include "media/base/data_buffer.h"
 
 namespace media {
 
 // Number of blocks of buffers used in the |fifo_|.
 const int kNumberOfBlocksBufferInFifo = 2;
 
 // Max length of sequence of TooManyFramesToProcessError errors.
 // The stream will be stopped as soon as this time limit is passed.
 const int kMaxErrorTimeoutInSeconds = 1;
 
+// A one-shot timer is created and started in Start() and it triggers
+// CheckInputStartupSuccess() after this amount of time. UMA stats marked
+// Media.Audio.InputStartupSuccessMac is then updated where true is added
+// if input callbacks have started, and false otherwise.
+const int kInputCallbackStartTimeoutInSeconds = 5;
+
 static std::ostream& operator<<(std::ostream& os,
                                 const AudioStreamBasicDescription& format) {
   os << "sample rate       : " << format.mSampleRate << std::endl
      << "format ID         : " << format.mFormatID << std::endl
      << "format flags      : " << format.mFormatFlags << std::endl
      << "bytes per packet  : " << format.mBytesPerPacket << std::endl
      << "frames per packet : " << format.mFramesPerPacket << std::endl
      << "bytes per frame   : " << format.mBytesPerFrame << std::endl
      << "channels per frame: " << format.mChannelsPerFrame << std::endl
      << "bits per channel  : " << format.mBitsPerChannel;
@@ skipping 10 matching lines @@
     : manager_(manager),
       number_of_frames_(input_params.frames_per_buffer()),
       sink_(NULL),
       audio_unit_(0),
       input_device_id_(audio_device_id),
       started_(false),
       hardware_latency_frames_(0),
       number_of_channels_in_frame_(0),
       fifo_(input_params.channels(),
             number_of_frames_,
-            kNumberOfBlocksBufferInFifo) {
+            kNumberOfBlocksBufferInFifo),
+      input_callback_is_active_(false) {
   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;
   format_.mBitsPerChannel = input_params.bits_per_sample();
   format_.mChannelsPerFrame = input_params.channels();
   format_.mFramesPerPacket = 1;  // uncompressed audio
@@ skipping 17 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() {}
 
 // Obtain and open the AUHAL AudioOutputUnit for recording.
 bool AUAudioInputStream::Open() {
+  DCHECK(thread_checker_.CalledOnValidThread());
   // Verify that we are not already opened.
   if (audio_unit_)
     return false;
 
   // Verify that we have a valid device.
   if (input_device_id_ == kAudioObjectUnknown) {
     NOTREACHED() << "Device ID is unknown";
     return false;
   }
 
@@ skipping 114 matching lines @@
   hardware_latency_frames_ = GetHardwareLatency();
 
   // The master channel is 0, Left and right are channels 1 and 2.
   // And the master channel is not counted in |number_of_channels_in_frame_|.
   number_of_channels_in_frame_ = GetNumberOfChannelsFromStream();
 
   return true;
 }
 
 void AUAudioInputStream::Start(AudioInputCallback* callback) {
+  DCHECK(thread_checker_.CalledOnValidThread());
   DCHECK(callback);
   DLOG_IF(ERROR, !audio_unit_) << "Open() has not been called successfully";
   if (started_ || !audio_unit_)
     return;
 
   // Check if we should defer Start() for http://crbug.com/160920.
   if (manager_->ShouldDeferStreamStart()) {
     // Use a cancellable closure so that if Stop() is called before Start()
     // actually runs, we can cancel the pending start.
     deferred_start_cb_.Reset(base::Bind(
         &AUAudioInputStream::Start, base::Unretained(this), callback));
     manager_->GetTaskRunner()->PostDelayedTask(
         FROM_HERE,
         deferred_start_cb_.callback(),
         base::TimeDelta::FromSeconds(
             AudioManagerMac::kStartDelayInSecsForPowerEvents));
     return;
   }
 
   sink_ = callback;
   last_success_time_ = base::TimeTicks::Now();
   StartAgc();
   OSStatus result = AudioOutputUnitStart(audio_unit_);
   if (result == noErr) {
     started_ = true;
+    // For UMA stat purposes, start a one-shot timer which detects when input
+    // callbacks starts indicating if input audio recording works as intended.
+    // CheckInputStartupSuccess() will check if |input_callback_is_active_| is
+    // true when the timer expires. This timer delay is currently set to
+    // 5 seconds to avoid false alarms.
+    input_callback_timer_.reset(new base::OneShotTimer());
+    input_callback_timer_->Start(
+        FROM_HERE,
+        base::TimeDelta::FromSeconds(kInputCallbackStartTimeoutInSeconds), this,

[tommi (sloooow) - chröme, 2015/10/30 15:08:44]

I think this uses base::Unretained() and due to that there may be a race since
the timer is created on the audio thread, destroyed there as well, but executes
on the browser thread (right?) and there it uses an unretained pointer to the
AUAudioInputStream object.  So if the timer is executing at the time the stream
is being deleted, we would have a use after free problem.

[henrika (OOO until Aug 14), 2015/10/30 15:56:35]

Discussed off line. Special case for Mac which does not create a unique
AudioThread but uses the main browser thread instead.

+        &AUAudioInputStream::CheckInputStartupSuccess);
   }
   OSSTATUS_DLOG_IF(ERROR, result != noErr, result)
       << "Failed to start acquiring data";
 }
 
 void AUAudioInputStream::Stop() {
+  DCHECK(thread_checker_.CalledOnValidThread());
   if (!started_)
     return;
   StopAgc();
+  input_callback_timer_.reset();
   OSStatus result = AudioOutputUnitStop(audio_unit_);
   DCHECK_EQ(result, noErr);
+  SetInputCallbackIsActive(false);
   started_ = false;
   sink_ = NULL;
   fifo_.Clear();
-
   OSSTATUS_DLOG_IF(ERROR, result != noErr, result)
       << "Failed to stop acquiring data";
 }
 
 void AUAudioInputStream::Close() {
+  DCHECK(thread_checker_.CalledOnValidThread());
   // It is valid to call Close() before calling open or Start().
   // It is also valid to call Close() after Start() has been called.
   if (started_) {
     Stop();
   }
   if (audio_unit_) {
     // Deallocate the audio unit’s resources.
     OSStatus result = AudioUnitUninitialize(audio_unit_);
     OSSTATUS_DLOG_IF(ERROR, result != noErr, result)
         << "AudioUnitUninitialize() failed.";
@@ skipping 82 matching lines @@
   // Update the AGC volume level based on the last setting above. Note that,
   // the volume-level resolution is not infinite and it is therefore not
   // possible to assume that the volume provided as input parameter can be
   // used directly. Instead, a new query to the audio hardware is required.
   // This method does nothing if AGC is disabled.
   UpdateAgcVolume();
 }
 
 double AUAudioInputStream::GetVolume() {
   // Verify that we have a valid device.
-  if (input_device_id_ == kAudioObjectUnknown){
+  if (input_device_id_ == kAudioObjectUnknown) {
     NOTREACHED() << "Device ID is unknown";
     return 0.0;
   }
 
   AudioObjectPropertyAddress property_address = {
     kAudioDevicePropertyVolumeScalar,
     kAudioDevicePropertyScopeInput,
     kAudioObjectPropertyElementMaster
   };
 
@@ skipping 73 matching lines @@
                                        UInt32 number_of_frames,
                                        AudioBufferList* io_data) {
   // Verify that the correct bus is used (Input bus/Element 1)
   DCHECK_EQ(bus_number, static_cast<UInt32>(1));
   AUAudioInputStream* audio_input =
       reinterpret_cast<AUAudioInputStream*>(user_data);
   DCHECK(audio_input);
   if (!audio_input)
     return kAudioUnitErr_InvalidElement;
 
+  // Indicate that input callbacks have started on the internal AUHAL IO
+  // thread. The |input_callback_is_active_| member is read from the creating
+  // thread when a timer fires once and set to false in Stop() on the same
+  // thread. It means that this thread is the only writer of
+  // |input_callback_is_active_| once the tread starts and it should therefore
+  // be safe to compare and then modify.
+  if (!audio_input->GetInputCallbackIsActive())

[tommi (sloooow) - chröme, 2015/10/30 15:08:44]

is this check necessary?

[henrika (OOO until Aug 14), 2015/10/30 15:56:35]

Not really; removed. Now only calls Set.

+    audio_input->SetInputCallbackIsActive(true);
+
   // Update the |mDataByteSize| value in the audio_buffer_list() since
   // |number_of_frames| can be changed on the fly.
   // |mDataByteSize| needs to be exactly mapping to |number_of_frames|,
   // otherwise it will put CoreAudio into bad state and results in
   // AudioUnitRender() returning -50 for the new created stream.
   // We have also seen kAudioUnitErr_TooManyFramesToProcess (-10874) and
   // kAudioUnitErr_CannotDoInCurrentContext (-10863) as error codes.
   // See crbug/428706 for details.
   UInt32 new_size = number_of_frames * audio_input->format_.mBytesPerFrame;
   AudioBuffer* audio_buffer = audio_input->audio_buffer_list()->mBuffers;
@@ skipping 231 matching lines @@
     kAudioDevicePropertyVolumeScalar,
     kAudioDevicePropertyScopeInput,
     static_cast<UInt32>(channel)
   };
   OSStatus result = AudioObjectIsPropertySettable(input_device_id_,
                                                   &property_address,
                                                   &is_settable);
   return (result == noErr) ? is_settable : false;
 }
 
+void AUAudioInputStream::SetInputCallbackIsActive(bool enabled) {
+  base::subtle::Release_Store(&input_callback_is_active_, enabled);
+}
+
+bool AUAudioInputStream::GetInputCallbackIsActive() {
+  return (base::subtle::Acquire_Load(&input_callback_is_active_) != false);
+}
+
+void AUAudioInputStream::CheckInputStartupSuccess() {
+  DCHECK(thread_checker_.CalledOnValidThread());

[tommi (sloooow) - chröme, 2015/10/30 15:08:44]

hmm... this suggests that we're actually not on the main thread but on the audio
thread, right?

[henrika (OOO until Aug 14), 2015/10/30 15:56:35]

For the record, we are on the main thread. Special case for Mac.

+  if (started_) {
+    // Check if we have called Start() and input callbacks have actually
+    // started in time as they should. If that is not the case, we have a
+    // problem and the stream is considered dead.
+    const bool input_callback_is_active = GetInputCallbackIsActive();
+    UMA_HISTOGRAM_BOOLEAN("Media.Audio.InputStartupSuccessMac",
+                          input_callback_is_active);
+    DVLOG(1) << "input_callback_is_active: " << input_callback_is_active;
+
+    if (!input_callback_is_active) {
+      // TODO(henrika): perhaps we should close the stream here and trigger
+      // HandleError with as suitable error code.
+    }
+  }
+}
+
 }  // namespace media