Comprehensive CVP Call Flow

[Ahmed Adeyemi]

Hello All,

        I have a CVP Script that i have been battling with for a few days now. On the ICM Script, i have  the flow as such

Start--> Set Variable (Media Server)--> Set Variable (Media Lib)--> Set Variable (ToExtVXML) -->Set Variable (UseVXMLParam)-->Run Ext Scritp (Play media) --> Run Ext Script (CVP Studio App)--> Queue to Skill Group) and release the call in any failure path.

I am unable to get the call past the Run External Script as seen in the attachment from ICM. Below is also the log from CVP Call Server.

I have checked the Dialed Number and the ECC Variable names to make sure they are spelt correctly and that the dialed number is in there correctly.

The call flow is CIPC-->CUCM-->CVP Call Server-->ICM-->CVP Call Server-->VVB-->CVP Call/VXML Server-->ICM

Looking at the log, the call never actually makes it to the VXML Server. The only error i see on the call server is "[DIALOG_FAILURE_EVENT] DialogID=10 SendSeqNo=1 ErrorCode=E_INVALID_DIALED_NUMBER" but i am stuck on what to do.

310: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DATAI.2} parseAndUpdateUuidsForResponse(String): remoteUuid=dc46918daa904b23d3fe1230bab63ba0, localUuid=00000000000000000000000000000000
 
311: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DATAI.2} Found an incoming CISCO-GUID hdr : 2892208000-0000065536-0000000020-1031763722, Generated a new CVP-ID hdr : AC63978000010000000000143D7F770A  
312: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DATAI.2} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: Display Name ["Test CIPC"] Is Using Survivability [false] CallServer build CVP_11_5_1_0_1_0_349  
313: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-PARAM:  {Thrd=DATAI.2} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: ReqURI (DN) sip:16576679998@10.119.127.75:5060 FromURI sip:16578599000@onevoicelab.com Video:false m_needs_postcallsurvey:false  
314: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DATAI.2} getMySessionIDHeader: value=00000000000000000000000000000000;remote=dc46918daa904b23d3fe1230bab63ba0  
315: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DATAI.2} NEW CALL with guid=AC63978000010000000000143D7F770A legid=ac639780-95e1c5b4-da4-3d7f770a dn=16576679998 ani=16578599000 uui=null calldate=Thu Jul 06 16:18:29 PDT 2017 video=false cachecallcontext = false is_postcallsurvey = false RouterCallKey = null RouterCallKeyDay = null RouterCallKeySequenceNumber = null  
316: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DATAI.2} Sending msg:>>HEADERS: (JMSType)=MsgBus:NEW_CALL (JMSDestination)=Topic(CVP.SIP.CC.REQ) (JMSTimestamp)=1499383109843 >>BODY: replyto=true callguid=AC63978000010000000000143D7F770A ani=16578599000 dnis=16576679998 timezone=America/Los_Angeles version=CVP_11_5 pstntrkgrpsrcip=10.119.127.61 calldate=Thu Jul 06 16:18:29 PDT 2017 calltypeid=4 localOffset=-420 calllegid=ac639780-95e1c5b4-da4-3d7f770a  >>STATE: isTabular=false isWriteable=true cursor=-1  
317: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DATAI.2} Sending msg:ICMEvent, sessionId=AC63978000010000000000143D7F770A callId=ac639780-95e1c5b4-da4-3d7f770a dialogId=0 sourceId=ac639780-95e1c5b4-da4-3d7f770a systemType=SIP mediatype= dnis=16576679998 ani=16578599000 srcAddress=10.119.127.61 locationsiteid=sessionId=AC63978000010000000000143D7F770A callType=4 cacheCallContext=false postcallsurveycall=false icmMessage=NEW_CALL  
561: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Core-router-group-0} --NEW SESSION CREATED--CALLGUID=AC63978000010000000000143D7F770A NUMBER OF ACTIVE SESSIONS= 1  
97: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID = AC63978000010000000000143D7F770A - New call  
98: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Processing from SIP_SS - [NEW_CALL] DialogID=0 SendSeqNo=0 DNIS=16576679998 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=AC63978000010000000000143D7F770A trunkGroupId=0 trunkNumber=0 serviceId=0 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables= ECC arrays= Peripheral Variables=  
99: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to UCCE - [NEW_CALL] DialogID=9 SendSeqNo=1 DNIS=16576679998 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=AC63978000010000000000143D7F770A trunkGroupId=100 trunkNumber=0 serviceId=1 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables=user.media.id: AC63978000010000000000143D7F770A, ECC arrays= Peripheral Variables=  
100: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Processing from UCCE - ,, [ICM_TEMPORARY_CONNECT], rckey=30609308, rcday=152127, DNIS=16576679998, ANI=16578599000  
101: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to SIP_SS - [CONNECT] DialogID=9 SendSeqNo=0 Label=777777 TxrHint=false rckey=152127 rcday=152127 rcseq=0 location= locationpkid= sipheader= uui= whisperAnnounce=null callguid=AC63978000010000000000143D7F770A ECC variables=user.media.id: AC63978000010000000000143D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=  
318: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND] Handling CONNECT :[CONNECT] DialogID=9 SendSeqNo=0 Label=777777 TxrHint=false rckey=152127 rcday=152127 rcseq=0 location= locationpkid= sipheader= uui= whisperAnnounce=null callguid=AC63978000010000000000143D7F770A ECC variables=user.media.id: AC63978000010000000000143D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=  
319: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} Static route matched 7777775 to StaticRoute: patterns like 777777> will route to vvb.onevoicelab.com  
320: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} Using Local Static Route for sip:7777775@vvb.onevoicelab.com  
321: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} Inside updateSessionIDForPassThrough  
322: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} parseAndUpdateUuidsForResponse(String): remoteUuid=dc46918daa904b23d3fe1230bab63ba0, localUuid=00000000000000000000000000000000
 
