Use ffmpeg packet.pos for restarting reading after reenabling video

media/filters/ffmpeg_demuxer.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "media/filters/ffmpeg_demuxer.h"
 
 #include <algorithm>
 #include <memory>
 #include <set>
 #include <utility>
@@ skipping 33 matching lines @@
 #include "media/media_features.h"
 
 #if BUILDFLAG(ENABLE_HEVC_DEMUXING)
 #include "media/filters/ffmpeg_h265_to_annex_b_bitstream_converter.h"
 #endif
 
 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;
 }
 
 }  // namespace
 
 static base::Time ExtractTimelineOffset(
     container_names::MediaContainerName container,
     const AVFormatContext* format_context) {
@@ skipping 231 matching lines @@
       media_log_(media_log),
       type_(UNKNOWN),
       liveness_(LIVENESS_UNKNOWN),
       end_of_stream_(false),
       last_packet_timestamp_(kNoTimestamp),
       last_packet_duration_(kNoTimestamp),
       video_rotation_(VIDEO_ROTATION_0),
       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;
   int rotation = 0;
   AVDictionaryEntry* rotation_entry = NULL;
 
   // Determine our media format.
   switch (stream->codecpar->codec_type) {
     case AVMEDIA_TYPE_AUDIO:
       DCHECK(audio_config_.get() && !video_config_.get());
@@ skipping 488 matching lines @@
     }
   }
 
   // Have capacity? Ask for more!
   if (HasAvailableCapacity() && !end_of_stream_) {
     demuxer_->NotifyCapacityAvailable();
   }
 }
 
 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 {
   return buffer_queue_.data_size();
 }
 
 TextKind FFmpegDemuxerStream::GetTextKind() const {
   DCHECK_EQ(type_, DemuxerStream::TEXT);
 
   if (stream_->disposition & AV_DISPOSITION_CAPTIONS)
@@ skipping 36 matching lines @@
     : host_(NULL),
       task_runner_(task_runner),
       // FFmpeg has no asynchronous API, so we use base::WaitableEvents inside
       // the BlockingUrlProtocol to handle hops to the render thread for network
       // reads and seeks.
       blocking_task_runner_(base::CreateSequencedTaskRunnerWithTraits(
           {base::MayBlock(), base::WithBaseSyncPrimitives(),
            base::TaskPriority::USER_BLOCKING})),
       stopped_(false),
       pending_read_(false),
+      pending_seek_position_(kNoTimestamp),
       data_source_(data_source),
       media_log_(media_log),
       bitrate_(0),
       start_time_(kNoTimestamp),
       text_enabled_(false),
       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());
   DCHECK(data_source_);
   DCHECK(!media_tracks_updated_cb_.is_null());
 }
 
 FFmpegDemuxer::~FFmpegDemuxer() {
   // NOTE: This class is not destroyed on |task_runner|, so we must ensure that
   // there are no outstanding WeakPtrs by the time we reach here.
@@ skipping 70 matching lines @@
   blocking_task_runner_->PostTask(
       FROM_HERE,
       base::Bind(&UnmarkEndOfStreamAndClearError, glue_->format_context()));
   pending_read_ = false;
 
   // TODO(dalecurtis): We probably should report PIPELINE_ERROR_ABORT here
   // instead to avoid any preroll work that may be started upon return, but
   // 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() {
   DCHECK(task_runner_->BelongsToCurrentThread());
 
   // The order of Stop() and Abort() is important here.  If Abort() is called
   // first, control may pass into FFmpeg where it can destruct buffers that are
   // in the process of being fulfilled by the DataSource.
   data_source_->Stop();
   url_protocol_->Abort();
@@ skipping 21 matching lines @@
   } else {
     // Don't use GetWeakPtr() here since we are on the wrong thread.
     task_runner_->PostTask(
         FROM_HERE, base::Bind(&FFmpegDemuxer::AbortPendingReads, weak_this_));
   }
 }
 
 void FFmpegDemuxer::Seek(base::TimeDelta time, const PipelineStatusCB& cb) {
   DCHECK(task_runner_->BelongsToCurrentThread());
   CHECK(pending_seek_cb_.is_null());
+  DCHECK_EQ(pending_seek_position_, kNoTimestamp);
+  pending_seek_cb_ = cb;
+  pending_seek_position_ = time;
 
-  // 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);
-
-  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),
+  SeekInternal(
+      time, nullptr,
       base::Bind(&FFmpegDemuxer::OnSeekFrameDone, weak_factory_.GetWeakPtr()));
 }
 
 base::Time FFmpegDemuxer::GetTimelineOffset() const {
   return timeline_offset_;
 }
 
 std::vector<DemuxerStream*> FFmpegDemuxer::GetAllStreams() {
   DCHECK(task_runner_->BelongsToCurrentThread());
   std::vector<DemuxerStream*> result;
@@ skipping 586 matching lines @@
   return nullptr;
 }
 
 void FFmpegDemuxer::OnSeekFrameDone(int result) {
   DCHECK(task_runner_->BelongsToCurrentThread());
   CHECK(!pending_seek_cb_.is_null());
 
   if (stopped_) {
     MEDIA_LOG(ERROR, media_log_) << GetDisplayName() << ": bad state";
     base::ResetAndReturn(&pending_seek_cb_).Run(PIPELINE_ERROR_ABORT);
+    pending_seek_position_ = kNoTimestamp;
     return;
   }
 
   if (result < 0) {
     // Use VLOG(1) instead of NOTIMPLEMENTED() to prevent the message being
     // captured from stdout and contaminates testing.
     // TODO(scherkus): Implement this properly and signal error (BUG=23447).
     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)
       stream->FlushBuffers();
   }
 
   // Resume reading until capacity.
   ReadFrameIfNeeded();
 
   // Notify we're finished seeking.
   base::ResetAndReturn(&pending_seek_cb_).Run(PIPELINE_OK);
