[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
Wed Sep 23 19:42:55 CDT 2009
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-23 19:42 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 & CPU load 100% when ...
related to 0015817 crash in local_attended_transfer, likel...
related to 0015845 Crash during attended transfer occurs
======================================================================
----------------------------------------------------------------------
(0111292) aragon (reporter) - 2009-09-23 19:42
https://issues.asterisk.org/view.php?id=15609#c111292
----------------------------------------------------------------------
euhhh,
After patching I have no SIP calls processing and no registered SIP
peers.
Lots of errors in CLI once I enable debug in logger.conf
Russel, I am happy to give you root access to this server.
I'll try to contact you on iirc tomorrow if you are around
Mostly the debug lines look like this
[Sep 23 20:35:06] DEBUG[5316]: db.c:196 ast_db_get: Unable to find key
'HotDesk' in family 'default/2538'
[Sep 23 20:35:11] DEBUG[5374]: manager.c:2232 process_message: Manager
received command 'Ping'
[Sep 23 20:35:12] DEBUG[9319]: manager.c:2232 process_message: Manager
received command 'login'
== Parsing '/etc/asterisk/manager.conf': [Sep 23 20:35:12] DEBUG[9319]:
config.c:895 config_text_file_load: Parsing /etc/asterisk/manager.conf
Found
[Sep 23 20:35:12] DEBUG[9319]: acl.c:355 ast_append_ha:
127.0.0.1/255.255.255.255 appended to acl for peer
[Sep 23 20:35:12] DEBUG[9319]: acl.c:370 ast_apply_ha: ##### Testing
127.0.0.1 with 127.0.0.1
[Sep 23 20:35:12] DEBUG[9319]: manager.c:2232 process_message: Manager
received command 'Command'
[Sep 23 20:35:12] DEBUG[9327]: manager.c:2232 process_message: Manager
received command 'login'
== Parsing '/etc/asterisk/manager.conf': [Sep 23 20:35:12] DEBUG[9327]:
config.c:895 config_text_file_load: Parsing /etc/asterisk/manager.conf
Found
[Sep 23 20:35:12] DEBUG[9327]: acl.c:355 ast_append_ha:
127.0.0.1/255.255.255.255 appended to acl for peer
[Sep 23 20:35:12] DEBUG[9327]: acl.c:370 ast_apply_ha: ##### Testing
127.0.0.1 with 127.0.0.1
[Sep 23 20:35:14] DEBUG[5091]: chan_sip.c:4761 sip_alloc: Allocating new
SIP dialog for 55c4ad5119dbc1e619331238127ad679 at 192.168.30.165 - REGISTER
(No RTP)
[Sep 23 20:35:14] DEBUG[5091]: chan_sip.c:8038 transmit_register:
Scheduled a registration timeout for 192.168.30.254 id
https://issues.asterisk.org/view.php?id=3408
[Sep 23 20:35:14] DEBUG[5091]: chan_sip.c:2300 __sip_semi_ack:
(Provisional) Stopping retransmission (but retaining packet) on
'55c4ad5119dbc1e619331238127ad679 at 192.168.30.165' Request 104: Found
[Sep 23 20:35:14] DEBUG[5091]: chan_sip.c:2258 __sip_ack: Stopping
retransmission on '55c4ad5119dbc1e619331238127ad679 at 192.168.30.165' of
Request 104: Match Found
[Sep 23 20:35:14] DEBUG[5091]: chan_sip.c:1694 initialize_initreq:
Initializing already initialized SIP dialog
55c4ad5119dbc1e619331238127ad679 at 192.168.30.165 (presumably reinvite)
[Sep 23 20:35:14] DEBUG[5091]: chan_sip.c:2300 __sip_semi_ack:
(Provisional) Stopping retransmission (but retaining packet) on
'55c4ad5119dbc1e619331238127ad679 at 192.168.30.165' Request 105: Found
[Sep 23 20:35:14] DEBUG[5380]: manager.c:2232 process_message: Manager
received command 'Ping'
[Sep 23 20:35:15] DEBUG[5091]: chan_sip.c:2258 __sip_ack: Stopping
retransmission on '55c4ad5119dbc1e619331238127ad679 at 192.168.30.165' of
Request 105: Match Found
[Sep 23 20:35:15] DEBUG[5091]: chan_sip.c:13138 handle_response_register:
Registration successful
[Sep 23 20:35:15] DEBUG[5091]: chan_sip.c:13141 handle_response_register:
Cancelling timeout 3408
[Sep 23 20:35:16] DEBUG[5374]: manager.c:2232 process_message: Manager
received command 'Ping'
[Sep 23 20:35:21] DEBUG[5374]: manager.c:2232 process_message: Manager
received command 'Ping'
[Sep 23 20:35:24] DEBUG[5380]: manager.c:2232 process_message: Manager
received command 'Ping'
[Sep 23 20:35:26] DEBUG[5374]: manager.c:2232 process_message: Manager
received command 'Ping'
Issue History
Date Modified Username Field Change
======================================================================
2009-09-23 19:42 aragon Note Added: 0111292
======================================================================
More information about the asterisk-bugs
mailing list