[asterisk-bugs] [Asterisk 0015609]: [patch] WARNING[23025]: channel.c:952 __ast_queue_frame: Exceptionally long voice queue length queuing to Local
Asterisk Bug Tracker
noreply at bugs.digium.com
Fri Nov 27 12:06:51 CST 2009
A NOTE has been added to this issue.
======================================================================
https://issues.asterisk.org/view.php?id=15609
======================================================================
Reported By: aragon
Assigned To: russell
======================================================================
Project: Asterisk
Issue ID: 15609
Category: Core/Channels
Reproducibility: have not tried
Severity: block
Priority: normal
Status: confirmed
Target Version: 1.4.28
Asterisk Version: SVN
JIRA: SWP-205
Regression: No
Reviewboard Link:
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-11-27 12:06 CST
======================================================================
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
----------------------------------------------------------------------
duplicate of 0015976 abort in filestream_destructor / ast_fi...
related to 0015109 [patch] Abort by memory allocator, poss...
has duplicate 0015900 Console flood & CPU load 100% when ...
has duplicate 0016096 Exceptionally long voice queue length q...
related to 0015817 crash in local_attended_transfer, likel...
related to 0015845 Crash during attended transfer occurs
related to 0015616 random crashes
related to 0016229 ERROR[24164]: utils.c:966 ast_carefulwr...
related to 0016081 [patch] utils.c:938 ast_carefulwrite: T...
======================================================================
----------------------------------------------------------------------
(0114330) aragon (reporter) - 2009-11-27 12:06
https://issues.asterisk.org/view.php?id=15609#c114330
----------------------------------------------------------------------
The problem from a high level analysis is that Asterisk delays RTP while
something is locked.
In our case Asterisk locks while doing some CDR reads/writes and
apparently during hangup phase when we try to write to MySQL CDR record. If
that database is corrupt then the Asterisk lock can take a very long time
while RTP is delayed. Other events like astdb get and put can also be
delayed to a point where the entire event is delayed past the
ast_carefulwrite threshold and not all info is written to the astdb file.
That results in agent login corruption.
After repairing the MySQL CDR database the warnings have disappeared and I
can no longer reproduce with a database show command. We have also added a
midnight routine to optimize MySQL database daily to prevent further
instances.
gdb_asterisk_pid_database_show.txt should have the required debug info to
determine whether the locking is normal or not. I attached gdb to Asterisk
while reproducing the error with a database show command. The same things
applies to database_show_valgrind.txt
Issue History
Date Modified Username Field Change
======================================================================
2009-11-27 12:06 aragon Note Added: 0114330
======================================================================
More information about the asterisk-bugs
mailing list