MSE: Replace crossfade splicing overlap trimming.

media/filters/chunk_demuxer_unittest.cc

Index: media/filters/chunk_demuxer_unittest.cc
diff --git a/media/filters/chunk_demuxer_unittest.cc b/media/filters/chunk_demuxer_unittest.cc
index 0d7c9a1c0d04b668ef4789ac40576f72dcad1290..891b4ad99a12639c9a48f825a0dc69b659366b85 100644
--- a/media/filters/chunk_demuxer_unittest.cc
+++ b/media/filters/chunk_demuxer_unittest.cc
@@ -165,30 +165,18 @@ MATCHER_P2(InitSegmentMismatchesMimeType,
                std::string(track_type_string_with_article) + " codec.");
 }
 
-MATCHER_P2(GeneratedSplice, duration_microseconds, time_microseconds, "") {
-  return CONTAINS_STRING(arg, "Generated splice of overlap duration " +
-                                  base::IntToString(duration_microseconds) +
-                                  "us into new buffer at " +
-                                  base::IntToString(time_microseconds) + "us.");
-}
-
-MATCHER_P2(SkippingSpliceAtOrBefore,
-           new_microseconds,
-           existing_microseconds,
+MATCHER_P3(TrimmedSpliceOverlap,
+           splice_time_us,
+           overlapped_start_us,
+           trim_duration_us,
            "") {
   return CONTAINS_STRING(
-      arg, "Skipping splice frame generation: first new buffer at " +
-               base::IntToString(new_microseconds) +
-               "us begins at or before existing buffer at " +
-               base::IntToString(existing_microseconds) + "us.");
+      arg, "Audio buffer splice at PTS=" + base::IntToString(splice_time_us) +
+               "us. Trimmed tail of overlapped buffer (PTS=" +
+               base::IntToString(overlapped_start_us) + "us) by " +
+               base::IntToString(trim_duration_us));
 }
 
-MATCHER_P(SkippingSpliceAlreadySpliced, time_microseconds, "") {
-  return CONTAINS_STRING(
-      arg, "Skipping splice frame generation: overlapped buffers at " +
-               base::IntToString(time_microseconds) +
-               "us are in a previously buffered splice.");
-}
 
 MATCHER_P(WebMSimpleBlockDurationEstimated, estimated_duration_ms, "") {
   return CONTAINS_STRING(arg, "Estimating WebM block duration to be " +
@@ -278,8 +266,8 @@ class ChunkDemuxerTest : public ::testing::Test {
         base::Bind(&ChunkDemuxerTest::DemuxerOpened, base::Unretained(this));
     Demuxer::EncryptedMediaInitDataCB encrypted_media_init_data_cb = base::Bind(
         &ChunkDemuxerTest::OnEncryptedMediaInitData, base::Unretained(this));
-    demuxer_.reset(new ChunkDemuxer(open_cb, encrypted_media_init_data_cb,
-                                    media_log_, true));
+    demuxer_.reset(
+        new ChunkDemuxer(open_cb, encrypted_media_init_data_cb, media_log_));
   }
 
   virtual ~ChunkDemuxerTest() {
@@ -972,7 +960,7 @@ class ChunkDemuxerTest : public ::testing::Test {
 
     // Append a media segment that goes from [0.527000, 1.014000).
     EXPECT_MEDIA_LOG(WebMSimpleBlockDurationEstimated(2));
-    EXPECT_MEDIA_LOG(GeneratedSplice(20000, 527000));
+    EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(527000, 524000, 20000));
     EXPECT_TRUE(AppendData(bear2->data() + 55290, 18785));
     CheckExpectedRanges("{ [0,1027) [1201,2736) }");
 
@@ -981,7 +969,7 @@ class ChunkDemuxerTest : public ::testing::Test {
     EXPECT_CALL(*this, InitSegmentReceivedMock(_));
     EXPECT_TRUE(AppendData(bear1->data(), 4370));
     EXPECT_MEDIA_LOG(WebMSimpleBlockDurationEstimated(23));
-    EXPECT_MEDIA_LOG(GeneratedSplice(26000, 779000));
+    EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(779000, 759000, 3000));

[wolenetz, 2016/09/22 23:48:37]

Why is this 3000 not 26000?

[chcunningham, 2016/10/27 23:36:06]

First, let me list some numbers...

A) splice time: 779000
B) start time of pre_splice_buffers->back() used in original calculation: 782000
C) start time of splice overlapped buffer: 759000
D) buffer durations (same for all buffers): 23000

