Use ffmpeg packet.pos for restarting reading after reenabling video

media/filters/ffmpeg_demuxer.cc

Index: media/filters/ffmpeg_demuxer.cc
diff --git a/media/filters/ffmpeg_demuxer.cc b/media/filters/ffmpeg_demuxer.cc
index 136fe32a7b9ab469020a8e9c0a606af25c3cb0ef..1db6eb3d8a300c80a41e640ebbb0055713c9cb40 100644
--- a/media/filters/ffmpeg_demuxer.cc
+++ b/media/filters/ffmpeg_demuxer.cc
@@ -51,6 +51,9 @@ namespace media {
 
 namespace {
 
+// Try to have two second's worth of encoded data per stream.
+const base::TimeDelta kDefaultStreamCapacity = base::TimeDelta::FromSeconds(2);

[DaleCurtis, 2017/05/24 22:24:17]

constexpr or this is a static initializer.

[servolk, 2017/05/24 22:58:19]

Done.

+
 void SetAVStreamDiscard(AVStream* stream, AVDiscard discard) {
   DCHECK(stream);
   stream->discard = discard;
@@ -302,7 +305,8 @@ FFmpegDemuxerStream::FFmpegDemuxerStream(
       is_enabled_(true),
       waiting_for_keyframe_(false),
       aborted_(false),
-      fixup_negative_timestamps_(false) {
+      fixup_negative_timestamps_(false),
+      stream_capacity_(kDefaultStreamCapacity) {
   DCHECK(demuxer_);
 
   bool is_encrypted = false;
@@ -811,9 +815,7 @@ void FFmpegDemuxerStream::SatisfyPendingRead() {
 }
 
 bool FFmpegDemuxerStream::HasAvailableCapacity() {
-  // Try to have two second's worth of encoded data per stream.
-  const base::TimeDelta kCapacity = base::TimeDelta::FromSeconds(2);
-  return buffer_queue_.IsEmpty() || buffer_queue_.Duration() < kCapacity;
+  return buffer_queue_.IsEmpty() || buffer_queue_.Duration() < stream_capacity_;
 }
 
 size_t FFmpegDemuxerStream::MemoryUsage() const {
@@ -870,6 +872,7 @@ FFmpegDemuxer::FFmpegDemuxer(
            base::TaskPriority::USER_BLOCKING})),
       stopped_(false),
       pending_read_(false),
+      pending_seek_position_(kNoTimestamp),
       data_source_(data_source),
       media_log_(media_log),
       bitrate_(0),
@@ -878,6 +881,8 @@ FFmpegDemuxer::FFmpegDemuxer(
       duration_known_(false),
       encrypted_media_init_data_cb_(encrypted_media_init_data_cb),
       media_tracks_updated_cb_(media_tracks_updated_cb),
+      last_audio_packet_pos_(-1),
+      restarting_stream_(nullptr),
       cancel_pending_seek_factory_(this),
       weak_factory_(this) {
   DCHECK(task_runner_.get());
@@ -968,6 +973,7 @@ void FFmpegDemuxer::AbortPendingReads() {
   // currently the PipelineImpl does not know how to handle this.
   if (!pending_seek_cb_.is_null())
     base::ResetAndReturn(&pending_seek_cb_).Run(PIPELINE_OK);
+  pending_seek_position_ = kNoTimestamp;
 }
 
 void FFmpegDemuxer::Stop() {
@@ -1009,50 +1015,12 @@ void FFmpegDemuxer::CancelPendingSeek(base::TimeDelta seek_time) {
 void FFmpegDemuxer::Seek(base::TimeDelta time, const PipelineStatusCB& cb) {
   DCHECK(task_runner_->BelongsToCurrentThread());
   CHECK(pending_seek_cb_.is_null());
-
-  // FFmpeg requires seeks to be adjusted according to the lowest starting time.
-  // Since EnqueuePacket() rebased negative timestamps by the start time, we
-  // must correct the shift here.
-  //
-  // Additionally, to workaround limitations in how we expose seekable ranges to
-  // Blink (http://crbug.com/137275), we also want to clamp seeks before the
-  // start time to the start time.
-  base::TimeDelta seek_time = start_time_ < base::TimeDelta()
-                                  ? time + start_time_
-                                  : time < start_time_ ? start_time_ : time;
-
-  // When seeking in an opus stream we need to ensure we deliver enough data to
-  // satisfy the seek preroll; otherwise the audio at the actual seek time will
-  // not be entirely accurate.
-  FFmpegDemuxerStream* audio_stream =
-      GetFirstEnabledFFmpegStream(DemuxerStream::AUDIO);
-  if (audio_stream) {
-    const AudioDecoderConfig& config = audio_stream->audio_decoder_config();
-    if (config.codec() == kCodecOpus)
-      seek_time = std::max(start_time_, seek_time - config.seek_preroll());
-  }
-
-  // Choose the seeking stream based on whether it contains the seek time, if no
-  // match can be found prefer the preferred stream.
-  //
-  // TODO(dalecurtis): Currently FFmpeg does not ensure that all streams in a
-  // given container will demux all packets after the seek point.  Instead it
-  // only guarantees that all packets after the file position of the seek will
-  // be demuxed.  It's an open question whether FFmpeg should fix this:
-  // http://lists.ffmpeg.org/pipermail/ffmpeg-devel/2014-June/159212.html
-  // Tracked by http://crbug.com/387996.
-  FFmpegDemuxerStream* demux_stream = FindPreferredStreamForSeeking(seek_time);
-  DCHECK(demux_stream);
-  const AVStream* seeking_stream = demux_stream->av_stream();
-  DCHECK(seeking_stream);
-
+  DCHECK_EQ(pending_seek_position_, kNoTimestamp);
   pending_seek_cb_ = cb;
-  base::PostTaskAndReplyWithResult(
-      blocking_task_runner_.get(), FROM_HERE,
-      base::Bind(&av_seek_frame, glue_->format_context(), seeking_stream->index,
-                 ConvertToTimeBase(seeking_stream->time_base, seek_time),
-                 // Always seek to a timestamp <= to the desired timestamp.
-                 AVSEEK_FLAG_BACKWARD),
+  pending_seek_position_ = time;
+
+  SeekInternal(
+      time, nullptr,
       base::Bind(&FFmpegDemuxer::OnSeekFrameDone, weak_factory_.GetWeakPtr()));
 }
 
@@ -1659,6 +1627,7 @@ void FFmpegDemuxer::OnSeekFrameDone(int result) {
   if (stopped_) {
     MEDIA_LOG(ERROR, media_log_) << GetDisplayName() << ": bad state";
     base::ResetAndReturn(&pending_seek_cb_).Run(PIPELINE_ERROR_ABORT);
+    pending_seek_position_ = kNoTimestamp;
     return;
   }
 
@@ -1669,6 +1638,15 @@ void FFmpegDemuxer::OnSeekFrameDone(int result) {
     VLOG(1) << "Not implemented";
   }
 
+  // If we had been restarting the video stream, we can cancel that now, because

[DaleCurtis, 2017/05/25 00:08:06]

I think this isn't true since you don't know how far along the seek is by the
time of enable; the enable must occur before the av_seek_frame() call. You can
only clear this if a user-initiated seek comes in while we're trying to seek for
a restart.

+  // we'll just restart reading it automatically from the new position after
+  // this new seek request is completed.
+  if (restarting_stream_) {
+    DVLOG(2) << "Cancelled stream restart due to intervening seek";
+    restarting_stream_ = nullptr;
+  }
+  last_audio_packet_pos_ = -1;
+
   // Tell streams to flush buffers due to seeking.
   for (const auto& stream : streams_) {
     if (stream)
@@ -1680,6 +1658,7 @@ void FFmpegDemuxer::OnSeekFrameDone(int result) {
 
   // Notify we're finished seeking.
   base::ResetAndReturn(&pending_seek_cb_).Run(PIPELINE_OK);
+  pending_seek_position_ = kNoTimestamp;
 }
 
 void FFmpegDemuxer::OnEnabledAudioTracksChanged(
@@ -1742,7 +1721,43 @@ void FFmpegDemuxer::OnSelectedVideoTrackChanged(
   if (selected_stream) {
     DVLOG(1) << __func__ << ": enabling stream " << selected_stream;
     selected_stream->SetEnabled(true, curr_time);
+    // Now that the video stream is re-enabled we'll want video renderer to
+    // restart playback from the |curr_time| position. For that we'll need to
+    // seek back to the last key frame preceeding |curr_time| in the
+    // |selected_stream|.
+    if (!pending_seek_cb_) {
+      selected_stream->FlushBuffers();
+      SeekInternal(curr_time, selected_stream,
+                   base::Bind(&FFmpegDemuxer::OnSeekDoneForRestartingStream,
+                              weak_factory_.GetWeakPtr(), selected_stream));
+    } else {

[DaleCurtis, 2017/05/24 22:24:18]

Lets avoid this whole issue by just not allowing track changes until the seek
completes. We do not allow multiple concurrent operations of other types for
simplicity.

I think that's one of the big issues we've had with track changes thus far; they
should be queued after any pending operations instead of taking affect
immediately. I.e., this queuing should happen in the Pipeline, not here.

[servolk, 2017/05/24 22:58:19]

Sure, if we didn't allow track changes during pending seeks that would make our
life (and this code) easier. But I think we need to consider a few points first:
1. Wouldn't that be counter to HTML5 spec? Track changes and seeks are initiated
by Javascript code and I'm not aware of any place in the html5 spec that says
that track changes during pending seeks are prohibited. On one hand it might be
common sense, but on the other hand apps might attempt that and we need to be
prepared to deal with it.
2. If we still decide to disallow it, how exactly should we do this? Postpone
track changes on the PipelineImpl level until a pending seek is completed?
Ignore (i.e. drop) track changes when there's a pending seek? DCHECK?

[DaleCurtis, 2017/05/24 23:15:46]

We're not talking about prohibiting them, we're talking about queuing them at a
different layer. Similar to how PipelineController keeps track of a pending seek
time.

Seeks have always been async, you fire it is not complete until the seeked
event. All I'm proposing here is that this is the wrong layer at which to be
handling the queuing, instead the pipeline should be delaying this track change
until the seek completes or delaying the seek until the track change completes.

+      // If there's already pending seek, we'll need to restart it after its
+      // completion and after SetAVStreamDiscard initiated by SetEnabled takes
+      // effect, in order to ensure we get a key frame for |selected_stream|.
+      auto old_pending_seek_cb = pending_seek_cb_;
+      DCHECK_NE(pending_seek_position_, kNoTimestamp);
+      DVLOG(2) << __func__ << ": Pending seek to " << pending_seek_position_
+               << " detected, postponing stream restart until seek completes.";
+      pending_seek_cb_ = base::Bind(
+          &FFmpegDemuxer::RestartPendingSeek, weak_factory_.GetWeakPtr(),
+          pending_seek_position_, old_pending_seek_cb);
+    }
+  }
+}
+
+void FFmpegDemuxer::OnSeekDoneForRestartingStream(FFmpegDemuxerStream* stream,
+                                                  int result) {
+  DCHECK(task_runner_->BelongsToCurrentThread());
+  if (result < 0) {
+    MEDIA_LOG(ERROR, media_log_)
+        << __func__ << ": seek failed: " << AVErrorToString(result);
+    return;
   }
+  DVLOG(2) << __func__ << ": will drop packets until last_audio_packet_pos_="
+           << last_audio_packet_pos_;
+  if (restarting_stream_)

[DaleCurtis, 2017/05/25 00:08:06]

This will need an early exit if a seek() comes in during the restart for now.

+    restarting_stream_->FlushBuffers();
+  restarting_stream_ = stream;
 }
 
 void FFmpegDemuxer::ReadFrameIfNeeded() {
@@ -1829,7 +1844,29 @@ void FFmpegDemuxer::OnReadFrameDone(ScopedAVPacket packet, int result) {
     }
 
     FFmpegDemuxerStream* demuxer_stream = streams_[packet->stream_index].get();
-    if (demuxer_stream->IsEnabled())
+
+    DVLOG(5) << "Got AVPacket: stream_index=" << packet->stream_index
+             << " type=" << demuxer_stream->type() << " pos=" << packet->pos
+             << " pts=" << packet->pts;
+
+    // If |restarting_stream_| is not null, we are in stream restart mode, which
+    // means we seeked back the ffmpeg reading position and now we need to drop
+    // packets from other streams until we reach the previously seen read
+    // position |last_audio_packet_pos_|.
+    bool drop_seen_packet =
+        restarting_stream_ && demuxer_stream != restarting_stream_ &&
+        last_audio_packet_pos_ >= 0 && packet->pos <= last_audio_packet_pos_;
+    if (drop_seen_packet) {
+      DVLOG(4) << "Dropping already seen packet packet: pos=" << packet->pos;
+    } else if (restarting_stream_ && demuxer_stream != restarting_stream_) {
+      DVLOG(2) << "Restarting reading packets: pos=" << packet->pos;
+      restarting_stream_ = nullptr;
+    }
+
+    if (!restarting_stream_ && demuxer_stream->type() == DemuxerStream::AUDIO)

[DaleCurtis, 2017/05/24 22:24:18]

Isn't this going to be incorrect for streams with embedded text tracks? I.e.
we'll end up duplicating some of the text packets?

+      last_audio_packet_pos_ = packet->pos;
+
+    if (demuxer_stream->IsEnabled() && !drop_seen_packet)
       demuxer_stream->EnqueuePacket(std::move(packet));
 
     // If duration estimate was incorrect, update it and tell higher layers.
@@ -1849,7 +1886,7 @@ void FFmpegDemuxer::OnReadFrameDone(ScopedAVPacket packet, int result) {
 bool FFmpegDemuxer::StreamsHaveAvailableCapacity() {
   DCHECK(task_runner_->BelongsToCurrentThread());
   for (const auto& stream : streams_) {
-    if (stream && stream->HasAvailableCapacity())
+    if (stream && stream->IsEnabled() && stream->HasAvailableCapacity())
       return true;
   }
   return false;
@@ -1901,4 +1938,72 @@ void FFmpegDemuxer::SetLiveness(DemuxerStream::Liveness liveness) {
   }
 }
 
+void FFmpegDemuxer::SeekInternal(base::TimeDelta time,
+                                 FFmpegDemuxerStream* preferred_stream,
+                                 const FFmpegSeekDoneCB& ffmpeg_seek_done_cb) {
+  DCHECK(task_runner_->BelongsToCurrentThread());
+  DVLOG(2) << __func__ << " time=" << time << " stream=" << preferred_stream;
+
+  // FFmpeg requires seeks to be adjusted according to the lowest starting time.
+  // Since EnqueuePacket() rebased negative timestamps by the start time, we
+  // must correct the shift here.
+  //
+  // Additionally, to workaround limitations in how we expose seekable ranges to
+  // Blink (http://crbug.com/137275), we also want to clamp seeks before the
+  // start time to the start time.
+  base::TimeDelta seek_time = start_time_ < base::TimeDelta()
+                                  ? time + start_time_
+                                  : time < start_time_ ? start_time_ : time;
+
+  // When seeking in an opus stream we need to ensure we deliver enough data to
+  // satisfy the seek preroll; otherwise the audio at the actual seek time will
+  // not be entirely accurate.
+  FFmpegDemuxerStream* audio_stream =
+      GetFirstEnabledFFmpegStream(DemuxerStream::AUDIO);
+  if (audio_stream) {
+    const AudioDecoderConfig& config = audio_stream->audio_decoder_config();
+    if (config.codec() == kCodecOpus)
+      seek_time = std::max(start_time_, seek_time - config.seek_preroll());
+  }
+
+  if (!preferred_stream) {
+    // Choose the seeking stream based on whether it contains the seek time, if
+    // no match can be found prefer the preferred stream.
+    //
+    // TODO(dalecurtis): Currently FFmpeg does not ensure that all streams in a

[DaleCurtis, 2017/05/24 22:24:18]

Note we may run into this issue now more frequently...

[servolk, 2017/05/24 22:58:19]

We might, especially considering that this is going to be triggered whenever a
background tab with background video track optimization comes into foreground.
But can we do anything to mitigate this issue?
I've read most of that FFmpeg mailing list thread, but it's not clear to me if
anything has actually been done in FFmpeg to fix this issue. Looks like there's
been some discussion between FFmpeg folks, but no further activity in that
thread after Aaron's message. Would we need to switch to avformat_seek_file to
fix this? Is that API now stable in FFmpeg?
Anyway, whatever we'd need to do to address this would probably need to be a
separate CL, since it sounds non-trivial.

[DaleCurtis, 2017/05/25 00:08:06]

I don't think that API fixes the issue. I experimented with it. It's unclear
what would need to be done, so we'll just have to see what happens. I think for
video it's not an issue, we'll always get a key frame, but audio or text tracks
may be stuck at a different point.

+    // given container will demux all packets after the seek point.  Instead it
+    // only guarantees that all packets after the file position of the seek will
+    // be demuxed.  It's an open question whether FFmpeg should fix this:
+    // http://lists.ffmpeg.org/pipermail/ffmpeg-devel/2014-June/159212.html
+    // Tracked by http://crbug.com/387996.
+    preferred_stream = FindPreferredStreamForSeeking(seek_time);
+    DCHECK(preferred_stream);
+  }
+  const AVStream* ffmpeg_stream = preferred_stream->av_stream();
+  DCHECK(ffmpeg_stream);
+
+  base::PostTaskAndReplyWithResult(
+      blocking_task_runner_.get(), FROM_HERE,
+      base::Bind(&av_seek_frame, glue_->format_context(), ffmpeg_stream->index,
+                 ConvertToTimeBase(ffmpeg_stream->time_base, seek_time),
+                 // Always seek to a timestamp <= to the desired timestamp.
+                 AVSEEK_FLAG_BACKWARD),
+      ffmpeg_seek_done_cb);
+}
+
+void FFmpegDemuxer::RestartPendingSeek(base::TimeDelta time,
+                                       const PipelineStatusCB& cb,
+                                       PipelineStatus prev_seek_status) {
+  DCHECK(task_runner_->BelongsToCurrentThread());
+  DCHECK_NE(pending_seek_position_, kNoTimestamp);
+  DCHECK(cb);
+  // We are going to ignore prev_seek_status here, because we are about to
+  // repeat the seek anyway. The previous seek outcome doesn't matter now.
+  DVLOG(2) << __func__ << ": Previous seek completed, re-seeking to "
+           << pending_seek_position_ << " to complete video stream restart.";
+  base::ResetAndReturn(&pending_seek_cb_);
+  pending_seek_position_ = kNoTimestamp;
+  Seek(time, cb);
+}
+
 }  // namespace media