<div dir="ltr"><br><div class="gmail_extra"><br><div class="gmail_quote">On Mon, Nov 16, 2015 at 9:30 AM, Steve Davies <span dir="ltr"><<a href="mailto:davies147@gmail.com" target="_blank">davies147@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div>Hi,</div><div><br></div>I believe there is a known issue in Postgres where if multiple threads call pgsql_exec(), then it can cause threads to get stuck inside Postgres - This is why I suggested that Postgres patch, which puts Asterisk locks around the call to pgsql_exec().<div><br></div><div>OTOH, I don't think you mentioned what DB you are using, so that might not apply...</div><br clear="all"></div></blockquote></div><br></div><div class="gmail_extra">So, this isn't a deadlock in the classic sense. Nor - based on the current evidence - does this look like a bug with Asterisk.<br><br></div><div class="gmail_extra">Looking at the provided locks:<br><br>=======================================================================<br>
=== 11.20.0<br>
=== Currently Held Locks<br>
=======================================================================<br>
===<br>
=== <pending> <lock#> (<file>): <lock type>
<line num> <function> <lock name> <lock addr>
(times locked)<br>
===<br>
=== Thread ID: 0xb6cffb70 (db_sync_thread started at [ 1018] db.c astdb_init())<br>
=== ---> Lock #0 (db.c): MUTEX 980 db_sync_thread &dblock 0x8214f60 (1)<br>
main/logger.c:1702 ast_bt_get_addresses() (0x813f3a6+19)<br>
main/lock.c:258 __ast_pthread_mutex_lock() (0x8138607+85)<br>
main/db.c:981 db_sync_thread()<br>
main/utils.c:1223 dummy_start()<br>
:0 start_thread()<br>
libc.so.6 clone() (0xb76e60d0+5E)<br><br><br></div><div class="gmail_extra">This is the db_sync_thread, holding the lock for the AstDB - that is, the SQLite3 database. The db_sync_thread commits transactions, and rolls them back in case of error. I would suspect that a gdb backtrace would show that we are currently beginning, committing, or rolling back a transaction. That's probably worth finding out.<br><br></div><div class="gmail_extra"><br>
=== -------------------------------------------------------------------<br>
===<br>
=== Thread ID: 0xb4fc3b70 (do_monitor started at [29517] chan_sip.c restart_monitor())<br>
=== ---> Lock #0 (chan_sip.c): MUTEX 28923 handle_request_do &netlock 0xb6190440 (1)<br>
main/logger.c:1702 ast_bt_get_addresses() (0x813f3a6+19)<br>
main/lock.c:258 __ast_pthread_mutex_lock() (0x8138607+85)<br>
channels/chan_sip.c:28926 handle_request_do()<br>
channels/chan_sip.c:28885 sipsock_read()<br>
main/io.c:292 ast_io_wait() (0x8132d08+175)<br>
channels/chan_sip.c:29484 do_monitor()<br>
main/utils.c:1223 dummy_start()<br>
:0 start_thread()<br>
libc.so.6 clone() (0xb76e60d0+5E)<br>
=== ---> Lock #1 (chan_sip.c): MUTEX 8959 sip_pvt_lock_full pvt 0x8391ec8 (1)<br>
main/logger.c:1702 ast_bt_get_addresses() (0x813f3a6+19)<br>
main/lock.c:258 __ast_pthread_mutex_lock() (0x8138607+85)<br>
main/astobj2.c:198 __ao2_lock() (0x80906ad+7C)<br>
channels/chan_sip.c:8960 sip_pvt_lock_full()<br>
channels/chan_sip.c:28939 handle_request_do()<br>
channels/chan_sip.c:28885 sipsock_read()<br>
main/io.c:292 ast_io_wait() (0x8132d08+175)<br>
channels/chan_sip.c:29484 do_monitor()<br>
main/utils.c:1223 dummy_start()<br>
:0 start_thread()<br>
libc.so.6 clone() (0xb76e60d0+5E)<br>
=== ---> Lock #2 (chan_sip.c): MUTEX 17047 register_verify peer 0xb4e44ed8 (1)<br>
main/logger.c:1702 ast_bt_get_addresses() (0x813f3a6+19)<br>
main/lock.c:258 __ast_pthread_mutex_lock() (0x8138607+85)<br>
main/astobj2.c:198 __ao2_lock() (0x80906ad+7C)<br>
channels/chan_sip.c:17048 register_verify()<br>
channels/chan_sip.c:28477 handle_request_register()<br>
channels/chan_sip.c:28785 handle_incoming()<br>
channels/chan_sip.c:28953 handle_request_do()<br>
channels/chan_sip.c:28885 sipsock_read()<br>
main/io.c:292 ast_io_wait() (0x8132d08+175)<br>
channels/chan_sip.c:29484 do_monitor()<br>
main/utils.c:1223 dummy_start()<br>
:0 start_thread()<br>
libc.so.6 clone() (0xb76e60d0+5E)<br>
=== ---> Waiting for Lock #3 (db.c): MUTEX 324 ast_db_put &dblock 0x8214f60 (1)<br>
main/logger.c:1702 ast_bt_get_addresses() (0x813f3a6+19)<br>
main/lock.c:258 __ast_pthread_mutex_lock() (0x8138607+85)<br>
main/db.c:325 ast_db_put() (0x80eeec4+D0)<br>
channels/chan_sip.c:16242 parse_register_contact()<br>
channels/chan_sip.c:17069 register_verify()<br>
channels/chan_sip.c:28477 handle_request_register()<br>
channels/chan_sip.c:28785 handle_incoming()<br>
channels/chan_sip.c:28953 handle_request_do()<br>
channels/chan_sip.c:28885 sipsock_read()<br>
main/io.c:292 ast_io_wait() (0x8132d08+175)<br>
channels/chan_sip.c:29484 do_monitor()<br>
main/utils.c:1223 dummy_start()<br>
:0 start_thread()<br>
libc.so.6 clone() (0xb76e60d0+5E)<br>
=== --- ---> Locked Here: db.c line 980 (db_sync_thread)<br>
=== -------------------------------------------------------------------<br><br></div><div class="gmail_extra">This sequence of locks shows that chan_sip is currently updating the SIP registry stored in the AstDB. Since we're currently in the middle of doing something with a transaction, it is blocked.<br></div><div class="gmail_extra"><br><br>
=== Thread ID: 0xb4485b70 (handle_tcptls_connection started at [ 745] tcptls.c ast_tcptls_server_root())<br>
=== ---> Waiting for Lock #0 (chan_sip.c): MUTEX 28923 handle_request_do &netlock 0xb6190440 (1)<br>
main/logger.c:1702 ast_bt_get_addresses() (0x813f3a6+19)<br>
main/lock.c:258 __ast_pthread_mutex_lock() (0x8138607+85)<br>
channels/chan_sip.c:28926 handle_request_do()<br>
channels/chan_sip.c:3045 _sip_tcp_helper_thread()<br>
channels/chan_sip.c:2572 sip_tcp_worker_fn()<br>
main/tcptls.c:694 handle_tcptls_connection()<br>
main/utils.c:1223 dummy_start()<br>
:0 start_thread()<br>
libc.so.6 clone() (0xb76e60d0+5E)<br>
=== --- ---> Locked Here: chan_sip.c line 28923 (handle_request_do)<br>
=== -------------------------------------------------------------------<br>
===<br>
=======================================================================<br><br></div><div class="gmail_extra">And this shows that the TCP/TLS thread is waiting on a lock held by the monitor thread; most likely, this is the SIP pvt lock currently held by the thread.<br><br></div><div class="gmail_extra"></div><div class="gmail_extra">Things to investigate:<br></div><div class="gmail_extra">(1) Get a gdb backtrace when this occurs, so you can find out exactly what the AstDB synchronization thread is doing that is blocking for a long period of time.<br></div><div class="gmail_extra">(2) Find out *exactly* what is occurring on your system. If the AstDB synchronization thread is taking a noticeable amount of time to do work, you almost certainly have either a problem in your AstDB; have other I/O problems on the system; or have something occurring here that is outside the control of Asterisk.<br></div><div class="gmail_extra"><br></div><div class="gmail_extra">Either way, nothing above makes me think there is a bug in Asterisk.<br></div><div class="gmail_extra"><br>-- <br><div class="gmail_signature"><div dir="ltr"><div><div dir="ltr"><div>Matthew Jordan<br></div><div>Digium, Inc. | Director of Technology<br></div><div>445 Jan Davis Drive NW - Huntsville, AL 35806 - USA</div><div>Check us out at: <a href="http://digium.com" target="_blank">http://digium.com</a> & <a href="http://asterisk.org" target="_blank">http://asterisk.org</a></div></div></div></div></div>
</div></div>