After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 763496 - queue: Can release serialized (ALLOCATION) query before downstream returned it
queue: Can release serialized (ALLOCATION) query before downstream returned it
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gstreamer (core)
git master
Other Linux
: Normal critical
: 1.8.2
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2016-03-11 14:07 UTC by Vivia Nikolaidou
Modified: 2016-11-25 11:39 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
queue: Only unblock upstream waiting for the query once downstream is finished (2.88 KB, patch)
2016-03-11 14:08 UTC, Sebastian Dröge (slomo)
none Details | Review
queue: Only unblock upstream waiting for the query once downstream is finished (3.72 KB, patch)
2016-03-11 14:17 UTC, Sebastian Dröge (slomo)
committed Details | Review

Description Vivia Nikolaidou 2016-03-11 14:07:49 UTC
==7075== Thread 16 queue0:src:
==7075== Invalid read of size 8
==7075==    at 0x54348A7: gst_pad_peer_query (gstpad.c:3995)
==7075==    by 0x71C2EF1: gst_base_transform_default_propose_allocation (gstbasetransform.c:1435)
==7075==    by 0x741DD86: gst_video_filter_propose_allocation (gstvideofilter.c:64)
==7075==    by 0x71C5EC0: gst_base_transform_default_query (gstbasetransform.c:1535)
==7075==    by 0x5434407: gst_pad_query (gstpad.c:3900)
==7075==    by 0x54349CA: gst_pad_peer_query (gstpad.c:4032)
==7075==    by 0x10D9FB1E: gst_queue_push_one (gstqueue.c:1422)
==7075==    by 0x10D9FB1E: gst_queue_loop (gstqueue.c:1485)
==7075==    by 0x545FB70: gst_task_func (gsttask.c:332)
==7075==    by 0x59AD35D: g_thread_pool_thread_proxy (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4600.2)
==7075==    by 0x59AC9C4: g_thread_proxy (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4600.2)
==7075==    by 0x8294453: start_thread (pthread_create.c:334)
==7075==    by 0x798DEAC: clone (in /lib/x86_64-linux-gnu/libc-2.22.so)
==7075==  Address 0xeaca2d0 is 0 bytes inside a block of size 80 free'd
==7075==    at 0x4C2AE6B: free (vg_replace_malloc.c:530)
==7075==    by 0x74269DB: gst_query_unref (gstquery.h:229)
==7075==    by 0x74269DB: gst_video_decoder_negotiate_pool (gstvideodecoder.c:3764)
==7075==    by 0x742CBCF: gst_video_decoder_negotiate_unlocked (gstvideodecoder.c:3861)
==7075==    by 0x742CBCF: gst_video_decoder_allocate_output_frame (gstvideodecoder.c:4005)
==7075==    by 0x1E743D9B: get_output_buffer.part.4 (gstavviddec.c:1190)
==7075==    by 0x1E744FBE: gst_ffmpegviddec_video_frame (gstavviddec.c:1376)
==7075==    by 0x1E744FBE: gst_ffmpegviddec_frame (gstavviddec.c:1511)
==7075==    by 0x1E745CED: gst_ffmpegviddec_handle_frame (gstavviddec.c:1624)
==7075==    by 0x7422865: gst_video_decoder_decode_frame (gstvideodecoder.c:3417)
==7075==    by 0x7422D1C: gst_video_decoder_chain_forward (gstvideodecoder.c:2201)
==7075==    by 0x7425472: gst_video_decoder_chain (gstvideodecoder.c:2503)
==7075==    by 0x542E37E: gst_pad_chain_data_unchecked (gstpad.c:4155)
==7075==    by 0x542E37E: gst_pad_push_data (gstpad.c:4407)
==7075==    by 0x5436082: gst_pad_push (gstpad.c:4526)
==7075==    by 0x71C162E: gst_base_transform_chain (gstbasetransform.c:2369)
==7075==  Block was alloc'd at
==7075==    at 0x4C29C0F: malloc (vg_replace_malloc.c:299)
==7075==    by 0x598B558: g_malloc (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4600.2)
==7075==    by 0x59A2742: g_slice_alloc (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4600.2)
==7075==    by 0x59A2DDD: g_slice_alloc0 (in /lib/x86_64-linux-gnu/libglib-2.0.so.0.4600.2)
==7075==    by 0x5446E83: gst_query_new_custom (gstquery.c:672)
==7075==    by 0x74268F4: gst_video_decoder_negotiate_pool (gstvideodecoder.c:3705)
==7075==    by 0x742CBCF: gst_video_decoder_negotiate_unlocked (gstvideodecoder.c:3861)
==7075==    by 0x742CBCF: gst_video_decoder_allocate_output_frame (gstvideodecoder.c:4005)
==7075==    by 0x1E743D9B: get_output_buffer.part.4 (gstavviddec.c:1190)
==7075==    by 0x1E744FBE: gst_ffmpegviddec_video_frame (gstavviddec.c:1376)
==7075==    by 0x1E744FBE: gst_ffmpegviddec_frame (gstavviddec.c:1511)
==7075==    by 0x1E745CED: gst_ffmpegviddec_handle_frame (gstavviddec.c:1624)
==7075==    by 0x7422865: gst_video_decoder_decode_frame (gstvideodecoder.c:3417)
==7075==    by 0x7422D1C: gst_video_decoder_chain_forward (gstvideodecoder.c:2201)
Comment 1 Sebastian Dröge (slomo) 2016-03-11 14:08:31 UTC
Created attachment 323711 [details] [review]
queue: Only unblock upstream waiting for the query once downstream is finished

