Deadlock under valgrind (tsdemux fault?)
Andrey Utkin
andrey.krieger.utkin at gmail.com
Tue Nov 12 14:00:36 PST 2013
This is a sort of bugreport.
I post this into maillist because GNOME bugzilla almost doesn't work
(couldn't even navigate to new bug filing page, requests timeout!).
The background is the need to check memory leaks in gstreamer
application. My app terminates well if launched normally, but it
deadlocks at termination under valgrind, specifically at setting NULL
state to previously PLAYING sub-bin with tsdemux element. The (likely)
same problem is reproduced with gst-launch, although can't say for
sure because i didn't find a way to get a backtrace of gst-launch in
hanged situation.
For now i'll provide all the info i have.
I use gstreamer and plugins of version 1.2.0, built and running at
amd64 gentoo on CPU with 4 logical cores.
As test input i use ffmpeg-generated MPEG TS with one video stream and
two (or more) audio streams:
/usr/local/src/ffmpeg/ffmpeg -re -f lavfi -i testsrc -re -f lavfi -i
aevalsrc="0.1*sin(2*PI*(360-2.5/2)*t) | 0.1*sin(2*PI*(360+2.5/2)*t)"
-re -f lavfi -i aevalsrc="sin(10*2*PI*t)*sin(880*2*PI*t)" -map 0:0
-map 1:0 -map 2:0 -f mpegts udp://225.1.1.1:1234
The used gst-launch command is:
GST_DEBUG=4 valgrind gst-launch-1.0 playbin uri=udp://225.1.1.1:1234
So, when i press Ctrl+C, it starts normal termination, but hangs with last line:
INFO GST_STATES
gstbin.c:2227:gst_bin_element_set_state:<tsdemux0> current PAUSED
pending VOID_PENDING, desired next READY
The same line is the last one when my app hangs in same way.
Full log is here: https://gist.github.com/krieger-od/e4f8f62e1caf7855ad35
gst-launch without valgrind performs well, full log is here:
https://gist.github.com/krieger-od/922e18059a923645fa83
My app's deadlocked state backtrace:
This is the thread issuing set_state(NULL):
(gdb) bt full
#0 0x000000000570b0a4 in __lll_lock_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00000000057065cf in _L_lock_543 () from /lib64/libpthread.so.0
No symbol table info available.
#2 0x000000000570642b in pthread_mutex_lock () from /lib64/libpthread.so.0
No symbol table info available.
#3 0x0000000004ed646e in g_rec_mutex_lock (mutex=0x72bc530) at
gthread-posix.c:377
No locals.
#4 0x00000000054465c0 in post_activate (pad=0x72bc4c0,
new_mode=GST_PAD_MODE_NONE) at gstpad.c:904
__PRETTY_FUNCTION__ = "post_activate"
#5 0x0000000005446e16 in gst_pad_activate_mode (pad=0x72bc4c0,
mode=GST_PAD_MODE_PUSH, active=0) at gstpad.c:1088
res = 0
parent = 0x72e2010
old = GST_PAD_MODE_PUSH
new = GST_PAD_MODE_NONE
dir = GST_PAD_SINK
peer = 0x72bc4d8
__PRETTY_FUNCTION__ = "gst_pad_activate_mode"
#6 0x000000000544690f in gst_pad_set_active (pad=0x72bc4c0, active=0)
at gstpad.c:967
parent = 0x72e2010
old = GST_PAD_MODE_PUSH
ret = 0
__PRETTY_FUNCTION__ = "gst_pad_set_active"
#7 0x000000000542f255 in activate_pads (vpad=0x7fefff380,
ret=0x7fefff3d0, active=0x7fefff414) at gstelement.c:2687
pad = 0x72bc4c0
cont = 1
#8 0x000000000543dda1 in gst_iterator_fold (it=0x978bc00,
func=0x542f216 <activate_pads>, ret=0x7fefff3d0,
user_data=0x7fefff414) at gstiterator.c:614
item = {g_type = 114365904, data = {{v_int = 120308928, v_uint
= 120308928, v_long = 120308928, v_ulong = 120308928, v_int64 =
120308928, v_uint64 = 120308928,
v_float = 1.29224298e-34, v_double =
5.944050821278803e-316, v_pointer = 0x72bc4c0}, {v_int = 0, v_uint =
0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0,
v_double = 0, v_pointer = 0x0}}}
result = GST_ITERATOR_OK
#9 0x000000000542f2da in iterator_activate_fold_with_resync
(iter=0x978bc00, func=0x542f216 <activate_pads>,
user_data=0x7fefff414) at gstelement.c:2707
ires = GST_ITERATOR_OK
ret = {g_type = 20, data = {{v_int = 1, v_uint = 1, v_long =
1, v_ulong = 1, v_int64 = 1, v_uint64 = 1, v_float = 1.40129846e-45,
v_double = 4.9406564584124654e-324,
v_pointer = 0x1}, {v_int = 0, v_uint = 0, v_long = 0,
v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0,
v_pointer = 0x0}}}
#10 0x000000000542f40a in gst_element_pads_activate
(element=0x72e2010, active=0) at gstelement.c:2751
iter = 0x978bc00
res = 1
__PRETTY_FUNCTION__ = "gst_element_pads_activate"
#11 0x000000000542f6fa in gst_element_change_state_func
(element=0x72e2010, transition=GST_STATE_CHANGE_PAUSED_TO_READY) at
gstelement.c:2815
state = GST_STATE_PAUSED
next = GST_STATE_READY
result = GST_STATE_CHANGE_SUCCESS
__PRETTY_FUNCTION__ = "gst_element_change_state_func"
#12 0x0000000008597df5 in mpegts_base_change_state (element=0x72e2010,
transition=GST_STATE_CHANGE_PAUSED_TO_READY) at mpegtsbase.c:1521
base = 0x72e2010
ret = <optimized out>
#13 0x000000000542ee9f in gst_element_change_state (element=0x72e2010,
transition=GST_STATE_CHANGE_PAUSED_TO_READY) at gstelement.c:2602
---Type <return> to continue, or q <return> to quit---
oclass = 0x72d9af0
ret = GST_STATE_CHANGE_SUCCESS
__PRETTY_FUNCTION__ = "gst_element_change_state"
#14 0x000000000542ed4b in gst_element_set_state_func
(element=0x72e2010, state=GST_STATE_READY) at gstelement.c:2558
current = GST_STATE_PAUSED
next = GST_STATE_READY
old_pending = GST_STATE_VOID_PENDING
ret = GST_STATE_CHANGE_FAILURE
transition = GST_STATE_CHANGE_PAUSED_TO_READY
old_ret = GST_STATE_CHANGE_SUCCESS
__PRETTY_FUNCTION__ = "gst_element_set_state_func"
#15 0x000000000542e939 in gst_element_set_state (element=0x72e2010,
state=GST_STATE_READY) at gstelement.c:2459
oclass = 0x72d9af0
result = GST_STATE_CHANGE_FAILURE
__PRETTY_FUNCTION__ = "gst_element_set_state"
#16 0x0000000005407f3a in gst_bin_element_set_state (bin=0x72ae1c0,
element=0x72e2010, base_time=2259325637400096,
start_time=112807062666, current=GST_STATE_PAUSED,
next=GST_STATE_READY)
at gstbin.c:2325
ret = GST_STATE_CHANGE_SUCCESS
child_current = GST_STATE_PAUSED
child_pending = GST_STATE_VOID_PENDING
locked = 0
found = 0x0
__PRETTY_FUNCTION__ = "gst_bin_element_set_state"
#17 0x0000000005409521 in gst_bin_change_state_func
(element=0x72ae1c0, transition=GST_STATE_CHANGE_PAUSED_TO_READY) at
gstbin.c:2648
child = 0x72e2010
bin = 0x72ae1c0
ret = GST_STATE_CHANGE_SUCCESS
current = GST_STATE_PAUSED
next = GST_STATE_READY
have_async = 0
have_no_preroll = 0
base_time = 2259325637400096
start_time = 112807062666
it = 0x6d0ad80
done = 0
data = {g_type = 114375168, data = {{v_int = 120463376, v_uint
= 120463376, v_long = 120463376, v_ulong = 120463376, v_int64 =
120463376, v_uint64 = 120463376,
v_float = 1.30997274e-34, v_double =
5.9516815663656919e-316, v_pointer = 0x72e2010}, {v_int = 0, v_uint =
0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0,
v_double = 0, v_pointer = 0x0}}}
__PRETTY_FUNCTION__ = "gst_bin_change_state_func"
#18 0x000000000542ee9f in gst_element_change_state (element=0x72ae1c0,
transition=GST_STATE_CHANGE_PAUSED_TO_READY) at gstelement.c:2602
oclass = 0x721ff50
ret = GST_STATE_CHANGE_SUCCESS
__PRETTY_FUNCTION__ = "gst_element_change_state"
#19 0x000000000542ed4b in gst_element_set_state_func
(element=0x72ae1c0, state=GST_STATE_NULL) at gstelement.c:2558
current = GST_STATE_PAUSED
next = GST_STATE_READY
old_pending = GST_STATE_VOID_PENDING
ret = GST_STATE_CHANGE_FAILURE
---Type <return> to continue, or q <return> to quit---
transition = GST_STATE_CHANGE_PAUSED_TO_READY
old_ret = GST_STATE_CHANGE_SUCCESS
__PRETTY_FUNCTION__ = "gst_element_set_state_func"
#20 0x000000000542e939 in gst_element_set_state (element=0x72ae1c0,
state=GST_STATE_NULL) at gstelement.c:2459
oclass = 0x721ff50
result = GST_STATE_CHANGE_FAILURE
__PRETTY_FUNCTION__ = "gst_element_set_state"
Also there is another instersting thread which is not in
pthread_cond_wait() as all the others are:
(gdb) bt full
#0 mpegts_packetizer_next_packet (packetizer=0x9820560,
packet=0x13f865b0) at mpegtspacketizer.c:773
priv = 0x98205b0
skip = <optimized out>
sync_offset = <optimized out>
packet_size = 188
__FUNCTION__ = "mpegts_packetizer_next_packet"
#1 0x0000000008599635 in mpegts_base_chain (pad=<optimized out>,
parent=0x72e22d0, buf=0x11420610) at mpegtsbase.c:1098
res = <optimized out>
base = 0x72e22d0
pret = <optimized out>
packetizer = 0x9820560
packet = {pid = 259, payload_unit_start_indicator = 0 '\000',
scram_afc_cc = 26 '\032', payload = 0x9822e34 "", data_start =
0x9822e30 "G\001\003\032", data_end = 0x9822eec "",
data = 0x9822e34 "", afc_flags = 0 '\000', pcr = 114261176,
offset = 151867}
klass = 0x72d9af0
__FUNCTION__ = "mpegts_base_chain"
#2 0x000000000544ec51 in gst_pad_chain_data_unchecked (pad=0x9785a50,
type=4112, data=0x11420610) at gstpad.c:3711
chainfunc = 0x8599510 <mpegts_base_chain>
ret = GST_FLOW_OK
parent = 0x72e22d0
__PRETTY_FUNCTION__ = "gst_pad_chain_data_unchecked"
#3 0x000000000544f714 in gst_pad_push_data (pad=0x97ad6a0, type=4112,
data=0x11420610) at gstpad.c:3941
peer = 0x9785a50
ret = GST_FLOW_OK
__PRETTY_FUNCTION__ = "gst_pad_push_data"
#4 0x000000000544fc65 in gst_pad_push (pad=0x97ad6a0,
buffer=0x11420610) at gstpad.c:4044
__PRETTY_FUNCTION__ = "gst_pad_push"
#5 0x0000000005436690 in gst_proxy_pad_chain_default (pad=0x98360a0,
parent=0x72ae700, buffer=0x11420610) at gstghostpad.c:128
res = GST_FLOW_OK
internal = 0x97ad6a0
__PRETTY_FUNCTION__ = "gst_proxy_pad_chain_default"
#6 0x000000000544ec51 in gst_pad_chain_data_unchecked (pad=0x98360a0,
type=4112, data=0x11420610) at gstpad.c:3711
chainfunc = 0x5436580 <gst_proxy_pad_chain_default>
ret = GST_FLOW_OK
parent = 0x72ae700
__PRETTY_FUNCTION__ = "gst_pad_chain_data_unchecked"
#7 0x000000000544f714 in gst_pad_push_data (pad=0x9836300, type=4112,
data=0x11420610) at gstpad.c:3941
peer = 0x98360a0
ret = GST_FLOW_OK
__PRETTY_FUNCTION__ = "gst_pad_push_data"
#8 0x000000000544fc65 in gst_pad_push (pad=0x9836300,
buffer=0x11420610) at gstpad.c:4044
__PRETTY_FUNCTION__ = "gst_pad_push"
#9 0x0000000005436690 in gst_proxy_pad_chain_default (pad=0x97adb20,
parent=0x9836300, buffer=0x11420610) at gstghostpad.c:128
res = GST_FLOW_OK
internal = 0x9836300
__PRETTY_FUNCTION__ = "gst_proxy_pad_chain_default"
#10 0x000000000544ec51 in gst_pad_chain_data_unchecked (pad=0x97adb20,
type=4112, data=0x11420610) at gstpad.c:3711
chainfunc = 0x5436580 <gst_proxy_pad_chain_default>
ret = GST_FLOW_OK
---Type <return> to continue, or q <return> to quit---
parent = 0x9836300
__PRETTY_FUNCTION__ = "gst_pad_chain_data_unchecked"
#11 0x000000000544f714 in gst_pad_push_data (pad=0x981e760, type=4112,
data=0x11420610) at gstpad.c:3941
peer = 0x97adb20
ret = GST_FLOW_OK
__PRETTY_FUNCTION__ = "gst_pad_push_data"
#12 0x000000000544fc65 in gst_pad_push (pad=0x981e760,
buffer=0x11420610) at gstpad.c:4044
__PRETTY_FUNCTION__ = "gst_pad_push"
#13 0x0000000007517e95 in gst_queue_push_one (queue=0x74af020) at
gstqueue.c:1119
buffer = 0x11420610
result = GST_FLOW_OK
data = 0x11420610
__PRETTY_FUNCTION__ = "gst_queue_push_one"
#14 0x0000000007518c14 in gst_queue_loop (pad=0x981e760) at gstqueue.c:1248
queue = 0x74af020
ret = GST_FLOW_OK
__PRETTY_FUNCTION__ = "gst_queue_loop"
#15 0x0000000005482d64 in gst_task_func (task=0x9a235a0) at gsttask.c:316
lock = 0x981e7d0
tself = 0x97ef630
priv = 0x9a23670
__PRETTY_FUNCTION__ = "gst_task_func"
#16 0x0000000005483e5f in default_func (tdata=0x7355d30,
pool=0x6d1a840) at gsttaskpool.c:70
func = 0x5482ac2 <gst_task_func>
user_data = 0x9a235a0
#17 0x0000000004eb4956 in g_thread_pool_thread_proxy (data=0x6d1a750)
at gthreadpool.c:309
task = 0x7355d30
pool = 0x6d1a750
#18 0x0000000004eb4391 in g_thread_proxy (data=0x97ef630) at gthread.c:801
thread = 0x97ef630
__PRETTY_FUNCTION__ = "g_thread_proxy"
#19 0x0000000005703da6 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#20 0x0000000006621abd in clone () from /lib64/libc.so.6
No symbol table info available.
Any help?
--
Andrey Utkin
More information about the gstreamer-devel
mailing list