From d8243fa6b34c7e4d6fdaefbd85710703d773bf44 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Per=20=C3=85hgren?= Date: Thu, 22 Feb 2018 17:51:39 +0100 Subject: [PATCH] Adding reporting and logging for events of call API skew shifts MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Bug: webrtc:8887 Change-Id: I8a73afcd85815f4167ab47bd625f264747c06f8e Reviewed-on: https://webrtc-review.googlesource.com/53066 Reviewed-by: Henrik Lundin Commit-Queue: Per Åhgren Cr-Commit-Position: refs/heads/master@{#22193} --- .../aec3/render_delay_controller.cc | 24 ++++++++++++++++++- .../aec3/render_delay_controller_metrics.cc | 23 ++++++++++++++++-- .../aec3/render_delay_controller_metrics.h | 8 +++++-- ...ender_delay_controller_metrics_unittest.cc | 4 ++-- 4 files changed, 52 insertions(+), 7 deletions(-) diff --git a/modules/audio_processing/aec3/render_delay_controller.cc b/modules/audio_processing/aec3/render_delay_controller.cc index f2a7b54290..e97386efe0 100644 --- a/modules/audio_processing/aec3/render_delay_controller.cc +++ b/modules/audio_processing/aec3/render_delay_controller.cc @@ -22,6 +22,7 @@ #include "modules/audio_processing/aec3/skew_estimator.h" #include "rtc_base/atomicops.h" #include "rtc_base/constructormagic.h" +#include "rtc_base/logging.h" namespace webrtc { @@ -55,6 +56,9 @@ class RenderDelayControllerImpl final : public RenderDelayController { SkewEstimator skew_estimator_; rtc::Optional delay_samples_; rtc::Optional skew_; + int previous_offset_blocks_ = 0; + int skew_shift_reporting_counter_ = 0; + size_t capture_call_counter_ = 0; int delay_change_counter_ = 0; size_t soft_reset_counter_ = 0; RTC_DISALLOW_IMPLICIT_CONSTRUCTORS(RenderDelayControllerImpl); @@ -125,6 +129,7 @@ void RenderDelayControllerImpl::Reset() { delay_ = rtc::nullopt; delay_samples_ = rtc::nullopt; skew_ = rtc::nullopt; + previous_offset_blocks_ = 0; std::fill(delay_buf_.begin(), delay_buf_.end(), 0.f); delay_estimator_.Reset(false); skew_estimator_.Reset(); @@ -140,6 +145,7 @@ rtc::Optional RenderDelayControllerImpl::GetDelay( const DownsampledRenderBuffer& render_buffer, rtc::ArrayView capture) { RTC_DCHECK_EQ(kBlockSize, capture.size()); + ++capture_call_counter_; // Estimate the delay with a delayed capture. RTC_DCHECK_LT(delay_buf_index_ + kBlockSize - 1, delay_buf_.size()); @@ -201,6 +207,22 @@ rtc::Optional RenderDelayControllerImpl::GetDelay( } } + // Log any changes in the skew. + skew_shift_reporting_counter_ = + std::max(0, skew_shift_reporting_counter_ - 1); + rtc::Optional skew_shift = + skew_shift_reporting_counter_ == 0 && + previous_offset_blocks_ != offset_blocks + ? rtc::Optional(offset_blocks - previous_offset_blocks_) + : rtc::nullopt; + previous_offset_blocks_ = offset_blocks; + if (skew_shift) { + RTC_LOG(LS_WARNING) << "API call skew shift of " << *skew_shift + << " blocks detected at capture block " + << capture_call_counter_; + skew_shift_reporting_counter_ = 3 * kNumBlocksPerSecond; + } + if (delay_samples_) { // Compute the render delay buffer delay. delay_ = ComputeBufferDelay( @@ -210,7 +232,7 @@ rtc::Optional RenderDelayControllerImpl::GetDelay( metrics_.Update(delay_samples_ ? rtc::Optional(delay_samples_->delay) : rtc::nullopt, - delay_ ? delay_->delay : 0); + delay_ ? delay_->delay : 0, skew_shift); data_dumper_->DumpRaw("aec3_render_delay_controller_delay", delay_samples ? delay_samples->delay : 0); diff --git a/modules/audio_processing/aec3/render_delay_controller_metrics.cc b/modules/audio_processing/aec3/render_delay_controller_metrics.cc index 696ac29a73..e5668da1c1 100644 --- a/modules/audio_processing/aec3/render_delay_controller_metrics.cc +++ b/modules/audio_processing/aec3/render_delay_controller_metrics.cc @@ -36,10 +36,16 @@ enum class DelayChangesCategory { kNumCategories }; +constexpr int kMaxSkewShiftCount = 20; + } // namespace -void RenderDelayControllerMetrics::Update(rtc::Optional delay_samples, - size_t buffer_delay_blocks) { +RenderDelayControllerMetrics::RenderDelayControllerMetrics() = default; + +void RenderDelayControllerMetrics::Update( + rtc::Optional delay_samples, + size_t buffer_delay_blocks, + rtc::Optional skew_shift_blocks) { ++call_counter_; if (!initial_update) { @@ -52,6 +58,10 @@ void RenderDelayControllerMetrics::Update(rtc::Optional delay_samples, delay_blocks_ = delay_blocks; } } + + if (skew_shift_blocks) { + skew_shift_count_ = std::min(kMaxSkewShiftCount, skew_shift_count_); + } } else if (++initial_call_counter_ == 5 * kNumBlocksPerSecond) { initial_update = false; } @@ -107,6 +117,15 @@ void RenderDelayControllerMetrics::Update(rtc::Optional delay_samples, } else { metrics_reported_ = false; } + + if (!initial_update && ++skew_report_timer_ == 60 * kNumBlocksPerSecond) { + RTC_HISTOGRAM_COUNTS_LINEAR("WebRTC.Audio.EchoCanceller.MaxSkewShiftCount", + skew_shift_count_, 0, kMaxSkewShiftCount, + kMaxSkewShiftCount + 1); + + skew_shift_count_ = 0; + skew_report_timer_ = 0; + } } void RenderDelayControllerMetrics::ResetMetrics() { diff --git a/modules/audio_processing/aec3/render_delay_controller_metrics.h b/modules/audio_processing/aec3/render_delay_controller_metrics.h index a93f0764ed..8c8845e62c 100644 --- a/modules/audio_processing/aec3/render_delay_controller_metrics.h +++ b/modules/audio_processing/aec3/render_delay_controller_metrics.h @@ -19,10 +19,12 @@ namespace webrtc { // Handles the reporting of metrics for the render delay controller. class RenderDelayControllerMetrics { public: - RenderDelayControllerMetrics() = default; + RenderDelayControllerMetrics(); // Updates the metric with new data. - void Update(rtc::Optional delay_samples, size_t buffer_delay_blocks); + void Update(rtc::Optional delay_samples, + size_t buffer_delay_blocks, + rtc::Optional skew_shift_blocks); // Returns true if the metrics have just been reported, otherwise false. bool MetricsReported() { return metrics_reported_; } @@ -35,9 +37,11 @@ class RenderDelayControllerMetrics { int reliable_delay_estimate_counter_ = 0; int delay_change_counter_ = 0; int call_counter_ = 0; + int skew_report_timer_ = 0; int initial_call_counter_ = 0; bool metrics_reported_ = false; bool initial_update = true; + int skew_shift_count_ = 0; RTC_DISALLOW_COPY_AND_ASSIGN(RenderDelayControllerMetrics); }; diff --git a/modules/audio_processing/aec3/render_delay_controller_metrics_unittest.cc b/modules/audio_processing/aec3/render_delay_controller_metrics_unittest.cc index 433c249554..1129f499c9 100644 --- a/modules/audio_processing/aec3/render_delay_controller_metrics_unittest.cc +++ b/modules/audio_processing/aec3/render_delay_controller_metrics_unittest.cc @@ -22,10 +22,10 @@ TEST(RenderDelayControllerMetrics, NormalUsage) { for (int j = 0; j < 3; ++j) { for (int k = 0; k < kMetricsReportingIntervalBlocks - 1; ++k) { - metrics.Update(rtc::nullopt, 0); + metrics.Update(rtc::nullopt, 0, rtc::nullopt); EXPECT_FALSE(metrics.MetricsReported()); } - metrics.Update(rtc::nullopt, 0); + metrics.Update(rtc::nullopt, 0, rtc::nullopt); EXPECT_TRUE(metrics.MetricsReported()); } }