[asterisk-dev] [Code Review] [patch] Use of MASTER_CHANNEL causes a race condition ending in a deadlock among channels

Tue Mar 1 04:48:14 CST 2011

On 110226 0527, Russell Bryant wrote:
> Sure enough.  You're right.  Score another for peer review!

FWIW, the horrible persistent deadlock #28643 that forced us to back out 
to 1.6 *is* indicating that the monitor thread is holding a channel lock 
and is blocked obtaining another channel's lock in MASTER_CHANNEL's 
ast_channel_get_by_name() call. I do not understand the present issue 
well enough, and am going to say something as stupid as I always do, but 
it seems to me that if that other channel was calling MASTER_CHANNEL at 
the same time, the first class deadlock would indeed occur.

I have no clear idea why does handle_incoming() write to 
MASTER_CHANNEL() on the sip monitor thread, but it does.

This is the stack of the thread

> Thread 17 (process 31955):
> #0  0x00007f7ddb3f3a94 in __lll_lock_wait () from /lib/libpthread.so.0
> #1  0x00007f7ddb3ef1ab in _L_lock_312 () from /lib/libpthread.so.0
> #2  0x00007f7ddb3eebb1 in pthread_mutex_lock () from /lib/libpthread.so.0
> #3  0x00000000004e384c in __ast_pthread_mutex_lock (filename=0x5a0af4 "channel.c", lineno=1641, func=0x5a2940 "ast_channel_cmp_cb", mutex_name=0x5a20d8 "chan", t=0xe45970) at lock.c:230
> #4  0x0000000000445a24 in __ao2_lock (user_data=0xe46558, file=0x5a0af4 "channel.c", func=0x5a2940 "ast_channel_cmp_cb", line=1641, var=0x5a20d8 "chan") at astobj2.c:157
> #5  0x000000000046dcff in ast_channel_cmp_cb (obj=0xe46558, arg=0x7f7db571c040, flags=0) at channel.c:1641
> #6  0x000000000044692d in internal_ao2_callback (c=0x7f7dd449eeb8, flags=0, cb_fn=0x46dca7, arg=0x7f7db571c040, data=0x0, type=DEFAULT, tag=0x0, file=0x0, line=0, funcname=0x0) at astobj2.c:669
> #7  0x0000000000446d3f in __ao2_callback (c=0x7f7dd449eeb8, flags=0, cb_fn=0x46dca7 <ast_channel_cmp_cb>, arg=0x7f7db571c040) at astobj2.c:765
> #8  0x0000000000446e98 in __ao2_find (c=0x7f7dd449eeb8, arg=0x7f7db571c040, flags=0) at astobj2.c:792
> #9  0x000000000046e169 in ast_channel_get_full (name=0xc04aa7 "14-1299999999.8842", name_len=0, exten=0x0, context=0x0) at channel.c:1709
> #10 0x000000000046e1b1 in ast_channel_get_by_name (name=0xc04aa7 "14-1299999999.8842") at channel.c:1715
> #11 0x00007f7dc538c671 in func_mchan_write (chan=0xc7cec8, function=0x7f7db571ce10 "MASTER_CHANNEL", data=0x7f7db571ce1f "HASH(SIP_CAUSE,SIP/dyn-CustomerName-19617-00001875)", value=0x7f7db571d1d0 "SIP 100 Trying") at func_channel.c:597
> #12 0x000000000050c411 in ast_func_write (chan=0xc7cec8, function=0x7f7db571cf30 "MASTER_CHANNEL(HASH(SIP_CAUSE,SIP/dyn-CustomerName-19617-00001875))", value=0x7f7db571d1d0 "SIP 100 Trying") at pbx.c:3580
> #13 0x00000000005219dc in pbx_builtin_setvar_helper (chan=0xc7cec8, name=0x7f7db571d2d0 "MASTER_CHANNEL(HASH(SIP_CAUSE,SIP/dyn-CustomerName-19617-00001875))", value=0x7f7db571d1d0 "SIP 100 Trying") at pbx.c:9537
> #14 0x00007f7dc0c852f9 in handle_incoming (p=0x121e1c8, req=0x7f7db571d4c0, addr=0x7f7db571df30, recount=0x7f7db571d47c, nounlock=0x7f7db571d478) at chan_sip.c:23638
> #15 0x00007f7dc0c86f4c in handle_request_do (req=0x7f7db571d4c0, addr=0x7f7db571df30) at chan_sip.c:24038
> #16 0x00007f7dc0c867f2 in sipsock_read (id=0xae0c80, fd=16, events=1, ignore=0x0) at chan_sip.c:23936
> #17 0x00000000004dd9e0 in ast_io_wait (ioc=0x7f7dcc093730, howlong=0) at io.c:288
> #18 0x00007f7dc0c88684 in do_monitor (data=0x0) at chan_sip.c:24455
> #19 0x000000000056aed5 in dummy_start (data=0x7f7dcc0ba5d0) at utils.c:971
> #20 0x00007f7ddb3ed3ba in start_thread () from /lib/libpthread.so.0
> #21 0x00007f7ddbc4902d in clone () from /lib/libc.so.6
> #22 0x0000000000000000 in ?? ()

