External Fetch Error

[René]

Could you upload somewhere SIP Server log of the call with failed treatment?

R.

[zafzef.mourad]

Any update please with this problem ....I have the same problem now.

[cavagnaro]

OP never answered back, so if you want help follow procedures...logs...as magic balls are out of service

[zafzef.mourad]

Thanks cavagnaro for ur fast answer.
I have a similar problem... But in my case we have 2 SIP servers both of them up....few days ago, I change the routing strategy ....after that one call of 2 work fine and I hear the voicexml application....second call don't work and I can't hear anything... In ORS logs, I saw that this problem is related only with call use SIP server 2 ...but all call use SIP 1 working fine
Here is the SIP server logs:
@20:34:00.0039 [0] 8.1.001.11 distribute_response: message EventAttachedDataChanged AttributeEventSequenceNumber00000000000dd9cd AttributeTimeinuSecs3952 AttributeTimeinSecs1427070840 (20:34:00) AttributeReferenceID16641 AttributeThirdPartyDN'4451000' AttributeThisDNRole2 AttributeThisDN'4451000' AttributeANI'5148620185' AttributeDNIS'5142815043' AttributeUserData[191] 00 02 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeConnID007402604d478123 AttributeCallID16777506 AttributeLocalCallType2 AttributeCallType2 20:34:00.004 Int 04544 Interaction message "EventAttachedDataChanged" generated 20:34:00.004 Trc 04542 EventAttachedDataChanged sent to [45] (00000011 SS_Advisors_PRI 10.10.10.134:64680) 20:34:00.004 Trc 04542 EventAttachedDataChanged sent to [42] (0000000e SS_Agent_CTIPS 10.10.10.145:63680) 20:34:00.004 Trc 04542 EventAttachedDataChanged sent to [43] (0000000f SS_Advisors_BKP 10.10.10.135:63676) 20:34:00.004 Trc 04542 EventAttachedDataChanged sent to [41] (0000000d SS_URS 10.10.10.68:50606) 20:34:00.004 Trc 04542 EventAttachedDataChanged sent to [33] (00000009 SS_OCS 10.10.10.137:11816) 20:34:00.004 Trc 04542 EventAttachedDataChanged sent to [31] (00000007 SS_Multimedia 10.10.10.139:53722) 20:34:00.004 Trc 04542 EventAttachedDataChanged sent to [30] (00000006 URS 10.10.10.68:60917) @20:34:00.0040 [ISCC] Updated call: i c:007402604d478123,2b4918a84c10 @ m:0000000000000000,0 p:2 i:01000122 nw:0000000000000000 t:2  p:0000000000000000,2b4918aa9c80 @ c:007402604d478123,2b4918a84c10 r:1 ----- n:5148620185:  p:0000000000000000,2b4918ad4e20 @ c:007402604d478123,2b4918a84c10 r:2 ----- n:4451000: @20:34:00.0040 [ISCC] UserData propagation has been started @20:34:00.0040 [ISCC] UserData propagation has been finished 20:34:00.004 -- call_info::committed changed @20:34:00.0040 [0] 8.1.001.11 distribute call/party event: message EventCallDataChanged AttributeEventSequenceNumber00000000000dd9ce AttributeTimeStamp550f5f7800000ff5 AttributeConnID007402604d478123 AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeCtrlParty'4451000' AttributeUserData[191] 00 02 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 20:34:00.004 Int 04544 Interaction message "EventCallDataChanged" generated 20:34:00.004 Trc 04542 EventCallDataChanged sent to [44] (00000013 ORS 10.10.10.68:38532) @20:34:00.0041 [0] 8.1.001.11 send_to_client: message EventACK AttributeEventSequenceNumber00000000000dd9cf AttributeTimeinuSecs4114 AttributeTimeinSecs1427070840 (20:34:00) AttributeReferenceID16641 AttributeUserEventRequestUpdateUserData 20:34:00.004 Trc 04542 EventACK sent to [44] (00000013 ORS 10.10.10.68:38532) 20:34:00.096 Trc 04541 RequestUpdateUserData received from [44] (00000013 ORS 10.10.10.68:38532) message RequestUpdateUserData AttributeThisDN'4451000' AttributeConnID007402604d478123 AttributeUserData[37] 00 01 00 00.. 'gsw-ivr-profile-name''AAA_AccesD' AttributeReferenceID16642 20:34:00.096 Int 04543 Interaction message "RequestUpdateUserData" received from 44 ("ORS") @20:34:00.0969 Call [007402604d478123]: urid 00090074 @20:34:00.0969 [0] 8.1.001.11 distribute_response: message EventAttachedDataChanged AttributeEventSequenceNumber00000000000dd9d0 AttributeTimeinuSecs96938 AttributeTimeinSecs1427070840 (20:34:00) AttributeReferenceID16642 AttributeThirdPartyDN'4451000' AttributeThisDNRole2 AttributeThisDN'4451000' AttributeANI'5148620185' AttributeDNIS'5142815043' AttributeUserData[226] 00 03 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 'gsw-ivr-profile-name''AAA_AccesD' AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeConnID007402604d478123 AttributeCallID16777506 AttributeLocalCallType2 AttributeCallType2 20:34:00.096 Int 04544 Interaction message "EventAttachedDataChanged" generated 20:34:00.097 Trc 04542 EventAttachedDataChanged sent to [45] (00000011 SS_Advisors_PRI 10.10.10.134:64680) 20:34:00.097 Trc 04542 EventAttachedDataChanged sent to [42] (0000000e SS_Agent_CTIPS 10.10.10.145:63680) 20:34:00.097 Trc 04542 EventAttachedDataChanged sent to [43] (0000000f SS_Advisors_BKP 10.10.10.135:63676) 20:34:00.097 Trc 04542 EventAttachedDataChanged sent to [41] (0000000d SS_URS 10.10.10.68:50606) 20:34:00.097 Trc 04542 EventAttachedDataChanged sent to [33] (00000009 SS_OCS 10.10.10.137:11816) 20:34:00.097 Trc 04542 EventAttachedDataChanged sent to [31] (00000007 SS_Multimedia 10.10.10.139:53722) 20:34:00.097 Trc 04542 EventAttachedDataChanged sent to [30] (00000006 URS 10.10.10.68:60917) @20:34:00.0970 [ISCC] Updated call: i c:007402604d478123,2b4918a84c10 @ m:0000000000000000,0 p:2 i:01000122 nw:0000000000000000 t:2  p:0000000000000000,2b4918aa9c80 @ c:007402604d478123,2b4918a84c10 r:1 ----- n:5148620185:  p:0000000000000000,2b4918ad4e20 @ c:007402604d478123,2b4918a84c10 r:2 ----- n:4451000: @20:34:00.0970 [ISCC] UserData propagation has been started @20:34:00.0970 [ISCC] UserData propagation has been finished 20:34:00.097 -- call_info::committed changed @20:34:00.0970 [0] 8.1.001.11 distribute call/party event: message EventCallDataChanged AttributeEventSequenceNumber00000000000dd9d1 AttributeTimeStamp550f5f7800017b2e AttributeConnID007402604d478123 AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeCtrlParty'4451000' AttributeUserData[226] 00 03 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 'gsw-ivr-profile-name''AAA_AccesD' 20:34:00.097 Int 04544 Interaction message "EventCallDataChanged" generated 20:34:00.097 Trc 04542 EventCallDataChanged sent to [44] (00000013 ORS 10.10.10.68:38532) @20:34:00.0970 [0] 8.1.001.11 send_to_client: message EventACK AttributeEventSequenceNumber00000000000dd9d2 AttributeTimeinuSecs97098 AttributeTimeinSecs1427070840 (20:34:00) AttributeReferenceID16642 AttributeUserEventRequestUpdateUserData 20:34:00.097 Trc 04542 EventACK sent to [44] (00000013 ORS 10.215.176.68:38532) 20:34:00.097 Trc 04541 RequestApplyTreatment received from [44] (00000013 ORS 10.10.10.68:38532) message RequestApplyTreatment AttributeThisDN'4451000' AttributeConnID007402604d478123 AttributeTreatmentType13 (TreatmentPlayApplication) AttributeTreatmentParms[206] 00 02 00 00.. 'APP_URI''https://ccc.des.uni:4000/Assiste/.............' 'LANGUAGE''French (Canada)' AttributeReferenceID16643 20:34:00.097 Int 04543 Interaction message "RequestApplyTreatment" received from 44 ("ORS") 20:34:00.097 -- created: CRequest@2b4918aa9920 RequestApplyTreatment-ORS[44]/16643 20:34:00.097: $+TLIB:CTI:Unknown:0:0 20:34:00.097 +++ CIFace::Request +++ -- new invoke -- thisCall by party Parsed: RequestApplyTreatment From: ORS[44]/16643 Numbers: +<4451000> -<none> Calls: 2b4918aa8de0:1 none Parties: 4451000.2b4918ab0880-2b4918aa8de0:1 none Status: parsed:1 queued:0 sent:0 acked:0 preevent:0 event:0 context:0 transferred:0 ----- -- validate -- state check: ok CIFace: Sent CRequest@2b4918aa9920 RequestApplyTreatment-ORS[44]/16643 FinishRequest CRequest@2b4918aa9920 RequestApplyTreatment-ORS[44]/16643 IFace stats: q=0 s=0 -- complete 20:34:00.097: $*:CTI:SIP:APPLY_TREATMENT:839 20:34:00.097 --- CIFace::Request --- 20:34:00.097: $-TLIB:CTI:Unknown:0:0 20:34:00.126: $+SIP:CTI:RTP_INFO:8320:0 20:34:00.126: $-SIP:CTI:RTP_INFO:8320:0 20:34:00.537: $+SIP:CTI:RTP_INFO:8321:0 20:34:00.537: $-SIP:CTI:RTP_INFO:8321:0 20:34:00.602: $+SIP:CTI:MEDIA_SERVICE_EVENT:8322:0 20:34:00.602: SIPTS: HandleMediaServiceFailed 20:34:00.602: SIPTS: SendTreatmentApplied 20:34:00.602: Adding OtherTrunkName(SME_TOR_SIP_MTL_1): done 20:34:00.602 -- thisCall by party 20:34:00.602 SetContext: for party 4451000.2b4918ab0880-2b4918aa8de0:1 20:34:00.602 +++ CIFace::Event +++ +++ Pre-event +++ Type EventTreatmentNotApplied Devices: <4451000/4451000> <-/-> <-/-> Calls: 16777506/007402604d478123/16777506.2b4918aa8de0/c:2/r:2 0/none Parties:D4451000/4451000.2b4918ab0880-2b4918aa8de0:1/l:2/r:1/Queued,RtRequest,Destination none none Cause: Null/0, Info: 50 Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=0 --- Pre-event --- +++ TreatmentError +++ @20:34:00.6027 [0] 8.1.001.11 distribute_response: message EventTreatmentNotApplied AttributeEventSequenceNumber00000000000dd9d3 AttributeTimeinuSecs602788 AttributeTimeinSecs1427070840 (20:34:00) AttributeTreatmentParms[206] 00 02 00 00.. 'APP_URI''https://ccc.des.uni:4000/Assiste/..............' 'LANGUAGE''French (Canada)' AttributeExtensions[165] 00 04 01 00.. 'MsmlResponseCode'423 'ResponseDescription''External document fetch error: Failed to prepare document' 'OtherTrunkName''SME_TOR_SIP_MTL_1' 'BusinessCall'1 AttributeReferenceID16643 AttributeErrorCode50 AttributeErrorMessage'Unspecified error' AttributeTreatmentType13 (TreatmentPlayApplication) AttributeOtherQueue'05142815043' AttributeThisQueue'4451000' AttributeThisDNRole2 AttributeThisDN'4451000' AttributeANI'5148620185' AttributeDNIS'5142815043' AttributeUserData[226] 00 03 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 'gsw-ivr-profile-name''AAA_AccesD' AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeConnID007402604d478123 AttributeCallID16777506 AttributeLocalCallType2 AttributeCallType2 AttributeCallState0 20:34:00.602 Int 04544 Interaction message "EventTreatmentNotApplied" generated 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [44] (00000013 ORS 10.10.10.68:38532) 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [45] (00000011 SS_Advisors_PRI 10.10.10.134:64680) 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [42] (0000000e SS_Agent_CTIPS 10.10.10.145:63680) 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [43] (0000000f SS_Advisors_BKP 10.10.10.135:63676) 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [41] (0000000d SS_URS 10.10.10.68:50606) 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [33] (00000009 SS_OCS 10.10.10.137:11816) 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [31] (00000007 SS_Multimedia 10.10.10.139:53722) 20:34:00.602 Trc 04542 EventTreatmentNotApplied sent to [30] (00000006 URS 10.10.10.68:60917) --- TreatmentError --- +++ Post-event +++ Type EventTreatmentNotApplied Devices: <4451000/4451000> <-/-> <-/-> Calls: 16777506/007402604d478123/16777506.2b4918aa8de0/c:2/r:2 0/none Parties:D4451000/4451000.2b4918ab0880-2b4918aa8de0:1/l:2/r:1/Queued,RtRequest,Destination none none Cause: Null/0, Info: 50 Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=0 --- Post-event --- 20:34:00.603 --- CIFace::Event --- 20:34:00.603: $-SIP:CTI:MEDIA_SERVICE_EVENT:8322:0 20:34:00.603: $+SIP:CTI:REQUEST_COMPLETE:8323:0 20:34:00.603: $-SIP:CTI:REQUEST_COMPLETE:8323:0 20:34:00.616 Trc 04541 RequestApplyTreatment received from [44] (00000013 ORS 10.10.10.68:38532) message RequestApplyTreatment AttributeThisDN'4451000' AttributeConnID007402604d478123 AttributeTreatmentType13 (TreatmentPlayApplication) AttributeTreatmentParms[123] 00 02 00 00.. 'APP_URI''http://dsps53.priv.des.uni:4000/PRJCT_Name/src-gen/badfetch.vxml' 'LANGUAGE''French (Canada)' AttributeReferenceID16644 20:34:00.616 Int 04543 Interaction message "RequestApplyTreatment" received from 44 ("ORS") 20:34:00.616 -- created: CRequest@2b4918a99270 RequestApplyTreatment-ORS[44]/16644 20:34:00.616: $+TLIB:CTI:Unknown:0:0 20:34:00.616 +++ CIFace::Request +++ -- new invoke -- thisCall by party Parsed: RequestApplyTreatment From: ORS[44]/16644 Numbers: +<4451000> -<none> Calls: 2b4918aa8de0:1 none Parties: 4451000.2b4918ab0880-2b4918aa8de0:1 none Status: parsed:1 queued:0 sent:0 acked:0 preevent:0 event:0 context:0 transferred:0 ----- -- validate -- state check: ok CIFace: Sent CRequest@2b4918a99270 RequestApplyTreatment-ORS[44]/16644 FinishRequest CRequest@2b4918a99270 RequestApplyTreatment-ORS[44]/16644 IFace stats: q=0 s=0 -- complete 20:34:00.616: $*:CTI:SIP:APPLY_TREATMENT:840 20:34:00.616 --- CIFace::Request --- 20:34:00.616: $-TLIB:CTI:Unknown:0:0 20:34:00.726: $+SIP:CTI:RTP_INFO:8324:0 20:34:00.726: $-SIP:CTI:RTP_INFO:8324:0 20:34:00.766 -- deleted: CRequest@2b4918aa9920 RequestApplyTreatment-ORS[44]/16643 20:34:00.829: $+SIP:CTI:MEDIA_SERVICE_EVENT:8325:0 20:34:00.829: SIPTS: HandleMediaServiceFailed 20:34:00.829: SIPTS: SendTreatmentApplied 20:34:00.829: Adding OtherTrunkName(SME_TOR_SIP_MTL_1): done 20:34:00.829 -- thisCall by party 20:34:00.829 SetContext: for party 4451000.2b4918ab0880-2b4918aa8de0:1 20:34:00.829 +++ CIFace::Event +++ +++ Pre-event +++ Type EventTreatmentNotApplied Devices: <4451000/4451000> <-/-> <-/-> Calls: 16777506/007402604d478123/16777506.2b4918aa8de0/c:2/r:3 0/none Parties:D4451000/4451000.2b4918ab0880-2b4918aa8de0:1/l:2/r:2/Queued,RtRequest,Destination none none Cause: Null/0, Info: 50 Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=0 --- Pre-event --- +++ TreatmentError +++ @20:34:00.8299 [0] 8.1.001.11 distribute_response: message EventTreatmentNotApplied AttributeEventSequenceNumber00000000000dd9d4 AttributeTimeinuSecs829923 AttributeTimeinSecs1427070840 (20:34:00) AttributeTreatmentParms[123] 00 02 00 00.. 'APP_URI''http://dsps53.priv.des.uni:4000/PRJCT_Name/src-gen/badfetch.vxml' 'LANGUAGE''French (Canada)' AttributeExtensions[165] 00 04 01 00.. 'MsmlResponseCode'423 'ResponseDescription''External document fetch error: Failed to prepare document' 'OtherTrunkName''SME_TOR_SIP_MTL_1' 'BusinessCall'1 AttributeReferenceID16644 AttributeErrorCode50 AttributeErrorMessage'Unspecified error' AttributeTreatmentType13 (TreatmentPlayApplication) AttributeOtherQueue'05142815043' AttributeThisQueue'4451000' AttributeThisDNRole2 AttributeThisDN'4451000' AttributeANI'5148620185' AttributeDNIS'5142815043' AttributeUserData[226] 00 03 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 'gsw-ivr-profile-name''AAA_AccesD' AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeConnID007402604d478123 AttributeCallID16777506 AttributeLocalCallType2 AttributeCallType2 AttributeCallState0 20:34:00.830 Int 04544 Interaction message "EventTreatmentNotApplied" generated 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [44] (00000013 ORS 10.10.10.68:38532) 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [45] (00000011 SS_Advisors_PRI 10.10.10.134:64680) 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [42] (0000000e SS_Agent_CTIPS 10.10.10.145:63680) 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [43] (0000000f SS_Advisors_BKP 10.10.10.135:63676) 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [41] (0000000d SS_URS 10.10.10.68:50606) 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [33] (00000009 SS_OCS 10.10.10.137:11816) 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [31] (00000007 SS_Multimedia 10.10.10.139:53722) 20:34:00.830 Trc 04542 EventTreatmentNotApplied sent to [30] (00000006 URS 10.10.10.68:60917) --- TreatmentError --- +++ Post-event +++ Type EventTreatmentNotApplied Devices: <4451000/4451000> <-/-> <-/-> Calls: 16777506/007402604d478123/16777506.2b4918aa8de0/c:2/r:3 0/none Parties:D4451000/4451000.2b4918ab0880-2b4918aa8de0:1/l:2/r:2/Queued,RtRequest,Destination none none Cause: Null/0, Info: 50 Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=0 --- Post-event --- 20:34:00.830 --- CIFace::Event --- 20:34:00.830: $-SIP:CTI:MEDIA_SERVICE_EVENT:8325:0 20:34:00.830: $+SIP:CTI:REQUEST_COMPLETE:8326:0 20:34:00.830: $-SIP:CTI:REQUEST_COMPLETE:8326:0 20:34:00.843 Trc 04541 RequestDeletePair received from [44] (00000013 ORS 10.10.10.68:38532) message RequestDeletePair AttributeThisDN'4451000' AttributeConnID007402604d478123 AttributeDataKey'ORSI::0' AttributeReferenceID16645 20:34:00.843 Int 04543 Interaction message "RequestDeletePair" received from 44 ("ORS") @20:34:00.8439 Call [007402604d478123]: urid 000a0074 @20:34:00.8439 [0] 8.1.001.11 distribute_response: message EventAttachedDataChanged AttributeEventSequenceNumber00000000000dd9d5 AttributeTimeinuSecs843929 AttributeTimeinSecs1427070840 (20:34:00) AttributeReferenceID16645 AttributeThirdPartyDN'4451000' AttributeThisDNRole2 AttributeThisDN'4451000' AttributeANI'5148620185' AttributeDNIS'5142815043' AttributeUserData[226] 00 03 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 'gsw-ivr-profile-name''AAA_AccesD' AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeConnID007402604d478123 AttributeCallID16777506 AttributeLocalCallType2 AttributeCallType2 20:34:00.843 Int 04544 Interaction message "EventAttachedDataChanged" generated 20:34:00.844 Trc 04542 EventAttachedDataChanged sent to [45] (00000011 SS_Advisors_PRI 10.10.10.134:64680) 20:34:00.844 Trc 04542 EventAttachedDataChanged sent to [42] (0000000e SS_Agent_CTIPS 10.10.10.145:63680) 20:34:00.844 Trc 04542 EventAttachedDataChanged sent to [43] (0000000f SS_Advisors_BKP 10.10.10.135:63676) 20:34:00.844 Trc 04542 EventAttachedDataChanged sent to [41] (0000000d SS_URS 10.10.10.68:50606) 20:34:00.844 Trc 04542 EventAttachedDataChanged sent to [33] (00000009 SS_OCS 10.10.10.137:11816) 20:34:00.844 Trc 04542 EventAttachedDataChanged sent to [31] (00000007 SS_Multimedia 10.10.10.139:53722) 20:34:00.844 Trc 04542 EventAttachedDataChanged sent to [30] (00000006 URS 10.10.10.68:60917) @20:34:00.8440 [ISCC] Updated call: i c:007402604d478123,2b4918a84c10 @ m:0000000000000000,0 p:2 i:01000122 nw:0000000000000000 t:2  p:0000000000000000,2b4918aa9c80 @ c:007402604d478123,2b4918a84c10 r:1 ----- n:5148620185:  p:0000000000000000,2b4918ad4e20 @ c:007402604d478123,2b4918a84c10 r:2 ----- n:4451000: @20:34:00.8440 [ISCC] UserData propagation has been started @20:34:00.8440 [ISCC] UserData propagation has been finished 20:34:00.844 -- call_info::committed changed @20:34:00.8441 [0] 8.1.001.11 distribute call/party event: message EventCallDataChanged AttributeEventSequenceNumber00000000000dd9d6 AttributeTimeStamp550f5f78000ce139 AttributeConnID007402604d478123 AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeCtrlParty'4451000' AttributeUserData[226] 00 03 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 'gsw-ivr-profile-name''AAA_AccesD' 20:34:00.844 Int 04544 Interaction message "EventCallDataChanged" generated 20:34:00.844 Trc 04542 EventCallDataChanged sent to [44] (00000013 ORS 10.10.10.68:38532) @20:34:00.8441 [0] 8.1.001.11 send_to_client: message EventACK AttributeEventSequenceNumber00000000000dd9d7 AttributeTimeinuSecs844134 AttributeTimeinSecs1427070840 (20:34:00) AttributeReferenceID16645 AttributeUserEventRequestDeletePair 20:34:00.844 Trc 04542 EventACK sent to [44] (00000013 ORS 10.215.176.68:38532) 20:34:00.844 Trc 04541 RequestDeletePair received from [44] (00000013 ORS 10.10.10.68:38532) message RequestDeletePair AttributeThisDN'4451000' AttributeConnID007402604d478123 AttributeDataKey'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092' AttributeReferenceID16646 20:34:00.844 Int 04543 Interaction message "RequestDeletePair" received from 44 ("ORS") @20:34:00.8441 Call [007402604d478123]: urid 000b0074 @20:34:00.8442 [0] 8.1.001.11 distribute_response: message EventAttachedDataChanged AttributeEventSequenceNumber00000000000dd9d8 AttributeTimeinuSecs844203 AttributeTimeinSecs1427070840 (20:34:00) AttributeReferenceID16646 AttributeThirdPartyDN'4451000' AttributeThisDNRole2 AttributeThisDN'4451000' AttributeANI'5148620185' AttributeDNIS'5142815043' AttributeUserData[58] 00 02 00 00.. 'CORE_CTI_ORIG''MTL' 'gsw-ivr-profile-name''AAA_AccesD' AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeConnID007402604d478123 AttributeCallID16777506 AttributeLocalCallType2 AttributeCallType2 20:34:00.844 Int 04544 Interaction message "EventAttachedDataChanged" generated

