Move underflow threshold limits out of the video renderer.

The threshold logic is incorrect when there's no audio track, which
the VideoRendererImpl has no knowledge of, so this logic needs to
live in the RendererImpl.

As a consequence of this, the underflow threshold is now based on
wall clock time instead of media time; which means non-realtime
playback will allow more or less media time to elapse before
underflow occurs.

Exposes a new command line flag --video-underflow-threshold-ms to
allow for experiments varying the threshold for YouTube.

BUG=423801, 470940
TEST=new unittests.

Review URL: https://codereview.chromium.org/1034233002

Cr-Commit-Position: refs/heads/master@{#323599}

9 files changed, 189 insertions, 36 deletions

diff --git a/content/browser/renderer_host/render_process_host_impl.cc b/content/browser/renderer_host/render_process_host_impl.cc
index ab8082e..24c4196 100644
--- a/content/browser/renderer_host/render_process_host_impl.cc
+++ b/content/browser/renderer_host/render_process_host_impl.cc
@@ -1319,6 +1319,7 @@ void RenderProcessHostImpl::PropagateBrowserCommandLineToRenderer(
     switches::kUseNormalPriorityForTileTaskWorkerThreads,
     switches::kV,
     switches::kVideoThreads,
+    switches::kVideoUnderflowThresholdMs,
     switches::kVModule,
     // Please keep these in alphabetical order. Compositor switches here should
     // also be added to chrome/browser/chromeos/login/chrome_restart_request.cc.
diff --git a/media/base/media_switches.cc b/media/base/media_switches.cc
index 44dea87..4390412 100644
--- a/media/base/media_switches.cc
+++ b/media/base/media_switches.cc
@@ -106,4 +106,9 @@ const char kEnableInbandTextTracks[] = "enable-inband-text-tracks";
 const char kRequireAudioHardwareForTesting[] =
     "require-audio-hardware-for-testing";
 
+// Allows clients to override the threshold for when the media renderer will
+// declare the underflow state for the video stream when audio is present.
+// TODO(dalecurtis): Remove once experiments for http://crbug.com/470940 finish.
+const char kVideoUnderflowThresholdMs[] = "video-underflow-threshold-ms";
+
 }  // namespace switches
diff --git a/media/base/media_switches.h b/media/base/media_switches.h
index 8c509a1ee..fa2bb9c 100644
--- a/media/base/media_switches.h
+++ b/media/base/media_switches.h
@@ -54,6 +54,8 @@ MEDIA_EXPORT extern const char kEnableInbandTextTracks[];
 
 MEDIA_EXPORT extern const char kRequireAudioHardwareForTesting[];
 
+MEDIA_EXPORT extern const char kVideoUnderflowThresholdMs[];
+
 }  // namespace switches
 
 #endif  // MEDIA_BASE_MEDIA_SWITCHES_H_
diff --git a/media/renderers/renderer_impl.cc b/media/renderers/renderer_impl.cc
index e81c97ae..8088b07 100644
--- a/media/renderers/renderer_impl.cc
+++ b/media/renderers/renderer_impl.cc
@@ -7,18 +7,24 @@
 #include "base/bind.h"
 #include "base/callback.h"
 #include "base/callback_helpers.h"
+#include "base/command_line.h"
 #include "base/compiler_specific.h"
 #include "base/location.h"
 #include "base/single_thread_task_runner.h"
+#include "base/strings/string_number_conversions.h"
 #include "media/base/audio_renderer.h"
 #include "media/base/bind_to_current_loop.h"
 #include "media/base/demuxer_stream_provider.h"
