[asterisk-bugs] [Asterisk 0014639]: Asterisk CPU usage 100% (deadlock?) when using Queue() with Local channels

[Asterisk Bug Tracker]

A NOTE has been added to this issue. 
====================================================================== 
http://bugs.digium.com/view.php?id=14639 
====================================================================== 
Reported By:                coolmig
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   14639
Category:                   Channels/chan_local
Reproducibility:            always
Severity:                   major
Priority:                   normal
Status:                     new
Asterisk Version:           1.4.22 
Regression:                 No 
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2009-03-10 12:26 CDT
Last Modified:              2009-03-10 15:14 CDT
====================================================================== 
Summary:                    Asterisk CPU usage 100% (deadlock?) when using
Queue() with Local channels
Description: 
I was testing a dialer I'm making, and found this situation: when I dial
more than one call to an agent using Local channels (busy with one call and
one or more in the queue), Asterisk goes 100% CPU all the time until the
queued calls get answered or hangup.

Core show locks shows this:

=======================================================================
=== Currently Held Locks ==============================================
=======================================================================
===
=== <file> <line num> <function> <lock name> <lock addr> (times locked)
===
=== Thread ID: 3077847952 (pbx_thread           started at [ 2645] pbx.c
ast_pbx_start())
=== ---> Waiting for Lock http://bugs.digium.com/view.php?id=0 (chan_agent.c):
MUTEX 2252 __login_exec
&p->app_lock 0x93d59d4 (1)
=== --- ---> Locked Here: chan_agent.c line 1080 (agent_new)
=== -------------------------------------------------------------------
===
=== Thread ID: 3073665936 (pbx_thread           started at [ 2645] pbx.c
ast_pbx_start())
=== ---> Lock http://bugs.digium.com/view.php?id=0 (chan_agent.c): MUTEX 1080
agent_new &p->app_lock
0x93d59d4 (1)
=== -------------------------------------------------------------------
===
=== Thread ID: 3075632016 (pbx_thread           started at [ 2645] pbx.c
ast_pbx_start())
=== ---> Tried and failed to get Lock http://bugs.digium.com/view.php?id=0
(chan_local.c): MUTEX 186
local_queue_frame (channel lock) 0x9464470 (0)
=== -------------------------------------------------------------------
===
=======================================================================

If I hangup the initial agent call, if takes a long time for the Queue to
deliver the other call to the agent, while the agent is with no call, core
show locks shows this:

=======================================================================
=== Currently Held Locks ==============================================
=======================================================================
===
=== <file> <line num> <function> <lock name> <lock addr> (times locked)
===
=== Thread ID: 3077847952 (pbx_thread           started at [ 2645] pbx.c
ast_pbx_start())
=== ---> Lock http://bugs.digium.com/view.php?id=0 (chan_agent.c): MUTEX 2252
__login_exec &p->app_lock
0x93d59d4 (1)
=== -------------------------------------------------------------------
===
=== Thread ID: 3076860816 (pbx_thread           started at [ 2645] pbx.c
ast_pbx_start())
=== ---> Tried and failed to get Lock http://bugs.digium.com/view.php?id=0
(chan_local.c): MUTEX 186
local_queue_frame (channel lock) 0x945d820 (0)
=== -------------------------------------------------------------------
===
=======================================================================

When the queued call finally is delivered to the agent, core show locks
shows this, and the 100% usage stops:

=======================================================================
=== Currently Held Locks ==============================================
=======================================================================
===
=== <file> <line num> <function> <lock name> <lock addr> (times locked)
===
=== Thread ID: 3077847952 (pbx_thread           started at [ 2645] pbx.c
ast_pbx_start())
=== ---> Waiting for Lock http://bugs.digium.com/view.php?id=0 (chan_agent.c):
MUTEX 2252 __login_exec
&p->app_lock 0x93d59d4 (1)
=== --- ---> Locked Here: chan_agent.c line 1080 (agent_new)
=== -------------------------------------------------------------------
===
=== Thread ID: 3075632016 (pbx_thread           started at [ 2645] pbx.c
ast_pbx_start())
=== ---> Lock http://bugs.digium.com/view.php?id=0 (chan_agent.c): MUTEX 1080
agent_new &p->app_lock
0x93d59d4 (1)
=== -------------------------------------------------------------------
===
=======================================================================
====================================================================== 

---------------------------------------------------------------------- 
 (0101494) coolmig (reporter) - 2009-03-10 15:14
 http://bugs.digium.com/view.php?id=14639#c101494 
---------------------------------------------------------------------- 
I tested this using the local channel to dial a SIP or IAX2 extension (the
final use it will have), with the following simple dialplan:

;Context where I generate the calls using Local Channels
[marcador-prueba_outbound-gencall]
exten => _X.,1,Wait(10)
exten => _X.,n,Dial(SIP/100)
;exten => _X.,n,Dial(IAX2/100)

;Context where I connect the generated calls when they answer
[marcador-prueba_outbound]
exten => s,1,Answer()
exten => s,n,Queue(prueba_outbound,ht)
exten => s,n,Hangup()

And the issue does not reproduce this way, so it happens only with pure
Local channels. 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-03-10 15:14 coolmig        Note Added: 0101494                          
======================================================================