AEC: Add UMA logging of buffer re-alignment

webrtc/modules/audio_processing/aec/aec_core.cc

 /*
  *  Copyright (c) 2012 The WebRTC project authors. All Rights Reserved.
  *
  *  Use of this source code is governed by a BSD-style license
  *  that can be found in the LICENSE file in the root of the source
  *  tree. An additional intellectual property rights grant can be found
  *  in the file PATENTS.  All contributing project authors may
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
@@ skipping 15 matching lines @@
 #include "webrtc/common_audio/ring_buffer.h"
 }
 #include "webrtc/base/checks.h"
 #include "webrtc/common_audio/signal_processing/include/signal_processing_library.h"
 #include "webrtc/modules/audio_processing/aec/aec_common.h"
 #include "webrtc/modules/audio_processing/aec/aec_core_optimized_methods.h"
 #include "webrtc/modules/audio_processing/aec/aec_rdft.h"
 #include "webrtc/modules/audio_processing/logging/apm_data_dumper.h"
 #include "webrtc/modules/audio_processing/utility/delay_estimator_wrapper.h"
 #include "webrtc/system_wrappers/include/cpu_features_wrapper.h"
+#include "webrtc/system_wrappers/include/metrics.h"
 #include "webrtc/typedefs.h"
 
 namespace webrtc {
+namespace {
+enum class DelaySource {
+  kSystemDelay,    // The delay values come from the OS.
+  kDelayAgnostic,  // The delay values come from the DA-AEC.
+};
+
+constexpr int kMinDelayLogValue = -200;
+constexpr int kMaxDelayLogValue = 200;
+constexpr int kNumDelayLogBuckets = 100;
+
+void MaybeLogDelayAdjustment(int moved_elements, DelaySource source) {
+  if (moved_elements == 0)
+    return;
+  switch (source) {
+    case DelaySource::kSystemDelay:
+      RTC_HISTOGRAM_COUNTS("WebRTC.Audio.AecDelayAdjustmentSystemValue",
+                           moved_elements, kMinDelayLogValue,
+                           kMaxDelayLogValue, kNumDelayLogBuckets);
+      return;
+    case DelaySource::kDelayAgnostic:
+      RTC_HISTOGRAM_COUNTS("WebRTC.Audio.AecDelayAdjustmentAgnosticValue",
+                           moved_elements, kMinDelayLogValue,
+                           kMaxDelayLogValue, kNumDelayLogBuckets);
+      return;
+  }

[peah-webrtc, 2016/05/18 08:22:11]

Is a default case needed, or is it fine to use like this when we are switching
agains an enum?

[hlundin-webrtc, 2016/05/18 10:15:44]

I believe it is fine. The compiler complains when I do not handle any of the
enum values.

+}
+}  // namespace
 
 // Buffer size (samples)
 static const size_t kBufSizePartitions = 250;  // 1 second of audio in 16 kHz.
 
 // Metrics
 static const size_t kSubCountLen = 4;
 static const size_t kCountLen = 50;
 static const int kDelayMetricsAggregationWindow = 1250;  // 5 seconds at 16 kHz.
 
 // Divergence metric is based on audio level, which gets updated every
@@ skipping 1729 matching lines @@
 
       // TODO(bjornv): Investigate how we should round the delay difference;
       // right now we know that incoming |knownDelay| is underestimated when
       // it's less than |aec->knownDelay|. We therefore, round (-32) in that
       // direction. In the other direction, we don't have this situation, but
       // might flush one partition too little. This can cause non-causality,
       // which should be investigated. Maybe, allow for a non-symmetric
       // rounding, like -16.
       int move_elements = (aec->knownDelay - knownDelay - 32) / PART_LEN;
       int moved_elements = WebRtc_MoveReadPtr(aec->far_time_buf, move_elements);
+      MaybeLogDelayAdjustment(moved_elements, DelaySource::kSystemDelay);

[hlundin-webrtc, 2016/05/18 08:04:30]

What is the unit for moved_elements? Should probably convert to ms.

[peah-webrtc, 2016/05/18 08:22:11]

For moved_elements below, each element corresponds to 4 ms in sample rate >= 16
kHz, and 8 ms in 8 kHz.

For this line, I'm not sure, but it would make sense to assume it is the same.

Please doublecheck my statement above!

[hlundin-webrtc, 2016/05/18 10:15:44]

Done.

       aec->knownDelay -= moved_elements * PART_LEN;
     } else {
       // 2 b) Apply signal based delay correction.
       int move_elements = SignalBasedDelayCorrection(aec);
       int moved_elements = WebRtc_MoveReadPtr(aec->far_time_buf, move_elements);
+      MaybeLogDelayAdjustment(moved_elements, DelaySource::kDelayAgnostic);

[peah-webrtc, 2016/05/18 08:22:11]

There is also delay adjustments being applied in echo_cancellation.cc (in the
EstBufDelayExtended(...) method). It could possibly make sense to log something
there as well?

[hlundin-webrtc, 2016/05/18 10:15:44]

Acknowledged. We'll keep that as a separate exercise.

       int far_near_buffer_diff =
           WebRtc_available_read(aec->far_time_buf) -
           WebRtc_available_read(aec->nearFrBuf) / PART_LEN;
       WebRtc_SoftResetDelayEstimator(aec->delay_estimator, moved_elements);
       WebRtc_SoftResetDelayEstimatorFarend(aec->delay_estimator_farend,
                                            moved_elements);
       aec->signal_delay_correction += moved_elements;
       // If we rely on reported system delay values only, a buffer underrun here
       // can never occur since we've taken care of that in 1) above.  Here, we
       // apply signal based delay correction and can therefore end up with
@@ skipping 134 matching lines @@
 
 int WebRtcAec_system_delay(AecCore* self) {
   return self->system_delay;
 }
 
 void WebRtcAec_SetSystemDelay(AecCore* self, int delay) {
   assert(delay >= 0);
   self->system_delay = delay;
 }
 }  // namespace webrtc