[asterisk-bugs] [Asterisk 0015609]: [patch] WARNING[23025]: channel.c:952 __ast_queue_frame: Exceptionally long voice queue length queuing to Local

[Asterisk Bug Tracker]

A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=15609 
====================================================================== 
Reported By:                aragon
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   15609
Category:                   Core/Channels
Reproducibility:            have not tried
Severity:                   crash
Priority:                   normal
Status:                     ready for testing
Asterisk Version:           SVN 
JIRA:                        
Regression:                 No 
SVN Branch (only for SVN checkouts, not tarball releases):  1.4  
SVN Revision (number only!): 206273 
Request Review:              
====================================================================== 
Date Submitted:             2009-07-29 09:26 CDT
Last Modified:              2009-09-28 08:32 CDT
====================================================================== 
Summary:                    [patch] WARNING[23025]: channel.c:952
__ast_queue_frame: Exceptionally long voice queue length queuing to Local
Description: 
Since upgrading to 1.4 SVN 206273 I see LOTS these errors when paging or
when calls are processed by app_queue.  When I see the messages during a
page I don't hear any paging (my Polycom phones continue to ring but no
paging audio).

I have no idea where the message is coming from how to reproduce, or
collect debug information for this specific issue.  I need help to find
root cause.
I think it could be caused by locking in autoservice since I see this lock
every time I see the warning message

=== Currently Held Locks ==============================================
=======================================================================
===
=== <file> <line num> <function> <lock name> <lock addr> (times locked)
===
=== Thread ID: 3057154960 (autoservice_run      started at [  238]
autoservice.c ast_autoservice_start())
=== ---> Waiting for Lock https://issues.asterisk.org/view.php?id=0
(autoservice.c): MUTEX 89 autoservice_run
&(&aslist)->lock 0x81798c8 (1)
=== --- ---> Locked Here: autoservice.c line 89 (autoservice_run)
=== -------------------------------------------------------------------


======================================================================
Relationships       ID      Summary
----------------------------------------------------------------------
related to          0015109 [patch] Abort by memory allocator, poss...
has duplicate       0015900 Console flood &amp; CPU load 100% when ...
related to          0015817 crash in local_attended_transfer, likel...
related to          0015845 Crash during attended transfer occurs
====================================================================== 

---------------------------------------------------------------------- 
 (0111420) YueNK (reporter) - 2009-09-28 08:32
 https://issues.asterisk.org/view.php?id=15609#c111420 
---------------------------------------------------------------------- 
Same problem as Newborn but with 1.6.0.15

I sometimes get thoses messages :
[Sep 28 14:22:10] WARNING[25978] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9990
[Sep 28 14:22:10] WARNING[25976] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9990
[Sep 28 14:22:10] WARNING[25977] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9990
[Sep 28 14:22:10] WARNING[25979] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9990
[Sep 28 14:22:10] WARNING[25976] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9990
[Sep 28 14:22:10] WARNING[25977] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9990
[Sep 28 14:36:27] WARNING[25975] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25971] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25970] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25972] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25979] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25977] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25974] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25973] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25975] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25971] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25978] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25972] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25979] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25976] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:36:27] WARNING[25970] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-9952
[Sep 28 14:42:54] WARNING[25972] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-7084
[Sep 28 14:42:54] WARNING[25970] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-7084
[Sep 28 14:42:54] WARNING[25977] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-7084
[Sep 28 14:42:54] WARNING[25975] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-7084
[Sep 28 14:42:54] WARNING[25976] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-7084
[Sep 28 14:42:54] WARNING[25972] channel.c: Exceptionally long voice queue
length queuing to IAX2/iaxasatna01-7084
But it doesn't immediatly make asterisk crash.


Anyway, twice a week, asterisk crashs : 
Sep 27 16:57:47 asw-na-01 kernel: asterisk[25381] general protection
rip:2aaac37876af rsp:2aab6f905cb0 error:0

/etc/init.d/asterisk restart, seem to restart correctly asterisk but I'm
unable to get into CLI (with asterisk -r), it freezes before the prompt.
I have to "Ctrl + C" and "kill -9" the duplicated safe_asterisk, before.

Even though I don't see those "Exceptionally long voice queue" message
just before the crash (they only appear several minutes before), I think
they are related.

I initially reported this problem in ticket 0015900.

I really don't know how to reproduce it and I can't really play with the
server, cause it processes about thousands calls a day.

Tell me if you want more infos or some tests. 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-09-28 08:32 YueNK          Note Added: 0111420                          
======================================================================