+#include "media/base/media_switches.h"
 #include "media/base/time_source.h"
 #include "media/base/video_renderer.h"
 #include "media/base/wall_clock_time_source.h"
 
 namespace media {
 
+// See |video_underflow_threshold_|.
+static const int kDefaultVideoUnderflowThresholdMs = 3000;
+
 RendererImpl::RendererImpl(
     const scoped_refptr<base::SingleThreadTaskRunner>& task_runner,
     scoped_ptr<AudioRenderer> audio_renderer,
@@ -36,9 +42,22 @@ RendererImpl::RendererImpl(
       cdm_context_(nullptr),
       underflow_disabled_for_testing_(false),
       clockless_video_playback_enabled_for_testing_(false),
+      video_underflow_threshold_(
+          base::TimeDelta::FromMilliseconds(kDefaultVideoUnderflowThresholdMs)),
       weak_factory_(this) {
   weak_this_ = weak_factory_.GetWeakPtr();
   DVLOG(1) << __FUNCTION__;
+
+  // TODO(dalecurtis): Remove once experiments for http://crbug.com/470940 are
+  // complete.
+  int threshold_ms = 0;
+  std::string threshold_ms_str(
+      base::CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
+          switches::kVideoUnderflowThresholdMs));
+  if (base::StringToInt(threshold_ms_str, &threshold_ms) && threshold_ms > 0) {
+    video_underflow_threshold_ =
+        base::TimeDelta::FromMilliseconds(threshold_ms);
+  }
 }
 
 RendererImpl::~RendererImpl() {
@@ -336,7 +355,7 @@ void RendererImpl::OnVideoRendererInitializeDone(PipelineStatus status) {
 
   if (audio_renderer_) {
     time_source_ = audio_renderer_->GetTimeSource();
-  } else {
+  } else if (!time_source_) {
     wall_clock_time_source_.reset(new WallClockTimeSource());
     time_source_ = wall_clock_time_source_.get();
   }
@@ -419,12 +438,37 @@ void RendererImpl::OnUpdateStatistics(const PipelineStatistics& stats) {
 
 void RendererImpl::OnBufferingStateChanged(BufferingState* buffering_state,
                                            BufferingState new_buffering_state) {
+  const bool is_audio = buffering_state == &audio_buffering_state_;
   DVLOG(1) << __FUNCTION__ << "(" << *buffering_state << ", "
-           << new_buffering_state << ") "
-           << (buffering_state == &audio_buffering_state_ ? "audio" : "video");
+           << new_buffering_state << ") " << (is_audio ? "audio" : "video");
   DCHECK(task_runner_->BelongsToCurrentThread());
+
   bool was_waiting_for_enough_data = WaitingForEnoughData();
 
+  // When audio is present, defer underflow callbacks for some time to avoid
+  // unnecessary glitches in audio; see http://crbug.com/144683#c53.
+  if (audio_renderer_ && !is_audio && state_ == STATE_PLAYING) {
+    if (video_buffering_state_ == BUFFERING_HAVE_ENOUGH &&
+        new_buffering_state == BUFFERING_HAVE_NOTHING &&
+        deferred_underflow_cb_.IsCancelled()) {
+      deferred_underflow_cb_.Reset(base::Bind(
+          &RendererImpl::OnBufferingStateChanged, weak_factory_.GetWeakPtr(),
+          buffering_state, new_buffering_state));
+      task_runner_->PostDelayedTask(FROM_HERE,
+                                    deferred_underflow_cb_.callback(),
+                                    video_underflow_threshold_);
+      return;
+    }
+
+    deferred_underflow_cb_.Cancel();
+  } else if (!deferred_underflow_cb_.IsCancelled() && is_audio &&
+             new_buffering_state == BUFFERING_HAVE_NOTHING) {
+    // If audio underflows while we have a deferred video underflow in progress
+    // we want to mark video as underflowed immediately and cancel the deferral.
+    deferred_underflow_cb_.Cancel();
+    video_buffering_state_ = BUFFERING_HAVE_NOTHING;
+  }
+
   *buffering_state = new_buffering_state;
 
   // Disable underflow by ignoring updates that renderers have ran out of data.
diff --git a/media/renderers/renderer_impl.h b/media/renderers/renderer_impl.h
index 03942d5..e0374fb 100644
--- a/media/renderers/renderer_impl.h
+++ b/media/renderers/renderer_impl.h
@@ -5,6 +5,7 @@
 #ifndef MEDIA_RENDERERS_RENDERER_IMPL_H_
 #define MEDIA_RENDERERS_RENDERER_IMPL_H_
 
+#include "base/cancelable_callback.h"
 #include "base/memory/ref_counted.h"
 #include "base/memory/scoped_ptr.h"
 #include "base/memory/weak_ptr.h"
@@ -64,6 +65,12 @@ class MEDIA_EXPORT RendererImpl : public Renderer {
   // Helper functions for testing purposes. Must be called before Initialize().
   void DisableUnderflowForTesting();
   void EnableClocklessVideoPlaybackForTesting();
+  void set_time_source_for_testing(TimeSource* time_source) {
+    time_source_ = time_source;
+  }
+  void set_video_underflow_threshold_for_testing(base::TimeDelta threshold) {
+    video_underflow_threshold_ = threshold;
+  }
 
  private:
   enum State {
@@ -171,6 +178,13 @@ class MEDIA_EXPORT RendererImpl : public Renderer {
   bool underflow_disabled_for_testing_;
   bool clockless_video_playback_enabled_for_testing_;
 
+  // Used to defer underflow for video when audio is present.
+  base::CancelableClosure deferred_underflow_cb_;
+
+  // The amount of time to wait before declaring underflow if the video renderer
+  // runs out of data but the audio renderer still has enough.
+  base::TimeDelta video_underflow_threshold_;
+
   base::WeakPtr<RendererImpl> weak_this_;
   base::WeakPtrFactory<RendererImpl> weak_factory_;
 
diff --git a/media/renderers/renderer_impl_unittest.cc b/media/renderers/renderer_impl_unittest.cc
index 30bad2fe..1dacbcc 100644
--- a/media/renderers/renderer_impl_unittest.cc
+++ b/media/renderers/renderer_impl_unittest.cc
@@ -110,6 +110,8 @@ class RendererImplTest : public ::testing::Test {
     if (start_status == PIPELINE_OK && audio_stream_) {
       EXPECT_CALL(*audio_renderer_, GetTimeSource())
           .WillOnce(Return(&time_source_));
+    } else {
+      renderer_impl_->set_time_source_for_testing(&time_source_);
     }
 
     renderer_impl_->Initialize(
@@ -174,10 +176,10 @@ class RendererImplTest : public ::testing::Test {
 
     base::TimeDelta start_time(
         base::TimeDelta::FromMilliseconds(kStartPlayingTimeInMs));
+    EXPECT_CALL(time_source_, SetMediaTime(start_time));
+    EXPECT_CALL(time_source_, StartTicking());
 
     if (audio_stream_) {
-      EXPECT_CALL(time_source_, SetMediaTime(start_time));
-      EXPECT_CALL(time_source_, StartTicking());
       EXPECT_CALL(*audio_renderer_, StartPlaying())
           .WillOnce(SetBufferingState(&audio_buffering_state_cb_,
                                       BUFFERING_HAVE_ENOUGH));
@@ -194,9 +196,10 @@ class RendererImplTest : public ::testing::Test {
   }
 
   void Flush(bool underflowed) {
+    if (!underflowed)
+      EXPECT_CALL(time_source_, StopTicking());
+
     if (audio_stream_) {
-      if (!underflowed)
-        EXPECT_CALL(time_source_, StopTicking());
       EXPECT_CALL(*audio_renderer_, Flush(_))
           .WillOnce(DoAll(SetBufferingState(&audio_buffering_state_cb_,
                                             BUFFERING_HAVE_NOTHING),
@@ -367,7 +370,7 @@ TEST_F(RendererImplTest, VideoStreamEnded) {
   InitializeWithVideo();
   Play();
 
-  // Video ended won't affect |time_source_|.
+  EXPECT_CALL(time_source_, StopTicking());
   EXPECT_CALL(callbacks_, OnEnded());
 
   video_ended_cb_.Run();
@@ -446,4 +449,87 @@ TEST_F(RendererImplTest, ErrorDuringInitialize) {
   InitializeAndExpect(PIPELINE_ERROR_DECODE);
 }
 
+TEST_F(RendererImplTest, AudioUnderflow) {
+  InitializeWithAudio();
+  Play();
+
+  // Underflow should occur immediately with a single audio track.
+  EXPECT_CALL(time_source_, StopTicking());
+  audio_buffering_state_cb_.Run(BUFFERING_HAVE_NOTHING);
+}
+
+TEST_F(RendererImplTest, AudioUnderflowWithVideo) {
+  InitializeWithAudioAndVideo();
+  Play();
+
+  // Underflow should be immediate when both audio and video are present and
+  // audio underflows.
+  EXPECT_CALL(time_source_, StopTicking());
+  audio_buffering_state_cb_.Run(BUFFERING_HAVE_NOTHING);
+}
+
+TEST_F(RendererImplTest, VideoUnderflow) {
+  InitializeWithVideo();
+  Play();
+
+  // Underflow should occur immediately with a single video track.
+  EXPECT_CALL(time_source_, StopTicking());
+  video_buffering_state_cb_.Run(BUFFERING_HAVE_NOTHING);
+}
+
+TEST_F(RendererImplTest, VideoUnderflowWithAudio) {
+  InitializeWithAudioAndVideo();
+  Play();
+
+  // Set a zero threshold such that the underflow will be executed on the next
+  // run of the message loop.
+  renderer_impl_->set_video_underflow_threshold_for_testing(base::TimeDelta());
+
+  // Underflow should be delayed when both audio and video are present and video
+  // underflows.
+  video_buffering_state_cb_.Run(BUFFERING_HAVE_NOTHING);
+  Mock::VerifyAndClearExpectations(&time_source_);
+
+  EXPECT_CALL(time_source_, StopTicking());
+  base::RunLoop().RunUntilIdle();
+}
+
+TEST_F(RendererImplTest, VideoUnderflowWithAudioVideoRecovers) {
+  InitializeWithAudioAndVideo();
+  Play();
+
+  // Set a zero threshold such that the underflow will be executed on the next
+  // run of the message loop.
+  renderer_impl_->set_video_underflow_threshold_for_testing(base::TimeDelta());
+
+  // Underflow should be delayed when both audio and video are present and video
+  // underflows.
+  video_buffering_state_cb_.Run(BUFFERING_HAVE_NOTHING);
+  Mock::VerifyAndClearExpectations(&time_source_);
+
+  // If video recovers, the underflow should never occur.
+  video_buffering_state_cb_.Run(BUFFERING_HAVE_ENOUGH);
+  base::RunLoop().RunUntilIdle();
+}
+
+TEST_F(RendererImplTest, VideoAndAudioUnderflow) {
+  InitializeWithAudioAndVideo();
+  Play();
+
+  // Set a zero threshold such that the underflow will be executed on the next
+  // run of the message loop.
+  renderer_impl_->set_video_underflow_threshold_for_testing(base::TimeDelta());
+
+  // Underflow should be delayed when both audio and video are present and video
+  // underflows.
+  video_buffering_state_cb_.Run(BUFFERING_HAVE_NOTHING);
+  Mock::VerifyAndClearExpectations(&time_source_);
+
+  EXPECT_CALL(time_source_, StopTicking());
+  audio_buffering_state_cb_.Run(BUFFERING_HAVE_NOTHING);
+
+  // Nothing else should primed on the message loop.
+  base::RunLoop().RunUntilIdle();
+}
+
 }  // namespace media
diff --git a/media/renderers/video_renderer_impl.cc b/media/renderers/video_renderer_impl.cc
index a43ddab..704c5ed 100644
--- a/media/renderers/video_renderer_impl.cc
+++ b/media/renderers/video_renderer_impl.cc
@@ -190,11 +190,6 @@ void VideoRendererImpl::ThreadMain() {
   const base::TimeDelta kIdleTimeDelta =
       base::TimeDelta::FromMilliseconds(10);
 
-  // If we have no frames and haven't painted any frame for certain amount of
-  // time, declare BUFFERING_HAVE_NOTHING.
-  const base::TimeDelta kTimeToDeclareHaveNothing =
-      base::TimeDelta::FromSeconds(3);
-
   for (;;) {
     base::AutoLock auto_lock(lock_);
 
@@ -212,19 +207,23 @@ void VideoRendererImpl::ThreadMain() {
 
     // Remain idle until we have the next frame ready for rendering.
     if (ready_frames_.empty()) {
+      base::TimeDelta wait_time = kIdleTimeDelta;
       if (received_end_of_stream_) {
         if (!rendered_end_of_stream_) {
           rendered_end_of_stream_ = true;
           task_runner_->PostTask(FROM_HERE, ended_cb_);
         }
-      } else if (!last_painted_time_.is_null() &&
-                 now - last_painted_time_ >= kTimeToDeclareHaveNothing) {
+      } else if (now >= latest_possible_paint_time_) {
+        // Declare HAVE_NOTHING if we don't have another frame by the time we
+        // are ready to paint the next one.
         buffering_state_ = BUFFERING_HAVE_NOTHING;
         task_runner_->PostTask(
             FROM_HERE, base::Bind(buffering_state_cb_, BUFFERING_HAVE_NOTHING));
+      } else {
+        wait_time = std::min(kIdleTimeDelta, latest_possible_paint_time_ - now);
       }
 
-      UpdateStatsAndWait_Locked(kIdleTimeDelta);
+      UpdateStatsAndWait_Locked(wait_time);
       continue;
     }
 
@@ -237,8 +236,6 @@ void VideoRendererImpl::ThreadMain() {
       continue;
     }
 
-    base::TimeTicks latest_possible_paint_time;
-
     // Deadline is defined as the duration between this frame and the next
     // frame, using the delta between this frame and the previous frame as the
     // assumption for frame duration.
@@ -246,10 +243,10 @@ void VideoRendererImpl::ThreadMain() {
     // TODO(scherkus): This can be vastly improved. Use a histogram to measure
     // the accuracy of our frame timing code. http://crbug.com/149829
     if (last_media_time_.is_null()) {
-      latest_possible_paint_time = now;
+      latest_possible_paint_time_ = now;
     } else {
       base::TimeDelta duration = target_paint_time - last_media_time_;
-      latest_possible_paint_time = target_paint_time + duration;
+      latest_possible_paint_time_ = target_paint_time + duration;
     }
 
     // Remain idle until we've reached our target paint window.
@@ -259,7 +256,7 @@ void VideoRendererImpl::ThreadMain() {
       continue;
     }
 
-    if (ready_frames_.size() > 1 && now > latest_possible_paint_time &&
+    if (ready_frames_.size() > 1 && now > latest_possible_paint_time_ &&
         drop_frames_) {
       DropNextReadyFrame_Locked();
       continue;
@@ -285,8 +282,7 @@ void VideoRendererImpl::PaintNextReadyFrame_Locked() {
   ready_frames_.pop_front();
   frames_decoded_++;
 
-  last_media_time_ = last_painted_time_ =
-      wall_clock_time_cb_.Run(next_frame->timestamp());
+  last_media_time_ = wall_clock_time_cb_.Run(next_frame->timestamp());
 
   paint_cb_.Run(next_frame);
 
@@ -443,7 +439,7 @@ void VideoRendererImpl::OnVideoFrameStreamResetDone() {
   DCHECK_EQ(buffering_state_, BUFFERING_HAVE_NOTHING);
 
   state_ = kFlushed;
-  last_media_time_ = last_painted_time_ = base::TimeTicks();
+  latest_possible_paint_time_ = last_media_time_ = base::TimeTicks();
   base::ResetAndReturn(&flush_cb_).Run();
 }
 
diff --git a/media/renderers/video_renderer_impl.h b/media/renderers/video_renderer_impl.h
index 6f6c027..ec3d72d 100644
--- a/media/renderers/video_renderer_impl.h
+++ b/media/renderers/video_renderer_impl.h
@@ -197,9 +197,8 @@ class MEDIA_EXPORT VideoRendererImpl
   // flushing.
   base::TimeTicks last_media_time_;
 
-  // The wallclock time of the last successfully painted frame. Set to null
-  // during flushing.
-  base::TimeTicks last_painted_time_;
+  // Equivalent to |last_media_time_| + the estimated duration of the frame.
+  base::TimeTicks latest_possible_paint_time_;
 
   // Keeps track of the number of frames decoded and dropped since the
   // last call to |statistics_cb_|. These must be accessed under lock.
diff --git a/media/renderers/video_renderer_impl_unittest.cc b/media/renderers/video_renderer_impl_unittest.cc
index c1a029f..df5c9d3 100644
--- a/media/renderers/video_renderer_impl_unittest.cc
+++ b/media/renderers/video_renderer_impl_unittest.cc
@@ -498,21 +498,27 @@ TEST_F(VideoRendererImplTest, Underflow) {
     Mock::VerifyAndClearExpectations(&mock_cb_);
   }
 
-  // Advance time slightly. Frames should be dropped and we should NOT signal
-  // having nothing.
-  AdvanceTimeInMs(100);
+  // Advance time slightly, but enough to exceed the duration of the last frame.
+  // Frames should be dropped and we should NOT signal having nothing.
+  {
+    SCOPED_TRACE("Waiting for frame drops");
+    WaitableMessageLoopEvent event;
+    EXPECT_CALL(mock_cb_, Display(HasTimestamp(10))).Times(0);
+    EXPECT_CALL(mock_cb_, Display(HasTimestamp(20))).Times(0);
+    EXPECT_CALL(mock_cb_, Display(HasTimestamp(30)))
+        .WillOnce(RunClosure(event.GetClosure()));
+    AdvanceTimeInMs(31);
+    event.RunAndWait();
+    Mock::VerifyAndClearExpectations(&mock_cb_);
+  }
 
-  // Advance time more. Now we should signal having nothing. And put
-  // the last frame up for display.
+  // Advance time more, such that a new frame should have been displayed by now.
   {
     SCOPED_TRACE("Waiting for BUFFERING_HAVE_NOTHING");
     WaitableMessageLoopEvent event;
     EXPECT_CALL(mock_cb_, BufferingStateChange(BUFFERING_HAVE_NOTHING))
         .WillOnce(RunClosure(event.GetClosure()));
-    EXPECT_CALL(mock_cb_, Display(HasTimestamp(10))).Times(0);
-    EXPECT_CALL(mock_cb_, Display(HasTimestamp(20))).Times(0);
-    EXPECT_CALL(mock_cb_, Display(HasTimestamp(30))).Times(1);
-    AdvanceTimeInMs(3000);  // Must match kTimeToDeclareHaveNothing.
+    AdvanceWallclockTimeInMs(9);
     event.RunAndWait();
     Mock::VerifyAndClearExpectations(&mock_cb_);
   }