... when flushing and deactivating pads. Otherwise downstream might have a
query that was already unreffed by upstream, causing crashes or other
interesting effects.
Comment 2 Sebastian Dröge (slomo) 2016-03-11 14:17:07 UTC
Created attachment 323714 [details] [review]
queue: Only unblock upstream waiting for the query once downstream is finished

... when flushing and deactivating pads. Otherwise downstream might have a
query that was already unreffed by upstream, causing crashes or other
interesting effects.
Comment 3 Sebastian Dröge (slomo) 2016-03-11 14:19:16 UTC
Review of attachment 323714 [details] [review]:

Someone needs to review this in a bit more detail

::: plugins/elements/gstqueue.c
@@ +1665,3 @@
         queue->srcresult = GST_FLOW_FLUSHING;
         /* the item del signal will unblock */
+        GST_QUEUE_SIGNAL_DEL (queue);

I think this can deadlock, as we now wait for downstream to shut down before
Comment 4 Sebastian Dröge (slomo) 2016-03-11 14:19:50 UTC
multiqueue has the same problem btw
Comment 5 Vivia Nikolaidou 2016-03-11 14:24:48 UTC
This is working for me so far, BTW.
Comment 6 Tim-Philipp Müller 2016-04-30 13:51:20 UTC
Just ran into

gstcheck.c:79:F:general:test_queries_while_flushing:0: Unexpected critical/warning: gst_pad_query: assertion 'GST_IS_QUERY (query)' failed
FAIL elements/queue (exit status: 1)

but haven't been able to reproduce so far, looked like it might be related though.
Comment 7 Sebastian Dröge (slomo) 2016-05-15 08:06:50 UTC
Comment on attachment 323714 [details] [review]
queue: Only unblock upstream waiting for the query once downstream is finished

commit 722ad087338520047241a319a506e464017bf0da
Author: Sebastian Dröge <sebastian@centricular.com>
Date:   Fri Mar 11 16:04:52 2016 +0200

    queue: Only unblock upstream waiting for the query once downstream is finished
    
    ... when flushing and deactivating pads. Otherwise downstream might have a
    query that was already unreffed by upstream, causing crashes or other
    interesting effects.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=763496
