Adds logging of native audio levels and UMA stats to track issues.
This changes added a simple measurement of levels "close to the audio hardware"
both for playout and for recording. These levels are logged once each 10 seconds.
It also adds WebRTC.Audio.RecordedOnlyZeros UMA stat and it is updated at
destuction. It will report true iff all reported recording leves are zero.
BUG=NONE
R=peah@webrtc.org
Review URL: https://codereview.webrtc.org/2328433003 .
Cr-Commit-Position: refs/heads/master@{#14160}
diff --git a/webrtc/modules/audio_device/audio_device_buffer.cc b/webrtc/modules/audio_device/audio_device_buffer.cc
index 5a65288..f87e068 100644
--- a/webrtc/modules/audio_device/audio_device_buffer.cc
+++ b/webrtc/modules/audio_device/audio_device_buffer.cc
@@ -18,7 +18,9 @@
#include "webrtc/base/logging.h"
#include "webrtc/base/format_macros.h"
#include "webrtc/base/timeutils.h"
+#include "webrtc/common_audio/signal_processing/include/signal_processing_library.h"
#include "webrtc/modules/audio_device/audio_device_config.h"
+#include "webrtc/system_wrappers/include/metrics.h"
namespace webrtc {
@@ -59,7 +61,10 @@
last_rec_samples_(0),
play_samples_(0),
last_play_samples_(0),
- last_log_stat_time_(0) {
+ last_log_stat_time_(0),
+ max_rec_level_(0),
+ max_play_level_(0),
+ num_rec_level_is_zero_(0) {
LOG(INFO) << "AudioDeviceBuffer::ctor";
// TODO(henrika): improve buffer handling and ensure that we don't allocate
// more than what is required.
@@ -88,6 +93,16 @@
LOG(INFO) << "average: "
<< static_cast<float>(total_diff_time) / num_measurements;
}
+
+ // Add UMA histogram to keep track of the case when only zeros have been
+ // recorded. Ensure that recording callbacks have started and that at least
+ // one timer event has been able to update |num_rec_level_is_zero_|.
+ // I am avoiding use of the task queue here since we are under destruction
+ // and reading these members on the creating thread feels safe.
+ if (rec_callbacks_ > 0 && num_stat_reports_ > 0) {
+ RTC_LOGGED_HISTOGRAM_BOOLEAN("WebRTC.Audio.RecordedOnlyZeros",
+ static_cast<int>(num_stat_reports_ == num_rec_level_is_zero_));
+ }
}
int32_t AudioDeviceBuffer::RegisterAudioCallback(
@@ -101,7 +116,7 @@
int32_t AudioDeviceBuffer::InitPlayout() {
LOG(INFO) << __FUNCTION__;
RTC_DCHECK(thread_checker_.CalledOnValidThread());
- last_playout_time_ = rtc::TimeMillis();
+ ResetPlayStats();
if (!timer_has_started_) {
StartTimer();
timer_has_started_ = true;
@@ -112,6 +127,7 @@
int32_t AudioDeviceBuffer::InitRecording() {
LOG(INFO) << __FUNCTION__;
RTC_DCHECK(thread_checker_.CalledOnValidThread());
+ ResetRecStats();
if (!timer_has_started_) {
StartTimer();
timer_has_started_ = true;
@@ -266,8 +282,8 @@
// Update some stats but do it on the task queue to ensure that the members
// are modified and read on the same thread.
- task_queue_.PostTask(
- rtc::Bind(&AudioDeviceBuffer::UpdateRecStats, this, num_samples));
+ task_queue_.PostTask(rtc::Bind(&AudioDeviceBuffer::UpdateRecStats, this,
+ audio_buffer, num_samples));
return 0;
}
@@ -336,8 +352,8 @@
// Update some stats but do it on the task queue to ensure that access of
// members is serialized hence avoiding usage of locks.
- task_queue_.PostTask(
- rtc::Bind(&AudioDeviceBuffer::UpdatePlayStats, this, num_samples_out));
+ task_queue_.PostTask(rtc::Bind(&AudioDeviceBuffer::UpdatePlayStats, this,
+ &play_buffer_[0], num_samples_out));
return static_cast<int32_t>(num_samples_out);
}
@@ -366,6 +382,7 @@
}
void AudioDeviceBuffer::StartTimer() {
+ num_stat_reports_ = 0;
last_log_stat_time_ = rtc::TimeMillis();
task_queue_.PostDelayedTask(rtc::Bind(&AudioDeviceBuffer::LogStats, this),
kTimerIntervalInMilliseconds);
@@ -390,7 +407,8 @@
<< "kHz] callbacks: " << rec_callbacks_ - last_rec_callbacks_
<< ", "
<< "samples: " << diff_samples << ", "
- << "rate: " << rate;
+ << "rate: " << rate << ", "
+ << "level: " << max_rec_level_;
diff_samples = play_samples_ - last_play_samples_;
rate = diff_samples / kTimerIntervalInSeconds;
@@ -399,13 +417,22 @@
<< "kHz] callbacks: " << play_callbacks_ - last_play_callbacks_
<< ", "
<< "samples: " << diff_samples << ", "
- << "rate: " << rate;
+ << "rate: " << rate << ", "
+ << "level: " << max_play_level_;
+ }
+
+ // Count number of times we detect "no audio" corresponding to a case where
+ // all level measurements have been zero.
+ if (max_rec_level_ == 0) {
+ ++num_rec_level_is_zero_;
}
last_rec_callbacks_ = rec_callbacks_;
last_play_callbacks_ = play_callbacks_;
last_rec_samples_ = rec_samples_;
last_play_samples_ = play_samples_;
+ max_rec_level_ = 0;
+ max_play_level_ = 0;
int64_t time_to_wait_ms = next_callback_time - rtc::TimeMillis();
RTC_DCHECK_GT(time_to_wait_ms, 0) << "Invalid timer interval";
@@ -416,16 +443,58 @@
time_to_wait_ms);
}
-void AudioDeviceBuffer::UpdateRecStats(size_t num_samples) {
+void AudioDeviceBuffer::ResetRecStats() {
+ rec_callbacks_ = 0;
+ last_rec_callbacks_ = 0;
+ rec_samples_ = 0;
+ last_rec_samples_ = 0;
+ max_rec_level_ = 0;
+ num_rec_level_is_zero_ = 0;
+}
+
+void AudioDeviceBuffer::ResetPlayStats() {
+ last_playout_time_ = rtc::TimeMillis();
+ play_callbacks_ = 0;
+ last_play_callbacks_ = 0;
+ play_samples_ = 0;
+ last_play_samples_ = 0;
+ max_play_level_ = 0;
+}
+
+void AudioDeviceBuffer::UpdateRecStats(const void* audio_buffer,
+ size_t num_samples) {
RTC_DCHECK(task_queue_.IsCurrent());
++rec_callbacks_;
rec_samples_ += num_samples;
+
+ // Find the max absolute value in an audio packet twice per second and update
+ // |max_rec_level_| to track the largest value.
+ if (rec_callbacks_ % 50 == 0) {
+ int16_t max_abs = WebRtcSpl_MaxAbsValueW16(
+ static_cast<int16_t*>(const_cast<void*>(audio_buffer)),
+ num_samples * rec_channels_);
+ if (max_abs > max_rec_level_) {
+ max_rec_level_ = max_abs;
+ }
+ }
}
-void AudioDeviceBuffer::UpdatePlayStats(size_t num_samples) {
+void AudioDeviceBuffer::UpdatePlayStats(const void* audio_buffer,
+ size_t num_samples) {
RTC_DCHECK(task_queue_.IsCurrent());
++play_callbacks_;
play_samples_ += num_samples;
+
+ // Find the max absolute value in an audio packet twice per second and update
+ // |max_play_level_| to track the largest value.
+ if (play_callbacks_ % 50 == 0) {
+ int16_t max_abs = WebRtcSpl_MaxAbsValueW16(
+ static_cast<int16_t*>(const_cast<void*>(audio_buffer)),
+ num_samples * play_channels_);
+ if (max_abs > max_play_level_) {
+ max_play_level_ = max_abs;
+ }
+ }
}
} // namespace webrtc
diff --git a/webrtc/modules/audio_device/audio_device_buffer.h b/webrtc/modules/audio_device/audio_device_buffer.h
index e384a31..5c4a063 100644
--- a/webrtc/modules/audio_device/audio_device_buffer.h
+++ b/webrtc/modules/audio_device/audio_device_buffer.h
@@ -86,11 +86,15 @@
// Called periodically on the internal thread created by the TaskQueue.
void LogStats();
+ // Clears all members tracking stats for recording and playout.
+ void ResetRecStats();
+ void ResetPlayStats();
+
// Updates counters in each play/record callback but does it on the task
// queue to ensure that they can be read by LogStats() without any locks since
// each task is serialized by the task queue.
- void UpdateRecStats(size_t num_samples);
- void UpdatePlayStats(size_t num_samples);
+ void UpdateRecStats(const void* audio_buffer, size_t num_samples);
+ void UpdatePlayStats(const void* audio_buffer, size_t num_samples);
// Ensures that methods are called on the same thread as the thread that
// creates this object.
@@ -199,6 +203,23 @@
// Writing to the array is done without a lock since it is only read once at
// destruction when no audio is running.
uint32_t playout_diff_times_[kMaxDeltaTimeInMs + 1] = {0};
+
+ // Contains max level (max(abs(x))) of recorded audio packets over the last
+ // 10 seconds where a new measurement is done twice per second. The level
+ // is reset to zero at each call to LogStats(). Only modified on the task
+ // queue thread.
+ int16_t max_rec_level_;
+
+ // Contains max level of recorded audio packets over the last 10 seconds
+ // where a new measurement is done twice per second.
+ int16_t max_play_level_;
+
+ // Counts number of times we detect "no audio" corresponding to a case where
+ // all level measurements since the last log has been exactly zero.
+ // In other words: this counter is incremented only if 20 measurements
+ // (two per second) in a row equals zero. The member is only incremented on
+ // the task queue and max once every 10th second.
+ size_t num_rec_level_is_zero_;
};
} // namespace webrtc