[asterisk-dev] Asterisk lock-up with impossible(?) lock backtrace

[Kirill Katsnelson]

I am trying to analyze https://issues.asterisk.org/view.php?id=18823 and 
would appreciate any help on it.

The culprit is a pbx_thread that runs dialplan while holding a channel 
lock. What I really cannot understand is its lock trace:

=== Thread ID: 140177859758416 (pbx_thread           started at [ 5035] 
pbx.c ast_pbx_start()) 0x7F7DB3894950
=== ---> Lock #0 (channel.c): MUTEX 3636 __ast_read chan 0xe45970 (1)
	/usr/sbin/asterisk(ast_bt_get_addresses+0x1a) [0x4ea973]
	/usr/sbin/asterisk(__ast_pthread_mutex_trylock+0xad) [0x4e3b3e]
	/usr/sbin/asterisk(__ao2_trylock+0x53) [0x445b89]
	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c86b38] 
handle_request_do 23992		if (!p->owner || !ast_channel_trylock(p->owner))
	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c867f2] 
sipsock_read 23936		handle_request_do(&req, &addr);
	/usr/sbin/asterisk(ast_io_wait+0x1ba) [0x4dd9e0]
	/usr/lib/asterisk/modules/chan_sip.so [0x7f7dc0c88684]		do_monitor 
24455		res = ast_io_wait(io, res);
	/usr/sbin/asterisk [0x56aed5]
	/lib/libpthread.so.0 [0x7f7ddb3ed3ba]
	/lib/libc.so.6(clone+0x6d) [0x7f7ddbc4902d]

I added the annotations obtained by resolving the addresses into source 
in gdb. According to the trace, the lock was obtained by a pbx_thread in 
do_monitor. But pbx_thread is not supposed to enter do_monitor ever! Or 
is it? How can I interpret that?

I identified the thread in gdb not using any information from "core show 
locks", and the thread holding the lock is really a pbx_thread. So only 
this backtrace is not clicking into the picture.

I have 2 lock-ups in 1.8.1 and 2 in 1.8.3-rc2, with cores and 
everything, and all 4 produce quite identical picture.

  -kkm