[Bug 744399] New: gstbaseparse does not set duration on buffers

[bugzilla at gnome.org]

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

            Bug ID: 744399
           Summary: gstbaseparse does not set duration on buffers
    Classification: Platform
           Product: GStreamer
           Version: 1.x
                OS: Linux
            Status: UNCONFIRMED
          Severity: normal
          Priority: Normal
         Component: gstreamer (core)
          Assignee: gstreamer-bugs at lists.freedesktop.org
          Reporter: alex.wabik at gmail.com
        QA Contact: gstreamer-bugs at lists.freedesktop.org
     GNOME version: ---

Bug summary:
1) have a source that outputs packetised h264 data with proper DTS, PTS and
DURATION set on buffers, but no framerate in the caps,
2) seek to such a place that the key frame is several seconds before the seek
position,
3) the baseparse resets DURATION on the buffers, output of the baseparse does
not contain DURATION
4) the gstvideodecoder, because of the lack of duration and lack of framerate,
will incorrectly clip the buffers to segment, making the key frame's PTS equal
to segment start
5) the sink prerolls the key frame instead of dropping it.
6) additional damage in PAUSED state: queue still thinks that it has 0%
buffered, because time of the last output buffer was outside of the segment.

I am sorry for not providing any testcase - I'm working on a proprietary
player, and playing very specific streams, I was not able yet to plug in gdppay
for dumping data :( Please verify if what I write here makes sense, I hope that
even without a testcase this analysis is clear. If I manage, I'll add some test
case later.

The whole pipeline looks like this:

custom_source ! queue2 use-buffering=true use-rate-estimate=false
max-size-buffers=0 max-size-bytes=0 max-size-time=0.5*GST_SECOND ! h264parse !
libav_h264dec ! sink

The source works in GST_FORMAT_TIME. It pushes proper buffers with PTS, DTS and
DURATION set. Caps are: video/x-h264, stream-format=byte-stream, alignment=au
(no framerate provided).

The pipeline is in GST_STATE_PAUSED and the seek to 17 seconds is performed.
The key frame is in PTS about 15 seconds, and the source starts giving data
starting with that key frame.

The queue2 does not report any buffering (other than 0%), as the pushed buffers
have timestamps ~15, that is below segment's start (17), and
gst_segment_to_running_time() returns -1.

gst_base_parse_chain() performs this:

    data = gst_adapter_map (parse->priv->adapter, av);
    /* arrange for actual data to be copied if subclass tries to,
     * since what is passed is tied to the adapter */
    tmpbuf = gst_buffer_new_wrapped_full (GST_MEMORY_FLAG_READONLY |
        GST_MEMORY_FLAG_NO_SHARE, (gpointer) data, av, 0, av, NULL, NULL);

    /* already inform subclass what timestamps we have planned,
     * at least if provided by time-based upstream */
    if (parse->priv->upstream_format == GST_FORMAT_TIME) {
      GST_BUFFER_PTS (tmpbuf) = parse->priv->next_pts;
      GST_BUFFER_DTS (tmpbuf) = parse->priv->next_dts;
    }

    /* keep the adapter mapped, so keep track of what has to be flushed */
    ret = gst_base_parse_handle_buffer (parse, tmpbuf, &skip, &flush);

The parser does set proper PTS and DTS on the buffer, but does not set DURATION
(although all input buffers contained proper DURATION). This is also visible in
the log:

gst_pad_chain_data_unchecked:<h264parse0:sink> calling chainfunction
&gst_base_parse_chain with buffer buffer: 0x1c5d316d0880, pts
0:00:15.348688000, dts 0:00:15.390400000, dur 0:00:00.041711000, size 1180,
offset 18446744073709551615, offset_end 18446744073709551615, flags 0x0
gst_base_parse_handle_buffer:<h264parse0> handling buffer of size 5737 with dts
0:00:15.348688000, pts 0:00:15.390400000, duration 99:99:99.999999999

In the decoder, the GstVideoCodecFrames do not contain proper duration. The log
that I got from the GstVideoDecoder element:

gst_video_decoder_prepare_finish_frame:<avdec_h264-1> sync timestamp
0:00:15.015000000 diff 5124095:34:31.724551616

It obtained a buffer with PTS=15 seconds. The diff is calculated as frame->pts
- decoder->output_segment.start, so it is negative, so it's logged as some
large value. Then, in gst_video_decoder_prepare_finish_frame:

if (frame->duration == GST_CLOCK_TIME_NONE) {
    frame->duration = gst_video_decoder_get_frame_duration (decoder, frame);
    GST_LOG_OBJECT (decoder,
        "Guessing duration %" GST_TIME_FORMAT " for frame...",
        GST_TIME_ARGS (frame->duration));
  }

Since the frame->duration is NONE, and the caps did not contain framerate (and
the parser inserted 0/1 framerate to the caps then so 
gst_video_decoder_get_frame_duration() also returns NONE), the frame->duration
will remain NONE. And I have that logged too:

gst_video_decoder_prepare_finish_frame:<avdec_h264-1> Guessing duration
99:99:99.999999999 for frame...

Then the gst_video_decoder_clip_and_push_buf() is called, and it finalizes the
bug by rewriting buffer's PTS to 17 seconds (although the PTS was in 15
seconds):

gst_video_decoder_clip_and_push_buf:<avdec_h264-1> accepting buffer inside
segment: 0:00:17.000000000 0:00:16.999999999 seg 0:00:17.000000000 to
99:99:99.999999999 time 0:00:17.000000000
gst_video_decoder_clip_and_push_buf:<avdec_h264-1> pushing buffer
0x25fef38a6610 of size 443520, PTS 0:00:17.000000000, dur 99:99:99.999999999

You can see in the log that GST_TIME_ARGS (GST_BUFFER_PTS (buf)) was logged as
0:00:17.000000000, and GST_TIME_ARGS (GST_BUFFER_PTS (buf) +
GST_BUFFER_DURATION (buf)) was logged as 0:00:16.999999999 (because DURATION is
still -1!). Why was the PTS incorrectly rewritten:

  duration = GST_BUFFER_DURATION (buf);
  [...]
  stop = GST_CLOCK_TIME_NONE;

  if (GST_CLOCK_TIME_IS_VALID (start) && GST_CLOCK_TIME_IS_VALID (duration)) {
    stop = start + duration;
  }

  segment = &decoder->output_segment;
  if (gst_segment_clip (segment, GST_FORMAT_TIME, start, stop, &cstart,
&cstop)) 

The duration is not valid, stop remains GST_CLOCK_TIME_NONE, so finally,
gst_segment_clip() obtains:

segment.start=17*GST_SECOND
segment.stop=-1,
start=15*GST_SECOND,
stop=-1, 

and with such data, cstart will be set to segment.start, cstop to segment.stop,
and gst_segment_clip() returns TRUE.

The buffer with PTS 15, in a segment that starts in 17, eventually gets to the
sink and is prerolled. Since the pipeline's state is PAUSED, no more buffers
will flow. No buffer flow on the queue2 srcpad will make it impossible for
queue2 to calculate correct srctime, so queue2 would never report buffering
with percent>0, and the application (which uses queue2 to ensure fluent
playback) will never put the pipeline to PLAYNIG state.

This bug can be mitigated by adding framerate to caps, but such a solution
would be inferior to just fixing the baseparse, because the application has no
knowledge of the framerate of the stream. It knows only the durations of all
buffers, so it would have to calculate framerate and update it every time the
buffer duration changes.

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