[asterisk-bugs] [Asterisk 0014918]: Asterisk 1.4.24.1 deadlock

Asterisk Bug Tracker noreply at bugs.digium.com
Mon Apr 27 10:29:12 CDT 2009


A NOTE has been added to this issue. 
====================================================================== 
http://bugs.digium.com/view.php?id=14918 
====================================================================== 
Reported By:                aragon
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   14918
Category:                   Channels/chan_local
Reproducibility:            random
Severity:                   major
Priority:                   normal
Status:                     new
Target Version:             1.4.25
Asterisk Version:           1.4.24 
Regression:                 Yes 
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2009-04-16 16:12 CDT
Last Modified:              2009-04-27 10:29 CDT
====================================================================== 
Summary:                    Asterisk 1.4.24.1 deadlock
Description: 
Asterisk locks randomly

This is the first lock on this system since upgrading to 1.4.24.1
yesterday

=======================================================================
=== Currently Held Locks ==============================================
=======================================================================
===
=== <file> <line num> <function> <lock name> <lock addr> (times locked)
===
=== Thread ID: 3086154656 (do_devstate_changes  started at [  363]
devicestate.c ast_device_state_engine_init())
=== ---> Tried and failed to get Lock http://bugs.digium.com/view.php?id=0
(channel.c): MUTEX 1101
channel_find_locked &c->lock 0x9469908 (0)
=== -------------------------------------------------------------------
===
=== Thread ID: 19549088 (do_monitor started at [16693] chan_sip.c
restart_monitor())
=== ---> Lock http://bugs.digium.com/view.php?id=0 (chan_sip.c): MUTEX 16545
do_monitor &iflock 0x4eb92e0
(1)
=== ---> Waiting for Lock http://bugs.digium.com/view.php?id=1 (pbx.c): MUTEX
2158 ast_extension_state_del
&(&hints)->lock 0x8166948 (1)
=== --- ---> Locked Here: pbx.c line 2194 (ast_add_hint)
=== -------------------------------------------------------------------
===
=== Thread ID: 30337952 (pbx_thread started at [ 2663] pbx.c
ast_pbx_start())
=== ---> Lock http://bugs.digium.com/view.php?id=0 (channel.c): MUTEX 2751
ast_write &chan->lock 0x9469908
(1)
=== ---> Lock http://bugs.digium.com/view.php?id=1 (chan_local.c): MUTEX 320
local_write &p->lock 0x9476338
(1)
=== -------------------------------------------------------------------
===
=== Thread ID: 30829472 (session_do started at [ 2475] manager.c
accept_thread())
=== ---> Lock http://bugs.digium.com/view.php?id=0 (manager.c): RDLOCK 2235
process_message &actionlock
0x8164460 (1)
=== ---> Lock http://bugs.digium.com/view.php?id=1 (pbx.c): MUTEX 4850
ast_add_extension2 &con->lock
0x95a6218 (1)
=== ---> Lock http://bugs.digium.com/view.php?id=2 (pbx.c): MUTEX 2194
ast_add_hint &(&hints)->lock
0x8166948 (1)
=== ---> Tried and failed to get Lock http://bugs.digium.com/view.php?id=3
(channel.c): MUTEX 1101
channel_find_locked &c->lock 0x9469908 (0)
=== -------------------------------------------------------------------
===
=== Thread ID: 25209760 (pbx_thread started at [ 2663] pbx.c
ast_pbx_start())
=== ---> Waiting for Lock http://bugs.digium.com/view.php?id=0 (chan_sip.c):
MUTEX 4648 sip_alloc &iflock
0x4eb92e0 (1)
=== --- ---> Locked Here: chan_sip.c line 16545 (do_monitor)
=== -------------------------------------------------------------------
===
=== Thread ID: 64269216 (session_do started at [ 2475] manager.c
accept_thread())
=== ---> Lock http://bugs.digium.com/view.php?id=0 (manager.c): RDLOCK 2235
process_message &actionlock
0x8164460 (1)
=== ---> Tried and failed to get Lock http://bugs.digium.com/view.php?id=1
(channel.c): MUTEX 1101
channel_find_locked &c->lock 0x9469908 (0)
=== -------------------------------------------------------------------
===
=======================================================================


====================================================================== 

---------------------------------------------------------------------- 
 (0103810) aragon (reporter) - 2009-04-27 10:29
 http://bugs.digium.com/view.php?id=14918#c103810 
---------------------------------------------------------------------- 
This just happened on another site I maintain.
This time it was the wake up call feature that stopped working and other
types of calls and features were working.
This is the first time I have seen the extensions become lagged.

