[Bug 743740] New: RTP playback doesn't handle missing packets well

GStreamer (bugzilla.gnome.org) bugzilla at gnome.org
Fri Jan 30 06:32:11 PST 2015 

https://bugzilla.gnome.org/show_bug.cgi?id=743740
  GStreamer | gstreamer (core) | git master

           Summary: RTP playback doesn't handle missing packets well
    Classification: Platform
           Product: GStreamer
           Version: git master
        OS/Version: Linux
            Status: UNCONFIRMED
          Severity: normal
          Priority: Normal
         Component: gstreamer (core)
        AssignedTo: gstreamer-bugs at lists.freedesktop.org
        ReportedBy: ak at sensi.org
         QAContact: gstreamer-bugs at lists.freedesktop.org
     GNOME version: ---


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

-- 
Configure bugmail: https://bugzilla.gnome.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the QA contact for the bug.
You are the assignee for the bug.

More information about the gstreamer-bugs mailing list