GNOME Bugzilla – Bug 616519
[mpegtsdemux] anormal pause (3sec) between prerolling and playing
Last modified: 2011-10-29 15:40:37 UTC
Hi, When running: gst-launch-0.10 -v filesrc location=channel5_small.pcap ! pcapparse ! mpegtsparse ! identity ! mpegtsdemux ! ffdec_h264 ! xvimagesink There is a not normal pause after prerolling. If it set 'show-preroll-frame=0 to xvimagesink, then the frozen image is not displayed during the pause. If I tried sync=0 then there is not cut and qos doe not change nothing. Moreover, if I open channel5_small.pcap with wireshark and then cut the file into 2 parts and then I take the last one. Then the result is the same. So the pause does not come from missing packets in the pcap file. The file channel5_small.pcap is accessible here: http://dl.free.fr/vo8qCKeOM Does anyone has an explanation of this pause ? If this is normal then is there a way to have the pipeline in PLAYING state only after the 'pause' ? Sincerely Julien
Hi, I have more informations: Using GST_DEBUG=GST_POLL:5 I can see: ----------------------------------------- ... BEGIN PREROLL ... ... END PREROLL ... ... PLAYING ... GST_POLL gstpoll.c:1141:gst_poll_wait: timeout :0:00:02.764643179 New clock: GstSystemClock ----------------------------------------- So the pause is there: 2.76 sec Julien
ping ? (http://dl.free.fr/vo8qCKeOM fails 1/5, just retry)
Created attachment 166780 [details] stream capture
The first buffer out of the decoder is sent with a ts starting 02.764643179 seconds after the start of the new segment. gst-launch-0.10 -v filesrc location=channel5_light.pcap ! pcapparse ! mpegtsparse ! mpegtsdemux ! queue ! ffdec_h264 ! identity single-segment=true silent=true ! fakesink -v Estableciendo el conducto a PAUSA … El conducto está PREPARÁNDOSE … /GstPipeline:pipeline0/GstPcapParse:pcapparse0.GstPad:src: caps = video/mpegts, systemstream=(boolean)true /GstPipeline:pipeline0/MpegTSParse:mpegtsparse0.GstPad:sink: caps = video/mpegts, systemstream=(boolean)true /GstPipeline:pipeline0/MpegTSParse:mpegtsparse0.GstPad:src0: caps = video/mpegts, systemstream=(boolean)true, packetsize=(int)188 /GstPipeline:pipeline0/GstMpegTSDemux:mpegtsdemux0.GstPad:sink: caps = video/mpegts, systemstream=(boolean)true, packetsize=(int)188 /GstPipeline:pipeline0/GstMpegTSDemux:mpegtsdemux0: pat-info = ((GValueArray*) 0x904e180) /GstPipeline:pipeline0/GstMpegTSDemux:mpegtsdemux0: pmt-info = ((MpegTsPmtInfo*) 0x8f3e8a0) /GstPipeline:pipeline0/GstQueue:queue0.GstPad:sink: caps = video/x-h264 /GstPipeline:pipeline0/GstQueue:queue0.GstPad:src: caps = video/x-h264 /GstPipeline:pipeline0/ffdec_h264:ffdec_h2640.GstPad:sink: caps = video/x-h264 /GstPipeline:pipeline0/ffdec_h264:ffdec_h2640.GstPad:src: caps = video/x-raw-yuv, width=(int)720, height=(int)576, framerate=(fraction)25/1, format=(fourcc)I420, interlaced=(boolean)true, pixel-aspect-ratio=(fraction)12/11 /GstPipeline:pipeline0/GstIdentity:identity0.GstPad:src: caps = video/x-raw-yuv, width=(int)720, height=(int)576, framerate=(fraction)25/1, format=(fourcc)I420, interlaced=(boolean)true, pixel-aspect-ratio=(fraction)12/11 /GstPipeline:pipeline0/GstIdentity:identity0.GstPad:sink: caps = video/x-raw-yuv, width=(int)720, height=(int)576, framerate=(fraction)25/1, format=(fourcc)I420, interlaced=(boolean)true, pixel-aspect-ratio=(fraction)12/11 /GstPipeline:pipeline0/GstFakeSink:fakesink0.GstPad:sink: caps = video/x-raw-yuv, width=(int)720, height=(int)576, framerate=(fraction)25/1, format=(fourcc)I420, interlaced=(boolean)true, pixel-aspect-ratio=(fraction)12/11 /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "preroll ******* " El conducto está PREPARADO … Estableciendo el conducto a REPRODUCIENDO … /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event ******* E (type: 102, GstEventNewsegment, update=(boolean)true, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, start=(gint64)0, stop=(gint64)-1, position=(gint64)0;) 0xb6d01b40" New clock: GstSystemClock /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (622080 bytes, timestamp: 0:00:02.590533334, duration: 0:00:00.040000000, offset: -1, offset_end: -1, flags: 544) 0x9064338"
Does this also happen with the new tsdemux element from gst-plugins-bad? And is this a broken file, i.e. is it correct that the first buffer has a timestamp of 2.7s?
Julien, could you please respond to the queries asked in comment#5 ?
Yes it happens with both tsdemux and mpegtsdemux. I think the ts is ok because this is a stream I receive immediately after sending a IGMP join. I mean I did not cut the beginning. The stream is attached to the comment #3 (< 1Mo)
There seems to be two things here: - the first video buffer is around 1.2 seconds late compared to audio - the video segment is dropped by capsfilter, as it's received before capsfilter is linked to its downstream element I'm not sure why capsfilter isn't yet linked.
Moreover, there's about 60 frames in this short sample, and the first 27 or so are not keyframes, and get dropped by ffdec_h264 as it waits to sync to the first keyframe.
There is a private stream with a buffer which comes first, with a timestamp of :03:20, whereas the first video buffer comes at :04:59. The first keyframe appears with a timestamp of :05:79. The difference betewen that first timestamp and the first keyframe is 2:59, similar to the pause you're reporting.
That's what I commented in 4, the first buffer out of the decoder is sent with a ts starting 02.764643179, which is the same timeout set by gst_poll_wait. A possible solution to this issue is sending from the decoder a segment update with the real start time of the segment, which is the one of the first keyframe and not the one of the first package sent by the demuxer.
That would clip other buffers though, including audio. Might be better for the user though, it's debatable...
Right, a pipeline with an audio and video sink would start playing the first 3s of audio and than start with the video. I would close it with NOTABUG