323: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} Found an incoming CISCO-GUID hdr : 2892208000-0000065536-0000000020-1031763722, Found an existing CVP-ID hdr: AC63978000010000000000143D7F770A  
324: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: INVITE TO <sip:7777775@vvb.onevoicelab.com;transport=tcp> FROM "Test CIPC" <sip:16578599000@10.119.127.75:5060> EXPIRES[60] 100REL[Unsupported]  
325: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-256-SIP-245} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]Trying to set headers in INVITE with these operations:   
326: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: Invitation proceeding 100  
327: 10.119.127.75: Jul 06 2017 16:18:29.843 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} No Session ID found in this request.  
328: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: Invitation accepted - ack'ing  
329: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: NO P_Asserted_Identity.   
330: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: CountObserver() is >0 and sending Re-Invite to caller.  
331: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-LOW:  {Thrd=pool-1-thread-257-SIP-246} Setting uuid to: 1a3298d31000015d231789f79020ea61  
332: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-257-SIP-246} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: Updated by : CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: with event type INV_ACCEPTED  
333: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-257-SIP-246} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: Send the 200 OK back to caller with SDP of this dialog.  
334: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-257-SIP-246} getMySessionIDHeader: value=1a3298d31000015d231789f79020ea61;remote=dc46918daa904b23d3fe1230bab63ba0  
335: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-257-SIP-246} Sending BUS MSG for Event Reportnew CSS:[EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=ANSWER CauseCode=CAUSE_NONE  
336: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-257-SIP-246} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1499383109875 >>BODY: callguid=AC63978000010000000000143D7F770A RouterCallKey=30609308 RouterCallKeySent=false causecode=0 timezone=America/Los_Angeles RouterCallKeySequenceNumber=0 version=CVP_11_5 labeltype=-1 RouterCallKeyDay=152127 calldate=Thu Jul 06 16:18:29 PDT 2017 label=7777775 localOffset=-420 eventid=4 calllegid=AC63978000010000000000143D7F770A-14993831098435  >>STATE: isTabular=false isWriteable=true cursor=-1  
102: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Processing from SIP_SS - [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=ANSWER CauseCode=CAUSE_NONE  
103: 10.119.127.75: Jul 06 2017 16:18:29.875 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to UCCE - [EVENT_REPORT] DialogID=9 SendSeqNo=2 EventID=ANSWER CauseCode=NONE  
337: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: DsSipInviteDialog ack'ed  
338: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} Inside updateSessionIDForPassThrough  
339: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} parseAndUpdateUuidsForResponse(String): remoteUuid=dc46918daa904b23d3fe1230bab63ba0, localUuid=1a3298d31000015d231789f79020ea61
 
