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

[Asterisk Bug Tracker]

The following issue requires your FEEDBACK. 
====================================================================== 
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:                   minor
Priority:                   normal
Status:                     feedback
Asterisk Version:           SVN 
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-08-04 13:19 CDT
====================================================================== 
Summary:                    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)
=== -------------------------------------------------------------------


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

---------------------------------------------------------------------- 
 (0108605) mmichelson (administrator) - 2009-08-04 13:19
 https://issues.asterisk.org/view.php?id=15609#c108605 
---------------------------------------------------------------------- 
That "core show locks" output is just plain bizarre. It's showing that the
autoservice thread cannot lock the aslist because the aslist was already
locked by another autoservice thread. The problem with this condition is
that there is supposed to only be *one* autoservice thread running, ever.

Was the core show locks output repeated many times, or was it just showing
that one thread? For anyone that is able to make this happen, it would be
helpful to see a gdb backtrace of all threads from an unoptimized build so
that I or someone else can verify that there are two autoservice threads
running.

Also for Ayth and cstadlmann, do you also see the same "core show locks"
output aragon is reporting, or are you just seeing the "exceptionally long
queue" message?  

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-08-04 13:19 mmichelson     Note Added: 0108605                          
2009-08-04 13:19 mmichelson     Status                   new => feedback     
======================================================================