[Home]

Summary:ASTERISK-15985: Exceptionally long voice queuing when using chan\Local to playback Extensions
Reporter:Timothy M. Rodriguez (timothy055)Labels:
Date Opened:2010-04-20 12:35:59Date Closed:2011-06-07 14:04:42
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_local
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:I've been building a conferencing app leveraging AMI, local channels, and
the ConfBridge app that plays pre-recorded media into a conference.

To playback, I've been creating a local channel to a playback app
(carrying the file name as a channel variable) and then setting the
exten to the ConfBridge via AMI. However, I've noticed if I do enough
playbacks (especially one after the other) I get the following error:

WARNING[5918]: channel.c:1038 __ast_queue_frame: Exceptionally long
voice queue length queuing to Local/1@playback-68a9;1

I'm suspicious it's the use
of local channels to originate the call. Since I'd think this would get
picked up with all the use of asterisk as an IVR.



****** ADDITIONAL INFORMATION ******

The audio will either start partially into the file or end early when doing this.
Comments:By: Timothy M. Rodriguez (timothy055) 2010-04-21 15:36:18

I think there may be an issue with playback in general.  I've reconfigured the app to instead dial a playback extension on a 2nd asterisk instance (the save version) over a SIP trunk and the erratic playback continues if I really hammer the playback extension.  Sometimes, playback does not occur at all.  

stack
 == Spawn extension (playbackcontext, PLAY, 3) exited non-zero on 'SIP/asterisk1-00000006'
By: Leif Madsen (lmadsen) 2010-04-26 11:38:31

Could you provide the dialplan and scenarios that can allow a developer to easily reproduce this?
By: Timothy M. Rodriguez (timothy055) 2010-04-27 13:44:15

Sure thing.

First I have a context for creating ConfBridges

[confbridges]
exten => _XXXXX,1,ConfBridge(${EXTEN},q)
exten => _XXXX,1,ConfBridge(${EXTEN},q)
exten => _XXX,1,ConfBridge(${EXTEN},q)
exten => _XX,1,ConfBridge(${EXTEN},q)
exten => _X,1,ConfBridge(${EXTEN},q)

I then issue a originate commands (using asterisk java) to bridge in the users that look as follows:

Channel: SIP/trunktodialtone/userextension
Context: confbridges
Exten: 1 (or any 1-5 digit number)
Priority: 1

Once the users are dialed into the conference I bridge in a playback extension to play the file in another context:

[media]
exten => _PLAY.,1,Answer
exten => _PLAY.,2,Playback(${CALLERID(name)})
exten => _PLAY.,3,Hangup

exten => _REC.,1,Answer
exten => _REC.,2,Record(${CALLERID(name)}.ulaw,0)
exten => _REC.,3,Dial(SIP/asterisk1/${CALLERID(num)})

I would do so by setting the Callerid(Name) as the file name and using another originate action that looked as follows:

Channel: Local/PLAY@media
Context: confbridges
Exten: 1 (or whatever the current confbridge was)
Priority: 1

This would result in erratic playback behavior where the media either started a few seconds late or ended a few seconds early after a few playbacks.

I tried a few variations.

1.  I put the playback context and extensions on a separate asterisk instance and bridged them in over a SIP trunk. (suspecting it was a local channel issue).
2.  Thinking that I was hammering the specific dialplan entry too many times (PLAY in this instance) I modified the dialplan to read PLAY. and issued a sequence number after the extension so the Channel became: SIP/trunkToAsterisk2/PLAY1 (and 2 and so forth).

Both exhibited the same issues.  At times, it would even crash the initial asterisk which was running the ConfBridges.

I tried a few different sequences:

1.  Briding in the users and playing back media, allowing it to complete, and reinitiating.  (If I allowed enough time in between playbacks, this would seldom cause issue).
2.  Playing the same file into the bridge multiple times.  This would work very erratically.  (Sometimes you'd hear the file a different spacings, as you'd expect, other times the file would play, then play again, or it wouldn't play at all.)
3.  Playing the same or different files into different conference bridges.  This fell somewhere in between, but on the whole worked erratically as well.  Files would play, not play, or terminate early.
By: Timothy M. Rodriguez (timothy055) 2010-04-27 13:47:17

The sip trunks were configured as follows:

On the second asterisk:

[asterisk1]
type=friend
host=192.168.1.5
nat=no
dtmfmode=rfc2833
canreinvite=yes
qualify=yes
port=5060
context=media

On the first asterisk:

[asterisk2]
type=friend
host=192.168.1.6
nat=no
dtmfmode=rfc2833
canreinvite=yes
qualify=yes
port=5060
context=confbridges

[trunktodialtone]
type=friend
host=192.168.1.10
nat=no
dtmfmode=rfc2833
canreinvite=yes
qualify=yes
port=5060


By: Mikko Korkalo (keitsi) 2010-05-21 10:36:31

hi,

I posted comment @ https://issues.asterisk.org/view.php?id=16507
So I'll post here too. In short: changing ulaw to alaw helped me.
I don't know if it's related, just a heads up.

Maybe this helps someone, definitely did help me!
By: Paul Belanger (pabelanger) 2010-06-25 09:10:20

We require a complete debug log to help triage the issue.

This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue:

http://svn.digium.com/svn/asterisk/trunk/doc/HOWTO_collect_debug_information.txt
By: Paul Belanger (pabelanger) 2010-06-30 08:48:31

Suspended due to lack of activity. Please request a bug marshal in #asterisk-bugs on the IRC network irc.freenode.net to reopen the issue should you have the additional information requested.

Further information can be found at http://www.asterisk.org/developers/bug-guidelines