[Bug 794199] New: qtdemux: Premature EOS when some files are played in push mode

Fri Mar 9 11:50:00 UTC 2018

https://bugzilla.gnome.org/show_bug.cgi?id=794199

            Bug ID: 794199
           Summary: qtdemux: Premature EOS when some files are played in
                    push mode
    Classification: Platform
           Product: GStreamer
           Version: git master
                OS: Linux
            Status: NEW
          Severity: normal
          Priority: Normal
         Component: gst-plugins-good
          Assignee: gstreamer-bugs at lists.freedesktop.org
          Reporter: aboya at igalia.com
        QA Contact: gstreamer-bugs at lists.freedesktop.org
     GNOME version: ---

Created attachment 369503
  --> https://bugzilla.gnome.org/attachment.cgi?id=369503&action=edit
Test vector

The attached file has 6 frames, in two GOPs, both with I-B-P layout.

It's demuxed correctly in pull mode.

$ gst-launch-1.0 -v filesrc location=ibpibp-non-frag.mp4 ! qtdemux ! fakesink
silent=false |egrep 'segment|chain'
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = event   *******
(fakesink0:sink) E (type: segment (17934), GstEventSegment,
segment=(GstSegment)"GstSegment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE,
rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME,
base=(guint64)0, offset=(guint64)0, start=(guint64)333333333,
stop=(guint64)2333333333, time=(guint64)0, position=(guint64)333333333,
duration=(guint64)18446744073709551615;";) 0x5649226dcb20
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (1025 bytes, dts: 0:00:00.000000000, pts: 0:00:00.333333333,
duration: 0:00:00.333333333, offset: -1, offset_end: -1, flags: 00000040
discont , meta: none) 0x7ff4c8005340
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (305 bytes, dts: 0:00:00.333333333, pts: 0:00:01.000000000,
duration: 0:00:00.333333333, offset: -1, offset_end: -1, flags: 00002000
delta-unit , meta: none) 0x7ff4c8005120
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (131 bytes, dts: 0:00:00.666666666, pts: 0:00:00.666666666,
duration: 0:00:00.333333334, offset: -1, offset_end: -1, flags: 00002000
delta-unit , meta: none) 0x7ff4c8005010
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (499 bytes, dts: 0:00:01.000000000, pts: 0:00:01.333333333,
duration: 0:00:00.333333333, offset: -1, offset_end: -1, flags: 00000000 ,
meta: none) 0x7ff4c8005120
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (487 bytes, dts: 0:00:01.333333333, pts: 0:00:02.000000000,
duration: 0:00:00.333333333, offset: -1, offset_end: -1, flags: 00002000
delta-unit , meta: none) 0x7ff4c8005340
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (215 bytes, dts: 0:00:01.666666666, pts: 0:00:01.666666666,
duration: 0:00:00.333333334, offset: -1, offset_end: -1, flags: 00002000
delta-unit , meta: none) 0x7ff4c8005450

On the other hand, it loses the last 2 frames when demuxed in push mode:

$ gst-launch-1.0 -v pushfilesrc location=ibpibp-non-frag.mp4 ! qtdemux !
fakesink silent=false |egrep 'segment|chain'
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = event   *******
(fakesink0:sink) E (type: segment (17934), GstEventSegment,
segment=(GstSegment)"GstSegment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE,
rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME,
base=(guint64)0, offset=(guint64)0, start=(guint64)0,
stop=(guint64)18446744073709551615, time=(guint64)0, position=(guint64)0,
duration=(guint64)18446744073709551615;";) 0x5619bebdeea0
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = event   *******
(fakesink0:sink) E (type: segment (17934), GstEventSegment,
segment=(GstSegment)"GstSegment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE,
rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME,
base=(guint64)0, offset=(guint64)0, start=(guint64)333333333,
stop=(guint64)2333333333, time=(guint64)0, position=(guint64)333333333,
duration=(guint64)18446744073709551615;";) 0x7f91ec0065c0
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (1025 bytes, dts: 0:00:00.000000000, pts: 0:00:00.333333333,
duration: 0:00:00.333333333, offset: -1, offset_end: -1, flags: 00004040
discont tag-memory , meta: none) 0x7f91ec00a400
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (305 bytes, dts: 0:00:00.333333333, pts: 0:00:01.000000000,
duration: 0:00:00.333333333, offset: -1, offset_end: -1, flags: 00006000
delta-unit tag-memory , meta: none) 0x7f91ec00a510
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (131 bytes, dts: 0:00:00.666666666, pts: 0:00:00.666666666,
duration: 0:00:00.333333334, offset: -1, offset_end: -1, flags: 00006000
delta-unit tag-memory , meta: none) 0x7f91ec00a620
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = chain   *******
(fakesink0:sink) (499 bytes, dts: 0:00:01.000000000, pts: 0:00:01.333333333,
duration: 0:00:00.333333333, offset: -1, offset_end: -1, flags: 00004000
tag-memory , meta: none) 0x7f91ec00a510

The offending code is this condition:

pts = QTSAMPLE_PTS (stream, sample);
[...]
if (G_UNLIKELY (demux->segment.stop != -1
        && demux->segment.stop <= pts && stream->on_keyframe)) {
  GST_DEBUG_OBJECT (demux, "we reached the end of our segment.");

Note that the `demux->segment.stop <= pts` comparison is wrong because it's
comparing buffer time across different GstSegments, instead of translating both
to stream time.

The difference is very important because the user requests to play e.g. the
range [0, 2) s *in stream time*; it should not need to care whether the track
(buffer) presentation range is actually [0.333, 2.333) because this file
already has an edit list to map that to [0, 2) s in stream time.

The `stream->on_keyframe` check is also interesting. I have not experimented
with it too much, but on first glance it looks like it would avoid entering the
`if` body on most files, which would explain why this issue has not been
detected before. Since most GOPs are longer than 3 frames and for most files
with basic edit lists, like the one attached, the buffer PTS match can only
occur in the last GOP, the chances of it happening on both buffer PTS =
segment.stop and exactly the next frame after an I-frame are quite low. (EOS is
sent later because as a reaction of upstream sending EOS itself when there are
no more bytes to read, not because of last frame emission*).

* To make things worse, our WebKit MSE implementation actually relies on EOS
not being sent on last frame emission when working on push mode. Today I've
learned that is the case most often but not always.

-- 
You are receiving this mail because:
You are the QA Contact for the bug.
You are the assignee for the bug.