144: 10.0.1.254: Sep 06 2016 19:47:25.121 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DATAI.2} Found an incoming CISCO-GUID hdr : 1462558336-0000065536-0000000001-4244701194, Generated a new CVP-ID hdr : 572CDE800001000000000001FD01000A 145: 10.0.1.254: Sep 06 2016 19:47:25.121 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DATAI.2} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Display Name ["Test Line 1001"] Is Using Survivability [false] CallServer build CVP_10_5_1_0_0_0_189 146: 10.0.1.254: Sep 06 2016 19:47:25.121 +0100: %CVP_10_5_SIP-7-PARAM: {Thrd=DATAI.2} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: ReqURI (DN) sip:82222222221@10.0.1.254:5060 FromURI sip:1001@10.0.1.253 Video:true m_needs_postcallsurvey:false 147: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DATAI.2} NEW CALL with guid=572CDE800001000000000001FD01000A legid=572cde80-7cf10f3a-2-fd01000a dn=82222222221 ani=1001 uui=null calldate=Tue Sep 06 19:47:25 BST 2016 video=true cachecallcontext = false is_postcallsurvey = false RouterCallKey = null RouterCallKeyDay = null RouterCallKeySequenceNumber = null 148: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DATAI.2} Sending msg:>>HEADERS: (JMSType)=MsgBus:NEW_CALL (JMSDestination)=Topic(CVP.SIP.CC.REQ) (JMSTimestamp)=1473187645136 >>BODY: replyto=true callguid=572CDE800001000000000001FD01000A ani=1001 dnis=82222222221 timezone=Europe/London mediatype=V version=CVP_10_5 pstntrkgrpsrcip=10.0.1.253 calldate=Tue Sep 06 19:47:25 BST 2016 calltypeid=7 localOffset=60 calllegid=572cde80-7cf10f3a-2-fd01000a >>STATE: isTabular=false isWriteable=true cursor=-1 106: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-112-ICM-1} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = -1 [null] - Processing ,, [MsgBus:NEW_CALL], ssId=SYS_SIP1, mediaType=V, location=, locationpkid=, locationsiteid=, srcaddr=10.0.1.253, pstntrunkgroupid=10.0.1.253 , pstntrunkgroupchannelnum=2147483647, sipheader=, rckey=, rcday=, rcseq=, uui=, calltypeid=7, CallContext:, user.media.id: 572CDE800001000000000001FD01000A, user.microapp.cvpmovies_params: B,, LEGID = null, DNIS = -1, ANI = -1 107: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-112-ICM-1} CALLGUID = 572CDE800001000000000001FD01000A - Correlation ID routed call 108: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-112-ICM-1} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Publishing ,, [ICM_REQUEST_INSTRUCTION], dialogueId=1, sendSeqNo=1, trunkGroupId=200, trunkNumber=0, serviceId=2, uui=, correlationId=1, location=, locationpkid=, pstntrunkgroupid=10.0.1.253 , pstntrunkgroupchannelnum=2147483647, sipheader=,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 109: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-113-ICM-2} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Processing ,, [ICM_TEMPORARY_CONNECT], dialogueId=1, sendSeqNo=1, label=8111111111, correlationId=2, callguid=572CDE800001000000000001FD01000A, rckey=70573100, rcday=151824, rcseq=2, CallContext:, user.microapp.input_type: D, user.microapp.UseVXMLParams: N, user.microapp.locale: en-gb, user.microapp.media_server: http://10.0.1.254,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 110: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-113-ICM-2} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Publishing ,, [MsgBus:CONNECT], ssId=SYS_SIP1, labelType=, label=8111111111, correlationId=2, command=null, rckey=70573100, rcday=151824, rcseq=2, CallContext:, user.microapp.input_type: D, user.microapp.UseVXMLParams: N, user.microapp.locale: en-gb, user.microapp.media_server: http://10.0.1.254,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 149: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-114-SIP-109} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] Handling CONNECT :>>HEADERS: (JMSType)=MsgBus:CONNECT (JMSDestination)=Topic(CVP.ICM.CC.RESP.SYS_SIP1) (JMSTimestamp)=1473187645136 (ServerID)=Call-Server-01.SYS_ICM1:ICM:ICM1:Call-Server-01.MsgBus001 >>BODY: callguid=572CDE800001000000000001FD01000A RouterCallKey=70573100 floatingvars=>>HEADERS: (JMSType)=MsgBus:FLOATINGVARS >>BODY: callvars=[, , , , , , , , , ] user.microapp.media_server=http://10.0.1.254 user.microapp.FromExtVXML=[null, null, null, null] user.microapp.ToExtVXML=[null, null, null, null, null] user.microapp.UseVXMLParams=N user.microapp.locale=en-gb user.microapp.input_type=D >>STATE: isTabular=false isWriteable=true cursor=-1 dnis=82222222221 correlationid=2 timezone=Europe/London RouterCallKeySequenceNumber=2 version=CVP_10_5 RouterCallKeyDay=151824 labeltype=-1 label=81111111112 localOffset=60 calllegid=572cde80-7cf10f3a-2-fd01000a >>STATE: isTabular=false isWriteable=false cursor=-1 150: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-114-SIP-109} Static route matched 81111111112 to StaticRoute: patterns like 8111111111> will route to vxml.mylab.local 151: 10.0.1.254: Sep 06 2016 19:47:25.136 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-114-SIP-109} Using Local Static Route for sip:81111111112@vxml.mylab.local 152: 10.0.1.254: Sep 06 2016 19:47:25.152 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-114-SIP-109} Found an incoming CISCO-GUID hdr : 1462558336-0000065536-0000000001-4244701194, Found an existing CVP-ID hdr: 572CDE800001000000000001FD01000A 153: 10.0.1.254: Sep 06 2016 19:47:25.152 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-114-SIP-109} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: INVITE TO FROM "Test Line 1001" EXPIRES[60] 100REL[Unsupported] 154: 10.0.1.254: Sep 06 2016 19:47:25.167 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: Invitation proceeding 100 155: 10.0.1.254: Sep 06 2016 19:47:25.415 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: Invitation accepted - ack'ing 156: 10.0.1.254: Sep 06 2016 19:47:25.415 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: NO P_Asserted_Identity. 157: 10.0.1.254: Sep 06 2016 19:47:25.431 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: CountObserver() is >0 and sending Re-Invite to caller. 158: 10.0.1.254: Sep 06 2016 19:47:25.431 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-115-SIP-110} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: with event type INV_ACCEPTED 159: 10.0.1.254: Sep 06 2016 19:47:25.431 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-115-SIP-110} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Send the 200 OK back to caller with SDP of this dialog. 160: 10.0.1.254: Sep 06 2016 19:47:25.431 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-115-SIP-110} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1473187645431 (ServerID)=Call-Server-01.SYS_SIP1:SIP:SIP1:Call-Server-01.MsgBus001 >>BODY: callguid=572CDE800001000000000001FD01000A RouterCallKey=70573100 RouterCallKeySent=false causecode=0 timezone=Europe/London RouterCallKeySequenceNumber=2 version=CVP_10_5 labeltype=-1 RouterCallKeyDay=151824 calldate=Tue Sep 06 19:47:25 BST 2016 label=81111111112 localOffset=60 eventid=4 calllegid=572CDE800001000000000001FD01000A-14731876451361 >>STATE: isTabular=false isWriteable=false cursor=-1 111: 10.0.1.254: Sep 06 2016 19:47:25.446 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-116-ICM-3} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = -1 [null] - Processing ,, [MsgBus:CALL_STATE_EVENT], ssId=SYS_SIP1, eventId=ANSWER, causeCode=NONE,, LEGID = null, DNIS = 82222222221, ANI = 1001 112: 10.0.1.254: Sep 06 2016 19:47:25.446 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-116-ICM-3} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Publishing ,, [ICM_EVENT_REPORT], dialogueId=1, sendSeqNo=2, eventId=ANSWER, causeCode=NONE,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 161: 10.0.1.254: Sep 06 2016 19:47:25.462 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: DsSipInviteDialog ack'ed 162: 10.0.1.254: Sep 06 2016 19:47:25.462 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-117-SIP-111} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: with event type INV_ACKED 163: 10.0.1.254: Sep 06 2016 19:47:25.462 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-117-SIP-111} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: Acked the invite. 60: 10.0.1.254: Sep 06 2016 19:47:25.601 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor1} VBServlet:service: HTTP Request from 10.0.1.249: { RECOVERY_VXML=flash:recovery.vxml, VERSION=CVP_10_5_1_0_0_0_189, CALL_DNIS=81111111112, CALL_UUI=, MSG_TYPE=PING, CALL_ID=572CDE800001000000000001FD01000A, ERROR_CODE=NONE(0), CLIENT_TYPE=IOS, CALL_LEGID=572CDE800001000000000001FD01000A-14731876451361@10.0.1.254, CALL_ANI=sip:1001@10.0.1.254:5060 } 61: 10.0.1.254: Sep 06 2016 19:47:25.601 +0100: %CVP_10_5_IVR-6-VBCLIENT_ADDED: Added client - Type: IOS Name: 10.0.1.249 [id:3013] 62: 10.0.1.254: Sep 06 2016 19:47:25.617 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor1} VXMLManager:generateVXML: CALLGUID=572CDE800001000000000001FD01000A Generated VXML from template 'SubmitBack.template' for client: 10.0.1.249 clientType: IOS 63: 10.0.1.254: Sep 06 2016 19:47:25.617 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor2} VBServlet:service: HTTP Request from 10.0.1.249: { RECOVERY_VXML=flash:recovery.vxml, CALL_DNIS=81111111112, CALL_UUI=, MSG_TYPE=CALL_NEW, ERROR_CODE=NONE(0), CALL_ID=572CDE800001000000000001FD01000A, CLIENT_TYPE=IOS, CALL_ANI=sip:1001@10.0.1.254:5060 } 64: 10.0.1.254: Sep 06 2016 19:47:25.617 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor2} CallSession:addCall: CALLGUID=572CDE800001000000000001FD01000A Added IVRCall ( DNIS=81111111112 client: 10.0.1.249) to CallSession at slot: 0 65: 10.0.1.254: Sep 06 2016 19:47:25.617 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor2} CallMsgPublisher:sendNewCall: CALLGUID=572CDE800001000000000001FD01000A DNIS=81111111112 Publishing NewCall message: >>HEADERS: (JMSType)=MsgBus:NEW_CALL >>BODY: replyto=true uui= callguid=572CDE800001000000000001FD01000A ani=sip:1001@10.0.1.254:5060 dnis=81111111112 timezone=Europe/London mediatype=A version=CVP_10_5 calldate=Tue Sep 06 19:47:25 BST 2016 location= calltypeid=5 localOffset=60 calllegid= >>STATE: isTabular=false isWriteable=true cursor=-1 113: 10.0.1.254: Sep 06 2016 19:47:25.617 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-118-ICM-4} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = -1 [null] - Processing ,, [MsgBus:NEW_CALL], ssId=SYS_IVR1, mediaType=A, location=, locationpkid=, locationsiteid=, srcaddr=, pstntrunkgroupid=, pstntrunkgroupchannelnum=2147483647, sipheader=, rckey=, rcday=, rcseq=, uui=, calltypeid=5, CallContext:, user.media.id: 572CDE800001000000000001FD01000A,, LEGID = null, DNIS = 82222222221, ANI = 1001 114: 10.0.1.254: Sep 06 2016 19:47:25.617 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-118-ICM-4} CALLGUID = 572CDE800001000000000001FD01000A - Correlation ID routed call 115: 10.0.1.254: Sep 06 2016 19:47:25.617 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-118-ICM-4} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Publishing ,, [ICM_REQUEST_INSTRUCTION], dialogueId=2, sendSeqNo=1, trunkGroupId=200, trunkNumber=1, serviceId=2, uui=, correlationId=2, location=, locationpkid=, pstntrunkgroupid=, pstntrunkgroupchannelnum=2147483647, sipheader=,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 116: 10.0.1.254: Sep 06 2016 19:47:25.632 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-119-ICM-5} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Processing ,, [ICM_RUN_SCRIPT_REQ], dialogueId=2, sendSeqNo=1, invokedId=1, scriptId=GD,-9,A,1, scriptConfiguration=1,1,Y,3,5,1,1,N,N,N, ced=, callguid=572CDE800001000000000001FD01000A, rckey=70573100, rcday=151824, rcseq=3, CallContext:, CallVariable9: CCAM_PM.wav, user.microapp.input_type: D, user.microapp.UseVXMLParams: N, user.microapp.locale: en-gb, user.microapp.media_server: http://10.0.1.254,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 117: 10.0.1.254: Sep 06 2016 19:47:25.632 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-119-ICM-5} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Publishing ,, [MsgBus:RUN_SCRIPT_REQ], ssId=SYS_IVR1, requestId=1, scriptId=GD,-9,A,1, scriptConfig=1,1,Y,3,5,1,1,N,N,N, ced=, rckey=70573100, rcday=151824, rcseq=3, switch_leg_ani=1001, switch_leg_dnis=82222222221, CallContext:, CallVariable9: CCAM_PM.wav, user.microapp.input_type: D, user.microapp.UseVXMLParams: N, user.microapp.locale: en-gb, user.microapp.media_server: http://10.0.1.254,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 66: 10.0.1.254: Sep 06 2016 19:47:25.632 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=SubscriptionMgr} CallMsgListener:onMsg: CALLGUID=572CDE800001000000000001FD01000A DNIS=81111111112 Received Call message : >>HEADERS: (JMSType)=MsgBus:RUN_SCRIPT_REQ (JMSDestination)=Topic(CVP.ICM.CC.REQ.SYS_IVR1) (JMSTimestamp)=1473187645632 (ServerID)=Call-Server-01.SYS_ICM1:ICM:ICM1:Call-Server-01.MsgBus001 >>BODY: ced= scriptconfiguration=1,1,Y,3,5,1,1,N,N,N callguid=572CDE800001000000000001FD01000A RouterCallKey=70573100 ani=1001 floatingvars=>>HEADERS: (JMSType)=MsgBus:FLOATINGVARS >>BODY: callvars=[, , , , , , , , CCAM_PM.wav, ] user.microapp.media_server=http://10.0.1.254 user.microapp.FromExtVXML=[null, null, null, null] user.microapp.ToExtVXML=[null, null, null, null, null] user.microapp.UseVXMLParams=N user.microapp.locale=en-gb user.microapp.input_type=D >>STATE: isTabular=false isWriteable=true cursor=-1 dnis=81111111112 timezone=Europe/London RouterCallKeySequenceNumber=3 version=CVP_10_5 RouterCallKeyDay=151824 localOffset=60 switch_leg_dnis=82222222221 switch_leg_ani=1001 calllegid= scriptid=GD,-9,A,1 requestid=1 >>STATE: isTabular=false isWriteable=false cursor=-1 67: 10.0.1.254: Sep 06 2016 19:47:25.632 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor2} VXMLManager:generateVXML: CALLGUID=572CDE800001000000000001FD01000A Generated VXML from template 'GetDigits-Regex.template' for client: 10.0.1.249 clientType: IOS 68: 10.0.1.254: Sep 06 2016 19:47:30.175 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor3} VBServlet:service: HTTP Request from 10.0.1.249: { CALL_INPUT_MODE=dtmf, CALL_CONFIDENCE=100, MSG_TYPE=CALL_RESULT, ERROR_CODE=NONE(0), CALL_ID=572CDE800001000000000001FD01000A, CALLCED=2, CALL_SEQ_NUM=1 } 69: 10.0.1.254: Sep 06 2016 19:47:30.175 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor3} CallMsgPublisher:sendRunScriptResult: CALLGUID=572CDE800001000000000001FD01000A DNIS=81111111112 Publishing RunScriptResult message: >>HEADERS: (JMSType)=MsgBus:SCRIPT_RESULT >>BODY: ced=2 callguid=572CDE800001000000000001FD01000A floatingvars=>>HEADERS: (JMSType)=MsgBus:FLOATINGVARS >>BODY: user.microapp.error_code=0 user.microapp.metadata=D|100|01|00|00|004543|GD,-9,A,1 >>STATE: isTabular=false isWriteable=true cursor=-1 dnis=81111111112 resultcode=true timezone=Europe/London version=CVP_10_5 calldate=Tue Sep 06 19:47:30 BST 2016 localOffset=60 calllegid= requestid=1 >>STATE: isTabular=false isWriteable=true cursor=-1 118: 10.0.1.254: Sep 06 2016 19:47:30.190 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-121-ICM-6} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Processing ,, [MsgBus:SCRIPT_RESULT], ssId=SYS_IVR1, requestId=1, resultCode=true, ced=2, CallContext:, user.microapp.error_code: 0, user.microapp.metadata: D|100|01|00|00|004543|GD,-9,A,1,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 119: 10.0.1.254: Sep 06 2016 19:47:30.190 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-121-ICM-6} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Publishing ,, [ICM_RUN_SCRIPT_RESULT], dialogueId=2, sendSeqNo=2, invokedId=1, resultCode=true, ced=2, newTransaction=false, CallContext:, user.microapp.error_code: 0, user.microapp.metadata: D|100|01|00|00|004543|GD,-9,A,1,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 120: 10.0.1.254: Sep 06 2016 19:47:30.190 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-122-ICM-7} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Processing ,, [ICM_RELEASE], dialogueId=2, sendSeqNo=2, cause=NORMAL_CALL_CLEARING,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 121: 10.0.1.254: Sep 06 2016 19:47:30.190 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-122-ICM-7} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Publishing ,, [MsgBus:DISCONNECT], ssId=SYS_IVR1, cause=NORMAL_CALL_CLEARING,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 122: 10.0.1.254: Sep 06 2016 19:47:30.190 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-123-ICM-8} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Processing ,, [ICM_CONNECT], dialogueId=1, sendSeqNo=2, labelType=NORMAL, label=3001, transferHint=0, CallContext:, CallVariable9: CCAM_PM.wav, user.microapp.metadata: D|100|01|00|00|004543|GD,-9,A,1, user.microapp.input_type: D, user.microapp.UseVXMLParams: N, user.microapp.error_code: 0, user.microapp.locale: en-gb, user.microapp.media_server: http://10.0.1.254,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 123: 10.0.1.254: Sep 06 2016 19:47:30.190 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-123-ICM-8} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Publishing ,, [MsgBus:CONNECT], ssId=SYS_SIP1, labelType=NORMAL, label=3001, correlationId=null, command=null, rckey=70573100, rcday=151824, rcseq=2, CallContext:, CallVariable9: CCAM_PM.wav, user.microapp.metadata: D|100|01|00|00|004543|GD,-9,A,1, user.microapp.input_type: D, user.microapp.UseVXMLParams: N, user.microapp.error_code: 0, user.microapp.locale: en-gb, user.microapp.media_server: http://10.0.1.254,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 70: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=SubscriptionMgr} CallMsgListener:onMsg: CALLGUID=572CDE800001000000000001FD01000A DNIS=81111111112 Received Call message : >>HEADERS: (JMSType)=MsgBus:DISCONNECT (JMSDestination)=Topic(CVP.ICM.CC.EVENT.SYS_IVR1) (JMSTimestamp)=1473187650190 (ServerID)=Call-Server-01.SYS_ICM1:ICM:ICM1:Call-Server-01.MsgBus001 >>BODY: callguid=572CDE800001000000000001FD01000A dnis=81111111112 causecode=0 timezone=Europe/London version=CVP_10_5 localOffset=60 calllegid= >>STATE: isTabular=false isWriteable=false cursor=-1 164: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] Handling CONNECT :>>HEADERS: (JMSType)=MsgBus:CONNECT (JMSDestination)=Topic(CVP.ICM.CC.RESP.SYS_SIP1) (JMSTimestamp)=1473187650190 (ServerID)=Call-Server-01.SYS_ICM1:ICM:ICM1:Call-Server-01.MsgBus001 >>BODY: callguid=572CDE800001000000000001FD01000A RouterCallKey=70573100 floatingvars=>>HEADERS: (JMSType)=MsgBus:FLOATINGVARS >>BODY: callvars=[, , , , , , , , CCAM_PM.wav, ] user.microapp.media_server=http://10.0.1.254 user.microapp.FromExtVXML=[null, null, null, null] user.microapp.error_code=0 user.microapp.metadata=D|100|01|00|00|004543|GD,-9,A,1 user.microapp.ToExtVXML=[null, null, null, null, null] user.microapp.UseVXMLParams=N user.microapp.locale=en-gb user.microapp.input_type=D >>STATE: isTabular=false isWriteable=true cursor=-1 dnis=82222222221 timezone=Europe/London RouterCallKeySequenceNumber=2 version=CVP_10_5 RouterCallKeyDay=151824 labeltype=1 label=3001 localOffset=60 calllegid=572cde80-7cf10f3a-2-fd01000a >>STATE: isTabular=false isWriteable=false cursor=-1 165: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} Static route matched 3001 to StaticRoute: patterns like 3XXX will route to cucm.mylab.local 166: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} Using Local Static Route for sip:3001@cucm.mylab.local 167: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: with event type TERMINATED 168: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} Static route exactly matched 91919191 to StaticRoute: patterns like 91919191 will route to vxml.mylab.local 169: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} Using Local Static Route for sip:91919191@vxml.mylab.local 170: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} Found an incoming CISCO-GUID hdr : 1462558336-0000065536-0000000001-4244701194, Found an existing CVP-ID hdr: 572CDE800001000000000001FD01000A 171: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [OUTBOUND]: INVITE TO FROM "Test Line 1001" EXPIRES[10] 100REL[Unsupported] 71: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=pool-1-thread-125-IVR-2} DisconnectTask:generateResponse: CALLGUID=572CDE800001000000000001FD01000A DNIS=81111111112 DisconnectResponse generated - CallReleaseCode: 0 172: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-126-SIP-113} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND] DURATION (msecs) = 5070 - HANGUP with Call History 72: 10.0.1.254: Sep 06 2016 19:47:30.206 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor3} VXMLManager:generateVXML: CALLGUID=572CDE800001000000000001FD01000A Generated VXML from template 'Disconnect.template' for client: 10.0.1.249 clientType: IOS 173: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-126-SIP-113} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876451361 - [OUTBOUND]: Terminated with Q.850;cause=16 174: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Invitation proceeding 100 175: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Invitation accepted - ack'ing 176: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: NO P_Asserted_Identity. 177: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: CountObserver() is >0 and sending Re-Invite to caller. 178: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-128-SIP-115} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: with event type INV_ACCEPTED 179: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-128-SIP-115} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: reinviting caller. 180: 10.0.1.254: Sep 06 2016 19:47:30.221 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-128-SIP-115} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: [1] Sending reinvite request. CSEQ:1 73: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor4} VBServlet:service: HTTP Request from 10.0.1.249: { MSG_TYPE=CALL_RESULT, ERROR_CODE=HANGUP(1), CALL_ID=572CDE800001000000000001FD01000A, CALL_SEQ_NUM=2 } 74: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor4} VXMLManager:generateAckVXML: CALLGUID=572CDE800001000000000001FD01000A Generated VXML from template 'Ack.template' for client: 10.0.1.249 clientType: IOS 75: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor4} CallSession:removeCallByDNIS: CALLGUID=572CDE800001000000000001FD01000A Removed IVRCall from CallSession ( DNIS=81111111112 eventId: 6 causeCode: 1). Removed from slot: 0 76: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor4} CallMsgPublisher:sendCallStateEvent: CALLGUID=572CDE800001000000000001FD01000A DNIS=81111111112 Publishing CallStateEvent message: >>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT >>BODY: callguid=572CDE800001000000000001FD01000A dnis=81111111112 RouterCallKeySent=false causecode=1 timezone=Europe/London version=CVP_10_5 calldate=Tue Sep 06 19:47:30 BST 2016 localOffset=60 calllegid= eventid=6 >>STATE: isTabular=false isWriteable=true cursor=-1 77: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=http-processor4} IVRSubSystem:checkInLicense: Released license for call: 572CDE800001000000000001FD01000A - PortCheckinStatus=PORT_CHECKIN_OK_PORT_STILL_IN_USE 181: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Reinvitation proceeding TRYING. 124: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-129-ICM-9} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Processing ,, [MsgBus:CALL_STATE_EVENT], ssId=SYS_IVR1, eventId=DISCONNECT, causeCode=NORMAL_COMPLETION,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 125: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-129-ICM-9} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Publishing ,, [ICM_EVENT_REPORT], dialogueId=2, sendSeqNo=3, eventId=DISCONNECT, causeCode=NORMAL_COMPLETION,, LEGID = , DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 126: 10.0.1.254: Sep 06 2016 19:47:30.237 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-129-ICM-9} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Deleted dialogue. Duration: 0 hrs, 0 mins, 5 secs, 101 msecs 182: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Reinvitation accepted. CSeq: 1 INVITE 183: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-130-SIP-116} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: with event type REINV_ACCEPTED 184: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-130-SIP-116} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Acked the invite. 185: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-130-SIP-116} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Sent reinvite ack. 186: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-130-SIP-116} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Notifying that ringtone is established 200 OK with caller. 187: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Called ring leg: CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: status code = 200: elapsed msecs = 46 188: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} Found an incoming CISCO-GUID hdr : 1462558336-0000065536-0000000001-4244701194, Found an existing CVP-ID hdr: 572CDE800001000000000001FD01000A 189: 10.0.1.254: Sep 06 2016 19:47:30.252 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-124-SIP-112} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: INVITE TO FROM "Test Line 1001" EXPIRES[60] 100REL[Unsupported] 190: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: Invitation proceeding 100 191: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND] - DsSipInvitation - ;tag=31~39040060-3c97-4a86-b924-e7cfeae0f4c7-20719834 - 1 REJECTED WITH 404 - Not Found Reason: Q.850;cause=1 192: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: with event type INV_REJECTED 193: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: with event type INV_REJECTED 194: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1473187650268 >>BODY: callguid=572CDE800001000000000001FD01000A RouterCallKeySent=false causecode=0 timezone=Europe/London version=CVP_10_5 calldate=Tue Sep 06 19:47:30 BST 2016 localOffset=60 eventid=1 calllegid=572CDE800001000000000001FD01000A-14731876502523 >>STATE: isTabular=false isWriteable=true cursor=-1 195: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-131-SIP-117} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND] DURATION (msecs) = 16 - HANGUP with Call History 196: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-131-SIP-117} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: No Dialog Cancelling: No final response on this leg. 197: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-131-SIP-117} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: hangup - com.dynamicsoft.DsLibs.DsSipDialog.DsSipDialogException: Invalid input: IN_HANGUP - invitation terminated 127: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-132-ICM-10} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = -1 [null] - Processing ,, [MsgBus:CALL_STATE_EVENT], ssId=SYS_SIP1, eventId=CONNECT_FAILURE, causeCode=NONE,, LEGID = null, DNIS = 81111111112, ANI = sip:1001@10.0.1.254:5060 128: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-132-ICM-10} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Publishing ,, [ICM_EVENT_REPORT], dialogueId=1, sendSeqNo=3, eventId=CONNECT_FAILURE, causeCode=NONE,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 198: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-133-SIP-118} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: with event type TERMINATED 199: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-133-SIP-118} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502523 - [OUTBOUND]: with event type TERMINATED 200: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-134-SIP-119} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT] DURATION (msecs) = 62 - HANGUP with Call History 201: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-134-SIP-119} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: Terminated with Q.850;cause=16 202: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-135-SIP-120} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Waiting 2000 millisecs before terminating. 203: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-136-SIP-121} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Updated by : CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572CDE800001000000000001FD01000A-14731876502062 - [RING-OUT]: with event type TERMINATED 129: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-137-ICM-11} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Processing ,, [ICM_RELEASE], dialogueId=1, sendSeqNo=3, cause=NO_ROUTE_TO_DESTINATION,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 130: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-137-ICM-11} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Publishing ,, [MsgBus:DISCONNECT], ssId=SYS_SIP1, cause=NO_ROUTE_TO_DESTINATION,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 204: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-139-SIP-123} MessagingWorker:run: CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] ICM Disconnecting the call with : >>HEADERS: (JMSType)=MsgBus:DISCONNECT (JMSDestination)=Topic(CVP.ICM.CC.EVENT.SYS_SIP1) (JMSTimestamp)=1473187650268 (ServerID)=Call-Server-01.SYS_ICM1:ICM:ICM1:Call-Server-01.MsgBus001 >>BODY: callguid=572CDE800001000000000001FD01000A dnis=82222222221 causecode=1 timezone=Europe/London version=CVP_10_5 localOffset=60 calllegid=572cde80-7cf10f3a-2-fd01000a >>STATE: isTabular=false isWriteable=false cursor=-1 205: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-139-SIP-123} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1473187650268 (ServerID)=Call-Server-01.SYS_SIP1:SIP:SIP1:Call-Server-01.MsgBus001 >>BODY: callguid=572CDE800001000000000001FD01000A RouterCallKey=70573100 RouterCallKeySent=true causecode=1 timezone=Europe/London RouterCallKeySequenceNumber=2 version=CVP_10_5 labeltype=1 RouterCallKeyDay=151824 calldate=Tue Sep 06 19:47:30 BST 2016 label=3001 localOffset=60 eventid=6 calllegid=572cde80-7cf10f3a-2-fd01000a >>STATE: isTabular=false isWriteable=false cursor=-1 131: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-140-ICM-12} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Processing ,, [MsgBus:CALL_STATE_EVENT], ssId=SYS_SIP1, eventId=DISCONNECT, causeCode=NORMAL_COMPLETION,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 132: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-140-ICM-12} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Publishing ,, [ICM_EVENT_REPORT], dialogueId=1, sendSeqNo=4, eventId=DISCONNECT, causeCode=NORMAL_COMPLETION,, LEGID = 572cde80-7cf10f3a-2-fd01000a, DNIS = 82222222221, ANI = 1001 133: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-140-ICM-12} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Deleted dialogue. Duration: 0 hrs, 0 mins, 5 secs, 132 msecs 134: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-140-ICM-12} CALLGUID = 572CDE800001000000000001FD01000A - Deleted call. Duration: 0 hrs, 0 mins, 5 secs, 132 msecs 135: 10.0.1.254: Sep 06 2016 19:47:30.268 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=pool-1-thread-140-ICM-12} ICMCallController:addToPostCallSurveyCallMap: CALLGUID = 572CDE800001000000000001FD01000A - Call will not be cached for post call survey 206: 10.0.1.254: Sep 06 2016 19:47:32.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-135-SIP-120} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] DURATION (msecs) = 7147 - HANGUP with Call History81111111112|-1;3001|1; 207: 10.0.1.254: Sep 06 2016 19:47:32.268 +0100: %CVP_10_5_SIP-3-SIP_CALL_ERROR: CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] - ABNORMALLY ENDING - SIP code [404], Reason Hdr [SIP;cause=404] Not Found, GW call using SURV TCL flag [false], NON NORMAL flag [true], DNIS [82222222221], ANI [1001] with AGE (msecs) 7147 and Call History : 81111111112|-1;3001|1; [id:5004] 208: 10.0.1.254: Sep 06 2016 19:47:32.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-135-SIP-120} Static route exactly matched 92929292 to StaticRoute: patterns like 92929292 will route to vxml.mylab.local 209: 10.0.1.254: Sep 06 2016 19:47:32.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-135-SIP-120} Using Local Static Route for sip:92929292@vxml.mylab.local 210: 10.0.1.254: Sep 06 2016 19:47:32.268 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-135-SIP-120} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: REFERRING TO: 78: 10.0.1.254: Sep 06 2016 19:47:32.283 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=pool-1-thread-142-Infrastructure-4} IVRSubSystem:portThresholdStateChange: - PortCheckoutStatus=PORT_CHECKOUT_OK 79: 10.0.1.254: Sep 06 2016 19:47:32.283 +0100: %CVP_10_5_IVR-7-CALL: {Thrd=pool-1-thread-142-Infrastructure-4} IVRSubSystem:setSubSystemStateBasedOnLicenseStatus: Transitioning to State: In Service Reason: Resource Usage at a safe level based on licensing status 211: 10.0.1.254: Sep 06 2016 19:47:32.330 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Received a NOTIFY: subscription = refer 212: 10.0.1.254: Sep 06 2016 19:47:32.330 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.8} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Subscription terminated subscription = refer 213: 10.0.1.254: Sep 06 2016 19:47:32.330 +0100: %CVP_10_5_SIP-3-SIP_CALL_ERROR: CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Refer failed with 404 - Not Found. May be a problem with Routing Configuration or Gateway Dial-Peer. [id:5004] 214: 10.0.1.254: Sep 06 2016 19:47:32.330 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=DIALOG_CALLBACK.4} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] Dialog Request Received: UPDATE CSEQ:104 rpid:"Test Line 1001" ;party=calling;screen=yes;privacy=off 215: 10.0.1.254: Sep 06 2016 19:47:32.330 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-144-SIP-126} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] DURATION (msecs) = 7209 - HANGUP with Call History81111111112|-1;3001|1; 216: 10.0.1.254: Sep 06 2016 19:47:32.330 +0100: %CVP_10_5_SIP-3-SIP_CALL_ERROR: CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND] - ABNORMALLY ENDING - SIP code [404], Reason Hdr [SIP;cause=404] Not Found, GW call using SURV TCL flag [false], NON NORMAL flag [true], DNIS [82222222221], ANI [1001] with AGE (msecs) 7209 and Call History : 81111111112|-1;3001|1; [id:5004] 217: 10.0.1.254: Sep 06 2016 19:47:32.330 +0100: %CVP_10_5_SIP-7-CALL: {Thrd=pool-1-thread-144-SIP-126} CALLGUID = 572CDE800001000000000001FD01000A LEGID = 572cde80-7cf10f3a-2-fd01000a - [INBOUND]: Terminated with SIP;cause=404 136: 10.0.1.254: Sep 06 2016 19:47:50.545 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=ICM Garbage Collector} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 2 [IVR_LEG] - Purged dialogue. 137: 10.0.1.254: Sep 06 2016 19:47:50.545 +0100: %CVP_10_5_ICM-7-CALL: {Thrd=ICM Garbage Collector} CALLGUID = 572CDE800001000000000001FD01000A, DLGID = 1 [SIP_LEG_PRERTE_CORRID] - Purged dialogue.