CVP Time Out Issue

[Roy_11]

Hi Experts ,

we have got below logs for very few calls in prod , could you please give some insights on this error and how to avoid this one  and need fix as well ?

102.222.251.208.1611943494355.92786,01/29/2021 13:07:06.650,A VoiceXML error occurred of type "error.badfetch": request (http://mediaserver:7000/CVP/Server) was timed out after 30000 milliseconds.
102.22.521.208.1611943494355.92786.,01/29/2021 13:07:06.650,An error has occurred.

Appreciate your all responses !!

Thanks! 

Roy 

[david.macias]

There's just not enough information. Can you reproduce this? Is there anything in the IIS logs showing what file was 404ed? One thing to consider is that there are times where a call doesn't fully connect/disconnect and you will see some random error messages when this happens. I call them "ghost calls" because they are there and not really there at the same time.

david

[Quigath]

Was there a failure case in one or more calls? If not, and you still saw this in the log then it might not be a problem. I see stuff like this all the time in my lab but it doesn't always mean there's a problem.

[Roy_11]

@Quigath 

its not happening for all call , its very few calls 1% of call were getting disconnect due to bat fetch error . not sure how to fix. its happening in production , could you please help me to fix this issue ?

@david.macias  hello david , here is answer for your questions .

when ever we called to IVR its playing well sometime during the call  we are facing issue call got disconnected it was played we are experiencing difficulties call has hangup . after i looked on backend logs  . Audio element  error showing  then call hangup on this audio element . below FYI Activity logs . could you please help us on this scenario 

Note : this is not custom audio element , this is default audio element .

,02/04/2021 09:21:42.710,StopExecution,enter,
02/04/2021 09:21:42.710,StopExecution,custom,MOHPath,http://102.221.511.207/en-us/app/HCC/MOH60.wav
,02/04/2021 09:21:45.546,StopExecution,interaction,audio_group,initial_audio_group
,02/04/2021 09:21:46.787,StopExecution,interaction,noinput,1
,02/04/2021 09:21:46.787,StopExecution,interaction,audio_group,noinput_audio_group
,02/04/2021 09:22:16.788,StopExecution,element,error,error.badfetch: request (http://mediaserver:7000/CVP/Server) was timed out after 30000 milliseconds.
,02/04/2021 09:22:16.788,StopExecution,exit,
,02/04/2021 09:22:16.788,StopExecution,exit,

[david.macias]

Is the failure always in the same spot? Often times while the activity log will show a failure in one spot it can mean the failure happened ahead of it. Anything in the error logs? Can you get VXML logs too?

david

[Roy_11]

@david.macias   Is the failure always in the same spot? No not same spot it will be dynamic spot but 1% of the calls were impacted .

Anything in the error logs? yes 

02/04/2021 12:46:16.662,A VoiceXML error occurred of type "error.badfetch": request (http://mediaserver:7000/CVP/Server) was timed out after 15000 milliseconds.
02/04/2021 12:46:16.662,An error has occurred.

Thanks!

Roy S

[david.macias]

You're going to have to go to your VXML browser logs either from the gateway or VVB. Can you post those?

david

[Roy_11]

Adding CVP Logs :

%CVP_11_6_VXML_SERVER-7-LOW_LEVEL: {Thrd=http-processor39} TimeOutManager:addObserver(), sessionid=A42988B8AF1F4D0737099A44E079372AApplication name=MicroApp,SessionMap size = 1454
%CVP_11_6_VXML_SERVER-3-VXML_SERVER_ERROR: CALLGUID= 467EE8CB663311EB8123D248FA8FCAD9, DNIS=6083238961, ANI=18137843287, APPNAME = AppV7 - null [id:6022]
%CVP_11_6_VXML-3-VXML_SERVER_VXML_API_ERROR: In element StopExecution encountered VXML_ERROR_EVENT with message: request (http://mediaserver:7000/CVP/Server) was timed out, after 30000 milliseconds.. The The name of the VoiceXML error event is error.badfetch. [id:6015]
%CVP_11_6_VXML-7-LOW_LEVEL: {Thrd=Thread-294} DatafeedQueueThread, AppName=AppV7, QueueSize = 0
%CVP_11_6_VXML-3-VXML_CALL_ERROR: DatafeedMgr.handleErrorEvent(): Call 467EE8CB663311EB8123D248FA8FCAD9 in application AppV7's element StopExecution encountered VXML_ERROR_EVENT with message: Error occurred in error.badfetch: request (http://mediaserver:7000/CVP/Server) was timed out, after 30000 milliseconds.. The name of the VoiceXML error event is error.badfetch. [id:6003]
%CVP_11_6_VXML-1-VXML_SERVER_SYSTEM_ERROR: In application AppV7 encountered SYSTEM_ERROR_EVENT with message: null. [id:6014]
%CVP_11_6_VXML-3-VXML_CALL_ERROR: DatafeedMgr.handleErrorEvent(): Call 467EE8CB663311EB8123D248FA8FCAD9 in application AppV7 encountered SYSTEM_ERROR_EVENT with message: null. [id:6003]
%CVP_11_6_VXML_SERVER-6-VXML_SERVER_CALLGUID_INFO: [CALL_RESULT]- Received callid=772FA9CD663311EB856DD248FA8FCAD9 [id:6021]
3

Thanks!

ROy

[david.macias]

These are not browser logs. You'll need to get those from the gateway or from the VVB.

david

[Roy_11]

@david.macias 

please find the VVB logs here , the call ID is 1FF649856BF011EBB6C7D248FA8FCAD9 , please do needful.

Thanks in advance!!!!!!

thanks!

Roy S

[david.macias]

I don't believe this is the whole log as the very first instance of that call id shows the timeout error. Need a log with the call from the very beginning.

I see you're using Nuance have you look at those logs to see if you're running out of licenses? You can get a bad fetch or no resource when that happens.

david

[Roy_11]

Please find the whole logs here , Thanks Roy

[david.macias]

On this log there's a single usable trace of a call (D33626EC6BEF11EBADF4D248FA8FCAD9) experiencing the error you mentioned, however the error seems to have happened after the call was sent to post call survey. It's not clear to me why it happened though as there's not enough verbosity in the logs, but I suspect an API call that is taking longer than 10 seconds, which happens often. I would maybe start with seeing how many more calls are failing in this spot, if a good bit, what happens in the post call survey that might be causing this, then fix. From there go to the next occurrence of the error and track it down.

david

[Roy_11]

Hello david 

Thanks for your quick info , But here i am attaching all logs like VVB , CVP and VXML logs as well with all debug enabled  . this log has all info which is related to failed call due to bad. fetch 

ANI :918667232280

Call ID 474B263B7E2111EBBA76D248FA8FCAD9 

VVB Info :::::::::::

admin:show status

Host Name          : AARCWIVPAP15011

Date               : Fri Feb 26, 2021 05:31:54

Time Zone          : Central Standard Time (America/Chicago)

Locale             : en_US.UTF-8

Product Ver        : 12.0.1.10000-17

Unified OS Version : 6.0.0.0-2

License MAC        : 55b76122c441

Uptime:

05:31:55 up  8:36,  1 user,  load average: 0.00, 0.02, 0.00

CPU Idle:   99.50%  System:   00.25%    User:   00.25%

  IOWAIT:   00.00%     IRQ:   00.00%    Soft:   00.00%

Memory Total:        8062100K

        Free:        3765144K

        Used:        4296956K

      Cached:        1491832K

      Shared:         311364K

     Buffers:         136816K

                        Total            Free            Used

Disk/active         26953964K       16550932K       10127864K (38%)

Disk/inactive       26953964K       15985144K       10693652K (41%)

Disk/logging        94110596K       35648556K       53674792K (61%)

admin:show version active

Active Master Version: 12.0.1.10000-17

Active Version Installed Software Options:

ciscovb.1161.ES01.82.cop

ciscovb.1161.ES01.81.cop

ciscovb.1161.ES01.82.Rollback.cop

ciscovb.1161.ES01.83.cop

ciscovb.1201.ES07.cop

admin:utils system upgrade status

Upgrade status: Ready to be configured

Thanks in advance 

[david.macias]

There are a good bit of bad fetches in those logs, it's going to take way too long through go to them and things are pretty busy right now. You need to identify who is throwing the 404 or what timer is causing this error to be triggered. A few things you want to look at:

- Missing prompts

- Backends that are taking longer than expected and you're not catching the timeout accurately

- Licenses running out

Good luck.

david