GNOME Bugzilla – Bug 743740
RTP playback doesn't handle missing packets well
Last modified: 2015-01-30 16:12:36 UTC
I'm trying to come up with a RTP playback pipeline that handles missing packets well. This is what this is what I'm using for creating the stream: gst-launch-1.0 videotestsrc ! x264enc ! mpegtsmux name=muxer ! rtpmp2tpay ! identity drop-probability=0.001 ! udpsink host=127.0.0.1 port=5000 (drop-probability simulates the UDP packet loss) And this one for playback: udpsrc port=5000 caps="application/x-rtp" ! rtpmp2tdepay ! decodebin ! autovideosink The problem here is that when rtpmp2tdepay detects a missing packet, it sets DISCONT flag on the next buffer. Then tsdemux detects that flag and sends a new GstSegmentEvent further down, and the sink interprets that event in such a way that all subsequent packets are declared 'late' and are dropped - probably the event messes up the timing parameters somehow. This is how it looks in the logs of the sink element: 1) packets arrive on time and get rendered: 0:00:15.920621341 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3343:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.035565802, end: 0:00:15.068899135 0:00:15.920650898 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:1902:gst_base_sink_get_sync_times:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.035565802, stop: 0:00:15.068899135, do_sync 1 0:00:15.920673884 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2475:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> reset rc_time to time 0:00:15.835565802 0:00:15.920691056 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2487:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> possibly waiting for clock to reach 0:00:15.035565802, adjusted 0:00:15.835565802 0:00:15.951847400 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2494:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> clock returned 0, jitter -0:00:00.030970813 0:00:15.951893386 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2813:gst_base_sink_is_too_late:<autovideosink0-actual-sink-xvimage> object was scheduled in time 0:00:15.951901967 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3425:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> rendering object 0x94c810 0:00:15.951911610 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:936:gst_base_sink_set_last_buffer_unlocked:<autovideosink0-actual-sink-xvimage> setting last buffer to 0x94c810 0:00:15.952248918 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3464:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> object unref after render 0x94c810 0:00:15.954075594 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3343:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.068910247, end: 0:00:15.102243580 0:00:15.954102505 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:1902:gst_base_sink_get_sync_times:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.068910247, stop: 0:00:15.102243580, do_sync 1 0:00:15.954118792 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2475:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> reset rc_time to time 0:00:15.868910247 0:00:15.954127947 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2487:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> possibly waiting for clock to reach 0:00:15.068910247, adjusted 0:00:15.868910247 0:00:15.985141109 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2494:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> clock returned 0, jitter -0:00:00.030877964 0:00:15.985194546 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2813:gst_base_sink_is_too_late:<autovideosink0-actual-sink-xvimage> object was scheduled in time 0:00:15.985203288 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3425:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> rendering object 0x7f45600047f0 0:00:15.985212621 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:936:gst_base_sink_set_last_buffer_unlocked:<autovideosink0-actual-sink-xvimage> setting last buffer to 0x7f45600047f0 0:00:15.985677332 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3464:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> object unref after render 0x7f45600047f0 2) Event (triggered by a missing packet) arrives, after which rendering breaks down: 0:00:15.987052955 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3171:gst_base_sink_event:<autovideosink0-actual-sink-xvimage> received event 0x7f45680718f0 segment event: 0x7f45680718f0, time 99:99:99.999999999, seq-num -1, GstEventSegment, segment=(GstSegment)"GstSegment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, base=(guint64)0, offset=(guint64)0, start=(guint64)15138810885, stop=(guint64)18446744073709551615, time=(guint64)0, position=(guint64)15138810885, duration=(guint64)18446744073709551615;"; 0:00:15.987113963 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3106:gst_base_sink_default_event:<autovideosink0-actual-sink-xvimage> configured segment time segment start=0:00:15.138810885, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:15.138810885, duration 99:99:99.999999999 3) subsequent packets are all 'late': 0:00:15.988224114 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3343:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.138810885, end: 0:00:15.172133107 0:00:15.988241837 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:1902:gst_base_sink_get_sync_times:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.138810885, stop: 0:00:15.172133107, do_sync 1 0:00:15.988253105 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2475:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> reset rc_time to time 0:00:00.800000000 0:00:15.988259384 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2487:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> possibly waiting for clock to reach 0:00:00.000000000, adjusted 0:00:00.800000000 0:00:15.988269633 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2494:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> clock returned 1, jitter 0:00:15.072160104 0:00:15.988277167 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3503:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> buffer late, dropping 0:00:15.988301079 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3464:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> object unref after render 0x7f45600045d0 0:00:15.989442088 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3343:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.205466441, end: 0:00:15.238799774 0:00:15.989462345 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:1902:gst_base_sink_get_sync_times:<autovideosink0-actual-sink-xvimage> got times start: 0:00:15.205466441, stop: 0:00:15.238799774, do_sync 1 0:00:15.989472817 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2475:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> reset rc_time to time 0:00:00.866655556 0:00:15.989479215 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2487:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> possibly waiting for clock to reach 0:00:00.066655556, adjusted 0:00:00.866655556 0:00:15.989488060 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:2494:gst_base_sink_do_sync:<autovideosink0-actual-sink-xvimage> clock returned 1, jitter 0:00:15.006723337 0:00:15.989500721 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3503:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> buffer late, dropping 0:00:15.989535006 28278 0x7f4568026f20 DEBUG basesink gstbasesink.c:3464:gst_base_sink_chain_unlocked:<autovideosink0-actual-sink-xvimage> object unref after render 0x94c700
I think this issue can be linked with https://bugzilla.gnome.org/show_bug.cgi?id=743363
Yep, same issue.
Note that using an rtpjitterbuffer, you'd already get some of this solved. *** This bug has been marked as a duplicate of bug 743363 ***
Jitterbuffer is not going to help with packets that are truly lost. It will rearrange packets that are out of order, but that is not the issue here.
If I remember well, it should produce GAP event, which triggers concealment instead of discontinuity. But I might be wrong, and it might not be implemented on the TS/RTP path.
I tested also with rtpjitterbuffer included, and set its do-lost property to true, but it doesn't help - the sink still gets the same new segment events, and behaves exactly as described above.
the concealmant bit is implemented per depayloader and demuxer|decoder, so this is really a tsdemux problem, which is the duplicate bug.