I observe a 120ms gap in udpsrc/udpsink every 5 seconds ... why?

[jim nualart]

At first I suspected the sender, since I was only using udpsrc to receive
data from an external source. But then I tested udpsink as follows:


export TESTSOURCE="audiotestsrc wave=0 is-live=true do-timestamp=true
samplesperbuffer=480"
export
AUDIO_CAPS=application/x-rtp,media=(string)audio,clock-rate=(int)48000,payload=(int)115,encoding-name=(string)L16
export UDPOUT="rtpL16pay pt=115 ! $AUDIO_CAPS ! udpsink host=127.0.0.1
port=6789 sync=false"

export GST_DEBUG=multiudpsink:6
timeout 60 gst-launch-1.0 $TESTSOURCE ! $UDPOUT 2> log

Every 5 seconds, there seems to be a 120ms gap, followed by a flurry of
activity as though we're trying to make up for the gap, then back to the
regular ~10ms timing. My original testing using udpsrc to receive
non-gstreamer sent UDP data shows similar results. There are a lot more
options on the receive side especially once you add rtpjitterbuffer, but
since udpsink shows the same behavior, I'm hoping there's one explanation
that covers both. Partial log snippet included below to show the timestamps
around the 5 second mark.

Putting a queue after the audiotestsrc and/or using sync=true on the sink
yields the same result. That it happens every 5 seconds makes me suspect
that there's some setting/property that I'm not aware of. Any insight here
would be very welcome.

Additionally, back to my original use of udpsrc ... I wanted to verify my
non-gstreamer UDP data sender so I did:
timeout 60 tcpdump -i eth1 udp port 6789  > udp.out
This output does NOT show a gap. Every once in a while, I do see blips
where data is not being sent at the expected 10ms intervals, but those are
infrequent, and not more than a +/- sub-10ms swing.

This is a snippet of the timestamps as seen from testing udpsink ...
log:
.... [snip] ....
0:00:04.879987735 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.890042776 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.900001810 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.910048919 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.920007765 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.930059563 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.940037688 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.950075379 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.960033593 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.970026948 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.980033991 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:04.990034211 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.000027493 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.009900708 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.121791415 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.121942663 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122069553 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122191678 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122307939 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122424282 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122540882 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122656812 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122772738 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.122889201 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.123005172 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.129936642 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.140018540 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.149928300 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0:00:05.160001366 10611 0x55f41c0f0400 LOG             multiudpsink
gstmultiudpsink.c:797:gst_multiudpsink_render_buffers:<udpsink0> 1 buffers,
2 memories -> to be sent to 1 clients
0
.... [snip] ....


thanks in advance,
-jim
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20200714/7ef9b32b/attachment.htm>