[asterisk-bugs] [Asterisk 0014918]: Asterisk 1.4.24.1 deadlock
Asterisk Bug Tracker
noreply at bugs.digium.com
Mon Apr 27 10:43:01 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:43 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)
=== -------------------------------------------------------------------
===
=======================================================================
======================================================================
----------------------------------------------------------------------
(0103811) aragon (reporter) - 2009-04-27 10:43
http://bugs.digium.com/view.php?id=14918#c103811
----------------------------------------------------------------------
I think these issues are all related to r165796
because they seem related to another ticket I opened
http://bugs.digium.com/view.php?id=14843
Calls are controlled with AGI scripts
zerohalo, bluefox; you also use AGI?
When we reverted r165796 we were able to fix the symptoms of 14843 but
never able to isolate root cause.
On this site r165796 is not reverted.
The unreachable status seem always to be prefixed with ast_carefulwrite
timeouts.
Now in this scenario I was able to capture some additional helpful
information.
-- Executing [s at customer-application-acd-reservations:9]
BackGround("SIP/5555555555-b784f890", "all-reps-busy") in new stack
-- <SIP/5192387308-b784f890> Playing 'all-reps-busy' (language 'en')
[Apr 27 11:23:43] NOTICE[4359]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:43] NOTICE[4359]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:43] NOTICE[4359]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:43] NOTICE[4359]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:43] NOTICE[4359]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '228' is now Lagged. (2018ms / 2000ms)
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '226' is now Lagged. (2017ms / 2000ms)
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '383' is now Lagged. (2021ms / 2000ms)
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '5192388060' is now Lagged. (2018ms /
2000ms)
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '428' is now Lagged. (2035ms / 2000ms)
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '422' is now Lagged. (2035ms / 2000ms)
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '421' is now Lagged. (2035ms / 2000ms)
[Apr 27 11:23:43] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '333' is now Lagged. (2017ms / 2000ms)
[Apr 27 11:23:43] NOTICE[4359]: utils.c:938 ast_carefulwrite: Timed out
trying to write
-- Executing [55555555555 at customer-executive:1]
Macro("SIP/383-b78fd600", "oakwood-dial-multi-629855") in new stack
-- Executing [s at macro-customer-dial-multi-629855:1]
AGI("SIP/383-b78fd600",
"/var/www/scopserv/telephony/scripts/agi/extension.php") in new stack
-- Launched AGI Script
/var/www/scopserv/telephony/scripts/agi/extension.php
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '404' is now Lagged. (2115ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '406' is now Lagged. (2117ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '335' is now Lagged. (2149ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '301' is now Lagged. (2147ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '245' is now Lagged. (2147ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '153' is now Lagged. (2147ms / 2000ms)
[Apr 27 11:23:44] NOTICE[4359]: 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 '164' is now Lagged. (2150ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '147' is now Lagged. (2165ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '230' is now Lagged. (2135ms / 2000ms)
[Apr 27 11:23:44] NOTICE[11156]: chan_sip.c:12908
handle_response_peerpoke: Peer '233' is now Lagged. (2135ms / 2000ms)
Issue History
Date Modified Username Field Change
======================================================================
2009-04-27 10:43 aragon Note Added: 0103811
======================================================================
More information about the asterisk-bugs
mailing list