GNOME Bugzilla – Bug 580796
[ffmpegdec] out-of-order timestamps
Last modified: 2010-10-06 16:59:06 UTC
Please describe the problem: Some streams containing complex video (interlaced, skipped or B-Frames) will often come out desync with the audio, or be jittery because of timestamp mis-ordering. The main reason why this happens is that in the current implementation of gstffmpegdec, there is no direct implicit link between incoming buffers and decoded frames. Depending on the profile, most decoders will queue some data before outputing the first frame. Also the chain function will reorganize incoming buffers to pad them to the remains of previous frames, this way some timestamps can be automatically lost. Lastly, the incoming timestamps will always be in the coded order, so if you have a sequence of IPBBPBB frames, the P frames timestamps will be future to the B frames, therefore they cannot be applied directly to the output. Luckily, FFMPEG provides a neat mechanism for reordering timestamps, it is used in ffplay to assign the proper pts on a decoded frame and works very well : /* pass the coded picture timestamp */ ffmpegdec->context->reordered_opaque = in_timestamp; len = avcodec_decode_video (ffmpegdec->context, ffmpegdec->picture, &have_data, data, size); /* recuperate the reordered timestamp */ in_timestamp = ffmpegdec->picture->reordered_opaque; The only problem is ensuring that in_timestamp exactly matches the coded frame. I've tackled this by using a circular list which tracks every incoming buffer and timestamps, then I use the decoder consumption amount (len) to move the tail of the list and have the next timestamp ready. I also invalidate a timestamp once it is used to prevent other frames from reusing it in cases where a large buffer contains multiple frames. This method is very accurate and addresses every cases of video I found to date. Steps to reproduce: Actual results: Expected results: Does this happen every time? Other information:
vanista, do you have a patch ?
Created attachment 134515 [details] [review] Proposed implementation
Consider this a proof of concept. I haven't had much time to implement and test this. However, be careful with the various subtleties, there is a reason behind each of them. If in doubt, please ask me :-)
Bumping this up to blocker, we can't make a release without this fixed.
commit a26b94d92c2e9e9f6dac0cdb5fb44ba06ee089c8 Author: Vanista <vanista@gmail.com> Date: Wed May 13 12:37:42 2009 +0200 gstffmpegdec: Handle out-of-order frames. Fixes #580796
This patch breaks avi files where the timestamp is actually the DTS and not the PTS. /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event ******* E (type: 118, taglist, video-codec=(string)\"DivX\\ MPEG-4\\ Version\\ 5\";) 0x7fafd4003a40" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event ******* E (type: 118, taglist, encoder=(string)\"VirtualDubMod\\ 1.5.10.1\\ \\(build\\ 2366/release\\)\";) 0x7fafd4003a00" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.000000000, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 32) 0x7fafd4003010" New clock: GstSystemClock /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.083416750, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003190" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.125125125, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003290" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.041708375, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003310" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.208541875, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003210" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.250250250, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003090" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.166833500, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003110" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.333667000, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x1637e80" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.375375375, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003010" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.291958625, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003190" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.458792125, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x7fafd4003290"
after reverting the patch: /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.000000000, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 32) 0x282a030" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.083416750, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a1b0" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.125125125, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a2b0" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.166833500, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a330" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.208541875, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a230" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.250250250, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a0b0" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.291958625, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a130" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.333667000, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x24d0e80" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.375375375, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a030" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.417083750, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a1b0" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.458792125, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a2b0" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.500500500, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a430" /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain ******* < (283728 bytes, timestamp: 0:00:00.542208875, duration: 0:00:00.041708375, offset: -1, offset_end: -1, flags: 256) 0x282a230"
We need to revert this patch. I'm also a bit afraid of all this extra state kept outside of ffmpeg to track timestamps. Vanista, do you have a file that does not work without this patch?
My use case is IPTV sources with HD feed using main profile (CABAC and B-Frames) additionally the feed is interlaced, so for each display frame there are a number of PES chunks. Sorry I can't provide a capture, it's copyrighted. I tried replicating the source using videotestsrc, x264enc and mpegtsmux but it looks like the mux prevents timestamps from going back in time. I also tried plugging the decoder right after the encoder and the ts come out reordered. At least, here are the timestamps of the sample in cause : mpegtsdemux ! fakesink : [...] 163 bytes, timestamp: 0:35:22.095200000 4048 bytes, timestamp: none 8096 bytes, timestamp: none 1963 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.111877777 5287 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.028466666 3535 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.045144444 3387 bytes, timestamp: none 170 bytes, timestamp: 0:35:21.995100000 1063 bytes, timestamp: none 170 bytes, timestamp: 0:35:22.011777777 1971 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.061833333 1870 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.078511111 820 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.228666666 4048 bytes, timestamp: none 5157 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.245344444 7871 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.161933333 4118 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.178611111 4429 bytes, timestamp: none 170 bytes, timestamp: 0:35:22.128566666 2268 bytes, timestamp: none 170 bytes, timestamp: 0:35:22.145244444 2177 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.195300000 1664 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.211977777 2483 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.362133333 4048 bytes, timestamp: none 1811 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.378811111 5155 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.295400000 3029 bytes, timestamp: none 165 bytes, timestamp: 0:35:22.312077777 [...] mpegtsdemux ! ffdec_h264 ! fakesink : 345600 bytes, timestamp: 0:35:22.095200000 345600 bytes, timestamp: 0:35:22.128566666 345600 bytes, timestamp: 0:35:22.295400000 345600 bytes, timestamp: 0:35:22.228666666 345600 bytes, timestamp: 0:35:22.262033333 345600 bytes, timestamp: 0:35:22.295400000 345600 bytes, timestamp: 0:35:22.328766666 345600 bytes, timestamp: 0:35:22.362133333 345600 bytes, timestamp: 0:35:22.462233333 345600 bytes, timestamp: 0:35:22.428866666 345600 bytes, timestamp: 0:35:22.462233333 345600 bytes, timestamp: 0:35:22.495600000 345600 bytes, timestamp: 0:35:22.528966666 345600 bytes, timestamp: 0:35:22.562333333 345600 bytes, timestamp: 0:35:22.595700000 345600 bytes, timestamp: 0:35:22.662433333 345600 bytes, timestamp: 0:35:22.662433333 345600 bytes, timestamp: 0:35:22.896000000 345600 bytes, timestamp: 0:35:22.829266666 345600 bytes, timestamp: 0:35:22.762533333 345600 bytes, timestamp: 0:35:22.795900000 345600 bytes, timestamp: 0:35:22.829266666 345600 bytes, timestamp: 0:35:22.862633333 345600 bytes, timestamp: 0:35:22.896000000 345600 bytes, timestamp: 0:35:22.996100000 [...] Within gstffmpeg the whole timestamp handling mechanism is pretty complex and there are lots of different cases to cover. My approach was to figure out how ffplay handles timestamps between demuxer and decoder. I strongly believe that the reordered_opaque property is the key, but I won't claim that my implementation with the circular list is perfect ;) Fact of the matter is, I get a lot of cases where timestamps coming out of ffdec do not match the intended timestamps, and ffplay works perfectly with these same samples. One thing that is twitchy about the implementation is the decoder's data consumption tracking. If a decoder doesn't give accurate information about this, the timestamps will be offset.
Vanista, can you check that this patch works for you too. The core of your handling is still there but the logic to also detect backwards timestamps and switching to DTS handling is now properly integrated, I hope. commit 686aadaf01d3374034d18cae1f45e36a3c3d80df Author: Wim Taymans <wim.taymans@collabora.co.uk> Date: Fri Jun 5 12:32:25 2009 +0200 ffmpeg: properly integrate timestamp handling The patch from Bug #580796 hacked around existing infrastructure to handle timestamps as DTS (as in all AVI files) causing the logic to be disabled. Properly hook the timestamp handling into the existing infrastructure to handle these cases too, partially reverting a26b94d92c2e9e9f6dac0cdb5fb44ba06ee089c8 and moving some stuff around. Refixes #580796.
please reopen if it is not fixed yet.
Works good with my samples! Thanks.
Turns out that the patch still had problems when QoS was enabled. The next patch uses a similar method for tracking timing info but is a little simpler and only uses ffmpeg tracking structures. commit 76d9685202e4443573d71c16b0445cbd3fb59aca Author: Wim Taymans <wim.taymans@collabora.co.uk> Date: Wed Oct 6 16:00:05 2010 +0200 ffdec: Add timestamp tracking Use ffmpeg reordered_opaque to track an id that combines all timing info we have for a frame. The ids are kept in a 255 item cache. Fixes #631075