and this is the locks:

> === Thread ID: 140177891780944 (do_monitor           started at [24486] chan_sip.c restart_monitor())
> === ---> Lock #0 (chan_sip.c): MUTEX 23978 handle_request_do &netlock 0x7f7dc0ed2f80 (1)
> 	/usr/sbin/asterisk(ast_bt_get_addresses+0x1a) [0x4ea973]
> 	/usr/sbin/asterisk(__ast_pthread_mutex_lock+0xad) [0x4e37d1]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c86a15]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c867f2]
> 	/usr/sbin/asterisk(ast_io_wait+0x1ba) [0x4dd9e0]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c88684]
> 	/usr/sbin/asterisk [0x56aed5]
> 	/lib/libpthread.so.0 [0x7f7ddb3ed3ba]
> 	/lib/libc.so.6(clone+0x6d) [0x7f7ddbc4902d]
> === ---> Lock #1 (astobj2.c): MUTEX 657 internal_ao2_callback c 0x7f7dd449e2d0 (1)
> 	/usr/sbin/asterisk(ast_bt_get_addresses+0x1a) [0x4ea973]
> 	/usr/sbin/asterisk(__ast_pthread_mutex_lock+0xad) [0x4e37d1]
> 	/usr/sbin/asterisk(__ao2_lock+0x53) [0x445a24]
> 	/usr/sbin/asterisk [0x4467fa]
> 	/usr/sbin/asterisk(__ao2_callback+0x59) [0x446d3f]
> 	/usr/sbin/asterisk(__ao2_find+0x2b) [0x446e98]
> 	/usr/sbin/asterisk [0x46e169]
> 	/usr/sbin/asterisk(ast_channel_get_by_name+0x24) [0x46e1b1]
> 	/usr/lib/asterisk/modules/func_channel.so [0x7f7dc538c671]
> 	/usr/sbin/asterisk(ast_func_write+0x15a) [0x50c411]
> 	/usr/sbin/asterisk(pbx_builtin_setvar_helper+0xd9) [0x5219dc]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c852f9]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c86f4c]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c867f2]
> 	/usr/sbin/asterisk(ast_io_wait+0x1ba) [0x4dd9e0]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c88684]
> 	/usr/sbin/asterisk [0x56aed5]
> 	/lib/libpthread.so.0 [0x7f7ddb3ed3ba]
> 	/lib/libc.so.6(clone+0x6d) [0x7f7ddbc4902d]
> === ---> Waiting for Lock #2 (channel.c): MUTEX 1641 ast_channel_cmp_cb chan 0xe45970 (1)
> 	/usr/sbin/asterisk(ast_bt_get_addresses+0x1a) [0x4ea973]
> 	/usr/sbin/asterisk(__ast_pthread_mutex_lock+0xad) [0x4e37d1]
> 	/usr/sbin/asterisk(__ao2_lock+0x53) [0x445a24]
> 	/usr/sbin/asterisk [0x46dcff]
> 	/usr/sbin/asterisk [0x44692d]
> 	/usr/sbin/asterisk(__ao2_callback+0x59) [0x446d3f]
> 	/usr/sbin/asterisk(__ao2_find+0x2b) [0x446e98]
> 	/usr/sbin/asterisk [0x46e169]
> 	/usr/sbin/asterisk(ast_channel_get_by_name+0x24) [0x46e1b1]
> 	/usr/lib/asterisk/modules/func_channel.so [0x7f7dc538c671]
> 	/usr/sbin/asterisk(ast_func_write+0x15a) [0x50c411]
> 	/usr/sbin/asterisk(pbx_builtin_setvar_helper+0xd9) [0x5219dc]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c852f9]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c86f4c]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c867f2]
> 	/usr/sbin/asterisk(ast_io_wait+0x1ba) [0x4dd9e0]
> 	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c88684]
> 	/usr/sbin/asterisk [0x56aed5]
> 	/lib/libpthread.so.0 [0x7f7ddb3ed3ba]
> 	/lib/libc.so.6(clone+0x6d) [0x7f7ddbc4902d]
> === --- ---> Locked Here: channel.c line 3636 (__ast_read)

  -kkm