Add logging to Intelligibility Enhancer

webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.cc

 /*
  *  Copyright (c) 2014 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.
  */
 
 #include "webrtc/modules/audio_processing/intelligibility/intelligibility_enhancer.h"
 
 #include <math.h>
 #include <stdlib.h>
 #include <algorithm>
 #include <limits>
 #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"
 
 namespace webrtc {
 
 namespace {
 
 const size_t kErbResolution = 2;
 const int kWindowSizeMs = 16;
 const int kChunkSizeMs = 10;  // Size provided by APM.
@@ skipping 53 matching lines @@
       capture_filter_bank_(CreateErbBank(num_noise_bins)),
       render_filter_bank_(CreateErbBank(freqs_)),
       gains_eq_(bank_size_),
       gain_applier_(freqs_, kMaxRelativeGainChange),
       audio_s16_(chunk_length_),
       chunks_since_voice_(kSpeechOffsetDelay),
       is_speech_(false),
       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),
                               RenderQueueItemVerifier<float>(num_noise_bins)) {
   RTC_DCHECK_LE(kRho, 1.f);
 
   const size_t erb_index = static_cast<size_t>(
       ceilf(11.17f * logf((kClipFreqKhz + 0.312f) / (kClipFreqKhz + 14.6575f)) +
             43.f));
   start_freq_ = std::max(static_cast<size_t>(1), erb_index * kErbResolution);
 
   size_t window_size = static_cast<size_t>(1) << RealFourier::FftOrder(freqs_);
   std::vector<float> kbd_window(window_size);
   WindowGenerator::KaiserBesselDerived(kKbdAlpha, window_size,
                                        kbd_window.data());
   render_mangler_.reset(new LappedTransform(
       num_render_channels_, num_render_channels_, chunk_length_,
       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_);
   const float gain = std::pow(10.f, gain_db / 20.f);
   for (auto& bin : noise) {
     bin *= gain;
   }
   // Disregarding return value since buffer overflow is acceptable, because it
   // is not critical to get each noise estimate.
   if (noise_estimation_queue_.Insert(&noise)) {
@@ skipping 16 matching lines @@
     const std::complex<float>* const* in_block,
     size_t in_channels,
     size_t frames,
     size_t /* out_channels */,
     std::complex<float>* const* out_block) {
   RTC_DCHECK_EQ(freqs_, frames);
   if (is_speech_) {
     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]);
   }
 }
 
 void IntelligibilityEnhancer::SnrBasedEffectActivation() {
   const float* clear_psd = clear_power_estimator_.power().data();
   const float* noise_psd = noise_power_estimator_.power().data();
   const float clear_power =
       std::accumulate(clear_psd, clear_psd + freqs_, 0.f);
   const float noise_power =
       std::accumulate(noise_psd, noise_psd + freqs_, 0.f);
   snr_ = kDecayRate * snr_ + (1.f - kDecayRate) * clear_power /
       (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();
       for (size_t i = 0; i < freqs_; ++i) {
         gains[i] = 1.f;
       }
     }
   } else {
-    is_active_ = snr_ < kMinInactiveSNR;
+    if (snr_ < kMinInactiveSNR) {
+      LOG(LS_INFO) << "Activating Intelligibility Enhancer.";
+      is_active_ = true;
+    }
   }
 }
 
 void IntelligibilityEnhancer::SolveForLambda(float power_target) {
   const float kConvergeThresh = 0.001f;  // TODO(ekmeyerson): Find best values
   const int kMaxIters = 100;             // for these, based on experiments.
 
   const float reciprocal_power_target =
       1.f / (power_target + std::numeric_limits<float>::epsilon());
   float lambda_bot = kLambdaBot;
@@ skipping 140 matching lines @@
   vad_.ProcessChunk(audio_s16_.data(), chunk_length_, sample_rate_hz_);
   if (vad_.last_voice_probability() > kVoiceProbabilityThreshold) {
     chunks_since_voice_ = 0;
   } else if (chunks_since_voice_ < kSpeechOffsetDelay) {
     ++chunks_since_voice_;
   }
   return chunks_since_voice_ < kSpeechOffsetDelay;
 }
 
 }  // namespace webrtc