340: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-LOW:  {Thrd=pool-1-thread-258-SIP-247} Setting uuid to: dc46918daa904b23d3fe1230bab63ba0  
341: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-258-SIP-247} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: Updated by : CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: with event type INV_ACKED  
342: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-258-SIP-247} Inside sendAckOnInvite   
343: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-258-SIP-247} getMySessionIDHeader: value=dc46918daa904b23d3fe1230bab63ba0;remote=1a3298d31000015d231789f79020ea61  
344: 10.119.127.75: Jul 06 2017 16:18:29.890 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-258-SIP-247} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: Acked the invite.  
562: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A CALLID=AC63978000010000000000143D7F770A [IVR]  - processing from VXMLServer - [NEW_CALL] ClientNewCallEvent,sessionId=AC63978000010000000000143D7F770A ani=sip:16578599000@10.119.127.75:5060 dnis=7777775 uui= callId=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 seqNo=1 invokationId=0 message=null ccbServletUrl= ccbServletReqTimeout=0  
563: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A CALLID=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 [IVR]  [Publishing to ICM_SS] [NEW_CALL] DialogID=0 SendSeqNo=0 DNIS=7777775 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=AC63978000010000000000143D7F770A trunkGroupId=0 trunkNumber=0 serviceId=0 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables= ECC arrays= Peripheral Variables=  
564: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CallServerReportingProvider:sendNewCall: CALLGUID=AC63978000010000000000143D7F770A DNIS=7777775 Publishing NewCall message: >>HEADERS: (JMSType)=MsgBus:NEW_CALL (AppName)=IVR >>BODY: replyto=true uui= callguid=AC63978000010000000000143D7F770A ani=16578599000 dnis=7777775 timezone=America/Los_Angeles mediatype=A version=CVP_11_5 calldate=Thu Jul 06 16:18:29 PDT 2017 location= calltypeid=5 localOffset=-420 calllegid=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75  >>STATE: isTabular=false isWriteable=true cursor=-1  
104: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID = AC63978000010000000000143D7F770A - New call  
105: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=10 [IVR_VRU_LEG_DIALOGUE] - Processing from IVR_SS - [NEW_CALL] DialogID=0 SendSeqNo=0 DNIS=7777775 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=AC63978000010000000000143D7F770A trunkGroupId=0 trunkNumber=0 serviceId=0 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables= ECC arrays= Peripheral Variables=  
106: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=10 [IVR_VRU_LEG_DIALOGUE] - Publishing to UCCE - [NEW_CALL] DialogID=10 SendSeqNo=1 DNIS=7777775 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=AC63978000010000000000143D7F770A trunkGroupId=100 trunkNumber=1 serviceId=1 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables=user.media.id: AC63978000010000000000143D7F770A, ECC arrays= Peripheral Variables=  
107: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=10 [IVR_VRU_LEG_DIALOGUE] - Processing  from UCCE - [DIALOG_FAILURE_EVENT] DialogID=10 SendSeqNo=1 ErrorCode=E_INVALID_DIALED_NUMBER  
108: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=10 [IVR_VRU_LEG_DIALOGUE] - Publishing to IVR_SS - [DIALOG_FAILURE_EVENT] DialogID=10 SendSeqNo=1 ErrorCode=E_INVALID_DIALED_NUMBER  
565: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A CALLID=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 [IVR]  [processing from ICM_SS] [DIALOG_FAILURE_EVENT] DialogID=10 SendSeqNo=1 ErrorCode=E_INVALID_DIALED_NUMBER  
566: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} IvrConnection:registerDisonnectTimer: CALLGUID=AC63978000010000000000143D7F770A CALLID=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 [IVR]  Register Disonnect Timer   
567: 10.119.127.75: Jul 06 2017 16:18:29.921 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A CALLID=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 [IVR]  - Publishing to VXMLServer -  [DIALOG_FAILURE_EVENT] DialogID=10 SendSeqNo=1 ErrorCode=E_INVALID_DIALED_NUMBER  
568: 10.119.127.75: Jul 06 2017 16:18:31.968 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A CALLID=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 [IVR]  process Timer Event   
569: 10.119.127.75: Jul 06 2017 16:18:31.968 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A CALLID=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 [IVR]  [Publishing to ICM_SS] [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_NORMAL_COMPLETION  
570: 10.119.127.75: Jul 06 2017 16:18:31.968 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CallServerReportingProvider:sendIVRCallStateEvent: CALLGUID=AC63978000010000000000143D7F770A DNIS=7777775CallStateEvent message: >>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (AppName)=IVR >>BODY: callguid=AC63978000010000000000143D7F770A dnis=7777775 RouterCallKeySent=false causecode=1 timezone=America/Los_Angeles version=CVP_11_5 calldate=Thu Jul 06 16:18:31 PDT 2017 localOffset=-420 calllegid=AC63978000010000000000143D7F770A-14993831098435@10.119.127.75 eventid=6  >>STATE: isTabular=false isWriteable=true cursor=-1  
571: 10.119.127.75: Jul 06 2017 16:18:31.968 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CallSession:removeConnectionByCallId: CALLGUID=AC63978000010000000000143D7F770A--REMOVING CONNECTION-- callId=AC63978000010000000000143D7F770A  
109: 10.119.127.75: Jul 06 2017 16:18:31.968 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=10 [IVR_VRU_LEG_DIALOGUE] - Processing from IVR_SS - [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_NORMAL_COMPLETION  
110: 10.119.127.75: Jul 06 2017 16:18:31.968 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=10 [IVR_VRU_LEG_DIALOGUE] - Publishing to UCCE - [EVENT_REPORT] DialogID=10 SendSeqNo=2 EventID=DISCONNECT CauseCode=CAUSE_NORMAL_COMPLETION  
572: 10.119.127.75: Jul 06 2017 16:18:31.968 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CallSession:removeConnectionByDialogId: CALLGUID=AC63978000010000000000143D7F770A--REMOVING CONNECTION-- dialogId=10  
345: 10.119.127.75: Jul 06 2017 16:18:35.452 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} Inside updateSessionIDForPassThrough  
346: 10.119.127.75: Jul 06 2017 16:18:35.452 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND] DURATION (msecs) = 5609 - DIALOG TERMINATED. Reason: Q.850;cause=16
 
