GNOME Bugzilla – Bug 674536
tsdemux: Freeze on pts-wrap with streaming sources
Last modified: 2014-06-13 09:53:12 UTC
When playing mpeg-ts from udp or http sources the playback freezes on pts-wrap. This can be reproduced by putting the attached file to a http server and playing it with playbin2 and tsdemux. If the same file is played locally with file-src it goes on perfectly fine when the pts-wrap occurs.
The sample file was rejected as attachment (I guess it's too big), so I uploaded it here: http://jusst.de/files/pts-wrap.ts
I tracked things a bit further and figured out, that the difference between file- and udp- or httpsrc is in mpegtspacketizer. The function mpegts_packetizer_pts_to_ts uses calculated clock skew if available. This is the case for udp and http. If this is not available the pcr observations are used. This is the case with filesrc. In the case of pcr observation usage rollovers are handled and hence the computed timestamp is continuous in the end. In the clock skew case rollover is not handled and after the rollover happens the timestamp jumps from the continuous timestamps starting at 0 to the timestamp actually included in the pes. I don't really understand how the clock skew part is handled at all and in which way the rollover should be handled there. I simply disable usage of computed clock skew completely for now, which seems to work around the problem: diff --git a/gst/mpegtsdemux/mpegtspacketizer.c b/gst/mpegtsdemux/mpegtspacketizer.c index 41ff6dd..8cc66d1 100644 --- a/gst/mpegtsdemux/mpegtspacketizer.c +++ b/gst/mpegtsdemux/mpegtspacketizer.c @@ -3208,6 +3208,7 @@ mpegts_packetizer_pts_to_ts (MpegTSPacketizer2 * packetizer, GstClockTime pts) { GstClockTime res = GST_CLOCK_TIME_NONE; +#if 0 /* Use clock skew if present */ if (packetizer->calculate_skew && GST_CLOCK_TIME_IS_VALID (packetizer->base_time)) { @@ -3217,6 +3218,7 @@ mpegts_packetizer_pts_to_ts (MpegTSPacketizer2 * packetizer, GstClockTime pts) res = pts - packetizer->base_pcrtime + packetizer->base_time + packetizer->skew; } else +#endif /* If not, use pcr observations */ if (packetizer->calculate_offset && packetizer->priv->first_pcr != -1) { /* Rollover */ Still I think someone who is familiar with the calculated clock skew and why it is actually there should take a look and suggest a real solution instead of just disabling it. If I come up with a better thought in the meantime, I will post it here.
Created attachment 212690 [details] [review] don't reset base_pcrtime I experimented a bit further and found out that the reset of base_pcrtime when mpegtspacketizer detect a rolliver thwarts the rollover detection in tsdemux.c, so that in the end the timestamp makes a jump in the size of MAX_PTS_DTS-new base_pcrtime. I don't see a reason why the reset of base_pcrtime would be needed at all with the rollover code in tsdemux. The attached patch disables it (for now just using compiler macros...), which works well for me so far. Still some comment by a developer more familiar with the timestamp handling would be nice.
Please don't commit this, it'll break the udp use-case. This needs more thinking.
(In reply to comment #4) > Please don't commit this, it'll break the udp use-case. This needs more > thinking. Could you outline why it breaks udp use-case? I test this with udp and don't see issues actually, atm.
To be more exact: I actually had the pts-wrap issue with udp source at first. With the patch I don't have it anymore.
I can confirm this. Freeze happens on all tested DVB-S live streams (streaming sources tested: getstream or Terracue IPTV gateway) at least once a day: base_pcrtime is resetted, buffer ts increase about several hours from one frame to the next and basesink sits (almost) forever on
+ Trace 230200
Thread 7 (Thread 0xb3c64b70 (LWP 6201))
Debug extract: mpegtspacketizer mpegtspacketizer.c:3216:mpegts_packetizer_pts_to_ts:ESC[00m pts 95443762411111 base_pcrtime:95440393690000 base_time:0:00:00.000000000 tsdemux tsdemux.c:1568:gst_ts_demux_push_pending_data:<tsdemux0:video_00a8>ESC[00m Pushing buffer list with timestamp: 0:00:04.342565555 basesink gstbasesink.c:2568:gst_base_sink_do_sync:<xvimagesink0> possibly waiting for clock to reach 0:00:04.222555555, adjusted 0:00:04.222555555 mpegtspacketizer mpegtspacketizer.c:2974:calculate_skew:ESC[00m backward timestamps at server, taking new base time mpegtspacketizer mpegtspacketizer.c:3216:mpegts_packetizer_pts_to_ts:ESC[00m pts 95443779211111 base_pcrtime:851518 base_time:0:00:00.000000000 tsdemux tsdemux.c:1568:gst_ts_demux_push_pending_data:<tsdemux0:video_00a8>ESC[00m Pushing buffer list with timestamp: 26:30:44.655404037 basesink gstbasesink.c:2568:gst_base_sink_do_sync:<xvimagesink0> possibly waiting for clock to reach 26:30:44.655400000, adjusted 26:30:44.655400000 Can provide another test stream, debugging output, backtraces if it helps ... Julian's patch fixes this. What is the status here? You don't recommend fixing it like this? Is another solution near? We will try with the existing patch so long because by now tsdemux is unusable on live TV-streams for us. Thanks.
It needs to be properly reviewed, and I don't have time right now. Fixing one use-case without making sure it doesn't break other use-cases is not recommended.
Created attachment 214483 [details] [review] mpegtspacketizer: Detect PCR wraparound in skew code If the received PCR is going backwards (by a safe margin), include that wraparound for further calculation.
Review of attachment 214483 [details] [review]: Patch works well for me, so far. The taken approach makes sense. I would suggest to push it.
commit 00f2111a5e75e5a7b1a1fd467b9918d4ba05e133 Author: Edward Hervey <edward.hervey@collabora.co.uk> Date: Sun May 20 13:27:29 2012 +0200 mpegtspacketizer: Detect PCR wraparound in skew code If the received PCR is going backwards (by a safe margin), include that wraparound for further calculation. https://bugzilla.gnome.org/show_bug.cgi?id=674536
Actually in long run tests with git version of friday (2012-06-08) it turns out that only one pts wrap is handled correctly. If a second wrap occurs the playback freezes. To reproduce this I used a ts-file containing no pts wrap and streaming it in a loop with tsplay as udp stream: tsplay -loop sample.ts 239.0.50.1:4444 gst-launch playbin2 uri=udp://239.0.50.1:4444 Wait for tsplay to loop twice (which will actually result in a PTS rollover being detected each time) and playback freezes. As a sample you can use http://jusst.de/files/cablecom-nick.ts for example.
Soo ... this introduces weird PCR wraps. They don't *actually* wrap, it's more like they get resetted/shifted. A wrap would be going from (close to) PCR_MAX to (close to) 0. In this case ... it goes backwards by 30s at each loop. I'm not 100% sure whether this should be handled or not.
Actually you are right about the "weird" wraps. My initial patch behaves even worse with this than the current git version does. Looking at the ISO13818 one should expect that PTS always reaches PCR_MAX before it wraps and earlier wraps are not allowed. Still we should think about a way to deal with this as ts muxers tend to do non-spec compliant stuff here and there. Maybe it would make more sense to deal with pts jumps that are not happening at PCR_MAX with a complete clock resync? Anyway, regarding the actual issue, the behaviour of git version with this weird wraps is just as it is with normal wraps seen on a DVB-S stream running 2 days.
Actually the clock skew code handles those (almost) fine. The problem is the PTS<=>PCR<=>Upstream adjustment in tsdemux which doesn't handle those cases. Will ponder it, seems somewhat valid in the end
the clock skew code could also be improved to detect those resets cleaner. Right now there's a reset of past data points/skew, resulting in rate jitter when there's a reset. It could estimate where the "next" upstream (i.e. inverse-adjusted) time would have been, and if it's not too far from the new upstream time, use that and not reset the past observations.
Created attachment 217275 [details] Handle resets of PCR/PTS < PCR_GST_MAX_VALUE We ran into the same issue now: Freeze on resetted PCR/PTS in a multicast stream containing a looped video. This is a common use-case for public screens with stuff like commercial content or so and should be handled. (Works fine with mpegtsdemux/flutsdemux ;-) The attached patch fixes the issue for our test-cases by kind of generalizing the existing detection of PCR wraps and PTS rollover for jumps < PCR_GST_MAX_VALUE (PCR) and PTS_DTS_MAX_VALUE (PTS), resp. Do you think this is the way to go? Possible that I missed other use-cases! The threshold is now set to 10 sec, which is ok for our test-content. Is that reasonable? I am not 100% sure, whether the calculation of the >pts_reset_diff value is correct in all the cases. Thanks for your feedback!
If the absolute difference is very close to the maximum PCR value (let's say a diff of 1 << 30 for example), then we should bump up/down by the maximum PCR value because it means it is very probable that it is an actual pcr wraparound. It *needs* to do that behaviour for *compliant* streams, else you end up with a discrepancy between (corrected) PCR values and local (corrected) clock. If the absolute difference is smaller than a small value (like 10s), it should be ignore. The question is what to do with values in between (i.e. it's not a glitch and it's not a compliant wrap-around).
(In reply to comment #18) > If the absolute difference is very close to the maximum PCR value (let's say a > diff of 1 << 30 for example), then we should bump up/down by the maximum PCR > value because it means it is very probable that it is an actual pcr wraparound. Ok, this should not interfere with the video-loop use-case where you can expect resets about 30sec to 2h or so. > > The question is what to do with values in between (i.e. it's not a glitch and > it's not a compliant wrap-around). Well that's what I tried to answer with the submitted patch: track the exact pcr_diff after (multiple) timestamp resets and account for in calculating current gstpcr values (calculate_skew()) ... AND do the same for the PTS (gst_ts_demux_record_pts()). Not sure if you can go with the latter only as does mpegtsdemux/flutsdemux that seem to handle ts discontinuities only by updating stream->base_time. Actually the observed freeze was triggered by too high PTS after the reset, because gst_ts_demux_record_pts() handles discontinuities >10sec as rollovers of about PTS_DTS_MAX_VALUE. But not when not tracking pcr resets I found calculate_skew() falling in other cases like basetime or skew reset, breaking the corrected PTS calculation.
With respect to "values in between", note that subtitles may have gaps in PTS that are of "medium size" and currently experience problems with the 'magic' in gst_ts_demux_record_pts() (see bug #678148).
Comment on attachment 217275 [details] Handle resets of PCR/PTS < PCR_GST_MAX_VALUE Patch does not work for all cases (and won't handle positive PTS jumps that are triggerd by subtitles) - therefore "obsolete". Strangely this patch handles almost all mpegts snippets when looped within a continuous live stream. Here is an example of a (recorded) ts-stream, that does not work when looped in live pipelines (non-live is ok): http://www.math.uni-bielefeld.de/~hkaelber/vid/stutter.ts After the 3rd loop video begins to stutter because corrected timestamps are too low and basesink drops because of "buffer late". Again, no problem with mpegtsdemux. Comparing outgoing timestamps produced by tsdemux in live vs. non-live pipelines shows that with every loop they decrease in the live case with respect to the non-live case. I suspect the problem in the depths of calculate_skew(). As this is pretty complex I don't dare touching it and maybe breaking other use cases for a solution that might in the end not be accepted. We go with a workaround until this is properly fixed ...
I had fixes for all of this .. but all went to dead ssd heaven :( I'll try to rewrite them at some point.
Have you been able to rewrite the fixes, Edward? If so, did this go in gstreamer-1.0?
Hi, Any update on this fix? Is this still broken? We too faced exactly the same problem of gstbasesink waiting forever, due to discontinuous timestamps BTW, does flutsdemux has this issue? Unfortunately, flutsdemux doesn't exist for 1.0 version for me to try out ~Jagadish
This should be fixed in 1.0: commit 121aa3ad13a85ecd9da17224260c4f51d062c875 Author: Edward Hervey <edward.hervey@collabora.co.uk> Date: Thu Jul 19 13:35:51 2012 +0200 mpegtspacketizer: Better detect PCR resets Assume that any differences in PCR greater than 15s means there is a reset in the stream. However there's still a problem with timestamp resets in the PES packets, I have a patch that fixes it almost but has a remaining problem (see the FIXME). Attaching...
Created attachment 241329 [details] [review] PES timestamp reset detection
Created attachment 241330 [details] [review] 0001-tsdemux-Handle-PES-timestamp-resets-better.patch
(In reply to comment #27) > Created an attachment (id=241330) [details] [review] > 0001-tsdemux-Handle-PES-timestamp-resets-better.patch Does not seem to work for our test-case (video-looping cf. comment 21) -> Discont buffer timestamps: 0:00:28.573428371 8333 0x9df4920 DEBUG tsdemux tsdemux.c:1604:gst_ts_demux_push_pending_data:<tsdemux0:video_00a8> Pushing buffer with PTS: 0:00:28.710496384 , DTS: 0:00:28.590496384 0:00:28.598321798 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:00:28.630509363 for pts 12:04:07.782300000 pcr_pid:0x00a8 0:00:28.598347772 8333 0x9df4920 DEBUG tsdemux tsdemux.c:1604:gst_ts_demux_push_pending_data:<tsdemux0:video_00a8> Pushing buffer with PTS: 0:00:28.630509363 , DTS: 99:99:99.999999999 0:00:28.607733805 8333 0x9df4920 ERROR tsdemux tsdemux.c:1384:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 5, stream 7 0:00:28.607871747 8333 0x9df4920 ERROR tsdemux tsdemux.c:1384:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 7, stream 14 0:00:28.607981324 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:02.031097787 for pts 12:04:07.422244444 pcr_pid:0x00a8 0:00:28.609460526 8333 0x9df4920 ERROR tsdemux tsdemux.c:1384:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 5, stream 10 0:00:28.609662723 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:02.010108898 for pts 12:04:07.401255555 pcr_pid:0x00a8 0:00:28.609779021 8333 0x9df4920 ERROR tsdemux tsdemux.c:1384:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 0, stream 9 0:00:28.609903412 8333 0x9df4920 ERROR tsdemux tsdemux.c:1384:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 6, stream 15 0:00:28.615506625 8333 0x9df4920 ERROR tsdemux tsdemux.c:1384:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 2, stream 10 0:00:28.648771886 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:02.031110559 for pts 12:04:07.422244444 pcr_pid:0x00a8 0:00:28.690171859 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:02.071123228 for pts 12:04:07.462244444 pcr_pid:0x00a8 0:00:28.715768970 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:01.969346907 for pts 12:04:07.360455555 pcr_pid:0x00a8 0:00:28.728756331 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:02.111135796 for pts 12:04:07.502244444 pcr_pid:0x00a8 0:00:28.757055547 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:01.938159375 for pts 12:04:07.329255555 pcr_pid:0x00a8 0:00:28.772491514 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:02.151148264 for pts 12:04:07.542244444 pcr_pid:0x00a8 0:00:28.784946762 8333 0x9df4920 DEBUG mpegtspacketizer mpegtspacketizer.c:3699:mpegts_packetizer_pts_to_ts: Returning timestamp 0:01:02.431216188 for pts 12:04:07.822300000 pcr_pid:0x00a8 0:00:28.784973081 8333 0x9df4920 DEBUG tsdemux tsdemux.c:1604:gst_ts_demux_push_pending_data:<tsdemux0:video_00a8> Pushing buffer with PTS: 0:01:02.431216188 , DTS: 99:99:99.999999999
Sebastian, We too tried with the patch that you gave. Doesnt seem to work. Still hangs whenever there is a clock skew! This has been a long pending bug and quite a number of people are seeing issues when you run your application for a long time :( I tried figuring our the code and adding my fix but then couldn't quite understand the code :( ~BO
Edward has some changes here that should fix this too: http://cgit.freedesktop.org/~bilboed/gst-plugins-bad/log/?h=0.10
Seems to be on version 0.10 and not 1.0. Finding it tough to migrate the patch since there have been lot of changes in 1.0 from 0.10 ~BO
The top two commits are the only relevant and can be applied to 1.0 with minimal changes
I tried that, giving compilation issues. I see a lot of lines are removed and most of them are missing in the original 1.0 code now
Created attachment 242409 [details] [review] 0001-tsdemux-Improve-handling-of-PTS-wraparounds-resets.patch This would be Edward's changes ported to latest git master
Sebastian, Wonderful. Thank you so much for this. Let me check and see the result ~BO
(In reply to comment #34) > Created an attachment (id=242409) [details] [review] > 0001-tsdemux-Improve-handling-of-PTS-wraparounds-resets.patch Great, works with all our test-cases on 1.x: full PCR/PTS reset, small PCR/PTS reset (<5min), continuous video looping over UDP. Pls. push! BTW: http://cgit.freedesktop.org/~bilboed/gst-plugins-bad/commit/?h=0.10&id=2c918dac65abfbc68cc8fa35dbd825c7b61fb501 does not look like 0.10 compatible, seems to miss some stuff only present in 1.0 branch. Would be nice if this could be cleanly backported to 0.10 ;-)
Not everything from my top commits were meant to fix this issue. Will update a new patch
Created attachment 242567 [details] [review] tsdemux: convert packet PTS/DTS as soon as possible We let the mpegtspacketizer deal with pcr wraparound/resets.
commit 65ba9b4756203786c54c9cbf10670a75438f14da Author: Edward Hervey <edward@collabora.com> Date: Fri Apr 26 15:39:30 2013 +0200 tsdemux: convert packet PTS/DTS as soon as possible We let the mpegtspacketizer deal with pcr wraparound/resets. https://bugzilla.gnome.org/show_bug.cgi?id=674536
Recently I migrated to gstreamer-1.2.2 version and I could reproduce this issue in my workspace using this file http://jusst.de/files/pts-wrap.ts After that I reverted back to gstreamer-1.0.8 version to cross-verify my observations. In 1.0.8 version also I found the same results. My test Setup: I am using professional broadcast card to multicast pts-wrap.ts file over udp. And I am receiving it on Gstreamer and VLC. While VLC plays this stream seamlessly, gstreamer outputs "5124069:03:59.034393780" timestamp during ROLL over, which is leading to hang. Here is my pipeline: pipeline1: gst-launch-1.0 udpsrc uri=234.0.0.139:8888 multicast-iface=eth1 ! tsdemux ! video/mpeg ! checksumsink Checksumsink Logs: gst_1_0_8_PTS_issue.log: http://goo.gl/X8s1Fi gst_1_2_2_PTS_issue.log: http://goo.gl/jFXYKU If I run this pipeline2, videodecoder keep producing below mentioned Warning and video freezes there. pipeline2: gst-launch-1.0 udpsrc uri=234.0.0.139:8888 multicast-iface=eth1 ! decodebin ! video/x-raw ! checksumsink --gst-debug=3 Warning: "gstvideodecoder.c:2313:gst_video_decoder_prepare_finish_frame:<avdec_mpeg2video0> decreasing timestamp (0:00:13.734374563 < 5124069:03:59.034393780)" Can anybody have a look at this please and reopen this bug??? Many thanks in advance.
The issue is occurring because the PTS rollover happens before the PCR rolls over. Since rollover is calculated only for PCR(in clock skew function) and NOT for PTS, PTS will have junk values I'm not sure if this is fixed in git master. Is it? I see things are handled differently as PCR group!
Need some kind of a state machine which will tackle following usecases - Rollover of PTS/PCR, PCR rolling over first and viceversa - Completely reset PTS/PCR. Outgoing PTS should be a continuation of last valid PTS(Buyg #725047) - Reducing PTS - Can happen during packet losses Let me put some thought into this
Issue is reproducible with 1.3.1 too. In mpegts_packetizer_pts_to_ts() PCR group handling is done in "else" part. But it always enters the "if" part since calculate_skew is set
I used pts-wrap.ts file which is given by bug reporter and ran experiments using gstreamer-1.2.2 version. Here are my observation. I have tapped res, pts, pcroffset, base_pcrtime, base_time, skew values for stream-pid 110. please find tapped details in the attached log. Log: http://goo.gl/201PiR 1. When input pts values get reset from 26:30:43.661355555 to 0:00:00.103666666, pcr-offset is still 0. There is 30 milisecond delay in pcr_offset calculation once the pts gets reset. This delay is leading to junk pts value on outgoing buffers untill pcr_offset is calculated. How to sync pts-reset and pcr_offset calculation. 2. Also I observed that skew value is too high from the beginning. I will be continuing with my experiments, meanwhile any lead or quick clue on this will be greatly appreciated and will be helpful for me to fix this issue.
Comment on attachment 242567 [details] [review] tsdemux: convert packet PTS/DTS as soon as possible Meh, this was committed ages ago :)
Edward, You mean to say the fix is in git master and not in 1.3.1? coz I could reproduce it with 1.3.1
I never said that. I just updated the status of *old* patches (look at the dates). I'm investigating the issue though.
The following fixes have been pushed: 97b3382 mpegtspacketizer: live: handle pcr/dts discrepancies some more fdf9bdf mpegtspacketizer: Fix wraparound detection issue
Created attachment 278393 [details] [review] mpegtspacketizer: live: handle pcr/dts discrepancies some more When wrapover/reset occur, we end up with a small window of time where the PTS/DTS will still be using the previous/next time-range. In order not to return bogus values, return GST_CLOCK_TIME_NONE if the PTS/DTS value to convert differs by more than 15s against the last seen PCR
Created attachment 278394 [details] [review] mpegtspacketizer: Fix wraparound detection issue Using 32bit unsigned values for corrected pcr/offset meant that we potentially ended up in bogus values Furthermore, refpcr - refpcroffset could end up being negative, which PCRTIME_TO_GSTTIME() can't handle (and returned a massive positive value)