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)