Created attachment 278598 [details] [review]
A patch to solve the issue

while technically correct, the items that are inserted either have no seqnum or we make sure we only insert the item once so the added code will not ever execute. 

Did you actually see a case where the item was leaked?

It takes place when there is some timeouts about the the same packet.

(In reply to comment #3)
> It takes place when there is some timeouts about the the same packet.

Could you be more specific when it happens? what series of events lead to the leaked event. In no case should it ever attempt to insert the ITEM_TYPE_LOST event twice (and the others don't have a seqnum so will never return FALSE).

The item leaked is created here http://cgit.freedesktop.org/gstreamer/gst-plugins-good/tree/gst/rtpmanager/gstrtpjitterbuffer.c?id=1.3.2#n2800, which provokes the leak of the item and the event. See the valgrind trace:

==5004== 6,480 (480 direct, 6,000 indirect) bytes in 15 blocks are definitely lost in loss record 8,550 of 8,597
==5004==    at 0x4C2AB80: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5004==    by 0x53E4610: g_malloc (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0)
==5004==    by 0x53FA22D: g_slice_alloc (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0)
==5004==    by 0x4EBE9B6: gst_structure_new_id_empty_with_size (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.302.0)
==5004==    by 0x4EC0E4E: gst_structure_new_valist (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.302.0)
==5004==    by 0x4EC0EF6: gst_structure_new (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.302.0)
==5004==    by 0xC1EB62E: wait_next_timeout (gstrtpjitterbuffer.c:2792)
==5004==    by 0x5403F14: ??? (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0)
==5004==    by 0x659E181: start_thread (pthread_create.c:312)
==5004==    by 0x5BBD30C: clone (clone.S:111)
==5004== 
==5004== 8,400 (1,920 direct, 6,480 indirect) bytes in 30 blocks are definitely lost in loss record 8,560 of 8,597
==5004==    at 0x4C2AB80: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5004==    by 0x53E4610: g_malloc (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0)
==5004==    by 0x53FA22D: g_slice_alloc (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0)
==5004==    by 0xC1EB648: wait_next_timeout (gstrtpjitterbuffer.c:776)
==5004==    by 0x5403F14: ??? (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0)
==5004==    by 0x659E181: start_thread (pthread_create.c:312)
==5004==    by 0x5BBD30C: clone (clone.S:111)

The entry point of this call i wait_next_timeout (http://cgit.freedesktop.org/gstreamer/gst-plugins-good/tree/gst/rtpmanager/gstrtpjitterbuffer.c?id=1.3.2#n2877)

Easy way to reproduce this:

tpm@xps:~/gst/glib-master/gst-plugins-good/tests/check$ make elements/rtpaux.valgrind
Running suite(s): rtpaux
==9521== 64 bytes in 1 blocks are definitely lost in loss record 2,563 of 3,764
==9521==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==9521==    by 0x5B1E539: g_malloc (gmem.c:97)
==9521==    by 0x5B34C5F: g_slice_alloc (gslice.c:1007)
==9521==    by 0x825BEFF: alloc_item (gstrtpjitterbuffer.c:815)
==9521==    by 0x825BEFF: do_lost_timeout (gstrtpjitterbuffer.c:2884)
==9521==    by 0x825BEFF: do_timeout (gstrtpjitterbuffer.c:2941)
==9521==    by 0x825BEFF: wait_next_timeout (gstrtpjitterbuffer.c:3020)
==9521==    by 0x5B3ED14: g_thread_proxy (gthread.c:764)
==9521==    by 0x5E0F0A3: start_thread (pthread_create.c:309)
==9521== 
==9521== 432 (32 direct, 400 indirect) bytes in 1 blocks are definitely lost in loss record 3,690 of 3,764
==9521==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==9521==    by 0x5B1E539: g_malloc (gmem.c:97)
==9521==    by 0x5B34C5F: g_slice_alloc (gslice.c:1007)
==9521==    by 0x55EE6F2: gst_structure_new_id_empty_with_size (gststructure.c:145)
==9521==    by 0x55F0ABE: gst_structure_new_valist (gststructure.c:281)
==9521==    by 0x55F0B66: gst_structure_new (gststructure.c:253)
==9521==    by 0x825BEE1: do_lost_timeout (gstrtpjitterbuffer.c:2876)
==9521==    by 0x825BEE1: do_timeout (gstrtpjitterbuffer.c:2941)
==9521==    by 0x825BEE1: wait_next_timeout (gstrtpjitterbuffer.c:3020)
==9521==    by 0x5B3ED14: g_thread_proxy (gthread.c:764)
==9521==    by 0x5E0F0A3: start_thread (pthread_create.c:309)
==9521==

Review of attachment 278598 [details] [review]:

::: gst/rtpmanager/gstrtpjitterbuffer.c
@@ +1393,3 @@
+  if (G_UNLIKELY (!rtp_jitter_buffer_insert (priv->jbuf, item, &head, NULL))) {
+    free_item (item);
+  }

This one should go away, events have no seqnum and as such will never be duplicates

@@ +2803,3 @@
   item = alloc_item (event, ITEM_TYPE_LOST, -1, -1, seqnum, lost_packets, -1);
+  if (G_UNLIKELY (!rtp_jitter_buffer_insert (priv->jbuf, item, &head, NULL))) {
+    free_item (item);

I can't reproduce the leak with the unit test here (even after disabling the sticky event misordering warnings). From looking at the code, if this happens it is a bug in a higher layer already. There shouldn't be an item with the same seqnum in the queue at this point.

The only way how I can see this happen is either
a) we received the packet with the seqnum now... in which case we shouldn't be in this code at all (nothing is lost!)
b) we queued a lost event already in the jitterbuffer but did not push it out yet (this should not happen unless the jitterbuffer is blocked downstream for too long)

Miguel, can you provide a testcase for this problem?


But from looking at the code, we don't seem to check in the chain function if the currently received packet currently has a lost item in the queue. If there is a lost item for it, we would discard the packet unless I'm missing something... just to request retransmission of that packet later.
Wim, is that correct?

@@ +3252,3 @@
           item = alloc_item (query, ITEM_TYPE_QUERY, -1, -1, -1, 0, -1);
+          if (G_UNLIKELY (!rtp_jitter_buffer_insert (priv->jbuf, item, &head,
+                      NULL))) {

Should go away, some as for events

While I *did* push a commit to fix this leak, there might indeed be another issue here ,but it's hard to say whether it's because of valgrind slowing everything down way too much or not.

I will attach a log of the test running under valgrind with an assert where that insertion fails.

Created attachment 341226 [details]
log of failure

Created attachment 341227 [details]
log of failure without valgrind

I can actually reproduce the issue outside of valgrind.

The change to apply to make it assert

@@ -3757,9 +3760,11 @@ do_lost_timeout (GstRtpJitterBuffer * jitterbuffer, TimerData * timer,
             "retry", G_TYPE_UINT, num_rtx_retry, NULL));
   }
   item = alloc_item (event, ITEM_TYPE_LOST, -1, -1, seqnum, lost_packets, -1);
-  if (!rtp_jitter_buffer_insert (priv->jbuf, item, &head, NULL))
+  if (!rtp_jitter_buffer_insert (priv->jbuf, item, &head, NULL)) {
     /* Duplicate */
+    g_assert(FALSE);
     free_item (item);
+  }
 
   if (GST_CLOCK_TIME_IS_VALID (timer->rtx_last)) {
     /* Store info to update stats if the packet arrives too late */

-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/gstreamer/gst-plugins-good/issues/118.