GNOME Bugzilla – Bug 721300
tee: Does not protect pad from being destroyed from pad probe during gst_pad_push()
Last modified: 2014-01-03 08:45:07 UTC
My app to removes pipeline parts while in PLAYING state. Have got a following crash backtrace from valgrind just now (after certain amount of uptime). The point is that tee srcpad is released (from main thread or whatever), and at the same time tee is pushing data though its srcpads. The other way should be releasing tee srcpad from BLOCK probe callback. But unfortunately it results in similar crash, see second part of log below. ==11961== Thread 5: ==11961== Invalid read of size 8 ==11961== at 0x4EDB3C6: g_mutex_get_impl (gthread-posix.c:121) ==11961== by 0x4EDB464: g_mutex_lock (gthread-posix.c:210) ==11961== by 0x545DA15: gst_pad_push_data (gstpad.c:3995) ==11961== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==11961== by 0x963D037: gst_tee_handle_data (gsttee.c:601) ==11961== by 0x963D4C7: gst_tee_chain (gsttee.c:699) ==11961== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==11961== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==11961== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==11961== by 0x7191003: gst_base_src_loop (gstbasesrc.c:2785) ==11961== by 0x54919BB: gst_task_func (gsttask.c:316) ==11961== by 0x5492AB6: default_func (gsttaskpool.c:70) ==11961== by 0x4EB79BD: g_thread_pool_thread_proxy (gthreadpool.c:309) ==11961== by 0x4EB73D2: g_thread_proxy (gthread.c:798) ==11961== by 0x5B68DA5: start_thread (in /lib64/libpthread-2.15.so) ==11961== by 0x6A86ABC: clone (in /lib64/libc-2.15.so) ==11961== Address 0xfac0cd8 is 24 bytes inside a block of size 576 free'd ==11961== at 0x4C2B2CC: free (vg_replace_malloc.c:446) ==11961== by 0x4E92379: g_free (gmem.c:252) ==11961== by 0x4EAAE8E: g_slice_free1 (gslice.c:1111) ==11961== by 0x51BC691: g_type_free_instance (gtype.c:1962) ==11961== by 0x51A5D8C: g_object_unref (gobject.c:3037) ==11961== by 0x540C2A3: gst_object_unref (gstobject.c:275) ==11961== by 0x4D1167: common_release_pad(_GstElement*, _GstPad*) (gst_utils.cpp:136) ...... ==11961== ==11961== Invalid read of size 4 ==11961== at 0x5B6B394: pthread_mutex_lock (in /lib64/libpthread-2.15.so) ==11961== by 0x4EDB46C: g_mutex_lock (gthread-posix.c:210) ==11961== by 0x545DA15: gst_pad_push_data (gstpad.c:3995) ==11961== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==11961== by 0x963D037: gst_tee_handle_data (gsttee.c:601) ==11961== by 0x963D4C7: gst_tee_chain (gsttee.c:699) ==11961== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==11961== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==11961== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==11961== by 0x7191003: gst_base_src_loop (gstbasesrc.c:2785) ==11961== by 0x54919BB: gst_task_func (gsttask.c:316) ==11961== by 0x5492AB6: default_func (gsttaskpool.c:70) ==11961== by 0x4EB79BD: g_thread_pool_thread_proxy (gthreadpool.c:309) ==11961== by 0x4EB73D2: g_thread_proxy (gthread.c:798) ==11961== by 0x5B68DA5: start_thread (in /lib64/libpthread-2.15.so) ==11961== by 0x6A86ABC: clone (in /lib64/libc-2.15.so) ==11961== Address 0x3333333333333343 is not stack'd, malloc'd or (recently) free'd ==13499== Thread 7: ==13499== Invalid read of size 8 ==13499== at 0x4EDB3C6: g_mutex_get_impl (gthread-posix.c:121) ==13499== by 0x4EDB464: g_mutex_lock (gthread-posix.c:210) ==13499== by 0x545AA44: probe_hook_marshal (gstpad.c:3104) ==13499== by 0x4E78F52: g_hook_list_marshal (ghook.c:676) ==13499== by 0x545ADD7: do_probe_callbacks (gstpad.c:3196) ==13499== by 0x545D8F5: gst_pad_push_data (gstpad.c:3974) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x963D037: gst_tee_handle_data (gsttee.c:601) ==13499== by 0x963D4C7: gst_tee_chain (gsttee.c:699) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x7199EDF: gst_base_transform_chain (gstbasetransform.c:2237) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0xB25906C: mpegtsmux_push_packets (mpegtsmux.c:1373) ==13499== by 0xB2583F7: mpegtsmux_collected_buffer (mpegtsmux.c:1209) ==13499== by 0x71A5E12: gst_collect_pads_default_collected (gstcollectpads.c:1539) ==13499== by 0x71A55F4: gst_collect_pads_check_collected (gstcollectpads.c:1337) ==13499== by 0x71A76CD: gst_collect_pads_chain (gstcollectpads.c:2177) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x962AF33: gst_queue_push_one (gstqueue.c:1118) ==13499== by 0x962BCB2: gst_queue_loop (gstqueue.c:1247) ==13499== by 0x54919BB: gst_task_func (gsttask.c:316) ==13499== by 0x5492AB6: default_func (gsttaskpool.c:70) ==13499== by 0x4EB79BD: g_thread_pool_thread_proxy (gthreadpool.c:309) ==13499== by 0x4EB73D2: g_thread_proxy (gthread.c:798) ==13499== by 0x5B68DA5: start_thread (in /lib64/libpthread-2.15.so) ==13499== by 0x6A86ABC: clone (in /lib64/libc-2.15.so) ==13499== Address 0x8b51678 is 24 bytes inside a block of size 576 free'd ==13499== at 0x4C2B2CC: free (vg_replace_malloc.c:446) ==13499== by 0x4E92379: g_free (gmem.c:252) ==13499== by 0x4EAAE8E: g_slice_free1 (gslice.c:1111) ==13499== by 0x51BC691: g_type_free_instance (gtype.c:1962) ==13499== by 0x51A5D8C: g_object_unref (gobject.c:3037) ==13499== by 0x540C2A3: gst_object_unref (gstobject.c:275) ==13499== by 0x963C881: gst_tee_release_pad (gsttee.c:424) ==13499== by 0x5436961: gst_element_release_request_pad (gstelement.c:335) ==13499== by 0x4D0F62: pad_block_cb(_GstPad*, _GstPadProbeInfo*, void*) (gst_utils.cpp:103) ==13499== by 0x545AA31: probe_hook_marshal (gstpad.c:3102) ==13499== by 0x4E78F52: g_hook_list_marshal (ghook.c:676) ==13499== by 0x545ADD7: do_probe_callbacks (gstpad.c:3196) ==13499== by 0x545D8F5: gst_pad_push_data (gstpad.c:3974) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x963D037: gst_tee_handle_data (gsttee.c:601) ==13499== by 0x963D4C7: gst_tee_chain (gsttee.c:699) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x7199EDF: gst_base_transform_chain (gstbasetransform.c:2237) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0xB25906C: mpegtsmux_push_packets (mpegtsmux.c:1373) ==13499== by 0xB2583F7: mpegtsmux_collected_buffer (mpegtsmux.c:1209) ==13499== by 0x71A5E12: gst_collect_pads_default_collected (gstcollectpads.c:1539) ==13499== by 0x71A55F4: gst_collect_pads_check_collected (gstcollectpads.c:1337) ==13499== by 0x71A76CD: gst_collect_pads_chain (gstcollectpads.c:2177) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x962AF33: gst_queue_push_one (gstqueue.c:1118) ==13499== by 0x962BCB2: gst_queue_loop (gstqueue.c:1247) ==13499== by 0x54919BB: gst_task_func (gsttask.c:316) ==13499== by 0x5492AB6: default_func (gsttaskpool.c:70) ==13499== by 0x4EB79BD: g_thread_pool_thread_proxy (gthreadpool.c:309) ==13499== by 0x4EB73D2: g_thread_proxy (gthread.c:798) ==13499== by 0x5B68DA5: start_thread (in /lib64/libpthread-2.15.so) ==13499== by 0x6A86ABC: clone (in /lib64/libc-2.15.so) ==13499== ==13499== Invalid read of size 4 ==13499== at 0x5B6B394: pthread_mutex_lock (in /lib64/libpthread-2.15.so) ==13499== by 0x4EDB46C: g_mutex_lock (gthread-posix.c:210) ==13499== by 0x545AA44: probe_hook_marshal (gstpad.c:3104) ==13499== by 0x4E78F52: g_hook_list_marshal (ghook.c:676) ==13499== by 0x545ADD7: do_probe_callbacks (gstpad.c:3196) ==13499== by 0x545D8F5: gst_pad_push_data (gstpad.c:3974) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x963D037: gst_tee_handle_data (gsttee.c:601) ==13499== by 0x963D4C7: gst_tee_chain (gsttee.c:699) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x7199EDF: gst_base_transform_chain (gstbasetransform.c:2237) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0xB25906C: mpegtsmux_push_packets (mpegtsmux.c:1373) ==13499== by 0xB2583F7: mpegtsmux_collected_buffer (mpegtsmux.c:1209) ==13499== by 0x71A5E12: gst_collect_pads_default_collected (gstcollectpads.c:1539) ==13499== by 0x71A55F4: gst_collect_pads_check_collected (gstcollectpads.c:1337) ==13499== by 0x71A76CD: gst_collect_pads_chain (gstcollectpads.c:2177) ==13499== by 0x545CD63: gst_pad_chain_data_unchecked (gstpad.c:3758) ==13499== by 0x545D9F6: gst_pad_push_data (gstpad.c:3991) ==13499== by 0x545DF47: gst_pad_push (gstpad.c:4094) ==13499== by 0x962AF33: gst_queue_push_one (gstqueue.c:1118) ==13499== by 0x962BCB2: gst_queue_loop (gstqueue.c:1247) ==13499== by 0x54919BB: gst_task_func (gsttask.c:316) ==13499== by 0x5492AB6: default_func (gsttaskpool.c:70) ==13499== by 0x4EB79BD: g_thread_pool_thread_proxy (gthreadpool.c:309) ==13499== by 0x4EB73D2: g_thread_proxy (gthread.c:798) ==13499== by 0x5B68DA5: start_thread (in /lib64/libpthread-2.15.so) ==13499== by 0x6A86ABC: clone (in /lib64/libc-2.15.so) ==13499== Address 0x3333333333333343 is not stack'd, malloc'd or (recently) free'd
Created attachment 265096 [details] [review] partially fixing patch After looking at above (see "tee: needs fixing locking in gsttee.c?"), i've made such a patch and now i am running with it. It allows me to release requestpad safely from main thread. But if i release it from BLOCK probe callback, the callback is called from within handle_data() and hangs on secondary GST_TEE_DYN_LOCK, obviously because it is not recursive. Could we afford recursive mutex? Before this patch, GST_TEE_DYN_LOCK was used only in release_pad(), which does not make sense.
The first approach is wrong, just releasing the tee srcpad at a random point in time. The second should work though and not crash.
This should fix it, please reopen otherwise (and if it fixes the problem I will backport to 1.2): commit 34f8b4d6f3e6a61519f23e8ef0644a6fdfc99daa Author: Sebastian Dröge <sebastian@centricular.com> Date: Thu Jan 2 11:13:27 2014 +0100 tee: Remove dyn lock It was used for pad-alloc in 0.10 but currently is completely unused and not necessary. All pad access is protected by the tee object lock and keeping another reference to the current pad. commit e80fd39947c697d591789feee918cd6a27f1ca15 Author: Sebastian Dröge <sebastian@centricular.com> Date: Thu Jan 2 11:09:59 2014 +0100 tee: Keep another ref to our one and only srcpad around while pushing A pad probe on that pad might otherwise just release the pad, drop the last reference and cause great misery. https://bugzilla.gnome.org/show_bug.cgi?id=721300