GNOME Bugzilla – Bug 636279
REGRESSION: Video often freezes during playback of mpeg2 files
Last modified: 2011-06-20 12:26:12 UTC
I play files using $ gst-launch playbin2 uri=file:////path/to/file.mpg I'm getting lots of messages WARNING: from element /GstPlayBin2:playbin20/GstPlaySink:playsink0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: A lot of buffers are being dropped. Additional debug info: gstbasesink.c(2699): gst_base_sink_is_too_late (): /GstPlayBin2:playbin20/GstPlaySink:playsink0/GstBin:vbin/GstAutoVideoSink:videosink/GstXvImageSink:videosink-actual-sink-xvimage: There may be a timestamping problem, or this computer is too slow. during freezes. Sound plays smoothly during freezes. I use JHBuild with the latest changes from freedesktop git repository. Tried playing the same file with the GStreamer packages installed from gstreamer-developers PPA, it plays fine. Sample video can be found at http://dl.dropbox.com/u/11507187/F12811_cnn.mpg
Same thing on windows with the latest OSSBuild, which was synced with git several hours ago.
> Sample video can be found at http://dl.dropbox.com/u/11507187/F12811_cnn.mpg That gives me a 404 not found.
It's still uploading currently. Dropbox client promises 10 minutes more.
Done, you can download the file.
Works fine for me, with and without deinterlacing. > Tried playing the same file with the GStreamer packages > installed from gstreamer-developers PPA, it plays fine. Could you specify the exact versions you got from the PPA?
gstreamer-tools - 0.10.30.5-1~lucid1 gstreamer-0.10-plugins-base - 0.10.30.5-2~lucid1 gstreamer-0.10-plugins-good - 0.10.25.5-1~lucid1 gstreamer-0.10-plugins-bad - 0.10.20-2~lucid3 gstreamer-0.10-plugins-ugly - 0.10.16-1~lucid1 Other accompanying packages have similar version. My system checks for updates every day, so I have most recent packages.
Thanks, just checking you were in fact using the pre-releaes. This is a bit surprising, because the changes between the last pre-relases and the releases don't look particularly intrusive or relevant: commit 7b312c5980f80b96afde55e3055d7b50a05693dc Author: Stefan Kost <ensonic@users.sf.net> Date: Wed Nov 24 17:34:21 2010 +0200 uridecodebin: disconnect signal handlers before disposing commit b27d93a84a3f7c2474c91479a5554de0fa1b1a29 Author: David Schleef <ds@schleef.org> Date: Tue Nov 30 15:28:50 2010 -0800 deinterlace: analyse RFF fields in correct order Code was repeating the second field, not the first. Fixes: #636179. commit b6b0de0c49816c5acb5c9635b2fe8dd4d4dc5215 Author: Mark Nauwelaerts <mark.nauwelaerts@collabora.co.uk> Date: Mon Nov 29 15:32:40 2010 +0100 rtspsrc: handle stale digest authentication session data In particular, handle Unauthorized server response when trying to convey keep-alive. Fixes #635532. commit e7b1655069fe2f03daf9e53b865bc110bd3c5131 Author: Thijs Vermeir <thijsvermeir@gmail.com> Date: Fri Nov 26 15:00:29 2010 +0100 rtph264depay: fix segfault on empty payload https://bugzilla.gnome.org/show_bug.cgi?id=635843
I also think so. Now I'm trying to roll back and check.
Have found that this bug is observed on all my OSSBuilds after 2010-11-11. Logs show there was some manipulation with the streamsynchronizer on 17-11...
Have downloaded updates from PPA. Again, plays fine.
Here are two excerpts from logs. The ossbuild version of 03-11-2010 0:00:12.593750000 3204 0A6AB990 LOG mpeg2dec gstmpeg2dec.c:854:clip_buffer:<mpeg2dec0> timestamp:0:00:01.407300000 , duration:0:00:00.040000000 0:00:12.593750000 3204 0A6AB990 LOG mpeg2dec gstmpeg2dec.c:880:clip_buffer:<mpeg2dec0> not dropping 0:00:12.593750000 3204 0A6AB990 LOG mpeg2dec gstmpeg2dec.c:1037:handle_slice:<mpeg2dec0> pushing buffer 0A6BA218, timestamp 0:00:01.407300000, duration 0:00:00.040000000 0:00:12.593750000 3204 0A6AB990 LOG mpeg2dec gstmpeg2dec.c:1038:handle_slice:<mpeg2dec0> ... with flags 300 0:00:12.640625000 3204 0A79D650 DEBUG GST_QOS gstbasesink.c:2760:gst_base_sink_do_render_stats:<videosink-actual-sink-d3dvideo> avg_render: 0:00:00.011326760 0:00:12.640625000 3204 0A79D650 DEBUG GST_QOS gstbasesink.c:2562:gst_base_sink_perform_qos:<videosink-actual-sink-d3dvideo> start: 0:00:00.519988889, entered 0:00:00.501201814, left 0:00:00.519988889, pt: 0:00:00.021212925, duration 0:00:00.040000000,jitter -18787075 0:00:12.640625000 3204 0A79D650 DEBUG GST_QOS gstbasesink.c:2567:gst_base_sink_perform_qos:<videosink-actual-sink-d3dvideo> avg_duration: 0:00:00.039997759, avg_pt: 0:00:00.014848474, avg_rate: 0.143256 0:00:12.640625000 3204 0A79D650 DEBUG GST_QOS gstbasesink.c:2602:gst_base_sink_perform_qos:<videosink-actual-sink-d3dvideo> updated: avg_duration: 0:00:00.039998039, avg_pt: 0:00:00.015644030, avg_rate: 0.158747 0:00:12.640625000 3204 0A79D650 DEBUG GST_QOS gstbasesink.c:2490:gst_base_sink_send_qos:<videosink-actual-sink-d3dvideo> qos: proportion: 0.158747, diff -18787075, timestamp 0:00:00.519988889 latest ossbuild version 0:00:02.546875000 2456 00B86AB8 LOG mpeg2dec gstmpeg2dec.c:1037:handle_slice:<mpeg2dec0> pushing buffer 00B97220, timestamp 0:00:01.407300000, duration 0:00:00.040000000 0:00:02.546875000 2456 00B86AB8 LOG mpeg2dec gstmpeg2dec.c:1038:handle_slice:<mpeg2dec0> ... with flags 300 0:00:02.562500000 2456 01B31EE8 DEBUG GST_QOS gstbasesink.c:2760:gst_base_sink_do_render_stats:<videosink-actual-sink-d3dvideo> avg_render: 0:00:00.009012112 0:00:02.562500000 2456 01B31EE8 DEBUG GST_QOS gstbasesink.c:2562:gst_base_sink_perform_qos:<videosink-actual-sink-d3dvideo> start: 0:00:00.519988889, entered 0:00:01.577641723, left 0:00:01.577641723, pt: 0:00:00.017652834, duration 0:00:00.040000000,jitter 1057652834 0:00:02.562500000 2456 01B31EE8 DEBUG GST_QOS gstbasesink.c:2567:gst_base_sink_perform_qos:<videosink-actual-sink-d3dvideo> avg_duration: 0:00:00.039997759, avg_pt: 0:00:00.014220253, avg_rate: 0.12753 0:00:02.562500000 2456 01B31EE8 DEBUG GST_QOS gstbasesink.c:2602:gst_base_sink_perform_qos:<videosink-actual-sink-d3dvideo> updated: avg_duration: 0:00:00.039998039, avg_pt: 0:00:00.014649325, avg_rate: 0.14245 0:00:02.562500000 2456 01B31EE8 DEBUG GST_QOS gstbasesink.c:2490:gst_base_sink_send_qos:<videosink-actual-sink-d3dvideo> qos: proportion: 0.142450, diff 1057652834, timestamp 0:00:00.519988889 0:00:02.562500000 2456 01B31EE8 DEBUG GST_QOS gstbasetransform.c:2674:gst_base_transform_update_qos:<vscale> qos: proportion: 0.142450, diff 1057652834, timestamp 0:00:00.519988889 0:00:02.562500000 2456 01B31EE8 DEBUG GST_QOS gstbasetransform.c:2674:gst_base_transform_update_qos:<vconv> qos: proportion: 0.142450, diff 1057652834, timestamp 0:00:00.519988889 As can be seen, the same frame causes the jitter of -18787075 in one case and 1057652834 in another
I also have found that the bug exists in this revision: http://code.google.com/p/ossbuild/source/detail?r=926 But doesn't exist in the previous revision.
Sounds like a regression in -bad then, moving..
The commit, caused the regression: http://cgit.freedesktop.org/gstreamer/gst-plugins-bad/commit/?id=2271608c4314d6d0a685c18c5c47d55495586159
I think that the commit that is referred to triggers a bug. This stream is using the same time_code for every 2 GOP's. for example, the first GOP's have time_code: 17:46:35.000000000 and the next 2 have TS 17:46:36.000000000. Using the same time_code for another GOP doesn't look normal, but don't know yet if this is allowed in the stream or how to handle this...
GOPchop (http://outflux.net/unix/software/gopchop/) shows different codes for all GOPs, at least for the first 20.
I tried this in gopchop and I see: 1 -> 17:46:34.09 2 -> 17:46:35.21 3 -> 17:46:35.08 So, yes in this tool they are different. But not increasing, which looks invalid...
Authors of the DVDlab reference some specification, saying that GOP time code is not necessary and can be invalid. http://www.mediachance.com/dvdlab/Help/chapters_idx.htm "Other problem with GOP timecode is that by specification it is not required to be present in the mpeg file, the file plays fine without it. Some encoders (very few actually) may not put the timecode, or the timecode may be totally wrong." I don't know which specification they mean. However, this file is real, and I have lots of similar ones.
Not sure what to do with this for the release - revert for now? Thijs?
Well, the problem is that I don't know how to create valid timestamps from invalid data in the stream. I also can't confirm that invalid GOP time code is accepted in the specifications. Maybe providing how this files are generated can help to find a work around for this. As the time information in the stream is wrong, the time in the container should be right. Otherwhise I don't know how correct timestamps could be created. The patch is solving a "real" problem with the specifications and triggering a bug from a unwritten "feature". Don't know what the (commit/revert) policy is in this case?
mplayer plays this file fine. vlc plays this file fine. GStreamer with -bad 0.10.20 plays this file fine. GStreamer with 0.10.21 doesn't play this file fine any longer, that's something we need to fix IMHO. Correct me if I'm wrong, but whatever your patch fixes, was broken in the previous release as well, right? So maybe that's unfortunate, but causing playback regressions with a major format seems even more undesirable to me, regardless of the rights and wrongs and the spec. Isn't there something we can do better here? How do mplayer/vlc handle this?
Reverted this for the release: commit e5f1cdd0e9362c14784c4e1e8c762623537af4c7 Author: Tim-Philipp Müller <tim.muller@collabora.co.uk> Date: Fri Jan 7 18:49:02 2011 +0000 Revert "mpegvideoparse: fix timestamp generation" This reverts commit 2271608c4314d6d0a685c18c5c47d55495586159. This patch needs more work so it doesn't cause grave playback regressions (multi-second freezes) with some files that have slightly broken timestamps but play fine everywhere else. https://bugzilla.gnome.org/show_bug.cgi?id=636279 https://bugzilla.gnome.org/show_bug.cgi?id=632222 Original bug has been re-opened so closing this one.
I don't want to close this just now because the problem is not solved, only moved. (In reply to comment #21) > mplayer plays this file fine. vlc plays this file fine. GStreamer with -bad > 0.10.20 plays this file fine. Because they don't look at the time-code, and push all buffers based on framerate. Which is IMHO wrong. > ... but causing > playback regressions with a major format seems even more undesirable to me, > regardless of the rights and wrongs and the spec. AFAIK only this file is broken with the patch, and not the whole format. I think it can help to get more information on this file and how it is created.
(In reply to comment #23) > AFAIK only this file is broken with the patch, and not the whole format. > I think it can help to get more information on this file and how it is created. These files were created by remuxing MPEG-2 transport stream from DVB-S with the FFmpeg. I stress that this was remuxing, not re-encoding, i.e. command line parameters were -vcodec copy -acodec copy FFmpeg doesn't touch GOP headers, therefore these data came from a satellite. Unfortunately, I don't know neither the satellite, nor the provider.
Ok, now we are there :-) (In reply to comment #24) > (In reply to comment #23) > These files were created by remuxing MPEG-2 transport stream from DVB-S with > the FFmpeg. In DVB-S streams the timing information is inside the transport stream. (We are testing here with similar DVB-S streams) > FFmpeg doesn't touch GOP headers, therefore these data came from a satellite. > Unfortunately, I don't know neither the satellite, nor the provider. This means you dropped the timing information (from the TS) stream and didn't fix the timing information in the GOP headers. (which is wrong) With this information I consider this files as not correct.
Let's close this then?
(In reply to comment #25) > > FFmpeg doesn't touch GOP headers, therefore these data came from a satellite. > > Unfortunately, I don't know neither the satellite, nor the provider. > This means you dropped the timing information (from the TS) stream and didn't > fix the timing information in the GOP headers. (which is wrong) I'm not sure about GOP headers, seems FFmpeg doesn't touch them, indeed. But it uses timing information in the TS to construct correct timestamps, so the first clause is invalid, timing information in the TS is not dropped.
(In reply to comment #27) > But it uses timing information in the TS to construct correct timestamps, so > the first clause is invalid, timing information in the TS is not dropped. Who is reconstructing correct timestamps? The stream is not a TS anymore, so reconstructing correct timestamps now is not possible anymore if the information is not saved in the GOP headers.
> Who is reconstructing correct timestamps? FFmpeg, or, more exactly, functions from its libraries libavformat, libavutil, etc. > The stream is not a TS anymore, so Right, but FFmpeg stores every access unit (a video frame or a batch of audio samples) in a separate structure AVPacket, which also carries all necessary information. Its demuxing function av_read_frame() calls low-level functions that parse MPEG-2 TS, read PTS and DTS from TS headers, assemble PES packets from the transport packets and store their data bytes, timestamps, and all other information in the AVPacket exemplars. These AVPackets are presented to the calling application. I have developed that application and it simply subtracts a constant from all timestamps to make them start from near 0. High-level muxing functions (av_write_frame and av_interleaved_write_frame) use information, stored in the AVPacket to correctly mux packets they receive. > reconstructing correct timestamps now is not possible anymore if the > information is not saved in the GOP headers. So, all timing information is stored and used, and everything is possible. GOP headers are left intact, right.
(In reply to comment #29) > So, all timing information is stored and used, and everything is possible. > GOP headers are left intact, right. So where is this information stored in the current file?
(In reply to comment #30) > (In reply to comment #29) > > So, all timing information is stored and used, and everything is possible. > > GOP headers are left intact, right. > So where is this information stored in the current file? As usual, in PES headers.
I should also mention, that GOP headers are stored among other data bytes in memory, pointed by AVPacket::data
Can you make that file available again, looks like I lost it...
Sorry, I also have lost it. Errm, to make sure, I'm correctly understood :) GOP headers are left untouched, the same as they were in the incoming TS stream.
One more thing. The "ISO/IEC 13818-2 Part 2" standard says that GOP time code is not used in the decoding process (in 6.1.1.7 and in 6.3.8). I think it is the artifact from the past.
I still have the file, uploading it to http://people.freedesktop.org/~tpm/samples/636279-F12811_cnn.mpg (but might take a while until it's done).