AudioService: Fixes for loopback underruns/timing issues.

Fixes a "choppy audio" issue on platforms with certain audio timing
parameters/scenarios. Investigation on crbug.com/934770 led to the
realization that three related problems needed to be addressed:

1. Fix the "gap" detection in audio::SnooperNode to check in BOTH
directions, not just one direction; and on both the input and output
flows. This accounts for the case where a device-switch in
audio::OutputController results in a sudden drastic shift in the delay
timestamps.

2. Add automatically-increasing capture delay logic to
audio::LoopbackStream to ensure the reads from all nodes' delay buffer
will never result in underrun.

3. Increased the accuracy of media::FakeAudioWorker/OutputStream by: a)
addressing a subtle source of error in task scheduling delay math due to
integer truncation; b) exposing timestamps to worker callbacks that
allow FakeAudioOutputStream to provide a |delay| and |delay_timestamp|
that behaves just like a real AudioOutputStream. This "lessens the blow"
of a device-switch to SnooperNode.

Bug: 934770
Change-Id: Ia75f18b2be3ad905f27d6ad882df9632764bb81c
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1504981
Commit-Queue: Yuri Wiitala <miu@chromium.org>
Reviewed-by: Max Morin <maxmorin@chromium.org>
Reviewed-by: Oskar Sundbom <ossu@chromium.org>
Reviewed-by: Weiyong Yao <braveyao@chromium.org>
Reviewed-by: Dale Curtis <dalecurtis@chromium.org>
Cr-Commit-Position: refs/heads/master@{#638427}

content/browser/media/capture/web_contents_audio_muter.cc

@@ -38,14 +38,15 @@ class AudioDiscarder : public media::AudioOutputStream {
  public:
   explicit AudioDiscarder(const media::AudioParameters& params)
       : worker_(media::AudioManager::Get()->GetWorkerTaskRunner(), params),
+        fixed_data_delay_(
+            media::FakeAudioWorker::ComputeFakeOutputDelay(params)),
         audio_bus_(media::AudioBus::Create(params)) {}
 
   // AudioOutputStream implementation.
   bool Open() override { return true; }
   void Start(AudioSourceCallback* callback) override {
-    worker_.Start(base::Bind(&AudioDiscarder::FetchAudioData,
-                             base::Unretained(this),
-                             callback));
+    worker_.Start(base::BindRepeating(&AudioDiscarder::FetchAudioData,
+                                      base::Unretained(this), callback));
   }
   void Stop() override { worker_.Stop(); }
   void SetVolume(double volume) override {}
@@ -55,14 +56,19 @@ class AudioDiscarder : public media::AudioOutputStream {
  private:
   ~AudioDiscarder() override {}
 
-  void FetchAudioData(AudioSourceCallback* callback) {
-    callback->OnMoreData(base::TimeDelta(), base::TimeTicks::Now(), 0,
+  void FetchAudioData(AudioSourceCallback* callback,
+                      base::TimeTicks ideal_time,
+                      base::TimeTicks now) {
+    // Real streams provide small tweaks to their delay values, alongside the
+    // current system time; and so the same is done here.
+    callback->OnMoreData(fixed_data_delay_ + (ideal_time - now), now, 0,
                          audio_bus_.get());
   }
 
   // Calls FetchAudioData() at regular intervals and discards the data.
   media::FakeAudioWorker worker_;
-  std::unique_ptr<media::AudioBus> audio_bus_;
+  const base::TimeDelta fixed_data_delay_;
+  const std::unique_ptr<media::AudioBus> audio_bus_;
 
   DISALLOW_COPY_AND_ASSIGN(AudioDiscarder);
 };

media/audio/fake_audio_input_stream.cc

@@ -54,7 +54,7 @@ bool FakeAudioInputStream::Open() {
 void FakeAudioInputStream::Start(AudioInputCallback* callback)  {
   DCHECK(audio_manager_->GetTaskRunner()->BelongsToCurrentThread());
   callback_ = callback;
-  fake_audio_worker_.Start(base::Bind(
+  fake_audio_worker_.Start(base::BindRepeating(
       &FakeAudioInputStream::ReadAudioFromSource, base::Unretained(this)));
 }
 
@@ -102,16 +102,27 @@ void FakeAudioInputStream::SetOutputDeviceForAec(
   // Not supported. Do nothing.
 }
 
-void FakeAudioInputStream::ReadAudioFromSource() {
+void FakeAudioInputStream::ReadAudioFromSource(base::TimeTicks ideal_time,
+                                               base::TimeTicks now) {
   DCHECK(audio_manager_->GetWorkerTaskRunner()->BelongsToCurrentThread());
   DCHECK(callback_);
 
   if (!audio_source_)
     audio_source_ = ChooseSource();
 
-  audio_source_->OnMoreData(base::TimeDelta(), base::TimeTicks::Now(), 0,
-                            audio_bus_.get());
-  callback_->OnData(audio_bus_.get(), base::TimeTicks::Now(), 1.0);
+  // This OnMoreData()/OnData() timing would never happen in a real system:
+  //
+  //   1. Real AudioSources would never be asked to generate audio that should
+  //      already be playing-out exactly at this very moment; they are asked to
+  //      do so for audio to be played-out in the future.
+  //   2. Real AudioInputStreams could never provide audio that is striking a
+  //      microphone element exactly at this very moment; they provide audio
+  //      that happened in the recent past.
+  //
+  // However, it would be pointless to add a FIFO queue here to delay the signal
+  // in this "fake" implementation. So, just hack the timing and carry-on.
+  audio_source_->OnMoreData(base::TimeDelta(), ideal_time, 0, audio_bus_.get());
+  callback_->OnData(audio_bus_.get(), ideal_time, 1.0);
 }
 
 using AudioSourceCallback = AudioOutputStream::AudioSourceCallback;

media/audio/fake_audio_input_stream.h

@@ -65,7 +65,7 @@ class MEDIA_EXPORT FakeAudioInputStream
   ~FakeAudioInputStream() override;
 
   std::unique_ptr<AudioOutputStream::AudioSourceCallback> ChooseSource();
-  void ReadAudioFromSource();
+  void ReadAudioFromSource(base::TimeTicks ideal_time, base::TimeTicks now);
 
   AudioManagerBase* audio_manager_;
   AudioInputCallback* callback_;

media/audio/fake_audio_output_stream.cc

@@ -22,10 +22,10 @@ AudioOutputStream* FakeAudioOutputStream::MakeFakeStream(
 FakeAudioOutputStream::FakeAudioOutputStream(AudioManagerBase* manager,
                                              const AudioParameters& params)
     : audio_manager_(manager),
+      fixed_data_delay_(FakeAudioWorker::ComputeFakeOutputDelay(params)),
       callback_(NULL),
       fake_worker_(manager->GetWorkerTaskRunner(), params),
-      audio_bus_(AudioBus::Create(params)) {
-}
+      audio_bus_(AudioBus::Create(params)) {}
 
 FakeAudioOutputStream::~FakeAudioOutputStream() {
   DCHECK(!callback_);
@@ -40,8 +40,8 @@ bool FakeAudioOutputStream::Open() {
 void FakeAudioOutputStream::Start(AudioSourceCallback* callback)  {
   DCHECK(audio_manager_->GetTaskRunner()->BelongsToCurrentThread());
   callback_ = callback;
-  fake_worker_.Start(base::Bind(
-      &FakeAudioOutputStream::CallOnMoreData, base::Unretained(this)));
+  fake_worker_.Start(base::BindRepeating(&FakeAudioOutputStream::CallOnMoreData,
+                                         base::Unretained(this)));
 }
 
 void FakeAudioOutputStream::Stop() {
@@ -62,9 +62,12 @@ void FakeAudioOutputStream::GetVolume(double* volume) {
   *volume = 0;
 }
 
-void FakeAudioOutputStream::CallOnMoreData() {
+void FakeAudioOutputStream::CallOnMoreData(base::TimeTicks ideal_time,
+                                           base::TimeTicks now) {
   DCHECK(audio_manager_->GetWorkerTaskRunner()->BelongsToCurrentThread());
-  callback_->OnMoreData(base::TimeDelta(), base::TimeTicks::Now(), 0,
+  // Real streams provide small tweaks to their delay values, alongside the
+  // current system time; and so the same is done here.
+  callback_->OnMoreData(fixed_data_delay_ + (ideal_time - now), now, 0,
                         audio_bus_.get());
 }
 

media/audio/fake_audio_output_stream.h

@@ -40,12 +40,13 @@ class MEDIA_EXPORT FakeAudioOutputStream : public MuteableAudioOutputStream {
   ~FakeAudioOutputStream() override;
 
   // Task that periodically calls OnMoreData() to consume audio data.
-  void CallOnMoreData();
+  void CallOnMoreData(base::TimeTicks ideal_time, base::TimeTicks now);
 
-  AudioManagerBase* audio_manager_;
+  AudioManagerBase* const audio_manager_;
+  const base::TimeDelta fixed_data_delay_;
   AudioSourceCallback* callback_;
   FakeAudioWorker fake_worker_;
-  std::unique_ptr<AudioBus> audio_bus_;
+  const std::unique_ptr<AudioBus> audio_bus_;
 
   DISALLOW_COPY_AND_ASSIGN(FakeAudioOutputStream);
 };

media/audio/null_audio_sink.cc

@@ -27,6 +27,7 @@ void NullAudioSink::Initialize(const AudioParameters& params,
                                RenderCallback* callback) {
   DCHECK(!started_);
   fake_worker_.reset(new FakeAudioWorker(task_runner_, params));
+  fixed_data_delay_ = FakeAudioWorker::ComputeFakeOutputDelay(params);
   audio_bus_ = AudioBus::Create(params);
   callback_ = callback;
   initialized_ = true;
@@ -54,8 +55,8 @@ void NullAudioSink::Play() {
   if (playing_)
     return;
 
-  fake_worker_->Start(base::Bind(
-      &NullAudioSink::CallRender, base::Unretained(this)));
+  fake_worker_->Start(
+      base::BindRepeating(&NullAudioSink::CallRender, base::Unretained(this)));
 
   playing_ = true;
 }
@@ -98,11 +99,16 @@ void NullAudioSink::SwitchOutputDevice(const std::string& device_id,
   std::move(callback).Run(OUTPUT_DEVICE_STATUS_ERROR_INTERNAL);
 }
 
-void NullAudioSink::CallRender() {
+void NullAudioSink::CallRender(base::TimeTicks ideal_time,
+                               base::TimeTicks now) {
   DCHECK(task_runner_->BelongsToCurrentThread());
 
-  int frames_received = callback_->Render(
-      base::TimeDelta(), base::TimeTicks::Now(), 0, audio_bus_.get());
+  // Since NullAudioSink is only used for cases where a real audio sink was not
+  // available, provide "idealized" delay-timing arguments. This will drive the
+  // smoothest playback (since video is sync'ed to audio). See
+  // content::AudioRendererImpl and media::AudioClock for further details.
+  int frames_received =
+      callback_->Render(fixed_data_delay_, ideal_time, 0, audio_bus_.get());
   if (!audio_hash_ || frames_received <= 0)
     return;
 

media/audio/null_audio_sink.h

@@ -51,7 +51,7 @@ class MEDIA_EXPORT NullAudioSink : public SwitchableAudioRendererSink {
 
  private:
   // Task that periodically calls Render() to consume audio data.
-  void CallRender();
+  void CallRender(base::TimeTicks ideal_time, base::TimeTicks now);
 
   bool initialized_;
   bool started_;
@@ -63,6 +63,7 @@ class MEDIA_EXPORT NullAudioSink : public SwitchableAudioRendererSink {
 
   scoped_refptr<base::SingleThreadTaskRunner> task_runner_;
   std::unique_ptr<FakeAudioWorker> fake_worker_;
+  base::TimeDelta fixed_data_delay_;
   std::unique_ptr<AudioBus> audio_bus_;
 
   DISALLOW_COPY_AND_ASSIGN(NullAudioSink);

media/audio/virtual_audio_input_stream.cc

@@ -54,8 +54,8 @@ bool VirtualAudioInputStream::Open() {
 void VirtualAudioInputStream::Start(AudioInputCallback* callback) {
   DCHECK(thread_checker_.CalledOnValidThread());
   callback_ = callback;
-  fake_worker_.Start(base::Bind(
-      &VirtualAudioInputStream::PumpAudio, base::Unretained(this)));
+  fake_worker_.Start(base::BindRepeating(&VirtualAudioInputStream::PumpAudio,
+                                         base::Unretained(this)));
 }
 
 void VirtualAudioInputStream::Stop() {
@@ -99,7 +99,8 @@ void VirtualAudioInputStream::RemoveInputProvider(
   DCHECK_LE(0, num_attached_output_streams_);
 }
 
-void VirtualAudioInputStream::PumpAudio() {
+void VirtualAudioInputStream::PumpAudio(base::TimeTicks ideal_time,
+                                        base::TimeTicks now) {
   DCHECK(worker_task_runner_->BelongsToCurrentThread());
 
   {
@@ -110,7 +111,7 @@ void VirtualAudioInputStream::PumpAudio() {
   }
   // Because the audio is being looped-back, the delay since since it was
   // recorded is zero.
-  callback_->OnData(audio_bus_.get(), base::TimeTicks::Now(), 1.0);
+  callback_->OnData(audio_bus_.get(), ideal_time, 1.0);
 }
 
 void VirtualAudioInputStream::Close() {

media/audio/virtual_audio_input_stream.h

@@ -80,7 +80,7 @@ class MEDIA_EXPORT VirtualAudioInputStream : public AudioInputStream {
   // Pulls audio data from all attached VirtualAudioOutputStreams, mixes and
   // converts the streams into one, and pushes the result to |callback_|.
   // Invoked on the worker thread.
-  void PumpAudio();
+  void PumpAudio(base::TimeTicks ideal_time, base::TimeTicks now);
 
   const scoped_refptr<base::SingleThreadTaskRunner> worker_task_runner_;
 

media/base/fake_audio_worker.cc

@@ -4,6 +4,8 @@
 
 #include "media/base/fake_audio_worker.h"
 
+#include <utility>
+
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/cancelable_callback.h"
@@ -16,6 +18,7 @@
 #include "base/threading/thread_checker.h"
 #include "base/time/time.h"
 #include "media/base/audio_parameters.h"
+#include "media/base/audio_timestamp_helper.h"
 
 namespace media {
 
@@ -26,7 +29,7 @@ class FakeAudioWorker::Worker
          const AudioParameters& params);
 
   bool IsStopped();
-  void Start(const base::Closure& worker_cb);
+  void Start(FakeAudioWorker::Callback worker_cb);
   void Stop();
 
  private:
@@ -45,11 +48,13 @@ class FakeAudioWorker::Worker
   void DoRead();
 
   const scoped_refptr<base::SingleThreadTaskRunner> worker_task_runner_;
-  const base::TimeDelta buffer_duration_;
+  const int sample_rate_;
+  const int frames_per_read_;
 
   base::Lock worker_cb_lock_;  // Held while mutating or running |worker_cb_|.
-  base::Closure worker_cb_ GUARDED_BY(worker_cb_lock_);
-  base::TimeTicks next_read_time_;
+  FakeAudioWorker::Callback worker_cb_ GUARDED_BY(worker_cb_lock_);
+  base::TimeTicks first_read_time_;
+  int64_t frames_elapsed_;
 
   // Used to cancel any delayed tasks still inside the worker loop's queue.
   base::CancelableClosure worker_task_cb_;
@@ -68,22 +73,32 @@ FakeAudioWorker::~FakeAudioWorker() {
   DCHECK(worker_->IsStopped());
 }
 
-void FakeAudioWorker::Start(const base::Closure& worker_cb) {
+void FakeAudioWorker::Start(FakeAudioWorker::Callback worker_cb) {
   DCHECK(worker_->IsStopped());
-  worker_->Start(worker_cb);
+  worker_->Start(std::move(worker_cb));
 }
 
 void FakeAudioWorker::Stop() {
   worker_->Stop();
 }
 
+// static
+base::TimeDelta FakeAudioWorker::ComputeFakeOutputDelay(
+    const AudioParameters& params) {
+  // Typical delay values used by real AudioOutputStreams on Win, Mac, and Linux
+  // tend to be around 1.5X to 3X of the buffer duration. So, 2X is chosen as a
+  // general-purpose value.
+  constexpr int kDelayFactor = 2;
+  return AudioTimestampHelper::FramesToTime(
+      params.frames_per_buffer() * kDelayFactor, params.sample_rate());
+}
+
 FakeAudioWorker::Worker::Worker(
     const scoped_refptr<base::SingleThreadTaskRunner>& worker_task_runner,
     const AudioParameters& params)
     : worker_task_runner_(worker_task_runner),
-      buffer_duration_(base::TimeDelta::FromMicroseconds(
-          params.frames_per_buffer() * base::Time::kMicrosecondsPerSecond /
-          static_cast<float>(params.sample_rate()))) {
+      sample_rate_(params.sample_rate()),
+      frames_per_read_(params.frames_per_buffer()) {
   // Worker can be constructed on any thread, but will DCHECK that its
   // Start/Stop methods are called from the same thread.
   DETACH_FROM_THREAD(thread_checker_);
@@ -98,13 +113,13 @@ bool FakeAudioWorker::Worker::IsStopped() {
   return !worker_cb_;
 }
 
-void FakeAudioWorker::Worker::Start(const base::Closure& worker_cb) {
+void FakeAudioWorker::Worker::Start(FakeAudioWorker::Callback worker_cb) {
   DCHECK_CALLED_ON_VALID_THREAD(thread_checker_);
   DCHECK(worker_cb);
   {
     base::AutoLock scoped_lock(worker_cb_lock_);
     DCHECK(!worker_cb_);
-    worker_cb_ = worker_cb;
+    worker_cb_ = std::move(worker_cb);
   }
   worker_task_runner_->PostTask(FROM_HERE,
                                 base::BindOnce(&Worker::DoStart, this));
@@ -112,7 +127,8 @@ void FakeAudioWorker::Worker::Start(const base::Closure& worker_cb) {
 
 void FakeAudioWorker::Worker::DoStart() {
   DCHECK(worker_task_runner_->BelongsToCurrentThread());
-  next_read_time_ = base::TimeTicks::Now();
+  first_read_time_ = base::TimeTicks::Now();
+  frames_elapsed_ = 0;
   worker_task_cb_.Reset(base::Bind(&Worker::DoRead, this));
   worker_task_cb_.callback().Run();
 }
@@ -137,24 +153,37 @@ void FakeAudioWorker::Worker::DoCancel() {
 void FakeAudioWorker::Worker::DoRead() {
   DCHECK(worker_task_runner_->BelongsToCurrentThread());
 
+  const base::TimeTicks read_time =
+      first_read_time_ +
+      AudioTimestampHelper::FramesToTime(frames_elapsed_, sample_rate_);
+  frames_elapsed_ += frames_per_read_;
+  base::TimeTicks next_read_time =
+      first_read_time_ +
+      AudioTimestampHelper::FramesToTime(frames_elapsed_, sample_rate_);
+
+  base::TimeTicks now;
   {
     base::AutoLock scoped_lock(worker_cb_lock_);
-    if (worker_cb_)
-      worker_cb_.Run();
+    // Important to sample the clock after waiting to acquire the lock.
+    now = base::TimeTicks::Now();
+    if (worker_cb_ && next_read_time > now) {
+      worker_cb_.Run(read_time, now);
+    }
   }
 
-  // Need to account for time spent here due to the cost of |worker_cb| as well
-  // as the imprecision of PostDelayedTask().
-  const base::TimeTicks now = base::TimeTicks::Now();
-  base::TimeDelta delay = next_read_time_ + buffer_duration_ - now;
-
-  // If we're behind, find the next nearest ontime interval.
-  if (delay < base::TimeDelta())
-    delay += buffer_duration_ * (-delay / buffer_duration_ + 1);
-  next_read_time_ = now + delay;
+  // If we're behind, find the next nearest ontime interval. Note, we could be
+  // behind many intervals (e.g., if the system is resuming from sleep).
+  if (next_read_time <= now) {
+    frames_elapsed_ = AudioTimestampHelper::TimeToFrames(now - first_read_time_,
+                                                         sample_rate_);
+    frames_elapsed_ =
+        ((frames_elapsed_ / frames_per_read_) + 1) * frames_per_read_;
+    next_read_time = first_read_time_ + AudioTimestampHelper::FramesToTime(
+                                            frames_elapsed_, sample_rate_);
+  }
 
   worker_task_runner_->PostDelayedTask(FROM_HERE, worker_task_cb_.callback(),
-                                       delay);
+                                       next_read_time - now);
 }
 
 }  // namespace media

media/base/fake_audio_worker.h

@@ -21,6 +21,12 @@ class AudioParameters;
 // call back the provided callback like a real audio consumer or producer would.
 class MEDIA_EXPORT FakeAudioWorker {
  public:
+  // The worker callback, which is run at regular intervals. |ideal_time| is
+  // when the callback was scheduled to run, while |now| is when the callback is
+  // actually being run.
+  using Callback = base::RepeatingCallback<void(base::TimeTicks ideal_time,
+                                                base::TimeTicks now)>;
+
   // |worker_task_runner| is the task runner on which the closure provided to
   // Start() will be executed on.  This may or may not be the be for the same
   // thread that invokes the Start/Stop methods.
@@ -32,13 +38,17 @@ class MEDIA_EXPORT FakeAudioWorker {
 
   // Start executing |worker_cb| at a regular intervals.  Stop() must be called
   // by the same thread before destroying FakeAudioWorker.
-  void Start(const base::Closure& worker_cb);
+  void Start(Callback worker_cb);
 
   // Stop executing the closure provided to Start(). Blocks until the worker
   // loop is not inside a closure invocation. Safe to call multiple times.
   // Must be called on the same thread that called Start().
   void Stop();
 
+  // Returns a reasonable fixed output delay value for a "sink" using a
+  // FakeAudioWorker.
+  static base::TimeDelta ComputeFakeOutputDelay(const AudioParameters& params);
+
  private:
   // All state and implementation is kept within this ref-counted class because
   // cancellation of posted tasks must happen on the worker thread some time

media/base/fake_audio_worker_unittest.cc

@@ -32,12 +32,14 @@ class FakeAudioWorkerTest : public testing::Test {
 
   ~FakeAudioWorkerTest() override = default;
 
-  void CalledByFakeWorker() { seen_callbacks_++; }
+  void CalledByFakeWorker(base::TimeTicks ideal_time, base::TimeTicks now) {
+    seen_callbacks_++;
+  }
 
   void RunOnAudioThread() {
     ASSERT_TRUE(message_loop_.task_runner()->BelongsToCurrentThread());
-    fake_worker_.Start(base::Bind(&FakeAudioWorkerTest::CalledByFakeWorker,
-                                  base::Unretained(this)));
+    fake_worker_.Start(base::BindRepeating(
+        &FakeAudioWorkerTest::CalledByFakeWorker, base::Unretained(this)));
   }
 
   void RunOnceOnAudioThread() {

media/base/silent_sink_suspender.cc

@@ -143,10 +143,17 @@ void SilentSinkSuspender::TransitionSinks(bool use_fake_sink) {
       is_transition_pending_ = false;
       is_using_fake_sink_ = true;
     }
-    fake_sink_.Start(
-        base::Bind(base::IgnoreResult(&SilentSinkSuspender::Render),
-                   base::Unretained(this), latest_output_delay_,
-                   latest_output_delay_timestamp_, 0, nullptr));
+    fake_sink_.Start(base::BindRepeating(
+        [](SilentSinkSuspender* suspender, base::TimeDelta frozen_delay,
+           base::TimeTicks frozen_delay_timestamp, base::TimeTicks ideal_time,
+           base::TimeTicks now) {
+          // TODO: Seems that the code in Render() might benefit from the two
+          // new timestamps being provided by FakeAudioWorker, in that it's call
+          // to base::TimeTicks::Now() can be eliminated (use |now| instead),
+          // along with its custom delay timestamp calculations.
+          suspender->Render(frozen_delay, frozen_delay_timestamp, 0, nullptr);
+        },
+        this, latest_output_delay_, latest_output_delay_timestamp_));
   } else {
     fake_sink_.Stop();
 

services/audio/loopback_stream.cc

@@ -23,11 +23,17 @@
 
 namespace audio {
 
-// static
-constexpr double LoopbackStream::kMaxVolume;
+namespace {
+
+// Start with a conservative, but reasonable capture delay that should work for
+// most platforms (i.e., not needing an increase during a loopback session).
+constexpr base::TimeDelta kInitialCaptureDelay =
+    base::TimeDelta::FromMilliseconds(20);
+
+}  // namespace
 
 // static
-constexpr base::TimeDelta LoopbackStream::kCaptureDelay;
+constexpr double LoopbackStream::kMaxVolume;
 
 LoopbackStream::LoopbackStream(
     CreatedCallback created_callback,
@@ -294,6 +300,7 @@ void LoopbackStream::FlowNetwork::Start() {
   first_generate_time_ = clock_->NowTicks();
   frames_elapsed_ = 0;
   next_generate_time_ = first_generate_time_;
+  capture_delay_ = kInitialCaptureDelay;
 
   flow_task_runner_->PostTask(
       FROM_HERE,
@@ -319,21 +326,38 @@ void LoopbackStream::FlowNetwork::GenerateMoreAudio() {
   TRACE_EVENT_WITH_FLOW0("audio", "GenerateMoreAudio", this,
                          TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT);
 
-  // Always generate audio from the recent past, to prevent buffer underruns
-  // in the inputs.
-  const base::TimeTicks delayed_capture_time =
-      next_generate_time_ - kCaptureDelay;
-
   // Drive the audio flows from the SnooperNodes and produce the single result
   // stream. Hold the lock during this part of the process to prevent any of the
   // control methods from altering the configuration of the network.
   double output_volume;
+  base::TimeTicks delayed_capture_time;
   {
     base::AutoLock scoped_lock(lock_);
     output_volume = volume_;
 
     HelpDiagnoseCauseOfLoopbackCrash("generating");
 
+    // Compute the reference time to use for audio rendering. Query each input
+    // node and update |capture_delay_|, if necessary. This is used to always
+    // generate audio from a "safe point" in the recent past, to prevent buffer
+    // underruns in the inputs. http://crbug.com/934770
+    delayed_capture_time = next_generate_time_ - capture_delay_;
+    for (SnooperNode* node : inputs_) {
+      const base::Optional<base::TimeTicks> suggestion =
+          node->SuggestLatestRenderTime(mix_bus_->frames());
+      if (suggestion.value_or(delayed_capture_time) < delayed_capture_time) {
+        const base::TimeDelta increase = delayed_capture_time - (*suggestion);
+        TRACE_EVENT_INSTANT2("audio", "GenerateMoreAudio Capture Delay Change",
+                             TRACE_EVENT_SCOPE_THREAD, "old capture delay (µs)",
+                             capture_delay_.InMicroseconds(), "change (µs)",
+                             increase.InMicroseconds());
+        delayed_capture_time = *suggestion;
+        capture_delay_ += increase;
+      }
+    }
+    TRACE_COUNTER_ID1("audio", "Loopback Capture Delay (µs)", this,
+                      capture_delay_.InMicroseconds());
+
     // Render the audio from each input, apply this stream's volume setting by
     // scaling the data, then mix it all together to form a single audio
     // signal. If there are no snoopers, just render silence.

services/audio/loopback_stream.h

@@ -99,13 +99,6 @@ class LoopbackStream : public media::mojom::AudioInputStream,
   // than 1.0.
   static constexpr double kMaxVolume = 2.0;
 
-  // The amount of time in the past from which to capture the audio. The audio
-  // recorded from each LoopbackGroupMember is being generated with a target
-  // playout time in the near future (usually 1 to 20 ms). To avoid underflow,
-  // LoopbackStream fetches the audio from a position in the recent past.
-  static constexpr base::TimeDelta kCaptureDelay =
-      base::TimeDelta::FromMilliseconds(20);
-
  private:
   // Drives all audio flows, re-mixing the audio from multiple SnooperNodes into
   // a single audio stream. This class mainly operates on a separate task runner
@@ -201,6 +194,14 @@ class LoopbackStream : public media::mojom::AudioInputStream,
     int64_t frames_elapsed_ = 0;
     base::TimeTicks next_generate_time_;
 
+    // The amount of time in the past from which to capture the audio. The audio
+    // recorded from each SnooperNode input is being generated with a target
+    // playout time in the near future (usually 1 to 20 ms). To avoid underflow,
+    // audio is always fetched from a safe position in the recent past.
+    //
+    // This is updated to match the SnooperNode whose recording is most delayed.
+    base::TimeDelta capture_delay_;
+
     // Used to transfer the audio from each SnooperNode and mix them into a
     // single audio signal. |transfer_bus_| is only allocated when first needed,
     // but |mix_bus_| is allocated in the constructor because it is always

services/audio/snooper_node.cc

@@ -39,6 +39,12 @@ constexpr int kStepBasisHz = 1000;
 // data extraction.
 constexpr int kResamplerRequestSize = 3 * media::SincResampler::kKernelSize;
 
+// Returns the deviation, around an estimated reference time, beyond which a
+// SnooperNode considers a skip in input/output to have occurred.
+base::TimeDelta GetReferenceTimeSkipThreshold(base::TimeDelta bus_duration) {
+  return bus_duration / 2;
+}
+
 }  // namespace
 
 // static
@@ -62,6 +68,7 @@ SnooperNode::SnooperNode(const media::AudioParameters& input_params,
       buffer_(
           Helper::TimeToFrames(kDelayBufferSize, input_params_.sample_rate())),
       write_position_(kNullPosition),
+      checkpoint_time_(base::TimeTicks::Min()),
       read_position_(kNullPosition),
       correction_fps_(0),
       resampler_(
@@ -118,13 +125,36 @@ void SnooperNode::OnData(const media::AudioBus& input_bus,
   if (write_position_ == kNullPosition) {
     write_position_ = kWriteStartPosition;
   } else {
+    const base::TimeDelta threshold =
+        GetReferenceTimeSkipThreshold(input_bus_duration_);
     const base::TimeDelta delta = reference_time - write_reference_time_;
-    if (delta >= input_bus_duration_) {
+    if (delta < -threshold) {
+      TRACE_EVENT_INSTANT1("audio", "SnooperNode Discards Input",
+                           TRACE_EVENT_SCOPE_THREAD, "wait_time_remaining (μs)",
+                           (-delta).InMicroseconds());
+      // It's illegal to back-track the |write_position_| and/or attempt to
+      // "rewrite history" in the delay buffer. Thus, simply drop input until it
+      // catches up. Events such as this are generally only caused by device-
+      // switching in audio::OutputController, where the delay timestamps may
+      // shift. http://crbug.com/934770
+      return;
+    } else if (delta > threshold) {
       TRACE_EVENT_INSTANT1("audio", "SnooperNode Input Gap",
                            TRACE_EVENT_SCOPE_THREAD, "gap (μs)",
                            delta.InMicroseconds());
+      // Skip the |write_position_| forward, which will create a zero-fill gap
+      // in the delay buffer.
       write_position_ +=
           Helper::TimeToFrames(delta, input_params_.sample_rate());
+    } else {
+      // Normal case: Continue writing into the delay buffer at the current
+      // |write_position_|.
+      //
+      // Note that, if input was being discarded (in the prior OnData() call),
+      // there will be no "recovery adjustment" to the |write_position_|.
+      // Instead, any significant jump in |write_reference_time_| will cause
+      // Render() to gradually re-synchronize the audio. There will be no
+      // zero-fill gap inserted into the delay buffer.
     }
   }
 
@@ -134,6 +164,34 @@ void SnooperNode::OnData(const media::AudioBus& input_bus,
   write_reference_time_ = reference_time + input_bus_duration_;
 }
 
+base::Optional<base::TimeTicks> SnooperNode::SuggestLatestRenderTime(
+    FrameTicks duration) {
+  DCHECK_GE(duration, 0);
+
+  const base::TimeTicks last_checkpoint_time = checkpoint_time_;
+  {
+    base::AutoLock scoped_lock(lock_);
+    if (write_position_ == kNullPosition) {
+      return base::nullopt;  // OnData() never called yet.
+    }
+    checkpoint_time_ = write_reference_time_;
+  }
+
+  // Do not suggest any changes if OnData() has not been called since the last
+  // call to this method. This may indicate an input discontinuity is occurring.
+  if (checkpoint_time_ == last_checkpoint_time) {
+    return base::nullopt;
+  }
+
+  // Suggest a render time no later than a "safety margin" away from the end of
+  // the data currently recorded in the delay buffer. This extra margin helps to
+  // avoid underruns when the machine is under high stress.
+  const base::TimeDelta buffer_duration =
+      Helper::FramesToTime(duration, output_params_.sample_rate());
+  return checkpoint_time_ - buffer_duration -
+         GetReferenceTimeSkipThreshold(buffer_duration);
+}
+
 void SnooperNode::Render(base::TimeTicks reference_time,
                          media::AudioBus* output_bus) {
   DCHECK_EQ(output_bus->channels(), output_params_.channels());
@@ -172,8 +230,10 @@ void SnooperNode::Render(base::TimeTicks reference_time,
         estimated_output_position + std::lround(resampler_.BufferedFrames());
     DCHECK_EQ(correction_fps_, 0);
   } else {
+    const base::TimeDelta threshold =
+        GetReferenceTimeSkipThreshold(output_bus_duration_);
     const base::TimeDelta delta = reference_time - render_reference_time_;
-    if (delta < output_bus_duration_) {  // Normal case: No gap.
+    if (delta.magnitude() < threshold) {  // Normal case: No gap.
       // Compute the drift, which is the number of frames the resampler is
       // behind in reading from the delay buffer. This calculation also accounts
       // for the frames buffered within the resampler.
@@ -207,12 +267,12 @@ void SnooperNode::Render(base::TimeTicks reference_time,
       } else {
         // No correction necessary.
       }
-    } else /* if (delta >= threshold) */ {  // Gap detected.
-      TRACE_EVENT_INSTANT1("audio", "SnooperNode Render Gap",
-                           TRACE_EVENT_SCOPE_THREAD, "gap (μs)",
+    } else {  // Some type of rewind, fast-forward, or a rendering gap.
+      TRACE_EVENT_INSTANT1("audio", "SnooperNode Render Skip",
+                           TRACE_EVENT_SCOPE_THREAD, "delta (μs)",
                            delta.InMicroseconds());
 
-      // Rather than flush and re-prime the resampler, just skip-ahead its next
+      // Rather than flush and re-prime the resampler, just seek to its next
       // read-from position.
       read_position_ +=
           Helper::TimeToFrames(delta, input_params_.sample_rate());

services/audio/snooper_node.h

@@ -9,6 +9,7 @@
 #include <memory>
 
 #include "base/macros.h"
+#include "base/optional.h"
 #include "base/synchronization/lock.h"
 #include "base/time/time.h"
 #include "media/base/audio_parameters.h"
@@ -74,6 +75,13 @@ class SnooperNode : public LoopbackGroupMember::Snooper {
               base::TimeTicks reference_time,
               double volume) final;
 
+  // Given the timing of recent OnData() calls and the |duration| of output that
+  // would be requested in a call to Render(), determine the latest possible
+  // |reference_time| for a Render() call that won't result in an underrun.
+  // Returns base::nullopt while current conditions prohibit making a reliable
+  // suggestion.
+  base::Optional<base::TimeTicks> SuggestLatestRenderTime(FrameTicks duration);
+
   // Renders more audio that was recorded from the GroupMember until
   // |output_bus| is filled, resampling and remixing the channels if necessary.
   // |reference_time| is used for detecting skip-ahead (i.e., a significant
@@ -119,6 +127,11 @@ class SnooperNode : public LoopbackGroupMember::Snooper {
   FrameTicks write_position_;             // Guarded by |lock_|.
   base::TimeTicks write_reference_time_;  // Guarded by |lock_|.
 
+  // Used by SuggestLatestRenderTime() to track whether OnData() has been called
+  // recently, and as a basis for its suggestion. Other methods should not
+  // depend on this value for anything.
+  base::TimeTicks checkpoint_time_;
+
   // The next frame position from which to read from the delay buffer. This is
   // the position of the frames about to be pushed into the resampler, not the
   // position of frames about to be Render()'ed.

services/audio/stream_factory.cc

@@ -54,9 +54,9 @@ void StreamFactory::CreateInputStream(
   CHECK_EQ(magic_bytes_, 0x600DC0DEu);
   DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
   SetStateForCrashing("creating input stream");
-  TRACE_EVENT_NESTABLE_ASYNC_INSTANT1(
+  TRACE_EVENT_NESTABLE_ASYNC_INSTANT2(
       "audio", "CreateInputStream", bindings_.dispatch_context().id_for_trace(),
-      "device id", device_id);
+      "device id", device_id, "params", params.AsHumanReadableString());
 
   if (processing_config && processing_config->settings.requires_apm() &&
       params.GetBufferDuration() != base::TimeDelta::FromMilliseconds(10)) {
@@ -112,10 +112,10 @@ void StreamFactory::CreateOutputStream(
   CHECK_EQ(magic_bytes_, 0x600DC0DEu);
   DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
   SetStateForCrashing("creating output stream");
-  TRACE_EVENT_NESTABLE_ASYNC_INSTANT1(
+  TRACE_EVENT_NESTABLE_ASYNC_INSTANT2(
       "audio", "CreateOutputStream",
       bindings_.dispatch_context().id_for_trace(), "device id",
-      output_device_id);
+      output_device_id, "params", params.AsHumanReadableString());
 
   media::mojom::AudioOutputStreamObserverAssociatedPtr observer;
   observer.Bind(std::move(observer_info));
@@ -183,10 +183,11 @@ void StreamFactory::CreateLoopbackStream(
   CHECK_EQ(magic_bytes_, 0x600DC0DEu);
   DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
   SetStateForCrashing("creating loopback stream");
-  TRACE_EVENT_NESTABLE_ASYNC_INSTANT1(
+  TRACE_EVENT_NESTABLE_ASYNC_INSTANT2(
       "audio", "CreateLoopbackStream",
       bindings_.dispatch_context().id_for_trace(), "group id",
-      group_id.GetLowForSerialization());
+      group_id.GetLowForSerialization(), "params",
+      params.AsHumanReadableString());
 
   auto stream = std::make_unique<LoopbackStream>(
       std::move(created_callback),