[asterisk-bugs] [Asterisk 0018803]: deadlock related to "handle_tcptls_connection" - tcp transport

[Asterisk Bug Tracker]

A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=18803 
====================================================================== 
Reported By:                luckman212
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   18803
Category:                   Channels/chan_sip/TCP-TLS
Reproducibility:            sometimes
Severity:                   crash
Priority:                   normal
Status:                     new
Asterisk Version:           1.8.2.3 
JIRA:                        
Regression:                 No 
Reviewboard Link:            
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2011-02-13 16:16 CST
Last Modified:              2011-02-16 11:46 CST
====================================================================== 
Summary:                    deadlock related to "handle_tcptls_connection" - tcp
transport
Description: 
I have been experiencing very frequent deadlocks (usually 2-3x per day,
sometimes more) in Asterisk 1.8.2.3 since I enabled the TCP transport for
one of my endpoints.  This *could* be a coincidence but it does seem to
correspond with the rest of the debugging info that I have. 

I'm running Asterisk 1.8.2.3 as part of a Pbx-In-a-Flash distribution
(CentOS 5.5) in a SIP-only (no DAHDI hardware) setup.  3 SIP trunks and 4
SIP peers, a small & simple setup.

What happens is that my pbx will be humming along and then suddenly I will
notice that I can no longer make or receive any calls.  The *CLI is still
responsive, but I notice that my trunks have stopped refreshing their
registrations (sip show registry will indicate Reg.Time not updating).  I
believe that Asterisk is deadlocking during the registration process for
this particular endpoint for which I've enabled the TCP transport.

I've compiled Asterisk with DEBUG_THREADS and DONT_OPTIMIZE and when the
deadlock occurs, I run the following command:

pbx*CLI> core show locks

This shows a handful of locks, but the most interesting one is (e.g):

=== Thread ID: 85511056 (handle_tcptls_connection started at [  274]
tcptls.c ast_tcptls_server_root())
=== ---> Waiting for Lock https://issues.asterisk.org/view.php?id=0
(chan_sip.c): MUTEX 23962 handle_request_do
&netlock 0x4977660 (1)
        /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x811edbe]
        /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xaa) [0x81185b9]
        /usr/lib/asterisk/modules/chan_sip.so [0x4933c89]
        /usr/lib/asterisk/modules/chan_sip.so [0x48c8c6d]
        /usr/lib/asterisk/modules/chan_sip.so [0x48c8422]
        /usr/sbin/asterisk [0x8186000]
        /usr/sbin/asterisk [0x8195ee1]
        /lib/libpthread.so.0 [0xadd832]
        /lib/libc.so.6(clone+0x5e) [0xa1cf6e]
=== --- ---> Locked Here: chan_sip.c line 23962 (handle_request_do)
=== -------------------------------------------------------------------
===
=== Thread ID: 86985616 (handle_tcptls_connection started at [  274]
tcptls.c ast_tcptls_server_root())
=== ---> Waiting for Lock https://issues.asterisk.org/view.php?id=0
(chan_sip.c): MUTEX 23962 handle_request_do
&netlock 0x4977660 (1)
        /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x811edbe]
        /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xaa) [0x81185b9]
        /usr/lib/asterisk/modules/chan_sip.so [0x4933c89]
        /usr/lib/asterisk/modules/chan_sip.so [0x48c8c6d]
        /usr/lib/asterisk/modules/chan_sip.so [0x48c8422]
        /usr/sbin/asterisk [0x8186000]
        /usr/sbin/asterisk [0x8195ee1]
        /lib/libpthread.so.0 [0xadd832]
        /lib/libc.so.6(clone+0x5e) [0xa1cf6e]
=== --- ---> Locked Here: chan_sip.c line 23962 (handle_request_do)
=== -------------------------------------------------------------------
===
=======================================================================


I have gdb installed but my skills w/ it are severely limited and I don't
know how to debug further.  

I think there is a chance that this issue has been reported before, at
https://issues.asterisk.org/view.php?id=17675

However that was with 1.6.x and the issue had been closed, so I am opening
this here in hopes that it can be debugged.
====================================================================== 

---------------------------------------------------------------------- 
 (0132032) davidw (reporter) - 2011-02-16 11:46
 https://issues.asterisk.org/view.php?id=18803#c132032 
---------------------------------------------------------------------- 
I'm not familiar with the internals of res_timing_pthread, but a blocked
write seems to be part of the deadlock cycle.

My guess is that you will find something like it is using a pipe to
deliver the timing pulses, but the pipe has filled and the the bit that
would read events off the pipe is waiting for a lock held by the thread
writing to the pipe. 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2011-02-16 11:46 davidw         Note Added: 0132032                          
======================================================================