Adds Media.Audio.InputDevicePropertyChangedMac UMA stat on Mac

media/audio/mac/audio_low_latency_input_mac.cc

Index: media/audio/mac/audio_low_latency_input_mac.cc
diff --git a/media/audio/mac/audio_low_latency_input_mac.cc b/media/audio/mac/audio_low_latency_input_mac.cc
index 4157c22396e222c7a35d54379f3e093365302012..8bec69da94700b1ddc783da27a1198ffecb56223 100644
--- a/media/audio/mac/audio_low_latency_input_mac.cc
+++ b/media/audio/mac/audio_low_latency_input_mac.cc
@@ -58,6 +58,36 @@ static std::ostream& operator<<(std::ostream& os,
   return os;
 }
 
+// Property address to monitor device changes. Use wildcards to match any and
+// all values for their associated type. Filtering for device-specific
+// notifications will take place in the callback.
+const AudioObjectPropertyAddress
+    AUAudioInputStream::kDeviceChangePropertyAddress = {
+        kAudioObjectPropertySelectorWildcard, kAudioObjectPropertyScopeWildcard,
+        kAudioObjectPropertyElementWildcard};
+
+// TODO(henrika): add comments...
+enum AudioDevicePropertyResult {
+  PROPERTY_DEVICE_HAS_CHANGED = 0,
+  PROPERTY_IO_STOPPED_ABNORMALLY = 1,

[o1ka, 2016/02/18 13:46:23]

I would not assign values to any but the first one - just to avoid somebody
following this style and assigning the same number multiple times.

[henrika (OOO until Aug 14), 2016/02/18 15:58:03]

This style is used all over Chrome in combination with UMA histograms. I have
been advices to use it before. See e.g.
https://code.google.com/p/chromium/codesearch#chromium/src/ui/gl/gl_surface_e...
or search for UMA_HISTOGRAM_ENUMERATION and you will find many examples.

[o1ka, 2016/02/18 16:54:30]

Thank you for the info, will save me some time in the future reviews :)

[henrika (OOO until Aug 14), 2016/02/19 12:46:11]

Acknowledged.