+  pending_seek_position_ = kNoTimestamp;
 }
 
 void FFmpegDemuxer::OnEnabledAudioTracksChanged(
     const std::vector<MediaTrack::Id>& track_ids,
     base::TimeDelta curr_time) {
   DCHECK(task_runner_->BelongsToCurrentThread());
 
   std::set<FFmpegDemuxerStream*> enabled_streams;
   for (const auto& id : track_ids) {
     FFmpegDemuxerStream* stream = track_id_to_demux_stream_map_[id];
@@ skipping 42 matching lines @@
   for (const auto& stream : streams_) {
     if (stream && stream->type() == DemuxerStream::VIDEO &&
         stream.get() != selected_stream) {
       DVLOG(1) << __func__ << ": disabling stream " << stream.get();
       stream->SetEnabled(false, curr_time);
     }
   }
   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() {
   DCHECK(task_runner_->BelongsToCurrentThread());
 
   // Make sure we have work to do before reading.
   if (stopped_ || !StreamsHaveAvailableCapacity() || pending_read_ ||
       !pending_seek_cb_.is_null()) {
     return;
   }
 
   // Allocate and read an AVPacket from the media. Save |packet_ptr| since
@@ skipping 64 matching lines @@
     //
     // https://code.google.com/p/chromium/issues/detail?id=169133#c10
     if (!packet->data) {
       ScopedAVPacket new_packet(new AVPacket());
       av_new_packet(new_packet.get(), 0);
       av_packet_copy_props(new_packet.get(), packet.get());
       packet.swap(new_packet);
     }
 
     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.
     if (duration_known_) {
       const base::TimeDelta duration = demuxer_stream->duration();
       if (duration != kNoTimestamp && duration > duration_) {
         duration_ = duration;
         host_->SetDuration(duration_);
       }
     }
   }
 
   // Keep reading until we've reached capacity.
   ReadFrameIfNeeded();
 }
 
 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;
 }
 
 bool FFmpegDemuxer::IsMaxMemoryUsageReached() const {
   DCHECK(task_runner_->BelongsToCurrentThread());
 
   // Max allowed memory usage, all streams combined.
   const size_t kDemuxerMemoryLimit = 150 * 1024 * 1024;
@@ skipping 31 matching lines @@
 }
 
 void FFmpegDemuxer::SetLiveness(DemuxerStream::Liveness liveness) {
   DCHECK(task_runner_->BelongsToCurrentThread());
   for (const auto& stream : streams_) {
     if (stream)
       stream->SetLiveness(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