MSE: Warn when keyframe after track_buffer is significantly in future

media/filters/source_buffer_stream.cc

Index: media/filters/source_buffer_stream.cc
diff --git a/media/filters/source_buffer_stream.cc b/media/filters/source_buffer_stream.cc
index 75c9c31fd344fab814e09c442fa15429f1422097..0237061804a43f5bc2fde013b73ff3896148078a 100644
--- a/media/filters/source_buffer_stream.cc
+++ b/media/filters/source_buffer_stream.cc
@@ -30,6 +30,9 @@ enum {
   // important for debugging splice generation.
   kMaxSpliceGenerationWarningLogs = 50,
   kMaxSpliceGenerationSuccessLogs = 20,
+
+  // Limit the number of MEDIA_LOG() logs for track buffer time gaps.
+  kMaxTrackBufferGapWarningLogs = 20,
 };

[xhwang, 2015/08/10 23:51:08]

nit: As discussed before, these could just be "const int"s.

[wolenetz, 2015/08/11 02:53:31]

Oops! Done :)

 
 // Helper method that returns true if |ranges| is sorted in increasing order,
@@ -134,6 +137,7 @@ SourceBufferStream::SourceBufferStream(const AudioDecoderConfig& audio_config,
       end_of_stream_(false),
       seek_buffer_timestamp_(kNoTimestamp()),
       selected_range_(NULL),
+      just_exhausted_track_buffer_(false),
       media_segment_start_time_(kNoDecodeTimestamp()),
       range_for_next_append_(ranges_.end()),
       new_media_segment_(false),
@@ -147,7 +151,8 @@ SourceBufferStream::SourceBufferStream(const AudioDecoderConfig& audio_config,
       pending_buffers_complete_(false),
       splice_frames_enabled_(splice_frames_enabled),
       num_splice_generation_warning_logs_(0),
-      num_splice_generation_success_logs_(0) {
+      num_splice_generation_success_logs_(0),
+      num_track_buffer_gap_warning_logs_(0) {
   DCHECK(audio_config.IsValidConfig());
   audio_configs_.push_back(audio_config);
 }
@@ -162,6 +167,7 @@ SourceBufferStream::SourceBufferStream(const VideoDecoderConfig& video_config,
       end_of_stream_(false),
       seek_buffer_timestamp_(kNoTimestamp()),
       selected_range_(NULL),
+      just_exhausted_track_buffer_(false),
       media_segment_start_time_(kNoDecodeTimestamp()),
       range_for_next_append_(ranges_.end()),
       new_media_segment_(false),
@@ -175,7 +181,8 @@ SourceBufferStream::SourceBufferStream(const VideoDecoderConfig& video_config,
       pending_buffers_complete_(false),
       splice_frames_enabled_(splice_frames_enabled),
       num_splice_generation_warning_logs_(0),
-      num_splice_generation_success_logs_(0) {
+      num_splice_generation_success_logs_(0),
+      num_track_buffer_gap_warning_logs_(0) {
   DCHECK(video_config.IsValidConfig());
   video_configs_.push_back(video_config);
 }
@@ -191,6 +198,7 @@ SourceBufferStream::SourceBufferStream(const TextTrackConfig& text_config,
       end_of_stream_(false),
       seek_buffer_timestamp_(kNoTimestamp()),
       selected_range_(NULL),
+      just_exhausted_track_buffer_(false),
       media_segment_start_time_(kNoDecodeTimestamp()),
       range_for_next_append_(ranges_.end()),
       new_media_segment_(false),
@@ -204,7 +212,8 @@ SourceBufferStream::SourceBufferStream(const TextTrackConfig& text_config,
       pending_buffers_complete_(false),
       splice_frames_enabled_(splice_frames_enabled),
       num_splice_generation_warning_logs_(0),
-      num_splice_generation_success_logs_(0) {}
+      num_splice_generation_success_logs_(0),
+      num_track_buffer_gap_warning_logs_(0) {}
 
 SourceBufferStream::~SourceBufferStream() {
   while (!ranges_.empty()) {
@@ -533,6 +542,7 @@ void SourceBufferStream::ResetSeekState() {
   track_buffer_.clear();
   config_change_pending_ = false;
   last_output_buffer_timestamp_ = kNoDecodeTimestamp();
+  just_exhausted_track_buffer_ = false;
   splice_buffers_index_ = 0;
   pending_buffer_ = NULL;
   pending_buffers_complete_ = false;
@@ -1140,8 +1150,10 @@ SourceBufferStream::Status SourceBufferStream::GetNextBufferInternal(
 
     // If the track buffer becomes empty, then try to set the selected range
     // based on the timestamp of this buffer being returned.
-    if (track_buffer_.empty())
+    if (track_buffer_.empty()) {
+      just_exhausted_track_buffer_ = true;
       SetSelectedRangeIfNeeded(last_output_buffer_timestamp_);
+    }
 
     return kSuccess;
   }
@@ -1165,6 +1177,26 @@ SourceBufferStream::Status SourceBufferStream::GetNextBufferInternal(
   }
 
   CHECK(selected_range_->GetNextBuffer(out_buffer));
+
+  DecodeTimestamp next_output_buffer_timestamp =
+      (*out_buffer)->GetDecodeTimestamp();
+  if (just_exhausted_track_buffer_) {
+    DCHECK((*out_buffer)->is_key_frame());
+    just_exhausted_track_buffer_ = false;
+    base::TimeDelta delta =
+        next_output_buffer_timestamp - last_output_buffer_timestamp_;
+    DCHECK_GE(delta, base::TimeDelta());
+    if (delta > GetMaxInterbufferDistance()) {
+      LIMITED_MEDIA_LOG(DEBUG, media_log_, num_track_buffer_gap_warning_logs_,
+                        kMaxTrackBufferGapWarningLogs)
+          << "Media append that overlapped current playback position caused "
+             "time gap in playing "
+          << GetStreamTypeName() << " stream because the next keyframe is "
+          << delta.InMilliseconds() << "ms beyond last overlapped frame. Media "
+                                       "may appear temporarily frozen.";
+    }
+  }
+
   last_output_buffer_timestamp_ = (*out_buffer)->GetDecodeTimestamp();
   return kSuccess;
 }