Add log message to help analyze why echo likelihood > 1.1

webrtc/modules/audio_processing/residual_echo_detector.cc

Index: webrtc/modules/audio_processing/residual_echo_detector.cc
diff --git a/webrtc/modules/audio_processing/residual_echo_detector.cc b/webrtc/modules/audio_processing/residual_echo_detector.cc
index b229d2e88f67847da0d313ea01dfbc48fde35f6d..2aeca420609ed4547db647bfb99b0e4594804efd 100644
--- a/webrtc/modules/audio_processing/residual_echo_detector.cc
+++ b/webrtc/modules/audio_processing/residual_echo_detector.cc
@@ -14,6 +14,7 @@
 #include <numeric>
 
 #include "webrtc/base/atomicops.h"
+#include "webrtc/base/logging.h"
 #include "webrtc/modules/audio_processing/audio_buffer.h"
 #include "webrtc/modules/audio_processing/logging/apm_data_dumper.h"
 #include "webrtc/system_wrappers/include/metrics.h"
@@ -113,6 +114,8 @@ void ResidualEchoDetector::AnalyzeCaptureAudio(
 
   // Update the covariance values and determine the new echo likelihood.
   echo_likelihood_ = 0.f;
+
+  int best_delay = -1;
   for (size_t delay = 0; delay < covariances_.size(); ++delay) {
     const size_t read_index =
         (kLookbackFrames + next_insertion_index_ - delay) % kLookbackFrames;
@@ -121,9 +124,38 @@ void ResidualEchoDetector::AnalyzeCaptureAudio(
                                capture_std_deviation, render_power_[read_index],
                                render_power_mean_[read_index],
                                render_power_std_dev_[read_index]);
-    echo_likelihood_ = std::max(
-        echo_likelihood_, covariances_[delay].normalized_cross_correlation());
+    if (covariances_[delay].normalized_cross_correlation() > echo_likelihood_) {
+      echo_likelihood_ = covariances_[delay].normalized_cross_correlation();
+      best_delay = delay;

[peah-webrtc, 2017/05/17 04:26:15]

I guess that the assignment in line 129 may fail on some platforms, as the
result may overflow (right?) You probably should do a static cast, or use an
optional<size_t> instead (but that is probably more expensive).

[ivoc, 2017/05/17 09:28:07]

I don't think it's possible for this assignment to fail on any platform. The
"delay" variable runs from 0 to kLookbackFrames, which is 650 (covariances_ has
a fixed size), which can easily be represented as an int. Since this is only a
temporary change and this is a simple solution, I would prefer to leave it like
this if that's okay with you.

[peah-webrtc, 2017/05/17 09:38:07]

Sorry, I meant that the compiler will complain. As you mention, the assignment
will not actually overflow. That is why I suggested the static_cast.

[ivoc, 2017/05/17 11:28:08]

Ah, that's a good point. Added static_cast.

+    }
+  }
+  // This is a temporary log message to help find the underlying cause for echo
+  // likelihoods > 1.0.
+  // TODO(ivoc): Remove once the issue is resolved.
+  if (echo_likelihood_ > 1.1f) {

[peah-webrtc, 2017/05/17 04:26:15]

Not fully sure about the static variable. I'd rather have chosen to have a
member variable instead, but I cannot see anything in the style guide that
forbids that.

[ivoc, 2017/05/17 09:28:07]

The reason I chose a static variable is so that all of the code for this log
message is localized here. But you're right that a member variable is a nicer
solution, so I changed this to be a member variable instead.

+    static int log_counter = 0;
+    // Make sure we don't spam the log.
+    if (log_counter < 5 && best_delay != -1) {
+      const size_t read_index =
+          (kLookbackFrames + next_insertion_index_ - best_delay) %

[peah-webrtc, 2017/05/17 04:26:15]

I just want to point out that the % operator involves a division. Please
consider using a conditional instead.

[ivoc, 2017/05/17 09:28:07]

You're right that divisions are slow, but this piece of code can be executed at
most 5 times, so it is not very performance critical. I also think that actually
logging the message will be much slower than a single division.

I did change this to an if statement instead of the division.

+          kLookbackFrames;
+      RTC_DCHECK_LT(read_index, render_power_.size());
+      LOG_F(LS_ERROR) << "Unexpected high echo likelihood value: "

[peah-webrtc, 2017/05/17 04:26:15]

Please consider using j-son type formatting, as in level_controller.cc. That
will simplify machine parsing of the log. That is a feedback that I've gotten
which I think makes sense, but in this case is probably not super necessary as
the logging is temporary. However, as you are listing a lot of variable values,
json-style may make sense in particular for that.

[ivoc, 2017/05/17 09:28:07]

That seems like a good idea, done.

+                      << echo_likelihood_ << ", delay: " << best_delay
+                      << ", covariance: "
+                      << covariances_[best_delay].covariance()
+                      << ", last capture power: " << capture_power
+                      << ", capture mean: " << capture_mean
+                      << ", capture_std_deviation: " << capture_std_deviation
+                      << ", last render power: " << render_power_[read_index]
+                      << ", render mean: " << render_power_mean_[read_index]
+                      << ", render std_deviation: "
+                      << render_power_std_dev_[read_index]
+                      << ", reliability: " << reliability_;
+      log_counter++;
+    }
   }
+
   reliability_ = (1.0f - kAlpha) * reliability_ + kAlpha * 1.0f;
   echo_likelihood_ *= reliability_;
   // This is a temporary fix to prevent echo likelihood values > 1.0.