[Apr 27 11:23:44] NOTICE[4500]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '451' is now Lagged. (3022ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '407' is now Lagged. (3017ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '401' is now Lagged. (3024ms / 2000ms)
[Apr 27 11:23:44] NOTICE[4500]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '160' is now Lagged. (3032ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '140' is now Lagged. (3019ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '207' is now Lagged. (3026ms / 2000ms)
[Apr 27 11:23:45] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '260' is now Lagged. (3025ms / 2000ms)
[Apr 27 11:23:45] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '239' is now Lagged. (3026ms / 2000ms)
[Apr 27 11:23:45] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '237' is now Lagged. (3032ms / 2000ms)
[Apr 27 11:23:45] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '229' is now Lagged. (3032ms / 2000ms)
[Apr 27 11:23:45] NOTICE[4500]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:45] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '312' is now Lagged. (3052ms / 2000ms)
[Apr 27 11:23:45] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '329' is now Lagged. (3060ms / 2000ms)
[Apr 27 11:23:45] NOTICE[4500]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:45] NOTICE[4500]: utils.c:938 ast_carefulwrite: Timed out
trying to write
  == Parsing '/etc/asterisk/manager.conf': Found

gdb asterisk --pid='10627'
[Thread debugging using libthread_db enabled]
[New Thread -1208097088 (LWP 10627)]
[New Thread 70917024 (LWP 29942)]
[New Thread 62704544 (LWP 29941)]
[New Thread 93797280 (LWP 29350)]
[New Thread 38914976 (LWP 29349)]
[New Thread 84618144 (LWP 29348)]
[New Thread 78252960 (LWP 26588)]
[New Thread 27429792 (LWP 21644)]
[New Thread 28658592 (LWP 20427)]
[New Thread 120368032 (LWP 19443)]
[New Thread 88566688 (LWP 17265)]
[New Thread 91339680 (LWP 4691)]
[New Thread 26790816 (LWP 2059)]
[New Thread 52251552 (LWP 16591)]
[New Thread 28167072 (LWP 7162)]
[New Thread 26299296 (LWP 7161)]
[New Thread 124947360 (LWP 3214)]
[New Thread 114707360 (LWP 2448)]
[New Thread 100875168 (LWP 2446)]
[New Thread 33110944 (LWP 29766)]
[New Thread 31890336 (LWP 28870)]
[New Thread 28412832 (LWP 28868)]
[New Thread 72149920 (LWP 28867)]
[New Thread 46726048 (LWP 28866)]
[New Thread 109005728 (LWP 28865)]
[New Thread 27675552 (LWP 14299)]
[New Thread 27921312 (LWP 6329)]
[New Thread 116427680 (LWP 16574)]
[New Thread 86584224 (LWP 14035)]
[New Thread 27184032 (LWP 13919)]
[New Thread 26545056 (LWP 11580)]
[New Thread 84945824 (LWP 11207)]
[New Thread 61205408 (LWP 11206)]
[New Thread 26028960 (LWP 11182)]
[New Thread 112143264 (LWP 11156)]
[New Thread 16280480 (LWP 10991)]
[New Thread 15829920 (LWP 10990)]
[New Thread 15354784 (LWP 10912)]
[New Thread 14936992 (LWP 10911)]
[New Thread 14666656 (LWP 10910)]
[New Thread 14044064 (LWP 10909)]
[New Thread 13613984 (LWP 10908)]
[New Thread 12987296 (LWP 10907)]
[New Thread 11316128 (LWP 10906)]
[New Thread 10288032 (LWP 10905)]
[New Thread 7805856 (LWP 10904)]
[New Thread 7560096 (LWP 10903)]
[New Thread 7314336 (LWP 10902)]
[New Thread 7068576 (LWP 10901)]
[New Thread 5155744 (LWP 10888)]
[New Thread 4889504 (LWP 10887)]
[New Thread 4545440 (LWP 10886)]
[New Thread -1209095264 (LWP 10740)]
[New Thread -1208849504 (LWP 10739)]
[New Thread -1208603744 (LWP 10738)]
[New Thread -1208357984 (LWP 10737)]
[New Thread -1208099936 (LWP 10725)]
Loaded symbols for /lib/libgcc_s.so.1
0x007737a2 in _dl_sysinfo_int80 ()
   from /lib/ld-linux.so.2
(gdb) bt full
http://bugs.digium.com/view.php?id=0  0x007737a2 in _dl_sysinfo_int80 () from
/lib/ld-linux.so.2
No symbol table info available.
http://bugs.digium.com/view.php?id=1  0x0094869b in __read_nocancel () from
/lib/tls/libpthread.so.0
No symbol table info available.
http://bugs.digium.com/view.php?id=2  0x0810ee91 in read_char ()
No symbol table info available.
http://bugs.digium.com/view.php?id=3  0x0810ef32 in el_getc ()
No symbol table info available.
http://bugs.digium.com/view.php?id=4  0x0810eda8 in read_getcmd ()
No symbol table info available.
http://bugs.digium.com/view.php?id=5  0x0810f073 in el_gets ()
No symbol table info available.
http://bugs.digium.com/view.php?id=6  0x08070a73 in main ()
No symbol table info available. 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-04-27 10:29 aragon         Note Added: 0103810                          
======================================================================




More information about the asterisk-bugs mailing list