[zafzef.mourad]

Here also ORS logs:

20:34:00.094 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.ProfileIVR' duration='1' /> 20:34:00.094 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.ProfileIVR' cond='(typeof App_ProfileIVR['setudata'] != 'undefined')' target='AppelsEntrants.CallRouting.PlayApplicationRVI' line='3218' /> 20:34:00.094 {ScxmlMetric:3} METRIC <state_enter sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.PlayApplicationRVI' type='state' /> 20:34:00.094 {ScxmlMetric:3} METRIC <onentry sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.PlayApplicationRVI' line='3155' /> 20:34:00.095 {ScxmlMetric:1} METRIC <extension sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='start' namespace='http://www.genesyslab.com/modules/dialog' /> 20:34:00.095 {ThreadSync:3} HandleThreadData: << 24 bytes << request to 65202(SIPServer_MTL_A) message RequestApplyTreatment AttributeReferenceID16643 AttributeTreatmentParms[206] 00 02 00 00.. 'APP_URI'''https://ccc.des.uni:4000/Assiste/.............SomePrivate URL' 'LANGUAGE''French (Canada)' AttributeTreatmentType13 (TreatmentPlayApplication) AttributeConnID007402604d478123 AttributeThisDN'4451000' ..sent to vmmtlg01.des.uni:7001(fd=15) 20:34:00.095 registered transaction 8033 in the storage, 2 elements now 20:34:00.095 {FMDialog:1} StartTreatment: ApplyTreatment status=0, referenceID=16643 20:34:00.095 {ORSInternal:3} +OrsEvent[0x7399500]:name=dialog.start.requestid 20:34:00.095 {ORSInternal:3} +IORSSessionTask[0x1d011680] 20:34:00.095 {SessionManager:2} Queueing Task: [Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN, Task: 0x1d011680, Deferred ACK: 0] 20:34:00.095 {Persistence:3} PersistenceManager::GetSessionServerInfo calling SessionIDServerNodeResultHandler session id[00RO9K1M24AGND7C8IODE2LAES0000QN] pHandler[0x198c8270] with result(185) tdelta cache processing[0] 20:34:00.095 {SessionManager:2} [ORSSessionQueueTaskCallback]: Persistence Callback: [Assigned Node: 185, Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN] (Task: 0x1d011680) 20:34:00.095 {ScxmlIO:3} Send - sending event to session (00RO9K1M24AGND7C8IODE2LAES0000QN) at this node 20:34:00.095 {ORSInternal:3} ~IORSSessionTask[0x1d011680] 20:34:00.097 <<<=== 'EventCallDataChanged'(161) seq=dd9d1 20:34:00.097 Int 04543 Interaction message "EventCallDataChanged" received from 65202 ("SIPServer_MTL_A")  : message EventCallDataChanged AttributeUserData[226] 00 03 00 00.. 'CORE_CTI_ORIG''MTL' 'ORSI:DEV_Cluster:0144A61LC4AGN1KT8IODE2LAES000092'(list) 'Session''00RO9K1M24AGND7C8IODE2LAES0000QN'  'Node''185'  'Url''http://vmmtlg01.des.uni:7082/scxml' 'gsw-ivr-profile-name''AAA_AccesD' AttributeCtrlParty'4451000' AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeConnID007402604d478123 AttributeTimeStamp550f5f7800017b2e AttributeEventSequenceNumber00000000000dd9d1 20:34:00.097 GCTICall: DataChanged: UserData:1, Extension:0, Reasons:0, event: EventCallDataChanged, callGUID 0144A61LC4AGN1KT8IODE2LAES000092 20:34:00.097 call id 007402604d478123. userdata was changed 20:34:00.097 {CallMonitor:1} OnCallInfoChanged 20:34:00.097 {ORSInternal:3} +OrsEvent[0x7397090]:name=interaction.udata.changed 20:34:00.097 {ORSInternal:3} +IORSSessionTask[0x1d015f20] 20:34:00.097 {SessionManager:2} Queueing Task: [Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN, Task: 0x1d015f20, Deferred ACK: 0] 20:34:00.097 {Persistence:3} PersistenceManager::GetSessionServerInfo calling SessionIDServerNodeResultHandler session id[00RO9K1M24AGND7C8IODE2LAES0000QN] pHandler[0x198ce660] with result(185) tdelta cache processing[0] 20:34:00.097 {SessionManager:2} [ORSSessionQueueTaskCallback]: Persistence Callback: [Assigned Node: 185, Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN] (Task: 0x1d015f20) 20:34:00.097 {ScxmlIO:3} Send - sending event to session (00RO9K1M24AGND7C8IODE2LAES0000QN) at this node 20:34:00.097 {ORSInternal:3} ~IORSSessionTask[0x1d015f20] 20:34:00.097 <<<=== 'EventACK'(138) seq=dd9d2 20:34:00.097 SRT[8032]: uncommitted transaction destroyed 20:34:00.107 {Persistence:3} DataStoreImplCassandra(47566699067712)::Store - Key 00RO9K1M24AGND7C8IODE2LAES0000QN 20:34:00.107 {ScxmlMetric:3} METRIC <event_queued sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='dialog.start.requestid' type='external' /> 20:34:00.107 {ScxmlMetric:3} METRIC <event_queued sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='interaction.udata.changed' type='external' /> 20:34:00.108 {Persistence:3} DataStoreImplCassandra(47566699067712)::Store itemKey[00RO9K1M24AGND7C8IODE2LAES0000QN] insertColumn successful retry[1] tdelta cassandra[1] 20:34:00.108 {Persistence:3} DataStoreImplCassandra::StoreSessionRecover sessionid[00RO9K1M24AGND7C8IODE2LAES0000QN] 20:34:00.108 {ScxmlMetric:3} METRIC <persist_store sid='00RO9K1M24AGND7C8IODE2LAES0000QN' type='session' req_id='0' /> 20:34:00.108 {ThreadSync:3} HandleThreadData: << 24 bytes << 20:34:00.108 {Persistence:3} PersistenceManager::HandleDataFromThread: enter threadId(37), type(11007), pData(1cb1b960) >>>>>>>>>>>>>>>>>>>>>>> 20:34:00.108 {Persistence:3} PersistenceManager::HandleDataFromThread -- requestType(2) requestSessionID(00RO9K1M24AGND7C8IODE2LAES0000QN) 20:34:00.108 {Persistence:3} ~PersistenceRequestInformationCassandra: destroy (1cb1b960) 20:34:00.108 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]erformWork(47566841747776) tdelta to entry[0] 20:34:00.108 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]rocessPutRecoverSessionIDServerInfo() m_max_session_age[7200] ttl[10800] 20:34:00.108 {ScxmlMetric:3} METRIC <persist_result sid='00RO9K1M24AGND7C8IODE2LAES0000QN' req_id='0' msg='Persistence result is not current; session is not considered to be persisted' /> 20:34:00.108 {ScxmlMetric:3} METRIC <event_processed sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='dialog.start.requestid' disposition='transition selected' /> 20:34:00.108 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]erformWork(47566841747776) tdelta cassandra[0] 20:34:00.108 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_application' event='*' line='4582' /> 20:34:00.108 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='dialog.start.requestid event received in user application thread ({name:"dialog.start.requestid", data:{requestid:"D0"}, invokeid:"", sendid:"", type:"platform"})' label='' level='1' /> 20:34:00.108 {ScxmlMetric:3} METRIC <eval_expr sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expression='storeUnhandledEvent();' result='undefined' /> 20:34:00.108 {ORSInternal:3} ~OrsEvent[0x7399500]:name=dialog.start.requestid 20:34:00.109 {ScxmlMetric:3} METRIC <event_processed sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='interaction.udata.changed' disposition='transition selected' /> 20:34:00.109 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_application' event='*' line='4582' /> 20:34:00.109 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='interaction.udata.changed event received in user application thread ({name:"interaction.udata.changed", data:{interactionid:"0144A61LC4AGN1KT8IODE2LAES000092"}, invokeid:"", sendid:"", type:"platform"})' label='' level='1' /> 20:34:00.109 {ScxmlMetric:3} METRIC <eval_expr sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expression='storeUnhandledEvent();' result='undefined' /> 20:34:00.109 {ORSInternal:3} ~OrsEvent[0x7397090]:name=interaction.udata.changed 20:34:00.121 {Persistence:3} DataStoreImplCassandra(47566699067712)::Store - Key 00RO9K1M24AGND7C8IODE2LAES0000QN 20:34:00.122 {Persistence:3} DataStoreImplCassandra(47566699067712)::Store itemKey[00RO9K1M24AGND7C8IODE2LAES0000QN] insertColumn successful retry[1] tdelta cassandra[1] 20:34:00.122 {Persistence:3} DataStoreImplCassandra::StoreSessionRecover sessionid[00RO9K1M24AGND7C8IODE2LAES0000QN] 20:34:00.122 {ScxmlMetric:3} METRIC <persist_store sid='00RO9K1M24AGND7C8IODE2LAES0000QN' type='session' req_id='0' /> 20:34:00.122 {ThreadSync:3} HandleThreadData: << 24 bytes << 20:34:00.122 {Persistence:3} PersistenceManager::HandleDataFromThread: enter threadId(37), type(11007), pData(1cb11460) >>>>>>>>>>>>>>>>>>>>>>> 20:34:00.122 {Persistence:3} PersistenceManager::HandleDataFromThread -- requestType(2) requestSessionID(00RO9K1M24AGND7C8IODE2LAES0000QN) 20:34:00.122 {Persistence:3} ~PersistenceRequestInformationCassandra: destroy (1cb11460) 20:34:00.122 {ScxmlMetric:3} METRIC <persist_result sid='00RO9K1M24AGND7C8IODE2LAES0000QN' req_id='0' msg='Session is now persisted' /> 20:34:00.122 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]erformWork(47566858533184) tdelta to entry[0] 20:34:00.122 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]rocessPutRecoverSessionIDServerInfo() m_max_session_age[7200] ttl[10800] 20:34:00.122 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]erformWork(47566858533184) tdelta cassandra[0] 20:34:00.603 <<<=== 'EventTreatmentNotApplied'(115) seq=dd9d3 20:34:00.603 SRT[8033]: uncommitted transaction destroyed 20:34:00.603 GCTICall: DataChanged: UserData:0, Extension:2, Reasons:0, event: EventTreatmentNotApplied, callGUID 0144A61LC4AGN1KT8IODE2LAES000092 20:34:00.603 Int 04543 Interaction message "EventTreatmentNotApplied" received from 65202 ("SIPServer_MTL_A@4451000")  : message EventTreatmentNotApplied AttributeCallState0 AttributeCallType2 AttributeLocalCallType2 AttributeCallID16777506 AttributeConnID007402604d478123 AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeDNIS'5142815043' AttributeANI'5148620185' AttributeThisDN'4451000' AttributeThisDNRole2 AttributeThisQueue'4451000' AttributeOtherQueue'05142815043' AttributeTreatmentType13 (TreatmentPlayApplication) AttributeErrorMessage'Unspecified error' AttributeErrorCode50 AttributeReferenceID16643 AttributeExtensions[165] 00 04 01 00.. 'MsmlResponseCode'423 'ResponseDescription''External document fetch error: Failed to prepare document' 'OtherTrunkName''SME_TOR_SIP_MTL_1' 'BusinessCall'1 AttributeTreatmentParms[206] 00 02 00 00.. 'APP_URI''https://ccc.des.uni:4000/Assiste/.............SomePrivate URL' 'LANGUAGE''French (Canada)' AttributeTimeinSecs1427070840 (20:34:00) AttributeTimeinuSecs602788 AttributeEventSequenceNumber00000000000dd9d3 20:34:00.603 {FMDialog:3} OnTreatmentError: referenceID=16643, status=1 20:34:00.603 {ORSInternal:3} +OrsEvent[0x7396fe0]:name=error.dialog.start 20:34:00.603 {ORSInternal:3} +IORSSessionTask[0x1d01a0a0] 20:34:00.603 {SessionManager:2} Queueing Task: [Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN, Task: 0x1d01a0a0, Deferred ACK: 0] 20:34:00.604 {Persistence:3} PersistenceManager::GetSessionServerInfo calling SessionIDServerNodeResultHandler session id[00RO9K1M24AGND7C8IODE2LAES0000QN] pHandler[0x198c3d70] with result(185) tdelta cache processing[0] 20:34:00.604 {SessionManager:2} [ORSSessionQueueTaskCallback]: Persistence Callback: [Assigned Node: 185, Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN] (Task: 0x1d01a0a0) 20:34:00.604 {ScxmlIO:3} Send - sending event to session (00RO9K1M24AGND7C8IODE2LAES0000QN) at this node 20:34:00.604 {ORSInternal:3} ~IORSSessionTask[0x1d01a0a0] 20:34:00.604 {ScxmlMetric:3} METRIC <event_queued sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='error.dialog.start' type='external' /> 20:34:00.604 {ScxmlMetric:3} METRIC <eval_condition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' condition='_event.data.requestid == App_PlayApplicationRVI['requestid']' result='true' /> 20:34:00.604 {ScxmlMetric:3} METRIC <event_processed sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='error.dialog.start' disposition='transition selected' /> 20:34:00.604 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.PlayApplicationRVI' duration='509' /> 20:34:00.604 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.PlayApplicationRVI' cond='_event.data.requestid == App_PlayApplicationRVI['requestid']' event='error.dialog.start' target='AppelsEntrants.CallRouting.Log1' line='3164' /> 20:34:00.604 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='Composer Application: SUB_WF_AAA_ROUTING_RULES Block: PlayApplicationRVI' label='' level='1' /> 20:34:00.605 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='ERROR: ({data:{requestid:"D0", description:"Unspecified error", error:"remote", extensions:{BusinessCall:1, MsmlResponseCode:423, OtherTrunkName:"SME_TOR_SIP_MTL_1", ResponseDescription:"External document fetch error: Failed to prepare document"}}, invokeid:"", name:"error.dialog.start", sendid:"", type:"platform"})' label='' level='1' /> 20:34:00.605 {ScxmlMetric:3} METRIC <eval_expr sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expression='storeException("PlayApplicationRVI", _event);' result='undefined' /> 20:34:00.605 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_event_handler' event='error' line='4645' /> 20:34:00.605 {ScxmlMetric:3} METRIC <eval_condition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' condition='!isEventHandledByApplication()' result='false' /> 20:34:00.605 {ScxmlMetric:3} METRIC <state_enter sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.Log1' type='state' /> 20:34:00.605 {ScxmlMetric:3} METRIC <onentry sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.Log1' line='3290' /> 20:34:00.605 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='00RO9K1M24AGND7C8IODE2LAES0000QN: Inside Log Block: Log1' label='' level='1' /> 20:34:00.605 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='***classonde: _event.name = error.dialog.start _event.data.description = Unspecified error _event.data.extensions.ResponseDescription = External document fetch error: Failed to prepare document' label='' level='2' /> 20:34:00.605 {ScxmlMetric:3} METRIC <event_queued sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='Log1.script.done' type='internal' /> 20:34:00.605 {ORSInternal:3} ~OrsEvent[0x7396fe0]:name=error.dialog.start 20:34:00.605 {ScxmlMetric:3} METRIC <event_processed sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='Log1.script.done' disposition='transition selected' /> 20:34:00.605 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.Log1' duration='1' /> 20:34:00.606 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.Log1' event='Log1.script.done' target='AppelsEntrants.CallRouting.PlayApplication1' line='3295' /> 20:34:00.606 {ScxmlMetric:3} METRIC <eval_expr sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expression='storeEvent("Log1", _event);' result='undefined' /> 20:34:00.606 {ScxmlMetric:3} METRIC <state_enter sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.PlayApplication1' type='state' /> 20:34:00.606 {ScxmlMetric:3} METRIC <onentry sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.PlayApplication1' line='3236' /> 20:34:00.606 {ScxmlMetric:1} METRIC <extension sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='start' namespace='http://www.genesyslab.com/modules/dialog' /> 20:34:00.606 {ThreadSync:3} HandleThreadData: << 24 bytes << request to 65202(SIPServer_MTL_A) message RequestApplyTreatment AttributeReferenceID16644 AttributeTreatmentParms[123] 00 02 00 00.. 'APP_URI''http://dsps53.priv.des.uni:4000/PRJCT_Name/src-gen/badfetch.vxml' 'LANGUAGE''French (Canada)' AttributeTreatmentType13 (TreatmentPlayApplication) AttributeConnID007402604d478123 AttributeThisDN'4451000' ..sent to vmmtlg01.des.uni:7001(fd=15) 20:34:00.606 registered transaction 8034 in the storage, 1 elements now 20:34:00.606 {FMDialog:1} StartTreatment: ApplyTreatment status=0, referenceID=16644 20:34:00.606 {ORSInternal:3} +OrsEvent[0x7396fe0]:name=dialog.start.requestid 20:34:00.606 {ORSInternal:3} +IORSSessionTask[0x1d015200] 20:34:00.606 {SessionManager:2} Queueing Task: [Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN, Task: 0x1d015200, Deferred ACK: 0] 20:34:00.606 {Persistence:3} PersistenceManager::GetSessionServerInfo calling SessionIDServerNodeResultHandler session id[00RO9K1M24AGND7C8IODE2LAES0000QN] pHandler[0x198c3560] with result(185) tdelta cache processing[0] 20:34:00.606 {SessionManager:2} [ORSSessionQueueTaskCallback]: Persistence Callback: [Assigned Node: 185, Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN] (Task: 0x1d015200) 20:34:00.606 {ScxmlIO:3} Send - sending event to session (00RO9K1M24AGND7C8IODE2LAES0000QN) at this node 20:34:00.606 {ORSInternal:3} ~IORSSessionTask[0x1d015200] 20:34:00.623 {Persistence:3} DataStoreImplCassandra(47566657104192)::Store - Key 00RO9K1M24AGND7C8IODE2LAES0000QN 20:34:00.623 {ScxmlMetric:3} METRIC <event_queued sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='dialog.start.requestid' type='external' /> 20:34:00.624 {Persistence:3} DataStoreImplCassandra(47566657104192)::Store itemKey[00RO9K1M24AGND7C8IODE2LAES0000QN] insertColumn successful retry[1] tdelta cassandra[1] 20:34:00.624 {Persistence:3} DataStoreImplCassandra::StoreSessionRecover sessionid[00RO9K1M24AGND7C8IODE2LAES0000QN] 20:34:00.624 {ScxmlMetric:3} METRIC <persist_store sid='00RO9K1M24AGND7C8IODE2LAES0000QN' type='session' req_id='0' /> 20:34:00.624 {ThreadSync:3} HandleThreadData: << 24 bytes << 20:34:00.624 {Persistence:3} PersistenceManager::HandleDataFromThread: enter threadId(47), type(11007), pData(12eed920) >>>>>>>>>>>>>>>>>>>>>>> 20:34:00.624 {Persistence:3} PersistenceManager::HandleDataFromThread -- requestType(2) requestSessionID(00RO9K1M24AGND7C8IODE2LAES0000QN) 20:34:00.624 {Persistence:3} ~PersistenceRequestInformationCassandra: destroy (12eed920) 20:34:00.624 {ScxmlMetric:3} METRIC <persist_result sid='00RO9K1M24AGND7C8IODE2LAES0000QN' req_id='0' msg='Events are queued; session is not considered to be persisted' /> 20:34:00.624 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]erformWork(47566866925888) tdelta to entry[0] 20:34:00.624 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]rocessPutRecoverSessionIDServerInfo() m_max_session_age[7200] ttl[10800] 20:34:00.624 {ScxmlMetric:3} METRIC <event_processed sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='dialog.start.requestid' disposition='transition selected' /> 20:34:00.624 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_application' event='*' line='4582' /> 20:34:00.624 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='dialog.start.requestid event received in user application thread ({name:"dialog.start.requestid", data:{requestid:"D1"}, invokeid:"", sendid:"", type:"platform"})' label='' level='1' /> 20:34:00.624 {ScxmlMetric:3} METRIC <eval_expr sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expression='storeUnhandledEvent();' result='undefined' /> 20:34:00.624 {ORSInternal:3} ~OrsEvent[0x7396fe0]:name=dialog.start.requestid 20:34:00.624 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]erformWork(47566866925888) tdelta cassandra[0] 20:34:00.637 {Persistence:3} DataStoreImplCassandra(47566657104192)::Store - Key 00RO9K1M24AGND7C8IODE2LAES0000QN 20:34:00.637 {Persistence:3} DataStoreImplCassandra(47566657104192)::Store itemKey[00RO9K1M24AGND7C8IODE2LAES0000QN] insertColumn successful retry[1] tdelta cassandra[0] 20:34:00.637 {Persistence:3} DataStoreImplCassandra::StoreSessionRecover sessionid[00RO9K1M24AGND7C8IODE2LAES0000QN] 20:34:00.638 {ScxmlMetric:3} METRIC <persist_store sid='00RO9K1M24AGND7C8IODE2LAES0000QN' type='session' req_id='0' /> 20:34:00.638 {ThreadSync:3} HandleThreadData: << 24 bytes << 20:34:00.638 {Persistence:3} PersistenceManager::HandleDataFromThread: enter threadId(47), type(11007), pData(12ee4180) >>>>>>>>>>>>>>>>>>>>>>> 20:34:00.638 {Persistence:3} PersistenceManager::HandleDataFromThread -- requestType(2) requestSessionID(00RO9K1M24AGND7C8IODE2LAES0000QN) 20:34:00.638 {Persistence:3} ~PersistenceRequestInformationCassandra: destroy (12ee4180) 20:34:00.638 {ScxmlMetric:3} METRIC <persist_result sid='00RO9K1M24AGND7C8IODE2LAES0000QN' req_id='0' msg='Session is now persisted' /> 20:34:00.638 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]erformWork(47566850140480) tdelta to entry[0] 20:34:00.638 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]rocessPutRecoverSessionIDServerInfo() m_max_session_age[7200] ttl[10800] 20:34:00.638 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]erformWork(47566850140480) tdelta cassandra[0] 20:34:00.830 <<<=== 'EventTreatmentNotApplied'(115) seq=dd9d4 20:34:00.830 SRT[8034]: uncommitted transaction destroyed 20:34:00.830 GCTICall: DataChanged: UserData:0, Extension:2, Reasons:0, event: EventTreatmentNotApplied, callGUID 0144A61LC4AGN1KT8IODE2LAES000092 20:34:00.830 Int 04543 Interaction message "EventTreatmentNotApplied" received from 65202 ("SIPServer_MTL_A@4451000")  : message EventTreatmentNotApplied AttributeCallState0 AttributeCallType2 AttributeLocalCallType2 AttributeCallID16777506 AttributeConnID007402604d478123 AttributeCallUUID'0144A61LC4AGN1KT8IODE2LAES000092' AttributeDNIS'5142815043' AttributeANI'5148620185' AttributeThisDN'4451000' AttributeThisDNRole2 AttributeThisQueue'4451000' AttributeOtherQueue'05142815043' AttributeTreatmentType13 (TreatmentPlayApplication) AttributeErrorMessage'Unspecified error' AttributeErrorCode50 AttributeReferenceID16644 AttributeExtensions[165] 00 04 01 00.. 'MsmlResponseCode'423 'ResponseDescription''External document fetch error: Failed to prepare document' 'OtherTrunkName''SME_TOR_SIP_MTL_1' 'BusinessCall'1 AttributeTreatmentParms[123] 00 02 00 00.. 'APP_URI''http://dsps53.priv.des.uni:4000/PRJCT_Name/src-gen/badfetch.vxml' 'LANGUAGE''French (Canada)' AttributeTimeinSecs1427070840 (20:34:00) AttributeTimeinuSecs829923 AttributeEventSequenceNumber00000000000dd9d4 20:34:00.830 {FMDialog:3} OnTreatmentError: referenceID=16644, status=1 20:34:00.830 {ORSInternal:3} +OrsEvent[0x7399500]:name=error.dialog.start 20:34:00.830 {ORSInternal:3} +IORSSessionTask[0x1d01fa00] 20:34:00.830 {SessionManager:2} Queueing Task: [Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN, Task: 0x1d01fa00, Deferred ACK: 0] 20:34:00.830 {Persistence:3} PersistenceManager::GetSessionServerInfo calling SessionIDServerNodeResultHandler session id[00RO9K1M24AGND7C8IODE2LAES0000QN] pHandler[0x198c3fe0] with result(185) tdelta cache processing[0] 20:34:00.830 {SessionManager:2} [ORSSessionQueueTaskCallback]: Persistence Callback: [Assigned Node: 185, Session ID: 00RO9K1M24AGND7C8IODE2LAES0000QN] (Task: 0x1d01fa00) 20:34:00.830 {ScxmlIO:3} Send - sending event to session (00RO9K1M24AGND7C8IODE2LAES0000QN) at this node 20:34:00.830 {ORSInternal:3} ~IORSSessionTask[0x1d01fa00] 20:34:00.831 {ScxmlMetric:3} METRIC <event_queued sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='error.dialog.start' type='external' /> 20:34:00.831 {ScxmlMetric:3} METRIC <event_processed sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='error.dialog.start' disposition='transition selected' /> 20:34:00.831 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_application' event='*' line='4582' /> 20:34:00.831 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='error.dialog.start event received in user application thread ({name:"error.dialog.start", data:{description:"Unspecified error", error:"remote", extensions:{BusinessCall:1, MsmlResponseCode:423, OtherTrunkName:"SME_TOR_SIP_MTL_1", ResponseDescription:"External document fetch error: Failed to prepare document"}, requestid:"D1"}, invokeid:"", sendid:"", type:"platform"})' label='' level='1' /> 20:34:00.831 {ScxmlMetric:3} METRIC <eval_expr sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expression='storeUnhandledEvent();' result='undefined' /> 20:34:00.831 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_event_handler' event='error' line='4645' /> 20:34:00.831 {ScxmlMetric:3} METRIC <eval_condition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' condition='!isEventHandledByApplication()' result='true' /> 20:34:00.832 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='unexpected error received in IPD event handler ({name:"error.dialog.start", data:{description:"Unspecified error", error:"remote", extensions:{BusinessCall:1, MsmlResponseCode:423, OtherTrunkName:"SME_TOR_SIP_MTL_1", ResponseDescription:"External document fetch error: Failed to prepare document"}, requestid:"D1"}, invokeid:"", sendid:"", type:"platform"})' label='' level='1' /> 20:34:00.832 {ScxmlMetric:3} METRIC <eval_condition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' condition='typeof _event != 'undefined' && typeof _event.data != 'undefined' && typeof _event.data.description != 'undefined'' result='true' /> 20:34:00.832 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='Error message: Unspecified error' label='' level='1' /> 20:34:00.832 {ScxmlMetric:3} METRIC <eval_expr sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expression='var autostop = (typeof _data.system.context.InteractionID != 'undefined') && (typeof _genesys.ixn.interactions[_data.system.context.InteractionID] != 'undefined') && (typeof _genesys.ixn.interactions[_data.system.context.InteractionID].voice ...' result='undefined' /> 20:34:00.832 {ScxmlMetric:3} METRIC <eval_condition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' condition='autostop' result='false' /> 20:34:00.832 {ScxmlMetric:3} METRIC <event_queued sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='application.exit' type='internal' /> 20:34:00.832 {ORSInternal:3} ~OrsEvent[0x7399500]:name=error.dialog.start 20:34:00.833 {ScxmlMetric:3} METRIC <event_processed sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='application.exit' disposition='transition selected' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting.PlayApplication1' duration='227' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting._composer_globalstate' duration='741' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting._composer_entry' duration='741' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants.CallRouting' duration='741' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants._composer_globalstate' duration='822' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants._composer_entry' duration='823' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='AppelsEntrants' duration='823' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_start' duration='823' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_event_handler' duration='834' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_application' duration='835' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_parallel' duration='835' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_globalstate' duration='835' /> 20:34:00.833 {ScxmlMetric:3} METRIC <transition sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_application' event='application.exit' target='_composer_global_exit' line='4579' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_enter sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_global_exit' type='final' /> 20:34:00.833 {ScxmlMetric:3} METRIC <onentry sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_global_exit' line='4673' /> 20:34:00.833 {ScxmlMetric:3} METRIC <log sid='00RO9K1M24AGND7C8IODE2LAES0000QN' expr='Reached Final global exit state for application. Session will terminate now.' label='' level='1' /> 20:34:00.833 {ScxmlMetric:3} METRIC <state_exit sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='_composer_global_exit' type='final' /> 20:34:00.833 {ORSInternal:3} +IxnThreadData[0x1a6b1500] 20:34:00.833 {ThreadSync:3} HandleThreadData: << 48 bytes << 20:34:00.833 {ORSURS:3} DeleteVirtualCall: << refID0 call'*00RO9K1M24AGND7C8IODE2LAES0000QN' context'' << 20:34:00.833 {ScxmlMetric:1} METRIC <appl_end sid='00RO9K1M24AGND7C8IODE2LAES0000QN' name='IXNPR_AAA.AppelsEntrants' url='http://dsps53.priv.des.uni:4000/PRJCT_Name/src-gen/IPD_IXNPR_AAA_AppelsEntrants.scxml' reason='normal' /> 20:34:00.833 {ThreadSync:3} HandleThreadData: << 96 bytes << 20:34:00.833 {SessionManager:1} [IDX]: >> GET ALL >> SESSID=00RO9K1M24AGND7C8IODE2LAES0000QN / 1 FMIDS 20:34:00.833 {ORSInternal:3} +IxnThreadData[0x7fff8ccc7c70] 20:34:00.833 CTITM: R:16645 DeleteUData(782,4451000) 20:34:00.833 registered transaction 8035 in the storage, 1 elements now 20:34:00.833 {ORSInternal:3} +IxnThreadData[0x7fff8ccc7c40] 20:34:00.833 CTITM: R:16646 DeleteUData(782,4451000) 20:34:00.833 registered transaction 8036 in the storage, 2 elements now 20:34:00.833 {FMInteraction:2} External detaching is initiated for ixn ID=0144A61LC4AGN1KT8IODE2LAES000092 20:34:00.833 {ORSInternal:3} ~IxnThreadData[0x7fff8ccc7c40] 20:34:00.833 {ORSInternal:3} ~IxnThreadData[0x7fff8ccc7c70] 20:34:00.833 {SessionManager:2} removing all keys with value[00RO9K1M24AGND7C8IODE2LAES0000QN] 20:34:00.833 {SessionManager:1} [IDX]: >> REMOVE ALL >> SESSID=00RO9K1M24AGND7C8IODE2LAES0000QN 20:34:00.833 {ORSInternal:3} ~IxnThreadData[0x1a6b1500] 20:34:00.833 {ORSScxml:1} 20:34:00.833: << SESSION TERMINATED(ID=00RO9K1M24AGND7C8IODE2LAES0000QN) 20:34:00.833 {Persistence:3} DataStoreImplCassandra(47566648711488)::Destroy - Key 00RO9K1M24AGND7C8IODE2LAES0000QN 20:34:00.833 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]erformWork(47566841747776) tdelta to entry[0] 20:34:00.833 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]erformWork(47566858533184) tdelta to entry[0] 20:34:00.833 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]rocessDeleteSessionIDServerInfo() sessionID(00RO9K1M24AGND7C8IODE2LAES0000QN) nodeID(185) 20:34:00.833 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]rocessDeleteRecoverSessionIDServerInfo() sessionID(00RO9K1M24AGND7C8IODE2LAES0000QN) nodeID(185) 20:34:00.834 {Schedule:3} RemoveScheduledSessionFromQueues p_session(00RO9K1M24AGND7C8IODE2LAES0000QN) ... 20:34:00.834 {Persistence:3} PMCWorker[0xbd7aea0]:[emoji14]erformWork(47566866925888) tdelta to entry[1] 20:34:00.834 {Persistence:3} PMCWorker[0xbd7aea0]:[emoji14]rocessDeleteScheduledSession() [00RO9K1M24AGND7C8IODE2LAES0000QN] [0] 20:34:00.834 {Persistence:3} PMCWorker[0xbd7aea0]::GetActionsForSession() for key(00RO9K1M24AGND7C8IODE2LAES0000QN) 20:34:00.834 {Persistence:3} PMCWorker[0xbd7b8b0]:[emoji14]erformWork(47566858533184) tdelta cassandra[1] 20:34:00.834 {Persistence:3} DataStoreImplCassandra(47566648711488)::Destroy p_strKey[00RO9K1M24AGND7C8IODE2LAES0000QN] removeColumn successful retry[1] tdelta cassandra[1] 20:34:00.834 {Persistence:3} PMCWorker[0xbd797e0]:[emoji14]erformWork(47566841747776) tdelta cassandra[1] 20:34:00.834 {ScxmlCommon:3} scxml:(fm) Removing session 00RO9K1M24AGND7C8IODE2LAES0000QN from session map 20:34:00.835 {Persistence:3} PMCWorker[0xbd7aea0]:[emoji14]erformWork(47566866925888) tdelta cassandra[1] 20:34:00.844 <<<=== 'EventCallDataChanged'(161)

[Kubig]

Attach the logs as any external link, not as part of the post (it is unreadable). Attach the MCP logs covering the issue, not just only SIP.

[cavagnaro]

And URS ones too