Now to explain. The original impl fetched more than one pre_splice_buffer and
the back of that list of buffers might have a PTS > than the splice PTS (true in
this case). Said another way, the PTS for back of the pre_splice_buffers
actually lands in the middle of the new splice buffer. The splice duration was
then calculated as B + D - A = 26000. I think this may have been a bug. The
buffers do overlap, but this does not actually correctly compute the duration of
their overlap.

Today's impl only grabs a single pre-splice buffer. The pre-splice buffer have a
PTS < the splice buffer, and its tail is overlapped by the splice buffer. Here
we compute the duration as C + D - A = 3000

In todays impl, the buffer B, with PTS > the splice buffer is still overlapped,
but we have no use for it, so it gets completely removed.

[wolenetz, 2016/10/28 23:08:18]

Acknowledged. The change in expectations makes sense. I believe we previously
had to have a > 3ms overlap (kCrossfadeDurationInMilliseconds = 5ms) to do the
splice, hence we had previously kept B in pre-splice buffers. The net overlap of
pre-splice and post-splice previously was indeed 26ms in this case, so on the
surface, that doesn't look like a previous bug. Regardless, new expectation in
this CL of *no crossfade* SGTM :)

     EXPECT_TRUE(AppendData(bear1->data() + 72737, 28183));
     CheckExpectedRanges("{ [0,2736) }");
 
@@ -1840,17 +1828,17 @@ TEST_F(ChunkDemuxerTest, Read) {
 TEST_F(ChunkDemuxerTest, OutOfOrderClusters) {
   ASSERT_TRUE(InitDemuxer(HAS_AUDIO | HAS_VIDEO));
   ASSERT_TRUE(AppendCluster(kDefaultFirstCluster()));
-  EXPECT_MEDIA_LOG(GeneratedSplice(13000, 10000));
+  EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(10000, 0, 13000));
   ASSERT_TRUE(AppendCluster(GenerateCluster(10, 4)));
 
   // Make sure that AppendCluster() does not fail with a cluster that has
   // overlaps with the previously appended cluster.
-  EXPECT_MEDIA_LOG(SkippingSpliceAlreadySpliced(0));
+  EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(5000, 0, 5000));

[wolenetz, 2016/09/22 23:48:37]

To be clear, this trims an *additional* 5ms from the original 23ms frame which
previously had 10ms trimmed from it, right? Or does this change to just
discarding 5ms from the original 23ms (which would be incorrect)?

To assist review/maintainability, can you read back the resulting buffers and
verify their durations/discard amounts after the next line or at end of this
unit test?

e.g, at end of this test, I would expect the buffers to be:
Audio: [0,5)[5,28)[28,45)[45,68)
Video: [0,5)[5,38)[38,45)[45,78) ** Note that the video case is underspecified
in the spec. I've filed https://github.com/w3c/media-source/issues/166 to track
clarifying that (and Chrome only adjusts overlapped video frame durations if the
overlapped frame had an estimated duration. Not very intuitive, and probably
leading to other problems.)

If we have this verification already in SourceBufferStreamTest, then maybe point
to such test(s) from this one? (or add it over there and point to it from this
test).

[chcunningham, 2016/10/27 23:36:06]

Added buffer times for readability. Did not add duration verification - instead
referenced SourceBufferStream tests that already do this.

[wolenetz, 2016/10/28 23:08:18]

Ack. Thanks for the additional verification and reference to the SBSTest that
verifies trimmed audio durations on overlap splice.

   ASSERT_TRUE(AppendCluster(GenerateCluster(5, 4)));
 
   // Verify that AppendData() can still accept more data.
   std::unique_ptr<Cluster> cluster_c(GenerateCluster(45, 2));
