bin: Deadlock when sending event
@thaytan
Submitted by Jan Schmidt Link to original bug (#744040)
Description
Encountered a locking order problem while doing some playing around in the playback test app: A flush occuring during a step leads to a basesink deadlock.
The sink element is posting STEP_DONE, holding the STREAM_LOCK. The app sends a new step event from the sync bus handler, which tries to take the STATE_LOCK.
Meanwhile, the app has sent a flushing seek, which is holding the STATE_LOCK, and trying to acquire the STREAM_LOCK.
It seems either basesink should drop the stream lock while sending the STEP_DONE message, or the app should not send the new step event from the sync bus message handler, I'm not sure which.
Thread 13 (Thread 0x7ff135534700 (LWP 30991)):
#0 0x0000003907e0ef1d in __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1 0x0000003907e09906 in __GI___pthread_mutex_lock (mutex=0x1a10c00) at ../nptl/pthread_mutex_lock.c:115
#2 0x00007ff13d8a4645 in gst_element_send_event (element=0x19cb040 [GstPlayBin], event=0x7ff1280050b0) at gstelement.c:1557
#3 0x000000000040b00d in do_shuttle (app=app@entry=0x7fff95060af0) at playback-test.c:1559
#4 0x000000000040d8c8 in msg_sync_step_done (bus=<optimized out>, message=<optimized out>, app=0x7fff95060af0)
at playback-test.c:1585
#5 0x00000036f6012d13 in g_cclosure_marshal_VOID__BOXEDv (closure=0x1cf0820, return_value=<optimized out>, instance=<optimized out>, args=<optimized out>, marshal_data=<optimized out>, n_params=<optimized out>, param_types=0x175bee0) at gmarshal.c:1160
#6 0x00000036f600feb2 in _g_closure_invoke_va (closure=closure@entry=0x1cf0820, return_value=return_value@entry=0x0, instance=instance@entry=0x186a2c0, args=args@entry=0x7ff135532db0, n_params=1, param_types=0x175bee0) at gclosure.c:831
#7 0x00000036f6029b60 in g_signal_emit_valist (instance=0x186a2c0, signal_id=<optimized out>, detail=267, var_args=var_args@entry=0x7ff135532db0) at gsignal.c:3218
#8 0x00000036f602a3af in g_signal_emit (instance=instance@entry=0x186a2c0, signal_id=<optimized out>, detail=<optimized out>)
at gsignal.c:3365
#9 0x00007ff13d88f12a in gst_bus_sync_signal_handler (bus=0x186a2c0 [GstBus], message=0x7ff11c1702c0, data=<optimized out>)
at gstbus.c:1197
#10 0x00007ff13d88f3c4 in gst_bus_post (bus=bus@entry=0x186a2c0 [GstBus], message=message@entry=0x7ff11c1702c0) at gstbus.c:329
#11 0x00007ff13d8a1bf8 in gst_element_post_message_default (element=element@entry=0x19cb040 [GstPlayBin], message=0x7ff11c1702c0)
at gstelement.c:1688
#12 0x00007ff13d883c4f in gst_bin_post_message (element=0x19cb040 [GstPlayBin], msg=0x7ff11c1702c0) at gstbin.c:2523
#13 0x00007ff13d883f79 in gst_bin_handle_message_func (bin=0x19cb040 [GstPlayBin], message=<optimized out>) at gstbin.c:3745
#14 0x00007ff13d8c4939 in gst_pipeline_handle_message (bin=0x19cb040 [GstPlayBin], message=0x7ff11c1702c0) at gstpipeline.c:574
#15 0x00007ff136247ca5 in gst_play_bin_handle_message (bin=0x19cb040 [GstPlayBin], msg=0x7ff11c1702c0) at gstplaybin2.c:2912
#16 0x00007ff13d880828 in bin_bus_handler (bus=bus@entry=0x186a1f0 [GstBus], message=message@entry=0x7ff11c1702c0, bin=bin@entry=0x19cb040 [GstPlayBin]) at gstbin.c:2981
#17 0x00007ff13d88f39b in gst_bus_post (bus=bus@entry=0x186a1f0 [GstBus], message=message@entry=0x7ff11c1702c0) at gstbus.c:323
#18 0x00007ff13d8a1bf8 in gst_element_post_message_default (element=element@entry=0x1b06020 [GstPlaySink], message=0x7ff11c1702c0)
at gstelement.c:1688
#19 0x00007ff13d883c4f in gst_bin_post_message (element=0x1b06020 [GstPlaySink], msg=0x7ff11c1702c0) at gstbin.c:2523
---Type <return> to continue, or q <return> to quit---
#20 0x00007ff13d883f79 in gst_bin_handle_message_func (bin=0x1b06020 [GstPlaySink], message=<optimized out>) at gstbin.c:3745
#21 0x00007ff13624ce30 in gst_play_sink_handle_message (bin=0x1b06020 [GstPlaySink], message=0x7ff11c1702c0) at gstplaysink.c:4632
#22 0x00007ff13d880828 in bin_bus_handler (bus=bus@entry=0x186a390 [GstBus], message=message@entry=0x7ff11c1702c0, bin=bin@entry=0x1b06020 [GstPlaySink]) at gstbin.c:2981
#23 0x00007ff13d88f39b in gst_bus_post (bus=bus@entry=0x186a390 [GstBus], message=message@entry=0x7ff11c1702c0) at gstbus.c:323
#24 0x00007ff13d8a1bf8 in gst_element_post_message_default (element=element@entry=0x7ff12000f790 [GstBin], message=0x7ff11c1702c0)
at gstelement.c:1688
#25 0x00007ff13d883c4f in gst_bin_post_message (element=0x7ff12000f790 [GstBin], msg=0x7ff11c1702c0) at gstbin.c:2523
#26 0x00007ff13d883f79 in gst_bin_handle_message_func (bin=0x7ff12000f790 [GstBin], message=<optimized out>) at gstbin.c:3745
#27 0x00007ff13d880828 in bin_bus_handler (bus=bus@entry=0x7ff120010230 [GstBus], message=message@entry=0x7ff11c1702c0, bin=bin@entry=0x7ff12000f790 [GstBin]) at gstbin.c:2981
#28 0x00007ff13d88f39b in gst_bus_post (bus=bus@entry=0x7ff120010230 [GstBus], message=message@entry=0x7ff11c1702c0) at gstbus.c:323
#29 0x00007ff13d8a1bf8 in gst_element_post_message_default (element=0x7ff124049a10 [GstXvImageSink], message=0x7ff11c1702c0)
at gstelement.c:1688
#30 0x00007ff13de482d7 in stop_stepping (sink=sink@entry=0x7ff124049a10 [GstXvImageSink], segment=segment@entry=0x7ff124049b68, current=current@entry=0x7ff124049918, rstart=<optimized out>, rstop=16605853000, eos=0) at gstbasesink.c:1694
#31 0x00007ff13de52def in gst_base_sink_chain_unlocked (basesink=basesink@entry=0x7ff124049a10 [GstXvImageSink], obj=obj@entry=0x7ff11c3541c0, is_list=is_list@entry=0, pad=<optimized out>) at gstbasesink.c:3457
#32 0x00007ff13de544a4 in gst_base_sink_chain_main (basesink=0x7ff124049a10 [GstXvImageSink], pad=<optimized out>, obj=0x7ff11c3541c0, is_list=0) at gstbasesink.c:3547
#33 0x00007ff13d8ba704 in gst_pad_push_data (data=0x7ff11c3541c0, type=4112, pad=0x7ff124040340 [GstPad]) at gstpad.c:3838
Thread 1 (Thread 0x7ff13d832980 (LWP 30975)):
#0 0x0000003907e0ef1d in __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1 0x0000003907e09906 in __GI___pthread_mutex_lock (mutex=0x7ff124048ce0) at ../nptl/pthread_mutex_lock.c:115
#2 0x00007ff13de4bc52 in gst_base_sink_flush_start (basesink=basesink@entry=0x7ff124049a10 [GstXvImageSink], pad=0x7ff124040340 [GstPad]) at gstbasesink.c:2910
#3 0x00007ff13de4c1c1 in gst_base_sink_default_event (basesink=0x7ff124049a10 [GstXvImageSink], event=0x7ff12009f020)
at gstbasesink.c:3001
#4 0x00007ff134281ac7 in gst_xvimagesink_event (sink=0x7ff124049a10 [GstXvImageSink], event=0x7ff12009f020) at xvimagesink.c:1036
#5 0x00007ff13d8b8ff8 in gst_pad_send_event_unchecked (pad=pad@entry=0x7ff124040340 [GstPad], event=event@entry=0x7ff12009f020, type=type@entry=320) at gstpad.c:5157
#6 0x00007ff13d8b96cf in gst_pad_push_event_unchecked (pad=pad@entry=0x1d4b600 [GstGhostPad], event=event@entry=0x7ff12009f020, type=320, type@entry=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at gstpad.c:4844
#7 0x00007ff13d8c24a4 in gst_pad_push_event (pad=pad@entry=0x1d4b600 [GstGhostPad], event=0x7ff12009f020) at gstpad.c:4975
#8 0x00007ff13d8c27f3 in event_forward_func (pad=pad@entry=0x1d4b600 [GstGhostPad], data=data@entry=0x7fff95059880) at gstpad.c:2849
#9 0x00007ff13d8bf5ae in gst_pad_forward (pad=pad@entry=0x7ff12801d930 [GstProxyPad], forward=forward@entry=0x7ff13d8c2730 <event_forward_func>, user_data=user_data@entry=0x7fff95059880) at gstpad.c:2803
#10 0x00007ff13d8bf6db in gst_pad_event_default (pad=pad@entry=0x7ff12801d930 [GstProxyPad], parent=parent@entry=0x1d4b600 [GstGhostPad], event=event@entry=0x7ff12009f020) at gstpad.c:2900
#11 0x00007ff13d8b8ff8 in gst_pad_send_event_unchecked (pad=pad@entry=0x7ff12801d930 [GstProxyPad], event=event@entry=0x7ff12009f020, type=type@entry=320) at gstpad.c:5157
#12 0x00007ff13d8b96cf in gst_pad_push_event_unchecked (pad=pad@entry=0x7ff1200a36d0 [GstPad], event=event@entry=0x7ff12009f020, type=320, type@entry=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at gstpad.c:4844
#13 0x00007ff13d8c24a4 in gst_pad_push_event (pad=0x7ff1200a36d0 [GstPad], event=event@entry=0x7ff12009f020) at gstpad.c:4975
#14 0x00007ff13de628a6 in gst_base_transform_sink_eventfunc (trans=0x7ff11c15c4d0 [GstVideoConvert], event=0x7ff12009f020)
at gstbasetransform.c:1923