Add amplitude peak latency tracing

This CL adds a new way to measure (estimate) end-to-end audio latency.
It adds the AmplitudePeakDetector class, which listens for jumps in
audio signal amplitude; when it detects a peak, it runs a callback,
which we use to start or stop trace events. We use one
AmplitudePeakDetector right after microphone input and one right
before speaker output. By having the trace start after detecting a
peak from the microphone, and stop before playing out the peak, we can
measure how long it took for the signal to propagate.

To actually measure latency using this technique, one should start a
trace recording the `audio.latency` category. Then, one should open a
test page which sets up an input via getUserMedia() and plays out that
audio via any method (e.g. using WebAudio's MediaStreamAudioSourceNode
or an audio element's srcObject). Then, one should clap in front of
the microphone to produce audio peaks, or use any other method to
generate clear, alternating loud and quiet audio input.

Notes:
- This method does not currently support having multiple inputs or
multiple outputs. The test page should have exactly one input and
output, and should be the only tab running in the browser at that time.
- The peak detection threshold is roughly -6dbFS. One could adjust
the microphone's gain if the peaks are never detected, or trigger
too easily.

Change-Id: I3a11069dc8f4843da09e625237d2f8a003428514
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/4317311
Reviewed-by: Olga Sharonova <olka@chromium.org>
Commit-Queue: Thomas Guilbert <tguilbert@chromium.org>
Reviewed-by: Siddhartha S <ssid@chromium.org>
Reviewed-by: Dale Curtis <dalecurtis@chromium.org>
Cr-Commit-Position: refs/heads/main@{#1117871}

base/trace_event/builtin_categories.h

@@ -190,6 +190,7 @@
   X(TRACE_DISABLED_BY_DEFAULT("android_view_hierarchy"))                 \
   X(TRACE_DISABLED_BY_DEFAULT("animation-worklet"))                      \
   X(TRACE_DISABLED_BY_DEFAULT("audio"))                                  \
+  X(TRACE_DISABLED_BY_DEFAULT("audio.latency"))                          \
   X(TRACE_DISABLED_BY_DEFAULT("audio-worklet"))                          \
   X(TRACE_DISABLED_BY_DEFAULT("base"))                                   \
   X(TRACE_DISABLED_BY_DEFAULT("blink.debug"))                            \

media/audio/audio_manager.cc

@@ -17,6 +17,7 @@
 #include "base/power_monitor/power_monitor.h"
 #include "base/task/single_thread_task_runner.h"
 #include "base/thread_annotations.h"
+#include "base/trace_event/trace_event.h"
 #include "build/build_config.h"
 #include "media/audio/fake_audio_log_factory.h"
 #include "media/base/media_switches.h"
@@ -164,4 +165,37 @@ bool AudioManager::Shutdown() {
   return true;
 }
 
+void AudioManager::TraceAmplitudePeak(bool trace_start) {
+  base::AutoLock scoped_lock(tracing_lock_);
+
+  constexpr char kTraceName[] = "AmplitudePeak";
+
+  if (trace_start) {
+    // We might have never closed the previous trace. Abort it now.
+    if (is_trace_started_) {
+      TRACE_EVENT_NESTABLE_ASYNC_END1(
+          TRACE_DISABLED_BY_DEFAULT("audio.latency"), kTraceName,
+          current_trace_id_, "aborted", true);
+    }
+
+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN0(
+        TRACE_DISABLED_BY_DEFAULT("audio.latency"), kTraceName,
+        ++current_trace_id_);
+
+    is_trace_started_ = true;
+    return;
+  }
+
+  if (!is_trace_started_) {
+    // Avoid ending traces that were never started.
+    return;
+  }
+
+  TRACE_EVENT_NESTABLE_ASYNC_END1(TRACE_DISABLED_BY_DEFAULT("audio.latency"),
+                                  kTraceName, current_trace_id_, "aborted",
+                                  false);
+
+  is_trace_started_ = false;
+}
+
 }  // namespace media

media/audio/audio_manager.h

@@ -10,6 +10,7 @@
 
 #include "base/functional/callback.h"
 #include "base/gtest_prod_util.h"
+#include "base/synchronization/lock.h"
 #include "base/threading/thread_checker.h"
 #include "build/build_config.h"
 #include "media/audio/audio_device_description.h"
@@ -181,6 +182,15 @@ class MEDIA_EXPORT AudioManager {
   // Limits the number of streams that can be created for testing purposes.
   virtual void SetMaxStreamCountForTesting(int max_input, int max_output);
 
+  // Starts or stops tracing when a peak in Audio signal amplitude is detected.
+  // Does nothing if a call to stop tracing is made without first starting the
+  // trace. Aborts the current trace if a call to start tracing is made without
+  // stopping the existing trace.
+  // Note: tracing is intended to be started from exactly one input stream and
+  // stopped from exactly one output stream. If multiple streams are starting
+  // and stopping traces, the latency measurements will not be valid.
+  void TraceAmplitudePeak(bool trace_start);
+
  protected:
   FRIEND_TEST_ALL_PREFIXES(AudioManagerTest, AudioDebugRecording);
   friend class AudioDeviceInfoAccessorForTests;
@@ -260,6 +270,10 @@ class MEDIA_EXPORT AudioManager {
  private:
   friend class AudioSystemHelper;
 
+  base::Lock tracing_lock_;
+  int current_trace_id_ GUARDED_BY(tracing_lock_) = 0;
+  bool is_trace_started_ GUARDED_BY(tracing_lock_) = false;
+
   std::unique_ptr<AudioThread> audio_thread_;
   bool shutdown_ = false;  // True after |this| has been shutdown.
 

media/audio/pulse/pulse_input.cc

@@ -42,7 +42,10 @@ PulseAudioInputStream::PulseAudioInputStream(
       pa_mainloop_(mainloop),
       pa_context_(context),
       log_callback_(std::move(log_callback)),
-      handle_(nullptr) {
+      handle_(nullptr),
+      peak_detector_(base::BindRepeating(&AudioManager::TraceAmplitudePeak,
+                                         base::Unretained(audio_manager_),
+                                         /*trace_start=*/true)) {
   DCHECK(mainloop);
   DCHECK(context);
   CHECK(params_.IsValid());
@@ -350,8 +353,12 @@ void PulseAudioInputStream::ReadData() {
       fifo_.IncreaseCapacity(increase_blocks_of_buffer);
     }
 
-    fifo_.Push(data, number_of_frames,
-               SampleFormatToBytesPerChannel(pulse::kInputSampleFormat));
+    const int bytes_per_sample =
+        SampleFormatToBytesPerChannel(pulse::kInputSampleFormat);
+
+    peak_detector_.FindPeak(data, number_of_frames, bytes_per_sample);
+
+    fifo_.Push(data, number_of_frames, bytes_per_sample);
 
     // Checks if we still have data.
     pa_stream_drop(handle_);

media/audio/pulse/pulse_input.h

@@ -16,6 +16,7 @@
 #include "media/audio/audio_device_name.h"
 #include "media/audio/audio_io.h"
 #include "media/audio/audio_manager.h"
+#include "media/base/amplitude_peak_detector.h"
 #include "media/base/audio_block_fifo.h"
 #include "media/base/audio_parameters.h"
 
@@ -95,6 +96,8 @@ class PulseAudioInputStream : public AgcAudioStream<AudioInputStream> {
   // #addr-of
   RAW_PTR_EXCLUSION pa_stream* handle_;
 
+  AmplitudePeakDetector peak_detector_;
+
   base::ThreadChecker thread_checker_;
 };
 

media/audio/pulse/pulse_output.cc

@@ -60,7 +60,10 @@ PulseAudioOutputStream::PulseAudioOutputStream(
       pa_stream_(nullptr),
       volume_(1.0f),
       source_callback_(nullptr),
-      buffer_size_(params_.GetBytesPerBuffer(kSampleFormatF32)) {
+      buffer_size_(params_.GetBytesPerBuffer(kSampleFormatF32)),
+      peak_detector_(base::BindRepeating(&AudioManager::TraceAmplitudePeak,
+                                         base::Unretained(manager_),
+                                         /*trace_start=*/false)) {
   CHECK(params_.IsValid());
   SendLogMessage("%s({device_id=%s}, {params=[%s]})", __func__,
                  device_id.c_str(), params.AsHumanReadableString().c_str());
@@ -178,6 +181,11 @@ void PulseAudioOutputStream::FulfillWriteRequest(size_t requested_bytes) {
                                     unwritten_frames_in_bus - frames_filled);
     }
 
+    // TODO(tguilbert): Consider moving this before each of the individual
+    // `pa_stream_write()` calls in the loop below, to improve the accuracy of
+    // the latency measurements.
+    peak_detector_.FindPeak(audio_bus_.get());
+
     audio_bus_->Scale(volume_);
 
     size_t frame_size = buffer_size_ / unwritten_frames_in_bus;

media/audio/pulse/pulse_output.h

@@ -30,6 +30,7 @@
 #include "base/threading/thread_checker.h"
 #include "media/audio/audio_io.h"
 #include "media/audio/audio_manager.h"
+#include "media/base/amplitude_peak_detector.h"
 #include "media/base/audio_parameters.h"
 
 struct pa_context;
@@ -114,6 +115,8 @@ class PulseAudioOutputStream : public AudioOutputStream {
 
   const size_t buffer_size_;
 
+  AmplitudePeakDetector peak_detector_;
+
   base::ThreadChecker thread_checker_;
 };
 

media/audio/win/audio_low_latency_input_win.cc

@@ -19,6 +19,7 @@
 #include "base/metrics/histogram_macros.h"
 #include "base/strings/stringprintf.h"
 #include "base/strings/utf_string_conversions.h"
+#include "base/trace_event/common/trace_event_common.h"
 #include "base/trace_event/trace_event.h"
 #include "base/win/core_winrt_util.h"
 #include "base/win/scoped_propvariant.h"
@@ -287,6 +288,9 @@ WASAPIAudioInputStream::WASAPIAudioInputStream(
     AudioManager::LogCallback log_callback)
     : manager_(manager),
       glitch_reporter_(SystemGlitchReporter::StreamType::kCapture),
+      peak_detector_(base::BindRepeating(&AudioManager::TraceAmplitudePeak,
+                                         base::Unretained(manager_),
+                                         /*trace_start=*/true)),
       data_discontinuity_reporter_(
           std::make_unique<DataDiscontinuityReporter>()),
       device_id_(device_id),
@@ -956,8 +960,10 @@ void WASAPIAudioInputStream::PullCaptureDataAndPushToSink() {
     if (flags & AUDCLNT_BUFFERFLAGS_SILENT) {
       fifo_->PushSilence(num_frames_to_read);
     } else {
-      fifo_->Push(data_ptr, num_frames_to_read,
-                  input_format_.Format.wBitsPerSample / 8);
+      const int bytes_per_sample = input_format_.Format.wBitsPerSample / 8;
+
+      peak_detector_.FindPeak(data_ptr, num_frames_to_read, bytes_per_sample);
+      fifo_->Push(data_ptr, num_frames_to_read, bytes_per_sample);
     }
 
     hr = audio_capture_client_->ReleaseBuffer(num_frames_to_read);

media/audio/win/audio_low_latency_input_win.h

@@ -80,6 +80,7 @@
 #include "media/audio/agc_audio_stream.h"
 #include "media/audio/system_glitch_reporter.h"
 #include "media/audio/win/audio_manager_win.h"
+#include "media/base/amplitude_peak_detector.h"
 #include "media/base/audio_converter.h"
 #include "media/base/audio_parameters.h"
 #include "media/base/media_export.h"
@@ -214,6 +215,8 @@ class MEDIA_EXPORT WASAPIAudioInputStream
   // text logs (when a stream ends).
   SystemGlitchReporter glitch_reporter_;
 
+  AmplitudePeakDetector peak_detector_;
+
   // Used to track and log data discontinuity warnings from
   // IAudioCaptureClient::GetBuffer.
   std::unique_ptr<DataDiscontinuityReporter> data_discontinuity_reporter_;

media/audio/win/audio_low_latency_output_win.cc

@@ -89,6 +89,9 @@ WASAPIAudioOutputStream::WASAPIAudioOutputStream(
     : creating_thread_id_(base::PlatformThread::CurrentId()),
       manager_(manager),
       glitch_reporter_(SystemGlitchReporter::StreamType::kRender),
+      peak_detector_(base::BindRepeating(&AudioManager::TraceAmplitudePeak,
+                                         base::Unretained(manager_),
+                                         /*trace_start=*/false)),
       format_(),
       params_(params),
       opened_(false),
@@ -751,8 +754,11 @@ bool WASAPIAudioOutputStream::RenderAudioFromSource(UINT64 device_frequency) {
           audio_bus.get());
 
       // During pause/seek, keep the pipeline filled with zero'ed frames.
-      if (!frames_filled)
+      if (!frames_filled) {
         memset(audio_data, 0, packet_size_frames_);
+      }
+
+      peak_detector_.FindPeak(audio_bus_.get());
 
       // Release the buffer space acquired in the GetBuffer() call.
       // Render silence if we were not able to fill up the buffer totally.
@@ -772,6 +778,8 @@ bool WASAPIAudioOutputStream::RenderAudioFromSource(UINT64 device_frequency) {
     audio_bus_->ToInterleaved<Float32SampleTypeTraitsNoClip>(
         frames_filled, reinterpret_cast<float*>(audio_data));
 
+    peak_detector_.FindPeak(audio_bus_.get());
+
     // Release the buffer space acquired in the GetBuffer() call.
     // Render silence if we were not able to fill up the buffer totally.
     DWORD flags = (num_filled_bytes < packet_size_bytes_)

media/audio/win/audio_low_latency_output_win.h

@@ -114,6 +114,7 @@
 #include "media/audio/audio_io.h"
 #include "media/audio/system_glitch_reporter.h"
 #include "media/audio/win/audio_manager_win.h"
+#include "media/base/amplitude_peak_detector.h"
 #include "media/base/audio_parameters.h"
 #include "media/base/media_export.h"
 
@@ -198,6 +199,8 @@ class MEDIA_EXPORT WASAPIAudioOutputStream
   // text logs (when a stream ends).
   SystemGlitchReporter glitch_reporter_;
 
+  AmplitudePeakDetector peak_detector_;
+
   // Rendering is driven by this thread (which has no message loop).
   // All OnMoreData() callbacks will be called from this thread.
   std::unique_ptr<base::DelegateSimpleThread> render_thread_;

media/base/BUILD.gn

@@ -43,6 +43,8 @@ source_set("base") {
   }
 
   sources = [
+    "amplitude_peak_detector.cc",
+    "amplitude_peak_detector.h",
     "android_overlay_config.cc",
     "android_overlay_config.h",
     "android_overlay_mojo_factory.h",