347: 10.119.127.75: Jul 06 2017 16:18:35.452 -0700: %CVP_11_5_SIP-7-LOW:  {Thrd=pool-1-thread-259-SIP-248} Setting uuid to: 1a3298d31000015d231789f79020ea61  
348: 10.119.127.75: Jul 06 2017 16:18:35.452 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-259-SIP-248} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: Updated by : CALLGUID = AC63978000010000000000143D7F770A LEGID = AC63978000010000000000143D7F770A-14993831098435 - [OUTBOUND]: with event type TERMINATED  
349: 10.119.127.75: Jul 06 2017 16:18:35.452 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-260-SIP-249} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: Waiting 2000 millisecs before terminating.  
350: 10.119.127.75: Jul 06 2017 16:18:35.452 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-260-SIP-249} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: Registering Timer 2000 millisecs before terminating.  
351: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-261-SIP-250} Sending BUS MSG for Event Reportnew CSS:[EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_CALLED_PARTY_DISCONNECTED  
111: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Processing from SIP_SS - [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_CALLED_PARTY_DISCONNECTED  
352: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-261-SIP-250} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1499383117468 >>BODY: callguid=AC63978000010000000000143D7F770A RouterCallKey=30609308 RouterCallKeySent=true causecode=13 timezone=America/Los_Angeles RouterCallKeySequenceNumber=0 version=CVP_11_5 labeltype=-1 RouterCallKeyDay=152127 calldate=Thu Jul 06 16:18:37 PDT 2017 label=7777775 localOffset=-420 eventid=6 calllegid=ac639780-95e1c5b4-da4-3d7f770a  >>STATE: isTabular=false isWriteable=true cursor=-1  
353: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-261-SIP-250} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND] DURATION (msecs) = 7625 - HANGUP with Call History7777775|-1;  
112: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_ICM-7-CALL:  {Thrd=Event-router-group-0} CALLGUID=AC63978000010000000000143D7F770A DialogId=9 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to UCCE - [EVENT_REPORT] DialogID=9 SendSeqNo=3 EventID=DISCONNECT CauseCode=CAUSE_CALLED_PARTY_DISCONNECTED  
354: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_SIP-7-LOW:  {Thrd=pool-1-thread-261-SIP-250} Adding session ID header in bye message  
355: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-261-SIP-250} getMySessionIDHeader: value=1a3298d31000015d231789f79020ea61;remote=dc46918daa904b23d3fe1230bab63ba0  
573: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} CallSession:removeConnectionByDialogId: CALLGUID=AC63978000010000000000143D7F770A--REMOVING CONNECTION-- dialogId=9  
574: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Event-router-group-0} -- SESSION DESTROYED--CALLGUID=AC63978000010000000000143D7F770A NUMBER OF ACTIVE SESSIONS= 0  
356: 10.119.127.75: Jul 06 2017 16:18:37.468 -0700: %CVP_11_5_SIP-7-CALL:  {Thrd=pool-1-thread-261-SIP-250} CALLGUID = AC63978000010000000000143D7F770A LEGID = ac639780-95e1c5b4-da4-3d7f770a - [INBOUND]: Terminated with Q.850;cause=16  
575: 10.119.127.75: Jul 06 2017 16:18:38.124 -0700: %CVP_11_5_IVR-7-CALL:  {Thrd=Global-task-executor-group-2} CallServerStatsManager:[[CallServer Stats][SessionManager Stats:[Total Number of Active Sessions=0][Total Number of Deleted Sessions=0][Total Number of Pcs Sessions=0][[CallServerPoolManager Stats][SessionPool Stats:[Total Number of Active Sessions=0][Total Number of Idle Sessions=1][IvrConnectionPool Stats:[Total Number of Active IvrConnections=0][Total Number of Idle IvrConnections=0][IvrConnectionPool Stats:[Total Number of Active IcmConnections=0][Total Number of Idle IcmConnections=1][NewDialogHandlerPool Stats:[Total Number of Active NewDialogHandlers=0][Total Number of Idle NewDialogHandlers=0]
[[QueueManager Stats][Name=CALLSERVER_TRANSPORT_MANAGER_QUEUE,Max Size=32768,Current Size=0[Name=EVENT_ROUTER_QUEUE,Max Size=15360,Current Size=0[Name=CALLSERVER_REPORTING_PROVIDER_QUEUE,Max Size=32768,Current Size=0[Name=SIP_MESSAGE_QUEUE,Max Size=32768,Current Size=0[[CallServer Worker Stats messages/second][TransportManager Reader Worker=0][EventRouter  Worker=0][[CallServer Worker TimerManager stats]Total Active TImer=0  

[Chintan Gajjar · Accepted solution]

from a glance, looks like the CVP is treating VRU leg as a new call and sending new call request to ICM.

Please use Send to VRU node, ans see if you get success there first.

couple of question:

1. whats the length of the network VRU label?

2. whats the Max DNIS set under ICM tab on your call server?

Max DNIS length on CVP should exactly match to length of the configured VRU label in ICM.

[Ahmed Adeyemi]

Thats for the response. Originally, i had the maximum DNIS on the ICM tab as 11 and i had 7 digit in the Network VRU Label. I updated the Network VRU to 11 digits and also added the send to VRU node and i still get the same result.

249: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID = 75CF6080000100000000002B3D7F770A - New call
250: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Processing from SIP_SS - [NEW_CALL] DialogID=0 SendSeqNo=0 DNIS=16576679998 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=75CF6080000100000000002B3D7F770A trunkGroupId=0 trunkNumber=0 serviceId=0 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables= ECC arrays= Peripheral Variables=
251: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to UCCE - [NEW_CALL] DialogID=23 SendSeqNo=1 DNIS=16576679998 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=75CF6080000100000000002B3D7F770A trunkGroupId=100 trunkNumber=0 serviceId=1 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables=user.media.id: 75CF6080000100000000002B3D7F770A, ECC arrays= Peripheral Variables=
252: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Processing from UCCE - ,, [ICM_TEMPORARY_CONNECT], rckey=307, rcday=152128, DNIS=16576679998, ANI=16578599000
253: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to SIP_SS - [CONNECT] DialogID=23 SendSeqNo=0 Label=77777777777 TxrHint=false rckey=152128 rcday=152128 rcseq=0 location= locationpkid= sipheader= uui= whisperAnnounce=null callguid=75CF6080000100000000002B3D7F770A ECC variables=user.media.id: 75CF6080000100000000002B3D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=
656: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND] Handling CONNECT :[CONNECT] DialogID=23 SendSeqNo=0 Label=77777777777 TxrHint=false rckey=152128 rcday=152128 rcseq=0 location= locationpkid= sipheader= uui= whisperAnnounce=null callguid=75CF6080000100000000002B3D7F770A ECC variables=user.media.id: 75CF6080000100000000002B3D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=
657: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} Static route matched 7777777777712 to StaticRoute: patterns like 777777> will route to vvb.onevoicelab.com
658: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} Using Local Static Route for sip:7777777777712@vvb.onevoicelab.com
659: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} Inside updateSessionIDForPassThrough
660: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} parseAndUpdateUuidsForResponse(String): remoteUuid=dc46918daa904b23d3fe1230bab63ba0, localUuid=00000000000000000000000000000000

661: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} Found an incoming CISCO-GUID hdr : 1976524928-0000065536-0000000043-1031763722, Found an existing CVP-ID hdr: 75CF6080000100000000002B3D7F770A
662: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: INVITE TO <sip:7777777777712@vvb.onevoicelab.com;transport=tcp> FROM "Test CIPC" <sip:16578599000@10.119.127.75:5060> EXPIRES[60] 100REL[Unsupported]
663: 10.119.127.75: Jul 07 2017 08:01:48.008 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-229-SIP-729} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]Trying to set headers in INVITE with these operations:
664: 10.119.127.75: Jul 07 2017 08:01:48.023 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: Invitation proceeding 100
665: 10.119.127.75: Jul 07 2017 08:01:48.023 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} No Session ID found in this request.
666: 10.119.127.75: Jul 07 2017 08:01:48.039 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: Invitation accepted - ack'ing
667: 10.119.127.75: Jul 07 2017 08:01:48.039 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: NO P_Asserted_Identity.
668: 10.119.127.75: Jul 07 2017 08:01:48.039 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: CountObserver() is >0 and sending Re-Invite to caller.
669: 10.119.127.75: Jul 07 2017 08:01:48.039 -0700: %CVP_11_5_SIP-7-LOW: {Thrd=pool-1-thread-230-SIP-730} Setting uuid to: 1d9237771000015dd61846566e7ac00f
670: 10.119.127.75: Jul 07 2017 08:01:48.039 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-230-SIP-730} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: Updated by : CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: with event type INV_ACCEPTED
671: 10.119.127.75: Jul 07 2017 08:01:48.039 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-230-SIP-730} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: Send the 200 OK back to caller with SDP of this dialog.
672: 10.119.127.75: Jul 07 2017 08:01:48.055 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-230-SIP-730} getMySessionIDHeader: value=1d9237771000015dd61846566e7ac00f;remote=dc46918daa904b23d3fe1230bab63ba0
673: 10.119.127.75: Jul 07 2017 08:01:48.055 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-230-SIP-730} Sending BUS MSG for Event Reportnew CSS:[EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=ANSWER CauseCode=CAUSE_NONE
254: 10.119.127.75: Jul 07 2017 08:01:48.055 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Processing from SIP_SS - [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=ANSWER CauseCode=CAUSE_NONE
674: 10.119.127.75: Jul 07 2017 08:01:48.055 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-230-SIP-730} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1499439708055 >>BODY: callguid=75CF6080000100000000002B3D7F770A RouterCallKey=307 RouterCallKeySent=false causecode=0 timezone=America/Los_Angeles RouterCallKeySequenceNumber=0 version=CVP_11_5 labeltype=-1 RouterCallKeyDay=152128 calldate=Fri Jul 07 08:01:48 PDT 2017 label=7777777777712 localOffset=-420 eventid=4 calllegid=75CF6080000100000000002B3D7F770A-149943970800812 >>STATE: isTabular=false isWriteable=true cursor=-1
255: 10.119.127.75: Jul 07 2017 08:01:48.055 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to UCCE - [EVENT_REPORT] DialogID=23 SendSeqNo=2 EventID=ANSWER CauseCode=NONE
675: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: DsSipInviteDialog ack'ed
676: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} Inside updateSessionIDForPassThrough
677: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} parseAndUpdateUuidsForResponse(String): remoteUuid=dc46918daa904b23d3fe1230bab63ba0, localUuid=1d9237771000015dd61846566e7ac00f