-  EXPECT_MEDIA_LOG(GeneratedSplice(6000, 45000));
+  EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(45000, 28000, 6000));
   ASSERT_TRUE(demuxer_->AppendData(
       kSourceId, cluster_c->data(), cluster_c->size(),
       append_window_start_for_next_append_, append_window_end_for_next_append_,
@@ -2183,7 +2171,6 @@ TEST_F(ChunkDemuxerTest, EndOfStreamRangeChanges) {
 
   // Add text track data and verify that the buffered ranges don't change
   // since the intersection of all the tracks doesn't change.
-  EXPECT_MEDIA_LOG(SkippingSpliceAtOrBefore(0, 0));
   EXPECT_CALL(host_, SetDuration(base::TimeDelta::FromMilliseconds(200)));
   AppendMuxedCluster(MuxedStreamInfo(kVideoTrackNum, "0K 33", 33),
                      MuxedStreamInfo(kAudioTrackNum, "0K 23K", 23),
@@ -2893,16 +2880,22 @@ TEST_F(ChunkDemuxerTest, GetBufferedRanges_SeparateStreams) {
   CheckExpectedRangesForMediaSource(
       "{ [0,23) [320,400) [520,570) [720,750) [920,950) }");
 
-  // Appending within buffered range should not affect buffered ranges.
-  EXPECT_MEDIA_LOG(GeneratedSplice(40000, 930000));
+  // Audio buffered ranges are trimmed from 970 to 950 due to splicing the
+  // previously buffered audio frame
+  // - existing frame trimmed from [900, 970) to [900-930),

[wolenetz, 2016/09/26 23:52:37]

nit: consistent [900,930)

[chcunningham, 2016/10/27 23:36:06]

Done.

[wolenetz, 2016/10/28 23:08:18]

Not done here actually :) (though done in at least one other place).
This is a really small nit though.

[chcunningham, 2016/11/02 01:28:42]

Done.

+  // - newly appended audio from [930, 950).
+  EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(930000, 900000, 40000));
   ASSERT_TRUE(AppendCluster(
       audio_id, GenerateSingleStreamCluster(930, 950, kAudioTrackNum, 20)));
+  CheckExpectedRanges(DemuxerStream::AUDIO,
+                      "{ [0,23) [300,400) [520,590) [720,750) [900,950) }");
+
+  // Appending within buffered range should not affect video buffered ranges.

[wolenetz, 2016/09/26 23:52:37]

nit: This isn't always true. But it is for the particular append done here.
Rephrase?

[chcunningham, 2016/10/27 23:36:06]

Done.

   ASSERT_TRUE(AppendCluster(
       video_id, GenerateSingleStreamCluster(930, 950, kVideoTrackNum, 20)));
-  CheckExpectedRanges(DemuxerStream::AUDIO,
-                      "{ [0,23) [300,400) [520,590) [720,750) [900,970) }");

[wolenetz, 2016/09/26 23:52:37]

Wow, this appears to have been broken before. Why wasn't the last range
previously also [900,950) before this CL?

[wolenetz, 2016/09/27 00:35:35]

Offline, yes looks like an artifact before (crossfade duration kept buffered
range duration longer?)

[chcunningham, 2016/10/27 23:36:06]

Right, not sure if this is a bug originally (much of the orignal splicing code
is difficult to grok), but when converting the new appended buffer to a splice
buffer (passing in the pre-splice buffers), we used the duration of the
pre-splice buffers if it exceeds the overlap duration (which happens in this
case since overlap = 20, pre-splice-duration=70). 

https://cs.chromium.org/chromium/src/media/base/stream_parser_buffer.cc?rcl=1...

I look forward to deleting this code

[wolenetz, 2016/10/28 23:08:18]

Acknowledged.

   CheckExpectedRanges(DemuxerStream::VIDEO,
                       "{ [0,33) [320,420) [500,570) [700,770) [920,950) }");
+
   CheckExpectedRangesForMediaSource(
       "{ [0,23) [320,400) [520,570) [720,750) [920,950) }");
 }
@@ -2974,14 +2967,20 @@ TEST_F(ChunkDemuxerTest, GetBufferedRanges_AudioVideo) {
                       "{ [0,33) [300,420) [500,570) [700,770) [900,950) }");
   CheckExpectedRanges("{ [0,23) [300,400) [500,570) [700,750) [900,950) }");
 
-  // Appending within buffered range should not affect buffered ranges.
-  EXPECT_MEDIA_LOG(GeneratedSplice(40000, 930000));
+  // Appending within buffered range should not affect video buffered ranges.

[wolenetz, 2016/09/26 23:52:37]

nit ditto: rephrase?

[chcunningham, 2016/10/27 23:36:06]

Done.

+  EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(930000, 900000, 40000));
   AppendMuxedCluster(MuxedStreamInfo(kAudioTrackNum, "930D20K"),
                      MuxedStreamInfo(kVideoTrackNum, "930D20K"));
-  CheckExpectedRanges(DemuxerStream::AUDIO,
-                      "{ [0,23) [300,400) [500,590) [700,750) [900,970) }");

[wolenetz, 2016/09/26 23:52:37]

ditto: why broken before?

[wolenetz, 2016/09/27 00:35:35]

Ditto Ack of offline.

   CheckExpectedRanges(DemuxerStream::VIDEO,
                       "{ [0,33) [300,420) [500,570) [700,770) [900,950) }");
+
+  // Audio buffered ranges are trimmed from 970 to 950 due to splicing the
+  // previously buffered audio frame.
+  // - existing frame trimmed from [900, 970) to [900-930),
+  // - newly appended audio from [930, 950).
+  CheckExpectedRanges(DemuxerStream::AUDIO,
+                      "{ [0,23) [300,400) [500,590) [700,750) [900,950) }");
+
   CheckExpectedRanges("{ [0,23) [300,400) [500,570) [700,750) [900,950) }");
 }
 
