Relands Adds WebRTC.Audio.Record/PlayoutSampleRateOffsetInPercent UMA stats to native WebRTC

First version was reverted in https://webrtc-review.googlesource.com/c/src/+/97941.
The issue is now fixed.

TBR=ivoc

Bug: b/113648245
Change-Id: If631fdea95aa963952f15e48e9d2d678797dc225
Reviewed-on: https://webrtc-review.googlesource.com/97942
Commit-Queue: Mirko Bonadei <mbonadei@webrtc.org>
Reviewed-by: Henrik Andreassson <henrika@webrtc.org>
Reviewed-by: Ivo Creusen <ivoc@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#24573}

modules/audio_device/android/audio_device_unittest.cc

@@ -755,9 +755,9 @@ TEST_F(AudioDeviceTest, UsesCorrectDelayEstimateForLowLatencyOutputPath) {
 // correct set of parameters.
 TEST_F(AudioDeviceTest, VerifyAudioDeviceBufferParameters) {
   EXPECT_EQ(playout_parameters_.sample_rate(),
-            audio_device_buffer()->PlayoutSampleRate());
+            static_cast<int>(audio_device_buffer()->PlayoutSampleRate()));
   EXPECT_EQ(record_parameters_.sample_rate(),
-            audio_device_buffer()->RecordingSampleRate());
+            static_cast<int>(audio_device_buffer()->RecordingSampleRate()));
   EXPECT_EQ(playout_parameters_.channels(),
             audio_device_buffer()->PlayoutChannels());
   EXPECT_EQ(record_parameters_.channels(),

modules/audio_device/audio_device_buffer.cc

@@ -181,50 +181,42 @@ void AudioDeviceBuffer::StopRecording() {
 }
 
 int32_t AudioDeviceBuffer::SetRecordingSampleRate(uint32_t fsHz) {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   RTC_LOG(INFO) << "SetRecordingSampleRate(" << fsHz << ")";
   rec_sample_rate_ = fsHz;
   return 0;
 }
 
 int32_t AudioDeviceBuffer::SetPlayoutSampleRate(uint32_t fsHz) {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   RTC_LOG(INFO) << "SetPlayoutSampleRate(" << fsHz << ")";
   play_sample_rate_ = fsHz;
   return 0;
 }
 
-int32_t AudioDeviceBuffer::RecordingSampleRate() const {
+uint32_t AudioDeviceBuffer::RecordingSampleRate() const {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   return rec_sample_rate_;
 }
 
-int32_t AudioDeviceBuffer::PlayoutSampleRate() const {
+uint32_t AudioDeviceBuffer::PlayoutSampleRate() const {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   return play_sample_rate_;
 }
 
 int32_t AudioDeviceBuffer::SetRecordingChannels(size_t channels) {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   RTC_LOG(INFO) << "SetRecordingChannels(" << channels << ")";
   rec_channels_ = channels;
   return 0;
 }
 
 int32_t AudioDeviceBuffer::SetPlayoutChannels(size_t channels) {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   RTC_LOG(INFO) << "SetPlayoutChannels(" << channels << ")";
   play_channels_ = channels;
   return 0;
 }
 
 size_t AudioDeviceBuffer::RecordingChannels() const {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   return rec_channels_;
 }
 
 size_t AudioDeviceBuffer::PlayoutChannels() const {
-  RTC_DCHECK(main_thread_checker_.CalledOnValidThread());
   return play_channels_;
 }
 
@@ -419,28 +411,52 @@ void AudioDeviceBuffer::LogStats(LogState state) {
     stats_.max_play_level = 0;
   }
 
-  // Log the latest statistics but skip the first round just after state was
+  // Cache current sample rate from atomic members.
-  // set to LOG_START. Hence, first printed log will be after ~10 seconds.
+  const uint32_t rec_sample_rate = rec_sample_rate_;
-  if (++num_stat_reports_ > 1 && time_since_last > 0) {
+  const uint32_t play_sample_rate = play_sample_rate_;
+
+  // Log the latest statistics but skip the first two rounds just after state
+  // was set to LOG_START to ensure that we have at least one full stable
+  // 10-second interval for sample-rate estimation. Hence, first printed log
+  // will be after ~20 seconds.
+  if (++num_stat_reports_ > 2 && time_since_last > 0) {
     uint32_t diff_samples = stats.rec_samples - last_stats_.rec_samples;
     float rate = diff_samples / (static_cast<float>(time_since_last) / 1000.0);
+    uint32_t abs_diff_rate_in_percent = 0;
+    if (rec_sample_rate > 0) {
+      abs_diff_rate_in_percent = static_cast<uint32_t>(
+          0.5f +
+          ((100.0f * std::abs(rate - rec_sample_rate)) / rec_sample_rate));
+      RTC_HISTOGRAM_PERCENTAGE("WebRTC.Audio.RecordSampleRateOffsetInPercent",
+                               abs_diff_rate_in_percent);
+    }
     RTC_LOG(INFO) << "[REC : " << time_since_last << "msec, "
-                  << rec_sample_rate_ / 1000 << "kHz] callbacks: "
+                  << rec_sample_rate / 1000 << "kHz] callbacks: "
                   << stats.rec_callbacks - last_stats_.rec_callbacks << ", "
                   << "samples: " << diff_samples << ", "
                   << "rate: " << static_cast<int>(rate + 0.5) << ", "
+                  << "rate diff: " << abs_diff_rate_in_percent << "%, "
                   << "level: " << stats.max_rec_level;
 
     diff_samples = stats.play_samples - last_stats_.play_samples;
     rate = diff_samples / (static_cast<float>(time_since_last) / 1000.0);
+    abs_diff_rate_in_percent = 0;
+    if (play_sample_rate > 0) {
+      abs_diff_rate_in_percent = static_cast<uint32_t>(
+          0.5f +
+          ((100.0f * std::abs(rate - play_sample_rate)) / play_sample_rate));
+      RTC_HISTOGRAM_PERCENTAGE("WebRTC.Audio.PlayoutSampleRateOffsetInPercent",
+                               abs_diff_rate_in_percent);
+    }
     RTC_LOG(INFO) << "[PLAY: " << time_since_last << "msec, "
-                  << play_sample_rate_ / 1000 << "kHz] callbacks: "
+                  << play_sample_rate / 1000 << "kHz] callbacks: "
                   << stats.play_callbacks - last_stats_.play_callbacks << ", "
                   << "samples: " << diff_samples << ", "
                   << "rate: " << static_cast<int>(rate + 0.5) << ", "
+                  << "rate diff: " << abs_diff_rate_in_percent << "%, "
                   << "level: " << stats.max_play_level;
-    last_stats_ = stats;
   }
+  last_stats_ = stats;
 
   int64_t time_to_wait_ms = next_callback_time - rtc::TimeMillis();
   RTC_DCHECK_GT(time_to_wait_ms, 0) << "Invalid timer interval";

modules/audio_device/audio_device_buffer.h

@@ -11,6 +11,8 @@
 #ifndef MODULES_AUDIO_DEVICE_AUDIO_DEVICE_BUFFER_H_
 #define MODULES_AUDIO_DEVICE_AUDIO_DEVICE_BUFFER_H_
 
+#include <atomic>
+
 #include "modules/audio_device/include/audio_device.h"
 #include "rtc_base/buffer.h"
 #include "rtc_base/criticalsection.h"
@@ -83,8 +85,8 @@ class AudioDeviceBuffer {
 
   int32_t SetRecordingSampleRate(uint32_t fsHz);
   int32_t SetPlayoutSampleRate(uint32_t fsHz);
-  int32_t RecordingSampleRate() const;
+  uint32_t RecordingSampleRate() const;
-  int32_t PlayoutSampleRate() const;
+  uint32_t PlayoutSampleRate() const;
 
   int32_t SetRecordingChannels(size_t channels);
   int32_t SetPlayoutChannels(size_t channels);
@@ -136,7 +138,7 @@ class AudioDeviceBuffer {
   // called on that same thread. When audio has started some methods will be
   // called on either a native audio thread for playout or a native thread for
   // recording. Some members are not annotated since they are "protected by
-  // design" and adding e.g. a race checker can cause failuries for very few
+  // design" and adding e.g. a race checker can cause failures for very few
   // edge cases and it is IMHO not worth the risk to use them in this class.
   // TODO(henrika): see if it is possible to refactor and annotate all members.
 
@@ -160,23 +162,17 @@ class AudioDeviceBuffer {
   // and it must outlive this object. It is not possible to change this member
   // while any media is active. It is possible to start media without calling
   // RegisterAudioCallback() but that will lead to ignored audio callbacks in
-  // both directions where native audio will be acive but no audio samples will
+  // both directions where native audio will be active but no audio samples will
   // be transported.
   AudioTransport* audio_transport_cb_;
 
-  // The members below that are not annotated are protected by design. They are
+  // Sample rate in Hertz. Accessed atomically.
-  // all set on the main thread (verified by |main_thread_checker_|) and then
+  std::atomic<uint32_t> rec_sample_rate_;
-  // read on either the playout or recording audio thread. But, media will never
+  std::atomic<uint32_t> play_sample_rate_;
-  // be active when the member is set; hence no conflict exists. It is too
-  // complex to ensure and verify that this is actually the case.
 
-  // Sample rate in Hertz.
+  // Number of audio channels. Accessed atomically.
-  uint32_t rec_sample_rate_;
+  std::atomic<size_t> rec_channels_;
-  uint32_t play_sample_rate_;
+  std::atomic<size_t> play_channels_;
-
-  // Number of audio channels.
-  size_t rec_channels_;
-  size_t play_channels_;
 
   // Keeps track of if playout/recording are active or not. A combination
   // of these states are used to determine when to start and stop the timer.