Exceptionally long voice queue length

Hello guys,

I use the current configuration:

  1. Asterisk 1.8.1 installed on the Ubuntu Linux 12.04
  2. Unimrcp server and extension 1.2.0 installed on the same machine
  3. Nuance TTS installed on the CenstOS

Current flow:

Asterisk is calling to the user -> user take a phone -> Nuance produces TSS through unimrcp asterisk extension

Current issue:

From time to time users got ''missed calls" from the asterisk, so it looks like asterisk is calling but just for a second, in asterisk logs it looks like there was a call, asterisk wait for 30 seconds and then recieve NO_ANSWED

Errors in the logs:
in the messages log file there is pattern for this issues:

[Oct 22 17:42:51] WARNING[30794] channel.c: Exceptionally long voice queue length queuing to Local/com.hae.servicecentre.dialOut.callNotify.CnArgAgiScript@java-agi-context-0b4d;2
Oct 22 17:49:00] NOTICE[12071] app_unimrcp.c: Destroy MRCP Handle TTS-10662
[Oct 22 17:49:00] NOTICE[31210] app_mrcpsynth.c: MRCPSynth() exiting status: INTERRUPTED on Local/com.hae.servicecentre.dialOut.callNotify.CnArgAgiScript@java-agi-context-8fed;2

And in general there are a lot of entries of this WARN messages:

Oct 22 17:42:51] WARNING[30794] channel.c: Exceptionally long voice queue length queuing to Local/com.hae.servicecentre.dialOut.callNotify.CnArgAgiScript@java-agi-context-0b4d;2

So my questions are:

  1. What does this error “channel.c: Exceptionally long voice queue length queuing to Local” mean
    what is this queue and why it can be too long

  2. How I can troubleshoot such issues

Thanks in advance,
Dmitriy

It is a queue of media and control frames that have been read by a channel, or sent as input to it, that are waiting to be processed (e.g. to be forwarded to another channel). The channel in question is a Local channel, rather than a real external one. Its name is “Local/com.hae.servicecentre.dialOut.callNotify.CnArgAgiScript@java-agi-context-0b4d;2”. The ;2 indicates that it is the outgoing half of the local channel (the one that actually runs the dialplan code for it).

The normal reason for it to get over long is that nothing is actually servicing it. This might be because of a deadlock, but there is far too little information to be sure.

Many thanks for your answer !

What details I can provide to describe this situation more? maybe some config files?

Could this situation happened because Nuance server can not process TSS from this queue ?

Thanks,
Dmitriy

Here is the dial plan for this flow

#include /etc/asterisk/test-call.conf
#include /etc/asterisk/mrcp-test.conf

[java-agi-context]
;
; at some point in time the outgoing caller-id needs to be set to the correct number
; like: exten => s,n,Set(CALLERID(number)=20654908x)
;
;;if we do not have a matching rule, send it to agi://localhost:/packagname.classname.agi
;;the reason for requiring a beginning with com is
;;is the prevention of matches against special extensions like t,s etc
exten => _com.,1,Agi(${agiServerUrl}/${EXTEN}?internalRequestId=${internalRequestId})
exten => h,1,Agi(${agiServerUrl}/${agiScriptName}Hangup?internalRequestId=${internalRequestId})
; maybe cleanup should be here, added 16/05/2013
exten => h,n,NoOp(DBdel ${internalRequestId})
exten => h,n,DBdeltree(${internalRequestId})

[java-meetme]

; at some point in time the outgoing caller-id needs to be set to the correct number
; like: exten => s,n,Set(CALLERID(number)=20654908x)
;
exten => s,1,Set(DB(${internalRequestId}/${PARTY_NAME}Status)=joined)
;share channel for easy retrieval by agiScript. for hanging up
exten => s,n,Set(DB(${internalRequestId}/${PARTY_NAME}Channel)=${CHANNEL})
exten => s,n,Set(DB(${internalRequestId}/${PARTY_NAME}Room)=${CONVERENCE_ROOM})
; uncomment MeetMe call as soon as we have “asterisk-dahdi” package installed
exten => s,n,MeetMe(${CONVERENCE_ROOM},${MEETME_OPTS})
exten => h,1,NoOp(${CALLERID}left)
;set variable to indicate callee has hung up to agi/meetme participants
exten => h,n,Set(DB(${internalRequestId}/${PARTY_NAME}Status)=left)
exten => h,n,Agi(${agiServerUrl}/${cleanupScript}?internalRequestId=${internalRequestId})
;wait so agiScript can read the status
exten => h,n,wait(60)
;clean up variables in database
exten => h,n,DBdel(${internalRequestId}/${PARTY_NAME}Status)
exten => h,n,DBdel(${internalRequestId}/${PARTY_NAME}Channel)
exten => h,n,DBdel(${internalRequestId}/${PARTY_NAME}Room)

;
; end of dialplan parts

wiki.asterisk.org/wiki/display/ … nformation

This is almost certainly the result of a bug, although there is likely to be something about your dialplan that is a co-factor.

Thanks for your reply David,

I increase debug level on the production environment and got the output.
However output is not clear for me.

I would like to provide this files:

  1. https://drive.google.com/file/d/0B5yGAV9fFmZMdllEUms1VWJyVkk/view?usp=sharing -short version

  2. https://drive.google.com/file/d/0B5yGAV9fFmZMa3NlM2t6MGw2OFk/view?usp=sharing - full version

Could someone point me to me to some bad flows in this log files ?

Thanks in advance,
Dmitriy