@@ -3321,8 +3320,7 @@ TEST_F(ChunkDemuxerTest, ConfigChange_Audio) {
 
   ExpectRead(DemuxerStream::AUDIO, 0);
 
-  // The first config change seen is from a splice frame representing an overlap
-  // of buffer from config 1 by buffers from config 2.
+  // Read until we encounter config 2.
   ReadUntilNotOkOrEndOfStream(DemuxerStream::AUDIO, &status, &last_timestamp);
   ASSERT_EQ(status, DemuxerStream::kConfigChanged);
   EXPECT_EQ(last_timestamp.InMilliseconds(), 524);
@@ -3333,11 +3331,10 @@ TEST_F(ChunkDemuxerTest, ConfigChange_Audio) {
   EXPECT_EQ(audio_config_2.samples_per_second(), 44100);
   EXPECT_EQ(audio_config_2.extra_data().size(), 3935u);
 
-  // The next config change is from a splice frame representing an overlap of
-  // buffers from config 2 by buffers from config 1.
+  // Read until we encounter config 1 again.
   ReadUntilNotOkOrEndOfStream(DemuxerStream::AUDIO, &status, &last_timestamp);
   ASSERT_EQ(status, DemuxerStream::kConfigChanged);
-  EXPECT_EQ(last_timestamp.InMilliseconds(), 782);
+  EXPECT_EQ(last_timestamp.InMilliseconds(), 759);

[wolenetz, 2016/09/26 23:52:37]

Is this 782 -> 759 change because the 782 buffer was needed for crossfade, but
instead we now just discard tail of 759 buffer?

[chcunningham, 2016/10/27 23:36:06]

Yes. See detailed explanation in my comments on InitDemuxerWithConfigChangeData

[wolenetz, 2016/10/28 23:08:18]

Acknowledged.

   ASSERT_TRUE(audio_config_1.Matches(audio->audio_decoder_config()));
 
   // Read until the end of the stream just to make sure there aren't any other
@@ -3638,7 +3635,7 @@ TEST_F(ChunkDemuxerTest, WebMIsParsingMediaSegmentDetection) {
 
   ASSERT_TRUE(InitDemuxer(HAS_AUDIO));
   EXPECT_MEDIA_LOG(WebMSimpleBlockDurationEstimated(23)).Times(2);
-  EXPECT_MEDIA_LOG(GeneratedSplice(22000, 2000));
+  EXPECT_MEDIA_LOG(TrimmedSpliceOverlap(2000, 1000, 22000));
   for (size_t i = 0; i < sizeof(kBuffer); i++) {
     DVLOG(3) << "Appending and testing index " << i;
     ASSERT_TRUE(AppendData(kBuffer + i, 1));