678: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-LOW: {Thrd=pool-1-thread-231-SIP-731} Setting uuid to: dc46918daa904b23d3fe1230bab63ba0
679: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-231-SIP-731} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: Updated by : CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: with event type INV_ACKED
680: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-231-SIP-731} Inside sendAckOnInvite
681: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-231-SIP-731} getMySessionIDHeader: value=dc46918daa904b23d3fe1230bab63ba0;remote=1d9237771000015dd61846566e7ac00f
682: 10.119.127.75: Jul 07 2017 08:01:48.070 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-231-SIP-731} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: Acked the invite.
1638: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A [IVR] - processing from VXMLServer - [NEW_CALL] ClientNewCallEvent,sessionId=75CF6080000100000000002B3D7F770A ani=sip:16578599000@10.119.127.75:5060 dnis=7777777777712 uui= callId=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 seqNo=1 invokationId=0 message=null ccbServletUrl= ccbServletReqTimeout=0
1639: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] [Publishing to ICM_SS] [NEW_CALL] DialogID=0 SendSeqNo=0 DNIS=7777777777712 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=75CF6080000100000000002B3D7F770A trunkGroupId=0 trunkNumber=0 serviceId=0 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables= ECC arrays= Peripheral Variables=
1640: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CallServerReportingProvider:sendNewCall: CALLGUID=75CF6080000100000000002B3D7F770A DNIS=7777777777712 Publishing NewCall message: >>HEADERS: (JMSType)=MsgBus:NEW_CALL (AppName)=IVR >>BODY: replyto=true uui= callguid=75CF6080000100000000002B3D7F770A ani=16578599000 dnis=7777777777712 timezone=America/Los_Angeles mediatype=A version=CVP_11_5 calldate=Fri Jul 07 08:01:48 PDT 2017 location= calltypeid=5 localOffset=-420 calllegid=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 >>STATE: isTabular=false isWriteable=true cursor=-1
256: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID = 75CF6080000100000000002B3D7F770A - Correlation ID routed call
257: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=24 [IVR_VRU_LEG_DIALOGUE] - Processing from IVR_SS - [NEW_CALL] DialogID=0 SendSeqNo=0 DNIS=7777777777712 ANI=16578599000 CED= rckey=0 rcday=0 rcseq=0 uui= callguid=75CF6080000100000000002B3D7F770A trunkGroupId=0 trunkNumber=0 serviceId=0 calledNumber= location= locationpkid= pstntrunkgroupid= sipheader= ECC variables= ECC arrays= Peripheral Variables=
258: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=24 [IVR_VRU_LEG_DIALOGUE] - Publishing to UCCE - [REQUEST_INSTRUCTION] DialogID=24 SendSeqNo=1 ANI=16578599000 DNIS=7777777777712 correlationId=12 trunkGroupId=200 trunkNumber=0 serviceId=2 uui= calledNumber= location= locationpkid= pstntrunkgroupid= pstntrunkgroupchannelnum=0 sipheader=
259: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=24 [IVR_VRU_LEG_DIALOGUE] - Processing from UCCE - [RUN_SCRIPT_REQ] DialogID=24 SendSeqNo=1 InvokeID=1 scriptId=GS,Server,V scriptConfiguration= ANI=16578599000 ced= callguid=75CF6080000100000000002B3D7F770A rckey=307 rcday=152128 rcseq=1 uui= featureType=0 featureParam1= _featureParam2= ECC variables=user.media.id: 75CF6080000100000000002B3D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=
260: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=24 [IVR_VRU_LEG_DIALOGUE] - Publishing to IVR_SS - [RUN_SCRIPT_REQ] DialogID=24 SendSeqNo=1 InvokeID=1 scriptId=GS,Server,V scriptConfiguration= ANI=16578599000 ced= callguid=75CF6080000100000000002B3D7F770A rckey=307 rcday=152128 rcseq=1 uui= featureType=0 featureParam1= _featureParam2= ECC variables=user.media.id: 75CF6080000100000000002B3D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=
1641: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] [processing from ICM_SS] [RUN_SCRIPT_REQ] DialogID=24 SendSeqNo=1 InvokeID=1 scriptId=GS,Server,V scriptConfiguration= ANI=16578599000 ced= callguid=75CF6080000100000000002B3D7F770A rckey=307 rcday=152128 rcseq=1 uui= featureType=0 featureParam1= _featureParam2= ECC variables=user.media.id: 75CF6080000100000000002B3D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=
1642: 10.119.127.75: Jul 07 2017 08:01:48.102 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] - Publishing to VXMLServer - [RUN_SCRIPT_REQ] DialogID=24 SendSeqNo=1 InvokeID=1 scriptId=GS,Server,V scriptConfiguration= ANI=16578599000 ced= callguid=75CF6080000100000000002B3D7F770A rckey=307 rcday=152128 rcseq=1 uui= featureType=0 featureParam1= _featureParam2= ECC variables=user.media.id: 75CF6080000100000000002B3D7F770A,user.microapp.app_media_lib: ..,user.microapp.media_server: http://10.119.127.75:7000/CVP,user.microapp.UseVXMLParams: N, ECC arrays=USER_MICROAPP_TOEXTVXML[0]:application=onevoicelab, Peripheral Variables=
1643: 10.119.127.75: Jul 07 2017 08:01:52.774 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Global-task-executor-group-7} CallServerStatsManager:[[CallServer Stats][SessionManager Stats:[Total Number of Active Sessions=1][Total Number of Deleted Sessions=0][Total Number of Pcs Sessions=0][[CallServerPoolManager Stats][SessionPool Stats:[Total Number of Active Sessions=1][Total Number of Idle Sessions=0][IvrConnectionPool Stats:[Total Number of Active IvrConnections=1][Total Number of Idle IvrConnections=0][IvrConnectionPool Stats:[Total Number of Active IcmConnections=2][Total Number of Idle IcmConnections=0][NewDialogHandlerPool Stats:[Total Number of Active NewDialogHandlers=0][Total Number of Idle NewDialogHandlers=0]
[[QueueManager Stats][Name=CALLSERVER_TRANSPORT_MANAGER_QUEUE,Max Size=32768,Current Size=0[Name=EVENT_ROUTER_QUEUE,Max Size=15360,Current Size=0[Name=CALLSERVER_REPORTING_PROVIDER_QUEUE,Max Size=32768,Current Size=0[Name=SIP_MESSAGE_QUEUE,Max Size=32768,Current Size=0[[CallServer Worker Stats messages/second][TransportManager Reader Worker=0][EventRouter Worker=0][[CallServer Worker TimerManager stats]Total Active TImer=-6
683: 10.119.127.75: Jul 07 2017 08:01:54.211 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} Inside updateSessionIDForPassThrough
684: 10.119.127.75: Jul 07 2017 08:01:54.211 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND] DURATION (msecs) = 6203 - DIALOG TERMINATED. Reason: Q.850;cause=16

685: 10.119.127.75: Jul 07 2017 08:01:54.211 -0700: %CVP_11_5_SIP-7-LOW: {Thrd=pool-1-thread-232-SIP-732} Setting uuid to: 1d9237771000015dd61846566e7ac00f
686: 10.119.127.75: Jul 07 2017 08:01:54.211 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-232-SIP-732} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: Updated by : CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75CF6080000100000000002B3D7F770A-149943970800812 - [OUTBOUND]: with event type TERMINATED
687: 10.119.127.75: Jul 07 2017 08:01:54.211 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-233-SIP-733} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: Waiting 2000 millisecs before terminating.
688: 10.119.127.75: Jul 07 2017 08:01:54.211 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-233-SIP-733} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: Registering Timer 2000 millisecs before terminating.
689: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-234-SIP-734} Sending BUS MSG for Event Reportnew CSS:[EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_CALLED_PARTY_DISCONNECTED
261: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Processing from SIP_SS - [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_CALLED_PARTY_DISCONNECTED
690: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-234-SIP-734} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1499439716242 >>BODY: callguid=75CF6080000100000000002B3D7F770A RouterCallKey=307 RouterCallKeySent=true causecode=13 timezone=America/Los_Angeles RouterCallKeySequenceNumber=0 version=CVP_11_5 labeltype=-1 RouterCallKeyDay=152128 calldate=Fri Jul 07 08:01:56 PDT 2017 label=7777777777712 localOffset=-420 eventid=6 calllegid=75cf6080-95f1a2ce-2556-3d7f770a >>STATE: isTabular=false isWriteable=true cursor=-1
262: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=23 [SIP_SWITCH_LEG_DIALOGUE] - Publishing to UCCE - [EVENT_REPORT] DialogID=23 SendSeqNo=3 EventID=DISCONNECT CauseCode=CAUSE_CALLED_PARTY_DISCONNECTED
691: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-234-SIP-734} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND] DURATION (msecs) = 8234 - HANGUP with Call History7777777777712|-1;
692: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_SIP-7-LOW: {Thrd=pool-1-thread-234-SIP-734} Adding session ID header in bye message
693: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-234-SIP-734} getMySessionIDHeader: value=1d9237771000015dd61846566e7ac00f;remote=dc46918daa904b23d3fe1230bab63ba0
1644: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CallSession:removeConnectionByDialogId: CALLGUID=75CF6080000100000000002B3D7F770A--REMOVING CONNECTION-- dialogId=23
694: 10.119.127.75: Jul 07 2017 08:01:56.242 -0700: %CVP_11_5_SIP-7-CALL: {Thrd=pool-1-thread-234-SIP-734} CALLGUID = 75CF6080000100000000002B3D7F770A LEGID = 75cf6080-95f1a2ce-2556-3d7f770a - [INBOUND]: Terminated with Q.850;cause=16
1645: 10.119.127.75: Jul 07 2017 08:01:59.274 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CallSession:forceCleanup: CALLGUID=75CF6080000100000000002B3D7F770AAbnormally ending CALLGUID=75CF6080000100000000002B3D7F770A DialogId=24 [IVR_VRU_LEG_DIALOGUE]
1646: 10.119.127.75: Jul 07 2017 08:01:59.274 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] [processing from ICM_SS] [DISCONNECT] DialogID=24 SendSeqNo=0 Cause=E_INVALID_VERSION
1647: 10.119.127.75: Jul 07 2017 08:01:59.274 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} IvrConnection:registerDisonnectTimer: CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] Register Disonnect Timer
1648: 10.119.127.75: Jul 07 2017 08:01:59.274 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] adding to pending Queue- [DISCONNECT] DialogID=24 SendSeqNo=0 Cause=E_INVALID_VERSION
1649: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] process Timer Event
1650: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] [Publishing to ICM_SS] [RUN_SCRIPT_RESULT] DialogID=0 SendSeqNo=0 InvokeID=1 Result=1 CED= newTransaction=0 ECC variables=user.microapp.error_code: 1, ECC arrays= Peripheral Variables=
1651: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CallServerReportingProvider:sendRunScriptResult: CALLGUID=75CF6080000100000000002B3D7F770A DNIS=7777777777712 Publishing RunScriptResult message: >>HEADERS: (JMSType)=MsgBus:SCRIPT_RESULT (AppName)=IVR >>BODY: callguid=75CF6080000100000000002B3D7F770A floatingvars=>>HEADERS: (JMSType)=MsgBus:FLOATINGVARS >>BODY: user.microapp.caller_input= user.microapp.error_code=1 >>STATE: isTabular=false isWriteable=true cursor=-1 dnis=7777777777712 resultcode=false timezone=America/Los_Angeles version=CVP_11_5 calldate=Fri Jul 07 08:02:01 PDT 2017 localOffset=-420 calllegid=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 requestid=1 >>STATE: isTabular=false isWriteable=true cursor=-1
1652: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A CALLID=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 [IVR] [Publishing to ICM_SS] [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_NORMAL_COMPLETION
1653: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CallServerReportingProvider:sendIVRCallStateEvent: CALLGUID=75CF6080000100000000002B3D7F770A DNIS=7777777777712CallStateEvent message: >>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (AppName)=IVR >>BODY: callguid=75CF6080000100000000002B3D7F770A dnis=7777777777712 RouterCallKeySent=false causecode=1 timezone=America/Los_Angeles version=CVP_11_5 calldate=Fri Jul 07 08:02:01 PDT 2017 localOffset=-420 calllegid=75CF6080000100000000002B3D7F770A-149943970800812@10.119.127.75 eventid=6 >>STATE: isTabular=false isWriteable=true cursor=-1
1654: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CallSession:removeConnectionByCallId: CALLGUID=75CF6080000100000000002B3D7F770A--REMOVING CONNECTION-- callId=75CF6080000100000000002B3D7F770A
263: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=24 [IVR_VRU_LEG_DIALOGUE] - Processing from IVR_SS - [EVENT_REPORT] DialogID=0 SendSeqNo=0 EventID=DISCONNECT CauseCode=CAUSE_NORMAL_COMPLETION
264: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_ICM-7-CALL: {Thrd=Event-router-group-0} CALLGUID=75CF6080000100000000002B3D7F770A DialogId=24 [IVR_VRU_LEG_DIALOGUE] - Publishing to UCCE - [EVENT_REPORT] DialogID=24 SendSeqNo=2 EventID=DISCONNECT CauseCode=CAUSE_NORMAL_COMPLETION
1655: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} CallSession:removeConnectionByDialogId: CALLGUID=75CF6080000100000000002B3D7F770A--REMOVING CONNECTION-- dialogId=24
1656: 10.119.127.75: Jul 07 2017 08:02:01.336 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Event-router-group-0} -- SESSION DESTROYED--CALLGUID=75CF6080000100000000002B3D7F770A NUMBER OF ACTIVE SESSIONS= 0
1657: 10.119.127.75: Jul 07 2017 08:02:52.790 -0700: %CVP_11_5_IVR-7-CALL: {Thrd=Global-task-executor-group-8} CallServerStatsManager:[[CallServer Stats][SessionManager Stats:[Total Number of Active Sessions=0][Total Number of Deleted Sessions=0][Total Number of Pcs Sessions=0][[CallServerPoolManager Stats][SessionPool Stats:[Total Number of Active Sessions=0][Total Number of Idle Sessions=0][IvrConnectionPool Stats:[Total Number of Active IvrConnections=0][Total Number of Idle IvrConnections=0][IvrConnectionPool Stats:[Total Number of Active IcmConnections=0][Total Number of Idle IcmConnections=0][NewDialogHandlerPool Stats:[Total Number of Active NewDialogHandlers=0][Total Number of Idle NewDialogHandlers=0]
[[QueueManager Stats][Name=CALLSERVER_TRANSPORT_MANAGER_QUEUE,Max Size=32768,Current Size=0[Name=EVENT_ROUTER_QUEUE,Max Size=15360,Current Size=0[Name=CALLSERVER_REPORTING_PROVIDER_QUEUE,Max Size=32768,Current Size=0[Name=SIP_MESSAGE_QUEUE,Max Size=32768,Current Size=0[[CallServer Worker Stats messages/second][TransportManager Reader Worker=0][EventRouter Worker=0][[CallServer Worker TimerManager stats]Total Active TImer=-7

[Chintan Gajjar]

Hi, Please attach the log file as an attachment.

If you copy paste the full logs it would show unnecessarily stretch the thread and it makes difficult to find out the latest comment.

now coming back to the actual problem, i see the difference now at least from the logs.

the Invalid Dialned numbed thing is gone and the send to VRU should be successful now.

i also see the call going into your VXML app "onevoicelab".

so now we have to focus on VXML part of it:

--> How does your VXML application look?

--> can you attach activity logs from VXML app?

--> is it deployed and running on VXML server?

--> test changing VXML app from "onevoicelab" to "HelloWorld" and check if it works?

[Ahmed Adeyemi]

Thank you. Yes the CVP app is deployed. I have the VXML Server activity log below as well as the screenshot of the app. Its complaining about not having a TTS server which i don't have the TTS parameter or any information in the TTS box.

Looking the HelloWorld Log, it looks like it worked from the log side, but all i hear on the phone side is just a beep and the call disconnects 4 seconds after the been, which is the same behavior i see on the onevoicelab app as well.

[Chintan Gajjar]

can you ping vlabccecvp1p.onevoicelab.com from your VXML gateway/voice browser?. it should resolve to CVP media server.

[Ahmed Adeyemi]

Yes, i am able to ping the name and also the IP Address from the VVB

[Chintan Gajjar]

Whats the version of VVB? from the logs i can see CVP is 11.5.

[Ahmed Adeyemi]

Its 11.5.1.10000-60

[Chintan Gajjar]

Hi, Can you collect the VVB engine logs covering the calls you made and attach to the thread, if possible also attach the VXML app.

[Ahmed Adeyemi]

Here are the logs/App. The call was placed at 8:04AM on July 9th (7/9) and its the only call on the flow. 

test_onevoicelab.zip-- Application used during this testing

cisco001mivr015.txt-- MIVR Logs from the VVB

activity_log2017 07-07-21-32-16.tx: Activity log based on the test_onevoicelab application

onevoicelab.zip-- Previous application used for testing. 

In all of this testing, no audio was heard at all. This also includes placing a call to the HelloWorld app, i don't hear any audio being played.

[Chintan Gajjar · Accepted solution]

i see you have application test_obevoicelab working fine from the logs:

20883: Jul 09 08:06:49.771 PDT %MIVR-SS_VB-7-UNK:[CALLID=3AB1668000010000000000503D7F770A-149961268308124] playAndRecognize done.
20884: Jul 09 08:06:49.774 PDT %MIVR-SS_VB-7-UNK:[CALLID=3AB1668000010000000000503D7F770A-149961268308124] Fetch:    http://10.119.127.75:7000/CVP/Server
20885: Jul 09 08:06:49.782 PDT %MIVR-SS_VB-7-UNK:[CALLID=3AB1668000010000000000503D7F770A-149961268308124] Fetch:    http://10.119.127.75:7000/CVP/Server
20886: Jul 09 08:06:49.786 PDT %MIVR-SS_VB-7-UNK:[CALLID=3AB1668000010000000000503D7F770A-149961268308124] playAndBargeIn Listen:   
20887: Jul 09 08:06:50.036 PDT %MIVR-SS_VB-7-UNK:[CALLID=3AB1668000010000000000503D7F770A-149961268308124] playAndBargeIn done.
20888: Jul 09 08:06:50.037 PDT %MIVR-SS_VB-7-UNK:[CALLID=3AB1668000010000000000503D7F770A-149961268308124] Fetch:    http://10.119.127.75:7000/CVP/Serve



The audio issue might be with some network or firewall blocking the RTP packets between phone and VVB.

whats the call flow? where is your phone registered and how it is reaching CVP?
while on call you can press "?" button twice on ip phone and see if the voice packets are received and what codec is choosen. 

[Ahmed Adeyemi]

Thanks. I am now able to get it to play the audio. I restarted the VXML Server and the VVB and now the audio is play through.

Just for everyone's reference, the call flow is 

Internal phone-->CUCM-->CVP Call Server-->ICM-->CVP Call Server-->VVB-->VXML Gateway-->ICM--> CVP Call Server-->CUCM if an agent is available or disconnect if no one is available.

[Chintan Gajjar]

glad that its working now!!

[Ahmed Adeyemi]

For some reason, it keeps generating the call as a new call when it returns from VVB/VXML Browser.