Add logging to Intelligibility Enhancer

webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.cc

Index: webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.cc
diff --git a/webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.cc b/webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.cc
index 243bd1222996fdfcfd6f5f38546ee7992c319ca4..e61ac27fb80f4927f2345df5531d8ebc2b6d2cff 100644
--- a/webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.cc
+++ b/webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.cc
@@ -17,6 +17,7 @@
 #include <numeric>
 
 #include "webrtc/base/checks.h"
+#include "webrtc/base/logging.h"
 #include "webrtc/common_audio/include/audio_util.h"
 #include "webrtc/common_audio/window_generator.h"
 
@@ -90,6 +91,7 @@ IntelligibilityEnhancer::IntelligibilityEnhancer(int sample_rate_hz,
       snr_(kMaxActiveSNR),
       is_active_(false),
       num_chunks_(0u),
+      num_active_chunks_(0u),
       noise_estimation_buffer_(num_noise_bins),
       noise_estimation_queue_(kMaxNumNoiseEstimatesToBuffer,
                               std::vector<float>(num_noise_bins),
@@ -110,6 +112,12 @@ IntelligibilityEnhancer::IntelligibilityEnhancer(int sample_rate_hz,
       kbd_window.data(), window_size, window_size / 2, this));
 }
 
+IntelligibilityEnhancer::~IntelligibilityEnhancer() {
+  LOG(LS_INFO) << "Intelligibility Enhancer was active for "

[hlundin-webrtc, 2016/06/30 08:59:36]

The dtor is not always executed at the end of a call. At least in Chrome, a fast
shutdown is performed if the user just closes the tab. +Ivo will know more about
this. But in essence, beware that you might not get the logging you expect.

[ivoc, 2016/06/30 09:13:48]

Indeed, don't rely on destructors being called in Chrome. It may make more sense
to log this periodically instead.

[aluebs-webrtc, 2016/06/30 23:21:54]

Thank you for pointing this out. I have been testing this a bit and it seems it
runs the destructor if the user hangs up, but it doesn't if they directly kill
the app from the app-switcher. I will leave this here, since I think it adds
value, but also added the num_chunk_ when the IE is activated and deactivated so
this percentage can be calculated from there if the destructor was not run.

+               << static_cast<float>(num_active_chunks_) / num_chunks_
+               << "%% of the call.";
+}
+
 void IntelligibilityEnhancer::SetCaptureNoiseEstimate(
     std::vector<float> noise, int gain_db) {
   RTC_DCHECK_EQ(noise.size(), num_noise_bins_);
@@ -146,25 +154,28 @@ void IntelligibilityEnhancer::ProcessAudioBlock(
     clear_power_estimator_.Step(in_block[0]);
   }
   SnrBasedEffectActivation();
-  if (is_active_ && num_chunks_++ % kGainUpdatePeriod == 0) {
-    MapToErbBands(clear_power_estimator_.power().data(), render_filter_bank_,
-                  filtered_clear_pow_.data());
-    MapToErbBands(noise_power_estimator_.power().data(), capture_filter_bank_,
-                  filtered_noise_pow_.data());
-    SolveForGainsGivenLambda(kLambdaTop, start_freq_, gains_eq_.data());
-    const float power_target = std::accumulate(
-        filtered_clear_pow_.data(),
-        filtered_clear_pow_.data() + bank_size_,
-        0.f);
-    const float power_top =
-        DotProduct(gains_eq_.data(), filtered_clear_pow_.data(), bank_size_);
-    SolveForGainsGivenLambda(kLambdaBot, start_freq_, gains_eq_.data());
-    const float power_bot =
-        DotProduct(gains_eq_.data(), filtered_clear_pow_.data(), bank_size_);
-    if (power_target >= power_bot && power_target <= power_top) {
-      SolveForLambda(power_target);
-      UpdateErbGains();
-    }  // Else experiencing power underflow, so do nothing.
+  if (is_active_) {
+    ++num_active_chunks_;
+    if (num_chunks_++ % kGainUpdatePeriod == 0) {
+      MapToErbBands(clear_power_estimator_.power().data(), render_filter_bank_,
+                    filtered_clear_pow_.data());
+      MapToErbBands(noise_power_estimator_.power().data(), capture_filter_bank_,
+                    filtered_noise_pow_.data());
+      SolveForGainsGivenLambda(kLambdaTop, start_freq_, gains_eq_.data());
+      const float power_target = std::accumulate(
+          filtered_clear_pow_.data(),
+          filtered_clear_pow_.data() + bank_size_,
+          0.f);
+      const float power_top =
+          DotProduct(gains_eq_.data(), filtered_clear_pow_.data(), bank_size_);
+      SolveForGainsGivenLambda(kLambdaBot, start_freq_, gains_eq_.data());
+      const float power_bot =
+          DotProduct(gains_eq_.data(), filtered_clear_pow_.data(), bank_size_);
+      if (power_target >= power_bot && power_target <= power_top) {
+        SolveForLambda(power_target);
+        UpdateErbGains();
+      }  // Else experiencing power underflow, so do nothing.
+    }
   }
   for (size_t i = 0; i < in_channels; ++i) {
     gain_applier_.Apply(in_block[i], out_block[i]);
@@ -182,6 +193,7 @@ void IntelligibilityEnhancer::SnrBasedEffectActivation() {
       (noise_power + std::numeric_limits<float>::epsilon());
   if (is_active_) {
     if (snr_ > kMaxActiveSNR) {
+      LOG(LS_INFO) << "Deactivating Intelligibility Enhancer.";
       is_active_ = false;
       // Set the target gains to unity.
       float* gains = gain_applier_.target();
@@ -190,7 +202,10 @@ void IntelligibilityEnhancer::SnrBasedEffectActivation() {
       }
     }
   } else {
-    is_active_ = snr_ < kMinInactiveSNR;
+    if (snr_ < kMinInactiveSNR) {
+      LOG(LS_INFO) << "Activating Intelligibility Enhancer.";
+      is_active_ = true;
+    }
   }
 }