AEC: Add UMA logging of buffer re-alignment

webrtc/modules/audio_processing/aec/aec_core.cc

Index: webrtc/modules/audio_processing/aec/aec_core.cc
diff --git a/webrtc/modules/audio_processing/aec/aec_core.cc b/webrtc/modules/audio_processing/aec/aec_core.cc
index 2cb6dd2ce7664cfc302b388644ccd77fca44c43a..83218f3432c5e4eacb7c866676064eadc5ba445f 100644
--- a/webrtc/modules/audio_processing/aec/aec_core.cc
+++ b/webrtc/modules/audio_processing/aec/aec_core.cc
@@ -33,9 +33,37 @@ extern "C" {
 #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.
@@ -1785,11 +1813,13 @@ void WebRtcAec_ProcessFrames(AecCore* aec,
       // 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;