AEC3: Add support for logging warnings on delay buffer changes
This reintroduces the WARNING log level of a previous CL [1],
via a default-off config flag.
[1] https://webrtc-review.googlesource.com/c/src/+/148528
Bug: None
Change-Id: Ica8583cbb24a1611cfc684ae02d5a0f582004024
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/156566
Commit-Queue: Sam Zackrisson <saza@webrtc.org>
Reviewed-by: Per Åhgren <peah@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#29489}
diff --git a/api/audio/echo_canceller3_config.h b/api/audio/echo_canceller3_config.h
index 7c8ca1b..efd6bb5 100644
--- a/api/audio/echo_canceller3_config.h
+++ b/api/audio/echo_canceller3_config.h
@@ -48,6 +48,7 @@
} delay_selection_thresholds = {5, 20};
bool use_external_delay_estimator = false;
bool downmix_before_delay_estimation = true;
+ bool log_warning_on_delay_changes = false;
} delay;
struct Filter {
diff --git a/api/audio/echo_canceller3_config_json.cc b/api/audio/echo_canceller3_config_json.cc
index c17497a..28aec9e 100644
--- a/api/audio/echo_canceller3_config_json.cc
+++ b/api/audio/echo_canceller3_config_json.cc
@@ -173,6 +173,8 @@
&cfg.delay.use_external_delay_estimator);
ReadParam(section, "downmix_before_delay_estimation",
&cfg.delay.downmix_before_delay_estimation);
+ ReadParam(section, "log_warning_on_delay_changes",
+ &cfg.delay.log_warning_on_delay_changes);
}
if (rtc::GetValueFromJsonObject(aec3_root, "filter", §ion)) {
@@ -361,7 +363,10 @@
ost << "\"use_external_delay_estimator\": "
<< (config.delay.use_external_delay_estimator ? "true" : "false") << ",";
ost << "\"downmix_before_delay_estimation\": "
- << (config.delay.downmix_before_delay_estimation ? "true" : "false");
+ << (config.delay.downmix_before_delay_estimation ? "true" : "false")
+ << ",";
+ ost << "\"log_warning_on_delay_changes\": "
+ << (config.delay.log_warning_on_delay_changes ? "true" : "false");
ost << "},";
ost << "\"filter\": {";
diff --git a/api/audio/test/echo_canceller3_config_json_unittest.cc b/api/audio/test/echo_canceller3_config_json_unittest.cc
index 5e98426..5274a0b 100644
--- a/api/audio/test/echo_canceller3_config_json_unittest.cc
+++ b/api/audio/test/echo_canceller3_config_json_unittest.cc
@@ -18,6 +18,7 @@
TEST(EchoCanceller3JsonHelpers, ToStringAndParseJson) {
EchoCanceller3Config cfg;
cfg.delay.down_sampling_factor = 1u;
+ cfg.delay.log_warning_on_delay_changes = true;
cfg.filter.shadow_initial.length_blocks = 7u;
cfg.suppressor.normal_tuning.mask_hf.enr_suppress = .5f;
std::string json_string = Aec3ConfigToJsonString(cfg);
@@ -34,6 +35,8 @@
// Expect changed values to carry through the transformation.
EXPECT_EQ(cfg.delay.down_sampling_factor,
cfg_transformed.delay.down_sampling_factor);
+ EXPECT_EQ(cfg.delay.log_warning_on_delay_changes,
+ cfg_transformed.delay.log_warning_on_delay_changes);
EXPECT_EQ(cfg.filter.shadow_initial.length_blocks,
cfg_transformed.filter.shadow_initial.length_blocks);
EXPECT_EQ(cfg.suppressor.normal_tuning.mask_hf.enr_suppress,
diff --git a/modules/audio_processing/aec3/block_processor.cc b/modules/audio_processing/aec3/block_processor.cc
index c02994b..fa9c7b3 100644
--- a/modules/audio_processing/aec3/block_processor.cc
+++ b/modules/audio_processing/aec3/block_processor.cc
@@ -171,8 +171,11 @@
bool delay_change =
render_buffer_->AlignFromDelay(estimated_delay_->delay);
if (delay_change) {
- RTC_LOG(LS_INFO) << "Delay changed to " << estimated_delay_->delay
- << " at block " << capture_call_counter_;
+ rtc::LoggingSeverity log_level =
+ config_.delay.log_warning_on_delay_changes ? rtc::LS_WARNING
+ : rtc::LS_INFO;
+ RTC_LOG_V(log_level) << "Delay changed to " << estimated_delay_->delay
+ << " at block " << capture_call_counter_;
echo_path_variability.delay_change =
EchoPathVariability::DelayAdjustment::kNewDetectedDelay;
}
diff --git a/modules/audio_processing/aec3/echo_remover.cc b/modules/audio_processing/aec3/echo_remover.cc
index 7cec47c..a05a389 100644
--- a/modules/audio_processing/aec3/echo_remover.cc
+++ b/modules/audio_processing/aec3/echo_remover.cc
@@ -334,7 +334,11 @@
if (gain_change_hangover_ == 0) {
constexpr int kMaxBlocksPerFrame = 3;
gain_change_hangover_ = kMaxBlocksPerFrame;
- RTC_LOG(LS_INFO) << "Gain change detected at block " << block_counter_;
+ rtc::LoggingSeverity log_level =
+ config_.delay.log_warning_on_delay_changes ? rtc::LS_WARNING
+ : rtc::LS_INFO;
+ RTC_LOG_V(log_level)
+ << "Gain change detected at block " << block_counter_;
} else {
echo_path_variability.gain_change = false;
}
diff --git a/modules/audio_processing/aec3/render_delay_buffer.cc b/modules/audio_processing/aec3/render_delay_buffer.cc
index bcaa566..6eb32e4 100644
--- a/modules/audio_processing/aec3/render_delay_buffer.cc
+++ b/modules/audio_processing/aec3/render_delay_buffer.cc
@@ -70,6 +70,7 @@
std::unique_ptr<ApmDataDumper> data_dumper_;
const Aec3Optimization optimization_;
const EchoCanceller3Config config_;
+ const rtc::LoggingSeverity delay_log_level_;
size_t down_sampling_factor_;
const int sub_block_size_;
BlockBuffer blocks_;
@@ -117,6 +118,9 @@
new ApmDataDumper(rtc::AtomicOps::Increment(&instance_count_))),
optimization_(DetectOptimization()),
config_(config),
+ delay_log_level_(config_.delay.log_warning_on_delay_changes
+ ? rtc::LS_WARNING
+ : rtc::LS_INFO),
down_sampling_factor_(config.delay.down_sampling_factor),
sub_block_size_(static_cast<int>(down_sampling_factor_ > 0
? kBlockSize / down_sampling_factor_
@@ -199,7 +203,7 @@
} else {
if (++num_api_calls_in_a_row_ > max_observed_jitter_) {
max_observed_jitter_ = num_api_calls_in_a_row_;
- RTC_LOG(LS_INFO)
+ RTC_LOG_V(delay_log_level_)
<< "New max number api jitter observed at render block "
<< render_call_counter_ << ": " << num_api_calls_in_a_row_
<< " blocks";
@@ -245,7 +249,7 @@
} else {
if (++num_api_calls_in_a_row_ > max_observed_jitter_) {
max_observed_jitter_ = num_api_calls_in_a_row_;
- RTC_LOG(LS_INFO)
+ RTC_LOG_V(delay_log_level_)
<< "New max number api jitter observed at capture block "
<< capture_call_counter_ << ": " << num_api_calls_in_a_row_
<< " blocks";
@@ -256,15 +260,15 @@
if (DetectExcessRenderBlocks()) {
// Too many render blocks compared to capture blocks. Risk of delay ending
// up before the filter used by the delay estimator.
- RTC_LOG(LS_INFO) << "Excess render blocks detected at block "
- << capture_call_counter_;
+ RTC_LOG_V(delay_log_level_)
+ << "Excess render blocks detected at block " << capture_call_counter_;
Reset();
event = BufferingEvent::kRenderOverrun;
} else if (RenderUnderrun()) {
// Don't increment the read indices of the low rate buffer if there is a
// render underrun.
- RTC_LOG(LS_INFO) << "Render buffer underrun detected at block "
- << capture_call_counter_;
+ RTC_LOG_V(delay_log_level_)
+ << "Render buffer underrun detected at block " << capture_call_counter_;
IncrementReadIndices();
// Incrementing the buffer index without increasing the low rate buffer
// index means that the delay is reduced by one.
@@ -293,9 +297,10 @@
if (!external_audio_buffer_delay_verified_after_reset_ &&
external_audio_buffer_delay_ && delay_) {
int difference = static_cast<int>(delay) - static_cast<int>(*delay_);
- RTC_LOG(LS_INFO) << "Mismatch between first estimated delay after reset "
- "and externally reported audio buffer delay: "
- << difference << " blocks";
+ RTC_LOG_V(delay_log_level_)
+ << "Mismatch between first estimated delay after reset "
+ "and externally reported audio buffer delay: "
+ << difference << " blocks";
external_audio_buffer_delay_verified_after_reset_ = true;
}
if (delay_ && *delay_ == delay) {
@@ -315,7 +320,7 @@
void RenderDelayBufferImpl::SetAudioBufferDelay(size_t delay_ms) {
if (!external_audio_buffer_delay_) {
- RTC_LOG(LS_INFO)
+ RTC_LOG_V(delay_log_level_)
<< "Receiving a first externally reported audio buffer delay of "
<< delay_ms << " ms.";
}
@@ -347,7 +352,8 @@
// Set the read indices according to the delay.
void RenderDelayBufferImpl::ApplyTotalDelay(int delay) {
- RTC_LOG(LS_INFO) << "Applying total delay of " << delay << " blocks.";
+ RTC_LOG_V(delay_log_level_)
+ << "Applying total delay of " << delay << " blocks.";
blocks_.read = blocks_.OffsetIndex(blocks_.write, -delay);
spectra_.read = spectra_.OffsetIndex(spectra_.write, delay);
ffts_.read = ffts_.OffsetIndex(ffts_.write, delay);