+  PROPERTY_HOG_MODE = 2,
+  PROPERTY_BUFFER_FRAME_SIZE = 3,
+  PROPERTY_BUFFER_FRAME_SIZE_RANGE = 4,
+  PROPERTY_STREAM_CONFIGURATION = 5,
+  PROPERTY_ACTUAL_SAMPLE_RATE = 6,
+  PROPERTY_NOMINAL_SAMPLE_RATE = 7,
+  PROPERTY_DEVICE_IS_RUNNING_SOMEWHERE = 8,
+  PROPERTY_DEVICE_IS_RUNNING = 9,
+  PROPERTY_DEVICE_IS_ALIVE = 10,
+  PROPERTY_MAX = PROPERTY_DEVICE_IS_ALIVE
+};
+
+// TODO(henrika): add comments...
+static void LogDevicePropertyChange(AudioDevicePropertyResult result) {
+  UMA_HISTOGRAM_ENUMERATION("Media.Audio.InputDevicePropertyChangedMac", result,
+                            PROPERTY_MAX + 1);
+}
+
 static OSStatus GetInputDeviceStreamFormat(
     AudioUnit audio_unit,
     AudioStreamBasicDescription* format) {
@@ -93,7 +123,8 @@ AUAudioInputStream::AUAudioInputStream(AudioManagerMac* manager,
       input_callback_is_active_(false),
       start_was_deferred_(false),
       buffer_size_was_changed_(false),
-      audio_unit_render_has_worked_(false) {
+      audio_unit_render_has_worked_(false),
+      device_listener_is_active_(false) {
   DCHECK(manager_);
 
   // Set up the desired (output) format specified by the client.
@@ -135,6 +166,7 @@ AUAudioInputStream::AUAudioInputStream(AudioManagerMac* manager,
 
 AUAudioInputStream::~AUAudioInputStream() {
   DVLOG(1) << "~dtor";
+  DeRegisterDeviceChangeListener();
 }
 
 // Obtain and open the AUHAL AudioOutputUnit for recording.
@@ -151,6 +183,8 @@ bool AUAudioInputStream::Open() {
     return false;
   }
 
+  RegisterDeviceChangeListener();
+
   // The requested sample-rate must match the hardware sample-rate.
   int sample_rate =
       AudioManagerMac::HardwareSampleRateForDevice(input_device_id_);
@@ -428,6 +462,7 @@ void AUAudioInputStream::Close() {
     Stop();
   }
   CloseAudioUnit();
+  DeRegisterDeviceChangeListener();
   // Inform the audio manager that we have been closed. This will cause our
   // destruction.
   manager_->ReleaseInputStream(this);
@@ -612,6 +647,10 @@ OSStatus AUAudioInputStream::OnDataIsAvailable(
   // be safe to modify.
   SetInputCallbackIsActive(true);
 
+  // We are only interested in device property changes in combination with
+  // failing input callbacks. Hence, might as well disable the listener now.
+  DeRegisterDeviceChangeListener();
+
   // 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|,
@@ -750,22 +789,94 @@ OSStatus AUAudioInputStream::Provide(UInt32 number_of_frames,
   return noErr;
 }
 
+OSStatus AUAudioInputStream::OnDevicePropertyChanged(

[o1ka, 2016/02/18 13:46:22]

Can there be a race between this call and deregistering |this| as a listener in
the destructor?

[henrika (OOO until Aug 14), 2016/02/18 15:58:03]

The call in the destructor is invalid (not needed) since we dereg in Close and
Close is responsible for the destruction. Will add a DCHECK just in case.

+    AudioObjectID object_id,
+    UInt32 num_addresses,
+    const AudioObjectPropertyAddress addresses[],
+    void* context) {
+  AUAudioInputStream* self = static_cast<AUAudioInputStream*>(context);
+  return self->DevicePropertyChanged(object_id, num_addresses, addresses);
+}
+
+OSStatus AUAudioInputStream::DevicePropertyChanged(
+    AudioObjectID object_id,
+    UInt32 num_addresses,
+    const AudioObjectPropertyAddress addresses[]) {
+  if (object_id != input_device_id_)
+    return noErr;
+
+  // Listeners will be called when possibly many properties have changed.

[o1ka, 2016/02/18 13:46:22]

Can the same listener be called concurrently?

[henrika (OOO until Aug 14), 2016/02/18 15:58:03]

The documentation does not say anything about that actually. Did some tests and
it seems like different types of callbacks can come from different threads (as
if some sort of thread pool was used). However, these callbacks simply must be
serialized somehow by the system and I have not found any example that uses
locks to make this method reentrant. 

+  // Consequently, the implementation of a listener must go through the array of
+  // addresses to see what exactly has changed.
+  for (UInt32 i = 0; i < num_addresses; ++i) {
+    const UInt32 property = addresses[i].mSelector;
+    switch (property) {
+      // Filter out and store certain property values provided by the
+      // AudioDevice class.
+      case kAudioDevicePropertyDeviceHasChanged:

[o1ka, 2016/02/18 13:46:22]

I would say that having both 'switch' and map is a bit of overkill, and having
switch in two places makes it a bit difficult to maintain without introducing
bugs. I would either store counters in an array by |PROPERTY_..| index and
update them here in a 'switch', or store everything in a map without using
'switch' here, and select what I'm interested in during
AddDevicePropertyChangesToUMA().

[henrika (OOO until Aug 14), 2016/02/18 15:58:03]

Great comment, thanks. Will add all to the map and filter at a later stage.

+      case kAudioDevicePropertyIOStoppedAbnormally:
+      case kAudioDevicePropertyHogMode:
+      case kAudioDevicePropertyBufferFrameSize:
+      case kAudioDevicePropertyBufferFrameSizeRange:
+      case kAudioDevicePropertyStreamConfiguration:
+      case kAudioDevicePropertyActualSampleRate:
+      case kAudioDevicePropertyNominalSampleRate:
+      case kAudioDevicePropertyDeviceIsRunningSomewhere:
+      case kAudioDevicePropertyDeviceIsRunning:
+      case kAudioDevicePropertyDeviceIsAlive:
+        // Use selector as key to a map and increase its value.
+        device_property_changes_map_[property]++;
+        break;
+      default:
+        // TODO(henrika): figure out if more property changes should be tracked.
+        DVLOG(1) << "No action for kAudioDeviceProperty: " << property;
+        break;
+    }
+  }
+  return noErr;
+}
+
+void AUAudioInputStream::RegisterDeviceChangeListener() {
+  DCHECK(thread_checker_.CalledOnValidThread());
+  DVLOG(1) << "RegisterDeviceChangeListener";
+  if (input_device_id_ == kAudioObjectUnknown)
+    return;
+
+  device_property_changes_map_.clear();
+
+  OSStatus result = AudioObjectAddPropertyListener(
+      input_device_id_, &kDeviceChangePropertyAddress,
+      &AUAudioInputStream::OnDevicePropertyChanged, this);
+  OSSTATUS_DLOG_IF(ERROR, result != noErr, result)
+      << "AudioObjectAddPropertyListener() failed!";
+  SetDeviceListenerIsActive(result == noErr);
+}
+
+void AUAudioInputStream::DeRegisterDeviceChangeListener() {
+  if (!GetDeviceListenerIsActive())
+    return;
+  DVLOG(1) << "DeRegisterDeviceChangeListener";
+  if (input_device_id_ == kAudioObjectUnknown)
+    return;
+  OSStatus result = AudioObjectRemovePropertyListener(

[o1ka, 2016/02/18 13:46:23]

Is it safe to call it second time if the first attempt failed?

[henrika (OOO until Aug 14), 2016/02/18 15:58:03]

I don't know since I've never been able to make the first call fail. Feels
unsafe to do so. Agree?

[o1ka, 2016/02/18 16:54:30]

Yes, I have the same feeling. In this case, it should be
SetDeviceListenerIsActive(false) before the call, I believe

[henrika (OOO until Aug 14), 2016/02/19 12:46:12]

Done.

+      input_device_id_, &kDeviceChangePropertyAddress,
+      &AUAudioInputStream::OnDevicePropertyChanged, this);
+  OSSTATUS_DLOG_IF(ERROR, result != noErr, result)
+      << "AudioObjectRemovePropertyListener() failed!";
+  SetDeviceListenerIsActive(!(result == noErr));
+}
+
 int AUAudioInputStream::HardwareSampleRate() {
   // Determine the default input device's sample-rate.
   AudioDeviceID device_id = kAudioObjectUnknown;
   UInt32 info_size = sizeof(device_id);
 
   AudioObjectPropertyAddress default_input_device_address = {
-    kAudioHardwarePropertyDefaultInputDevice,
-    kAudioObjectPropertyScopeGlobal,
-    kAudioObjectPropertyElementMaster
-  };
+      kAudioHardwarePropertyDefaultInputDevice, kAudioObjectPropertyScopeGlobal,
+      kAudioObjectPropertyElementMaster};
   OSStatus result = AudioObjectGetPropertyData(kAudioObjectSystemObject,
-                                               &default_input_device_address,
-                                               0,
-                                               0,
-                                               &info_size,
-                                               &device_id);
+                                               &default_input_device_address, 0,
+                                               0, &info_size, &device_id);
   if (result != noErr)
     return 0.0;
 
@@ -773,16 +884,10 @@ int AUAudioInputStream::HardwareSampleRate() {
   info_size = sizeof(nominal_sample_rate);
 
   AudioObjectPropertyAddress nominal_sample_rate_address = {
-    kAudioDevicePropertyNominalSampleRate,
-    kAudioObjectPropertyScopeGlobal,
-    kAudioObjectPropertyElementMaster
-  };
-  result = AudioObjectGetPropertyData(device_id,
-                                      &nominal_sample_rate_address,
-                                      0,
-                                      0,
-                                      &info_size,
-                                      &nominal_sample_rate);
+      kAudioDevicePropertyNominalSampleRate, kAudioObjectPropertyScopeGlobal,
+      kAudioObjectPropertyElementMaster};
+  result = AudioObjectGetPropertyData(device_id, &nominal_sample_rate_address,
+                                      0, 0, &info_size, &nominal_sample_rate);
   if (result != noErr)
     return 0.0;
 
@@ -798,40 +903,35 @@ double AUAudioInputStream::GetHardwareLatency() {
   // Get audio unit latency.
   Float64 audio_unit_latency_sec = 0.0;
   UInt32 size = sizeof(audio_unit_latency_sec);
-  OSStatus result = AudioUnitGetProperty(audio_unit_,
-                                         kAudioUnitProperty_Latency,
-                                         kAudioUnitScope_Global,
-                                         0,
-                                         &audio_unit_latency_sec,
-                                         &size);
+  OSStatus result = AudioUnitGetProperty(
+      audio_unit_, kAudioUnitProperty_Latency, kAudioUnitScope_Global, 0,
+      &audio_unit_latency_sec, &size);
   OSSTATUS_DLOG_IF(WARNING, result != noErr, result)
       << "Could not get audio unit latency";
 
   // Get input audio device latency.
   AudioObjectPropertyAddress property_address = {
-    kAudioDevicePropertyLatency,
-    kAudioDevicePropertyScopeInput,
-    kAudioObjectPropertyElementMaster
-  };
+      kAudioDevicePropertyLatency, kAudioDevicePropertyScopeInput,
+      kAudioObjectPropertyElementMaster};
   UInt32 device_latency_frames = 0;
   size = sizeof(device_latency_frames);
   result = AudioObjectGetPropertyData(input_device_id_, &property_address, 0,
                                       nullptr, &size, &device_latency_frames);
   DLOG_IF(WARNING, result != noErr) << "Could not get audio device latency.";
 
-  return static_cast<double>((audio_unit_latency_sec *
-      format_.mSampleRate) + device_latency_frames);
+  return static_cast<double>((audio_unit_latency_sec * format_.mSampleRate) +
+                             device_latency_frames);
 }
 
 double AUAudioInputStream::GetCaptureLatency(
     const AudioTimeStamp* input_time_stamp) {
   // Get the delay between between the actual recording instant and the time
   // when the data packet is provided as a callback.
-  UInt64 capture_time_ns = AudioConvertHostTimeToNanos(
-      input_time_stamp->mHostTime);
+  UInt64 capture_time_ns =
+      AudioConvertHostTimeToNanos(input_time_stamp->mHostTime);
   UInt64 now_ns = AudioConvertHostTimeToNanos(AudioGetCurrentHostTime());
-  double delay_frames = static_cast<double>
-      (1e-9 * (now_ns - capture_time_ns) * format_.mSampleRate);
+  double delay_frames = static_cast<double>(1e-9 * (now_ns - capture_time_ns) *
+                                            format_.mSampleRate);
 
   // Total latency is composed by the dynamic latency and the fixed
   // hardware latency.
@@ -841,10 +941,8 @@ double AUAudioInputStream::GetCaptureLatency(
 int AUAudioInputStream::GetNumberOfChannelsFromStream() {
   // Get the stream format, to be able to read the number of channels.
   AudioObjectPropertyAddress property_address = {
-    kAudioDevicePropertyStreamFormat,
-    kAudioDevicePropertyScopeInput,
-    kAudioObjectPropertyElementMaster
-  };
+      kAudioDevicePropertyStreamFormat, kAudioDevicePropertyScopeInput,
+      kAudioObjectPropertyElementMaster};
   AudioStreamBasicDescription stream_format;
   UInt32 size = sizeof(stream_format);
   OSStatus result = AudioObjectGetPropertyData(
@@ -877,8 +975,8 @@ void AUAudioInputStream::HandleError(OSStatus err) {
   // carries one extra level of information.
   UMA_HISTOGRAM_SPARSE_SLOWLY("Media.InputErrorMac",
                               GetInputCallbackIsActive() ? err : (err * -1));
-  NOTREACHED() << "error " << GetMacOSStatusErrorString(err)
-               << " (" << err << ")";
+  NOTREACHED() << "error " << GetMacOSStatusErrorString(err) << " (" << err
+               << ")";
   if (sink_)
     sink_->OnError(this);
 }
@@ -886,13 +984,10 @@ void AUAudioInputStream::HandleError(OSStatus err) {
 bool AUAudioInputStream::IsVolumeSettableOnChannel(int channel) {
   Boolean is_settable = false;
   AudioObjectPropertyAddress property_address = {
-    kAudioDevicePropertyVolumeScalar,
-    kAudioDevicePropertyScopeInput,
-    static_cast<UInt32>(channel)
-  };
-  OSStatus result = AudioObjectIsPropertySettable(input_device_id_,
-                                                  &property_address,
-                                                  &is_settable);
+      kAudioDevicePropertyVolumeScalar, kAudioDevicePropertyScopeInput,
+      static_cast<UInt32>(channel)};
+  OSStatus result = AudioObjectIsPropertySettable(
+      input_device_id_, &property_address, &is_settable);
   return (result == noErr) ? is_settable : false;
 }
 
@@ -904,8 +999,20 @@ bool AUAudioInputStream::GetInputCallbackIsActive() {
   return (base::subtle::Acquire_Load(&input_callback_is_active_) != false);
 }
 
+void AUAudioInputStream::SetDeviceListenerIsActive(bool enabled) {
+  base::subtle::Release_Store(&device_listener_is_active_, enabled);
+}
+
+bool AUAudioInputStream::GetDeviceListenerIsActive() {
+  return (base::subtle::Acquire_Load(&device_listener_is_active_) != false);
+}
+
 void AUAudioInputStream::CheckInputStartupSuccess() {
   DCHECK(thread_checker_.CalledOnValidThread());
+  // Remove the observer for changes in device properties. The notifier is
+  // currently only used to track down events that might lead to failure in
+  // starting input audio. Don't keep the observer alive longer than needed.
+  DeRegisterDeviceChangeListener();
   // Only add UMA stat related to failing input audio for streams where
   // the AGC has been enabled, e.g. WebRTC audio input streams.
   if (IsRunning() && GetAutomaticGainControl()) {
@@ -950,25 +1057,89 @@ void AUAudioInputStream::AddHistogramsForFailedStartup() {
                             manager_->low_latency_input_streams());
   UMA_HISTOGRAM_COUNTS_1000("Media.Audio.NumberOfBasicInputStreamsMac",
                             manager_->basic_input_streams());
-  // |number_of_frames_| is set at construction and corresponds to the requested
-  // (by the client) number of audio frames per I/O buffer connected to the
-  // selected input device. Ideally, this size will be the same as the native
-  // I/O buffer size given by |io_buffer_frame_size_|.
+  // |number_of_frames_| is set at construction and corresponds to the
+  // requested (by the client) number of audio frames per I/O buffer connected
+  // to the selected input device. Ideally, this size will be the same as the
+  // native I/O buffer size given by |io_buffer_frame_size_|.
   UMA_HISTOGRAM_SPARSE_SLOWLY("Media.Audio.RequestedInputBufferFrameSizeMac",
                               number_of_frames_);
   DVLOG(1) << "number_of_frames_: " << number_of_frames_;
-  // This value indicates the number of frames in the IO buffers connected to
-  // the selected input device. It has been set by the audio manger in Open()
-  // and can be the same as |number_of_frames_|, which is the desired buffer
-  // size. These two values might differ if other streams are using the same
-  // device and any of these streams have asked for a smaller buffer size.
+  // This value indicates the number of frames in the IO buffers connected
+  // to the selected input device. It has been set by the audio manger in
+  // Open() and can be the same as |number_of_frames_|, which is the desired
+  // buffer size. These two values might differ if other streams are using the
+  // same device and any of these streams have asked for a smaller buffer size.
   UMA_HISTOGRAM_SPARSE_SLOWLY("Media.Audio.ActualInputBufferFrameSizeMac",
                               io_buffer_frame_size_);
   DVLOG(1) << "io_buffer_frame_size_: " << io_buffer_frame_size_;
-  // TODO(henrika): this value will currently always report true. It should be
+  // TODO(henrika): this value will currently always report true. It should
+  // be
   // fixed when we understand the problem better.
   UMA_HISTOGRAM_BOOLEAN("Media.Audio.AutomaticGainControlMac",
                         GetAutomaticGainControl());
+  // TODO(henrika): add comments...
+  AddDevicePropertyChangesToUMA();
+}
+
+void AUAudioInputStream::AddDevicePropertyChangesToUMA() {
+  DVLOG(1) << "AddDevicePropertyChangesToUMA";
+  while (!device_property_changes_map_.empty()) {

[o1ka, 2016/02/18 13:46:22]

You could just iterate through the map from the beginning to the end and then
empty it after, it would be more efficient.

[henrika (OOO until Aug 14), 2016/02/18 15:58:03]

Thanks. Will change.

+    UInt32 device_property = device_property_changes_map_.begin()->first;
+    int change_count = device_property_changes_map_.begin()->second;
+    DVLOG(1) << "property: " << device_property << " changed: " << change_count;
+    AudioDevicePropertyResult uma_result = PROPERTY_MAX;
+    switch (device_property) {
+      case kAudioDevicePropertyDeviceHasChanged:
+        uma_result = PROPERTY_DEVICE_HAS_CHANGED;
+        DVLOG(1) << "kAudioDevicePropertyDeviceHasChanged";
+        break;
+      case kAudioDevicePropertyIOStoppedAbnormally:
+        uma_result = PROPERTY_IO_STOPPED_ABNORMALLY;
+        DVLOG(1) << "kAudioDevicePropertyIOStoppedAbnormally";
+        break;
+      case kAudioDevicePropertyHogMode:
+        uma_result = PROPERTY_HOG_MODE;
+        DVLOG(1) << "kAudioDevicePropertyHogMode";
+        break;
+      case kAudioDevicePropertyBufferFrameSize:
+        uma_result = PROPERTY_BUFFER_FRAME_SIZE;
+        DVLOG(1) << "kAudioDevicePropertyBufferFrameSize";
+        break;
+      case kAudioDevicePropertyBufferFrameSizeRange:
+        uma_result = PROPERTY_BUFFER_FRAME_SIZE_RANGE;
+        DVLOG(1) << "kAudioDevicePropertyBufferFrameSizeRange";
+        break;
+      case kAudioDevicePropertyStreamConfiguration:
+        uma_result = PROPERTY_STREAM_CONFIGURATION;
+        DVLOG(1) << "kAudioDevicePropertyStreamConfiguration";
+        break;
+      case kAudioDevicePropertyActualSampleRate:
+        uma_result = PROPERTY_ACTUAL_SAMPLE_RATE;
+        DVLOG(1) << "kAudioDevicePropertyActualSampleRate";
+        break;
+      case kAudioDevicePropertyNominalSampleRate:
+        uma_result = PROPERTY_NOMINAL_SAMPLE_RATE;
+        DVLOG(1) << "kAudioDevicePropertyNominalSampleRate";
+        break;
+      case kAudioDevicePropertyDeviceIsRunningSomewhere:
+        uma_result = PROPERTY_DEVICE_IS_RUNNING_SOMEWHERE;
+        DVLOG(1) << "kAudioDevicePropertyDeviceIsRunningSomewhere";
+        break;
+      case kAudioDevicePropertyDeviceIsRunning:
+        uma_result = PROPERTY_DEVICE_IS_RUNNING;
+        DVLOG(1) << "kAudioDevicePropertyDeviceIsRunning";
+        break;
+      case kAudioDevicePropertyDeviceIsAlive:
+        uma_result = PROPERTY_DEVICE_IS_ALIVE;
+        DVLOG(1) << "kAudioDevicePropertyDeviceIsAlive";
+        break;
+      default:
+        LOG(ERROR) << "Invalid device property change";
+        break;
+    }
+    LogDevicePropertyChange(uma_result);
+    device_property_changes_map_.erase(device_property_changes_map_.begin());
+  }
 }
 
 }  // namespace media