Genesys CTI User Forum
Genesys CTI User Forum => Genesys CTI Technical Discussion => Topic started by: PFCCWA on February 06, 2013, 04:48:24 PM
-
Hello,
Has anyone experienced a problem whereby a missing announcement/file caused the following error:
[b][i]'ResponseDescription' 'External document fetch error: Failed to fetch file'[/i][/b]
We are using the latest sip release (8.1.001), and Media Control Platform (8.1.6).
The issue appears related to sip as it doesnt occur in 8.0.4.
If we add the missing announcement, then it works as expected but our issue is if someone accidently deletes it or renames incorrectly none of the callers can route to an agent - callers hear silence.
thanks.
-
I have installed same version as you and the behavior is too same as your,but if the SIP server received this message (Fetch failed),generates EventTreatmentNotApplied and the strategy continue to the next block. What behavior do you expect or want?
-
The problem is, the strategy does not continue to the next block, just stops and fails on the play announcement block - on sip 8.1 however on sip 8.0.4 the strategy continues to the next block as expected.
What sip version are you on?
Thanks.
-
I have installed latest patch for SIP server - 8.1.001.17,but I tried a lot of version from 8.1.000.xx to current,and I have not noticed your behavior. Did you check the strategy,if the announcement block has correctly configured an error output? Could you check if SIP server generates an event EventTreatmentNotApplied and distributed it to the URS?
If I rename a file and that I call this prompt in strategy,SIP server jump on next block and generate EventTreatmentNotApplied
-
PFCCWA,
Could you post here snippet of URS log showing RequestApplyTreatment and following error response from SIP Server and reaction of URS?
R.
-
The file will play if it is restored then removed (mcp must use the cache to play it) however if i was to restart mcp the same problem occurs (assume restarting clears the cache?).
URS log:
[i]request to 65200(sipserver) message RequestApplyTreatment
AttributeReferenceID 106
AttributeExtensions [22] 00 01 00 00..
'geo-location' 'geo1'
AttributeTreatmentParms [60] 00 01 03 00..
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 0
'ID' 1111
AttributeTreatmentType 7 (TreatmentPlayAnnouncement)
AttributeConnID 00e90220c303c004
AttributeThisDN 'RP1'
..sent to [siphost]:3000(fd=724)
_B_I_00e90220c303c004 [14:28] treatment===========>TREATMENT_REQUEST
12:15:20.725_A_I_00e90220c303c004 [0E:0c] ----------->TMESSAGE
12:15:20.725_I_I_00e90220c303c004 [09:04] <<<<<<<<<<<<suspend interpretator(WAIT_PLAY_TREATMENT), func:TreatmentPlayAnnouncement timers:00000
received from 65200(sipserver)[siphost]:3000(fd=) message EventAttachedDataChanged(refid=99)
12:15:20.725_T_I_00e90220c303c004 [14:32] EventAttachedDataChanged is received for tserver sipserver[SIP] (this dn=RP1, refid=99)
received from 65200(sipserver)[siphost]:3000(fd=) message EventAttachedDataChanged(refid=100)
12:15:20.725_T_I_00e90220c303c004 [14:32] EventAttachedDataChanged is received for tserver sipserver[SIP] (this dn=RP1, refid=100)
received from 65200(sipserver)[siphost]:3000(fd=) message EventAttachedDataChanged(refid=101)
12:15:20.725_T_I_00e90220c303c004 [14:32] EventAttachedDataChanged is received for tserver sipserver[SIP] (this dn=RP1, refid=101)
received from 65200(sipserver)[siphost]:3000(fd=) message EventAttachedDataChanged(refid=102)
12:15:20.741_T_I_00e90220c303c004 [14:32] EventAttachedDataChanged is received for tserver sipserver[SIP] (this dn=RP1, refid=102)
received from 65200(sipserver)[siphost]:3000(fd=) message EventAttachedDataChanged(refid=103)
12:15:20.741_T_I_00e90220c303c004 [14:32] EventAttachedDataChanged is received for tserver sipserver[SIP] (this dn=RP1, refid=103)
received from 65200(sipserver)[siphost]:3000(fd=) message EventACK
AttributeUserEvent RequestDistributeEvent
AttributeThisDN 'exr'
AttributeTimeinSecs 1360239320 (12:15:20)
AttributeTimeinuSecs 758000
AttributeCustomerID 'Resources'
AttributeEventSequenceNumber 0000000000003b3f
received from 65200(sipserver)[siphost]:3000(fd=) message EventAttachedDataChanged(refid=104)
12:15:20.741_T_I_00e90220c303c004 [14:32] EventAttachedDataChanged is received for tserver sipserver[SIP] (this dn=RP1, refid=104)
received from 65200(sipserver)[siphost]:3000(fd=) message EventAttachedDataChanged(refid=105)
12:15:20.741_T_I_00e90220c303c004 [14:32] EventAttachedDataChanged is received for tserver sipserver[SIP] (this dn=RP1, refid=105)
12:15:22.007_M_I_ [10:1d] PULSE (calls: 1(1)=0+1-0, targets=0, time=1360239322, mem=0,47137,418,152,178,1)
12:15:22.007_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(0 0/1024)
12:15:24.007_M_I_ [10:1d] PULSE (calls: 1(1)=1+0-0, targets=0, time=1360239324, mem=0,47137,418,152,178,1)
12:15:24.007_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(0 0/1024)
12:15:26.007_M_I_ [10:1d] PULSE (calls: 1(1)=1+0-0, targets=0, time=1360239326, mem=0,47137,418,152,178,1)
12:15:26.007_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(0 0/1024)
12:15:28.007_M_I_ [10:1d] PULSE (calls: 1(1)=1+0-0, targets=0, time=1360239328, mem=0,47137,418,152,178,1)
12:15:28.007_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(0 0/1024)
12:15:30.007_M_I_ [10:1d] PULSE (calls: 1(1)=1+0-0, targets=0, time=1360239330, mem=0,47137,418,152,178,1)
12:15:30.007_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(0 0/1024)
received from 65200(sipserver)[siphost]:3000(fd=) message EventRouteUsed
AttributeCallState 22
AttributeCallType 2
AttributePropagatedCallType 2
AttributeCallID 4
AttributeConnID 00e90220c303c004
AttributeCallUUID 'BPDRUTEMVT665ALU9BP41P2RDG000004'
AttributeDNIS '111111'
AttributeANI '1111111111'
AttributeCustomerID 'Resources'
AttributeThisDN 'RP1'
AttributeThisDNRole 2
AttributeThisQueue 'RP1'
AttributeOtherQueue '111111'
AttributeOtherDN '1111111111'
AttributeOtherDNRole 1
AttributeThirdPartyDN '111111'
AttributeThirdPartyDNRole 2
AttributeExtensions [145] 00 04 01 00..
'MsmlResponseCode' 423
'ResponseDescription' 'External document fetch error: Failed to fetch file'
'OtherTrunkName' 'AVA'
'BusinessCall' 1
AttributeTimeinSecs 1360239331 (12:15:31)
AttributeTimeinuSecs 399000
AttributeEventSequenceNumber 0000000000003b48
12:15:31.366_T_I_00e90220c303c004 [14:0c] EventRouteUsed(strange) is received for tserver sipserver[SIP] (this dn=RP1)
_T_I_00e90220c303c004 [14:0a] del DN (sipserver[SIP] RP1) (ref.id=0)
_T_W_00e90220c303c004 [14:0a] there is no DNs for call, activate delayed selfdestruction
received from 65200(sipserver)[siphost]:3000(fd=) message EventDiverted[/i]
SIP log:
[i]--- Pre-event ---
+++ TreatmentError +++
@12:15:21.3980 [0] 8.1.001.15 distribute_event: message EventTreatmentNotApplied
AttributeEventSequenceNumber 0000000000003b45
AttributeTimeinuSecs 398000
AttributeTimeinSecs 1360239321 (12:15:21)
AttributeTreatmentParms [60] 00 01 03 00..
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 0
'ID' 1111
AttributeExtensions [145] 00 04 01 00..
'MsmlResponseCode' 423
'ResponseDescription' 'External document fetch error: Failed to fetch file'
'OtherTrunkName' 'AVA'
'BusinessCall' 1
AttributeErrorCode 50
AttributeErrorMessage 'Unspecified error'
AttributeTreatmentType 7 (TreatmentPlayAnnouncement)
AttributeThisQueue '111111'
AttributeThisDNRole 2
AttributeThisDN '111111'
AttributeCustomerID 'Resources'
AttributeANI '1111111111'
AttributeDNIS '111111'
AttributeCallUUID 'BPDRUTEMVT665ALU9BP41P2RDG000004'
AttributeConnID 00e90220c303c004
AttributeCallID 4
AttributePropagatedCallType 2
AttributeCallType 2
AttributeCallState 0
12:15:21.398 Int 04544 Interaction message "EventTreatmentNotApplied" generated
--- TreatmentError ---
+++ Post-event +++
Type EventTreatmentNotApplied
Devices: <111111/111111> <-/-> <-/->
Calls: 4/00e90220c303c004/4.2a7be38/c:2/r:1 0/none
Parties: D111111/111111.35e8ee8-2a7be38:1/l:2/r:0/Queued,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 ---
12:15:21.398 --- CIFace::Event ---
12:15:21.398: Max recovery Attempts exceeded, Treatment will be stopped
12:15:21.398: SIPTR(65): complete
12:15:21.398: SIPTR(63): Step 1 - SipTransactionProcessMsml(65) complete
12:15:21.398: SIPTR(63): complete
12:15:21.398: SIPCM: transaction SipScenario(63) complete
12:15:21.398: PI: 00 S[IN]D[1111111111]C[*D[1111111111]]P[msml_geo1]
12:15:21.398: PI: 00 S[QN]D[111111]E[-]MS[C[*D[msml_geo1]]]P[1111111111]
12:15:21.398: call1 4 idle
12:15:21.398: $-NET:SIP::0:1984[/i]
-
You have to had configured wrongly something (strategy block,SIP/URS options,..). I have installed same versions and I did not see described behaviors. If an SIP receives an error "Fetch failed",generates EventNotTreatmentApplied and URS continue in strategy. Check your strategy design
-
Doesnt explain why it works on sip 8.0.4 versions?..
I have checked the strategy within monitoring section and the call does not proceed out of the play announcement block, through red or green ports.
Will try latest SIP (..001.17)..
-
It's true that I have never used SIP in version 8.0,only in 8.1 and as I wrote I did not register described behavior. Did you reload application template after upgrade (SIP 8.0 x 8.1)?What version of URS do you use?
-
Tried URS 8.0 and 8.1.2, both had problem with SIP 8.1 but no issues with 8.0.4.
Am using sip 8.1 application template and configuration options, however did this with both versions (8.0 and 8.1) with only 8.0 working.
-
If SIP server sent EventTreatmentNotApplied to the URS it looks like a bad behavior on URS side. URS have to continue to next block through red (error) output.
-
Based on provided log snippet, URS doesn't receive EventTreatmentNotApplied but EventRouteUsed. That means that SIP Server took over the interaction.
@PFCCWA - Would it be possible to post here snippet of SIP Server log showing request to play treatment, response from Media Server (error) and following operations.
R.
-
Looking at the sip logs, tge EventTreatmentNotApplied is not sent to urs when using sip 8.1 - it is also applied to the ACD queue (attributrethisdn=111111 as per log) - and call fails.
If I use sip 8.0.4, the EventTreatmentNotApplied is applied to the route point (attributethisdn=RP1 as per log), and sent to urs - so call continues.
-
Could you post SIP options export?
-
sip config file below.
Tried latest sip release, same issue.
Tried default 8.1 template options, still occuring.
[TServer]
accept-dn-type = +extension +position +acdqueue +routedn +trunk +routequeue
acw-in-idle-force-ready = true
after-routing-timeout = 10
agent-emu-login-on-call = false
agent-group =
agent-logout-on-unreg = false
agent-logout-reassoc = false
agent-no-answer-action = none
agent-no-answer-overflow =
agent-no-answer-timeout = 15
agent-only-private-calls = false
agent-strict-id = false
am-detected = connect
ani-distribution = inbound-calls-only
audio-codecs = telephone-event,PCMU,PCMA,G723,G729,GSM
auto-logout-ready = true
auto-logout-timeout = 481
background-processing = false
background-timeout = 60 msec
backup-mode = none
backwds-compat-acw-behavior = false
busy-tone = music/busy_5sec
busy-tone-duration = 5
call-rq-gap = 0
cancel-monitor-on-disconnect = true
check-tenant-profile = false
clid-withheld-name = PRIVATE
collect-tone = music/collect
consult-user-data = separate
convert-otherdn = +agentid +reserveddn +fwd
correct-rqid = false
cos =
cpd-info-timeout = 30
customer-id = Resources
default-dn =
default-dn-type = none
default-monitor-mode = mute
default-monitor-scope = call
default-music = music/default.wav
default-video-file =
device-rq-gap = 0
dial-plan =
divert-on-ringing = false
dn-del-mode = never
dn-scope = undefined
dtmf-payload = 101
emergency-recording-cleanup-enabled = false
emergency-recording-filename =
emulate-login = on-RP
emulated-login-state = not-ready
enable-ims = false
enable-unknown-gateway = false
enforce-external-domains =
event-ringing-on-100trying = true
external-registrar =
extn-no-answer-overflow =
extn-no-answer-timeout = 15
fast-busy-tone = music/atb_5sec
fax-detected = drop
find-trunk-by-location = false
forced-notready = true
ims-default-icid-prefix =
ims-default-icid-suffix =
ims-default-orig-ioi =
ims-propagate-pcvector = false
ims-route =
inbound-bsns-calls = false
info-pass-through =
inherit-bsns-type = false
init-dnis-by-ruri = false
internal-bsns-calls = false
internal-registrar-domains =
internal-registrar-enabled = true
internal-registrar-persistent = true
intrusion-enabled = true
kpl-interval = 10
kpl-loss-rate = 10,100
kpl-tolerance = 3
legal-guard-time = 0
log-trace-flags = +iscc +cfg$dn -cfgserv +passwd +udata -devlink -sw -req -callops -conn -client
logout-on-disconnect = true
make-call-alert-info =
management-port = 3001
map-sip-errors = true
max-legs-per-sm = 0
max-pred-req-delay = 3
merged-user-data = main-only
monitor-internal-calls = true
msml-support = true
music-in-conference-file = music/conference.wav
music-in-queue-file = music/on_hold_pcma.wav
mwi-agent-enable = false
mwi-domain =
mwi-extension-enable = false
mwi-group-enable = false
mwi-host =
mwi-mode = SUBSCRIBE
mwi-port = 5061
nas-indication = none
nas-private = false
observing-routing-point =
outbound-bsns-calls = true
override-switch-acw = false
override-to-on-divert = false
p-asserted-identity =
parking-music = music/silence
partition-id = SipServerDefaultPartition
posn-no-answer-overflow =
posn-no-answer-timeout = 15
prd-dist-call-ans-time = 0
predictive-call-router-timeout = 0
preview-expired = 90
privacy =
propagated-call-type = false
recall-no-answer-timeout = 15
record-consult-calls = false
recording-filename =
refer-enabled = true
reg-interval = 60
registrar-default-timeout = 1800
releasing-party-report = false
restart-period = 20
ring-tone = music/RingTone.wav
ringing-on-route-point = true
route-failure-alarm-high-wm = 10
route-failure-alarm-low-wm = 1
route-failure-alarm-period = 0
router-timeout = 10
rq-conflict-check = true
server-role = 0
session-refresh-interval = 1800
set-notready-on-busy = false
silence-tone = music/silence
sip-address = 1**.**.***.**
sip-address-srv =
sip-call-retain-timeout = 1
sip-dtmf-send-rtp = true
sip-enable-100rel = true
sip-enable-call-info = false
sip-enable-moh = true
sip-enable-sdp-application-filter = false
sip-enable-sdp-codec-filter = false
sip-hold-rfc3264 = true
sip-invite-timeout = 0
sip-invite-treatment-timeout = 0
sip-ip-tos = 256
sip-port = 5060
sip-port-tls = 0
sip-preserve-contact = false
sip-proxy-headers-enabled = true
sip-replaces-mode = 0
sip-retry-timeout = 30
sip-ring-tone-mode = 0
sip-tls-cert =
sip-tls-cert-key =
sip-tls-trusted-ca =
sip-treatment-dtmf-interruptable = false
sip-treatments-continuous = false
stranded-call-redirection-limit = 4
stranded-calls-overflow =
stranded-on-arrival-calls-overflow =
subscription-timeout = 180
sync-emu-agent = false
timed-acw-in-idle = true
unknown-bsns-calls = false
unknown-xfer-merge-udata = false
untimed-wrap-up-value = 1000
use-display-name = false
user-data-limit = 16000
userdata-map-trans-prefix = X-Genesys
wrap-up-threshold = 0
wrap-up-time = 7
rq-expire-tmout = 0
rq-expire-tout = 0
enable-msml-media-services = true
enable-overload-control = false
http-port = 0
max-load-factor-percentage = 200
mime-body-type =
min-load-factor-percentage = 110
presence-enabled = false
sip-enable-sdp-encryption-removal = false
sip-force-rport = false
sip-interface =
sip-refer-to-sst-enabled = true
sync-emu-acw = false
xs-heartbeat-interval = 180
[log-filter]
default-filter-type = copy
[link-control]
ha-sync-dly-lnk-conn = false
link-alarm-high = 0
link-alarm-low = 0
quiet-cleanup = false
quiet-startup = false
reg-delay = 10
reg-silent = true
restart-cleanup-dly = 0
restart-cleanup-limit = 0
use-link-bandwidth = auto
[license]
license-file = 7260@[licensehost]
num-of-licenses = 100
num-sdn-licenses = 100
[extrouter]
cast-type = route direct-callid reroute direct-uui direct-ani direct-notoken dnis-pool direct-digits pullback route-uui direct-network-callid
cof-ci-defer-create = 0
cof-ci-defer-delete = 0
cof-ci-req-tout = 500 msec
cof-ci-wait-all = false
cof-feature = false
cof-rci-tout = 10 sec
compound-dn-representation = true
default-dn =
default-network-call-id-matching =
direct-digits-key = CDT_Track_Num
dn-for-unexpected-calls =
epp-tout = 0 sec
event-propagation = list
match-call-once = true
network-request-timeout = 20 sec
reconnect-tout = 5 sec
register-attempts = 5
register-tout = 2 sec
report-connid-changes = false
request-tout = 20 sec
resource-allocation-mode = circular
resource-load-maximum = 0
route-dn =
tcs-queue =
tcs-use = never
timeout = 60 sec
use-data-from = current
use-implicit-access-numbers = false
handle-vsp = all
[call-cleanup]
cleanup-idle-tout = 0
notify-idle-tout = 0
periodic-check-tout = 10 min
[backup-sync]
addp-remote-timeout = 60
addp-timeout = 30
addp-trace = on
protocol = default
sync-reconnect-tout = 20 sec
[agent-reservation]
collect-lower-priority-requests = true
reject-subsequent-request = true
request-collection-time = 100 msec
reservation-time = 10000 msec
[log-filter-data]
<kv-pair-key> = copy
[log]
all = D:\Program Files\GCTI\logs\sipserver\sipserver
expire = 3 day
keep-startup-file = true
message_format = short
segment = 10000
verbose = all
buffering = true
standard = network
-
Could you upload somewhere SIP Server log of the call with failed treatment?
R.
-
Any update please with this problem ....I have the same problem now.
-
OP never answered back, so if you want help follow procedures...logs...as magic balls are out of service
-
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
-
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)
-
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.
-
And URS ones too