Comment 8 Tim-Philipp Müller 2016-05-19 21:10:42 UTC
Should this be picked into 1.8 or too risky/unsure?
Comment 9 Sebastian Dröge (slomo) 2016-05-19 21:21:59 UTC
It's on my to-backport list. Just wanted to wait a bit for it to mature :)
Comment 10 Jesper Larsen 2016-11-25 11:30:10 UTC
It seems like this commit could cause a deadlock. Doing some stress testing of an application revealed a deadlock. The back trace of the two threads locked is pasted in the bottom.

Running version 1.10.1

Thread 1101 is sending an allocation query to a queue. The thread is waiting in gst_queue_handle_sink_query for the serialised query to be handled. As far as I can tell, the pad stream lock is held while we wait.

Meanwhile, thread 4 is setting the pipeline state to NULL, and is waiting for said stream lock before flushing the queue.

There are no other threads related to the pipeline running.

Reverting 722ad087338520047241a319a506e464017bf0da appears to remove the deadlock.

Thread 1101 (Thread 0x449ff460 (LWP 7965))

  • #0 syscall
    from /lib/libc.so.6
  • #1 g_cond_wait
    at gthread-posix.c line 1395
  • #2 gst_queue_handle_sink_query
    at gstqueue.c line 1048
  • #3 gst_pad_query
    at gstpad.c line 3950
  • #4 gst_pad_peer_query
    at gstpad.c line 4082
  • #5 gst_base_src_prepare_allocation
    at gstbasesrc.c line 3139
  • #6 gst_base_src_negotiate
    at gstbasesrc.c line 3283
  • #7 gst_base_src_loop
    at gstbasesrc.c line 2702
  • #8 gst_task_func
    at gsttask.c line 334
  • #9 default_func
    at gsttaskpool.c line 68
  • #10 g_thread_pool_thread_proxy
    at gthreadpool.c line 307
  • #11 g_thread_proxy
    at gthread.c line 784
  • #12 start_thread
    from /lib/libpthread.so.0

Thread 4 (Thread 0x42577460 (LWP 5122))

  • #0 __lll_lock_wait
    from /lib/libpthread.so.0
  • #1 pthread_mutex_lock
    from /lib/libpthread.so.0
  • #2 gst_queue_sink_activate_mode
    at gstqueue.c line 1683
  • #3 gst_queue_sink_activate_mode
    at gstqueue.c line 1658
  • #4 activate_mode_internal
    at gstpad.c line 1178
  • #5 gst_pad_set_active
    at gstpad.c line 1079
  • #6 activate_pads
    at gstelement.c line 2783
  • #7 gst_iterator_fold
    at gstiterator.c line 616
  • #8 iterator_activate_fold_with_resync
    at gstelement.c line 2807
  • #9 gst_element_pads_activate
    at gstelement.c line 2851
  • #10 gst_element_change_state_func
    at gstelement.c line 2917
  • #11 gst_element_change_state
    at gstelement.c line 2695
  • #12 gst_element_set_state_func
    at gstelement.c line 2649
  • #13 gst_element_set_state
    at gstelement.c line 2550
  • #14 gst_bin_element_set_state
    at gstbin.c line 2613
  • #15 gst_bin_change_state_func
    at gstbin.c line 2955
  • #16 gst_pipeline_change_state
    at gstpipeline.c line 499
  • #17 gst_element_change_state
    at gstelement.c line 2695
  • #18 gst_element_continue_state
    at gstelement.c line 2403
  • #19 gst_element_change_state
    at gstelement.c line 2741
  • #20 gst_element_set_state_func
    at gstelement.c line 2649
  • #21 gst_element_set_state
    at gstelement.c line 2550

Comment 11 Sebastian Dröge (slomo) 2016-11-25 11:39:53 UTC
Please file a new bug about this, and ideally provide a testcase. Thanks :)