Rene/Cavagnaro,
Below are the logs of tserver:
22:09:46.285 Trc 04541 RequestRouteCall received from [476] (00000034 routing_server 10.9.2.194:2019)
message RequestRouteCall
AttributeThisDN '17016'
AttributeConnID 00660197a04b93c4
AttributeOtherDN '17017'
AttributeExtensions [57] 00 03 00 00..
'CUSTOMER_ID' 'Resources'
'VQ' ''
'SWITCH' 'Avaya_Switch'
AttributeRouteType 0 (RouteTypeUnknown)
AttributeReason [14] 00 01 01 00..
'RTR' 110
AttributeReferenceID 1286
22:09:46.285 Int 04543 Interaction message "RequestRouteCall" received from 476 ("routing_server")
@22:09:46.2850 [gctmi] Distributing request RequestRouteCall
@22:09:46.2850 [asai] Party [00660197a04b93c4:17016,s809,tRP,rDST,lINT] (reqRouteCall)
TP_AsaiData
FACILITY CRV:8078
Facility: INVOKE
InvokeId: 2
Operation: RouteSelect
CalledNum: (unknown),'17017'
@22:09:46.2850 [>>] 08 00 00 1B 08 02 80 78 62 96 1C 13 91 A1 10 02 01 02 02 01 B7 40 08 70 06 80 31 37 30 31 37
@22:09:46.3010 [<<] 08 00 00 17 08 02 00 78 5A 96 1C 0F 91 A1 0C 02 01 01 02 01 B9 40 04 08 02 81 90
TP_AsaiData
RELEASE_COMPLETE CRV:78
Facility: INVOKE
InvokeId: 1
Operation: RouteEnd
Cause: C_NORMAL
@22:09:46.3010 [asai] (processOperRouteEnd)
@22:09:46.3010 [gctmi] request RequestRouteCall deactivated in reqMgr
@22:09:46.3010 [gctmi] TMsg [EventRouteUsed(17016)] distributing to model
@22:09:46.3010 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] distributing EventRouteUsed
@22:09:46.3010 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] processRouteUsed
@22:09:46.3010 [gctm] Call [00660197a04b93c4/16cb,sOG,tOG,l1] RouteQueue waits for matching divert/r-used.
@22:09:46.3010 [gctmi] TMsg [EventRouteUsed(17016)] (re)distributing to model in 250mS
@22:09:46.3010 [gctmi] request RequestRouteCall deactivated in reqMgr
@22:09:46.3010 [gctmi] TMsg [EventDiverted(17016)] distributing to model
@22:09:46.3010 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] distributing EventDiverted
@22:09:46.3010 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] processDiverted
@22:09:46.3010 [gctmi] TMsg [EventDiverted(17016)] (re)distributing to model in 250mS
@22:09:46.3480 [<<] 08 00 00 1B 08 02 BA 4E 62 96 1C 13 91 A1 10 02 01 02 02 01 95 40 08 10 02 16 CB 96 47 01 99
TP_AsaiData
FACILITY CRV:ba4e
Facility: INVOKE
InvokeId: 2
Operation: EventReport
CallID[1]: 5835
Event[1]: Redirected
@22:09:46.3480 [asai] (processEvReportRedirected)
@22:09:46.3480 [gctmi] TMsg [EventReleased(17016)] distributing to model
@22:09:46.3480 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] distributing EventReleased
@22:09:46.3480 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] processReleased
@22:09:46.3480 [gctmi] TMsg [EventRouteUsed(17016)] (re)distributing to model in 250mS
@22:09:46.3480 [<<] 08 00 00 46 08 02 BA 4F 62 96 1C 3E 91 A1 3B 02 01 02 02 01 95 40 33 10 02 16 CB 6C 0B 81 30 31 32 33 36 30 36 33 39 35 70 05 81 33 30 30 30 96 0A 03 80 81 95 47 01 91 49 06 8C 31 37 30 31 B7 7C 08 00 01 16 CB 48 84 98 F1
TP_AsaiData
FACILITY CRV:ba4f
Facility: INVOKE
InvokeId: 2
Operation: EventReport
CallID[1]: 5835
CallingNum: (ISDN_telephony),'0123606395'
CalledNum: (ISDN_telephony),'3000'
TrunkGroupId[1]: (dir/gr/memb),0/1/21
Event[1]: Offered
Domain[1]: (VDN),'17017'
UniversalCallId: 00 01 16 CB 48 84 98 F1
@22:09:46.3480 [asai] (processEvReportOffered)
@22:09:46.3480 [gctmi] TMsg [EventQueued(17017)] distributing to model
@22:09:46.3480 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] distributing EventQueued
@22:09:46.3480 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] processQueued
@22:09:46.3480 [asai] Call [00660197a04b93c4/16cb,sOG,tOG,l1] (createParty)
@22:09:46.3480 [gctm] Party [00660197a04b93c4:17017,s0,tRP,rDST,lINT] created.
@22:09:46.3480 [asai] Party [00660197a04b93c4:17017,s0,tRP,rDST,lINT] (AsaiIntParty)
@22:09:46.3480 [asai] Party [00660197a04b93c4:17017,s0,tRP,rDST,lINT] setting id to 0
@22:09:46.3480 [gctm] Party [00660197a04b93c4:17016,s809,tRP,rDST,lINT] rls-party certain match to EventQueued
@22:09:46.3480 [gctm] Call [00660197a04b93c4/16cb,sOG,tOG,l1] ReleaseParty match found.
@22:09:46.3480 [gctmi] Party [00660197a04b93c4:17016,s809,tRP,rDST,lINT] processRouteUsed
@22:09:46.3480 [gctm] Party [00660197a04b93c4:17016,s809,tRP,rDST,lINT] Changing state to 9
@22:09:46.3480 [gctmi] request RequestRouteCall removed from reqMgr
@22:09:46.3480 [0] 7.5.009.00 distribute_response: message EventRouteUsed
AttributeEventSequenceNumber 000000000000d4f6
AttributeTimeinuSecs 348000
AttributeTimeinSecs 1216649386 (22:09:46)
AttributeExtensions [35] 00 02 01 00..
'G3Cause' 625
'UCID' bin: F1 98 84 48.. (len=8)
AttributeThirdPartyDNRole 2
AttributeThirdPartyDN '17017'
AttributeOtherDNRole 1
AttributeOtherDN '0123606395'
AttributeThisDNRole 2
AttributeThisDN '17016'
AttributeANI '0123606395'
AttributeDNIS '3000'
AttributeUserData [414] 00 11 00 00..
'RVQID' ''
'RTargetTypeSelected' '100'
'RTargetRuleSelected' ''
'RTargetObjectSelected' ''
'RTargetAgentSelected' ''
'RTargetPlaceSelected' ''
'RTenant' 'Resources'
'RStrategyName' 'CLIRouteToRP_test'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
AttributeCallUUID '29FN0B80GH0NFB3GIDAVMT2M7G0006CB'
AttributeConnID 00660197a04b93c4
AttributeCallID 5835
AttributeCallType 2
AttributeNetworkCallID 1216649457
AttributeThisQueue '17016'
AttributeCallState 0
AttributeReason [14] 00 01 01 00..
'RTR' 110
AttributeReferenceID 1286
@22:09:46.3480 [ISCC] Debug: Translate: '0123606395' -> ''; result 1 ()
22:09:46.348 Int 04544 Interaction message "EventRouteUsed" generated
22:09:46.348 Trc 04542 EventRouteUsed sent to [476] (00000034 routing_server 10.9.2.194:2019)
22:09:46.348 Trc 04542 EventRouteUsed sent to [448] (00000039 reporting_statserver 10.9.2.195:2393)
22:09:46.348 Trc 04542 EventRouteUsed sent to [472] (0000002f ccpulse_statserver 10.9.2.195:2706)
22:09:46.348 Trc 04542 EventRouteUsed sent to [432] (00000004 bpi_statserver 10.9.2.194:2451)
22:09:46.348 Trc 04542 EventRouteUsed sent to [396] (00000002 routing_statserver 10.9.2.194:2437)
@22:09:46.3480 [gctmi] Party [00660197a04b93c4:17016,s9,tRP,rDST,lINT] processDiverted
@22:09:46.3480 [gctm] Party [00660197a04b93c4:17016,s9,tRP,rDST,lINT] Changing state to 0
@22:09:46.3480 [0] 7.5.009.00 distribute_event: message EventDiverted
AttributeEventSequenceNumber 000000000000d4f7
AttributeTimeinuSecs 348000
AttributeTimeinSecs 1216649386 (22:09:46)
AttributeExtensions [19] 00 01 02 00..
'UCID' bin: F1 98 84 48.. (len=8)
AttributeThirdPartyDNRole 2
AttributeThirdPartyDN '17017'
AttributeOtherDNRole 1
AttributeOtherDN '0123606395'
AttributeThisDNRole 2
AttributeThisDN '17016'
AttributeANI '0123606395'
AttributeDNIS '3000'
AttributeUserData [414] 00 11 00 00..
'RVQID' ''
'RTargetTypeSelected' '100'
'RTargetRuleSelected' ''
'RTargetObjectSelected' ''
'RTargetAgentSelected' ''
'RTargetPlaceSelected' ''
'RTenant' 'Resources'
'RStrategyName' 'CLIRouteToRP_test'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
AttributeCallUUID '29FN0B80GH0NFB3GIDAVMT2M7G0006CB'
AttributeConnID 00660197a04b93c4
AttributeCallID 5835
AttributeCallType 2
AttributeNetworkCallID 1216649457
AttributeThisQueue '17016'
AttributeCallState 0
@22:09:46.3480 [ISCC] Debug: Translate: '0123606395' -> ''; result 1 ()
22:09:46.348 Int 04544 Interaction message "EventDiverted" generated
22:09:46.348 Trc 04542 EventDiverted sent to [448] (00000039 reporting_statserver 10.9.2.195:2393)
22:09:46.348 Trc 04542 EventDiverted sent to [476] (00000034 routing_server 10.9.2.194:2019)
22:09:46.348 Trc 04542 EventDiverted sent to [472] (0000002f ccpulse_statserver 10.9.2.195:2706)
22:09:46.348 Trc 04542 EventDiverted sent to [432] (00000004 bpi_statserver 10.9.2.194:2451)
22:09:46.348 Trc 04542 EventDiverted sent to [396] (00000002 routing_statserver 10.9.2.194:2437)
@22:09:46.3480 [gctmi] Party [00660197a04b93c4:17016,s0,tRP,rDST,lINT] processRouteUsed
@22:09:46.3480 [gctmi] Party [00660197a04b93c4:17016,s0,tRP,rDST,lINT] EventRouteUsed ignored, already in state.
@22:09:46.3480 [ISCC] Debug: Party removed [ssp view]:
@ c:00660197a04b93c4,017ec9b0 @ m:0000000000000000,00000000,0000000000000000 p:2 i:000016cb nw:00000000:000116cb488498f1 t:2
- p:01be4b80 @ c:00660197a04b93c4,017ec9b0 r:2 t:0 s:0 n:17016
p:01beb0b8 @ c:00660197a04b93c4,017ec9b0 r:2 t:0 s:0 n:17017
@22:09:46.3480 [ISCC] Debug: Party removed:
@ c:00660197a04b93c4,017ec9b0 @ m:0000000000000000,00000000 p:1 i:000016cb nw:000116cb488498f1 t:2
- p:0000000000000000,01be4b80 @ c:00660197a04b93c4,017ec9b0 r:2 ------ n:17016:
@22:09:46.3480 [ISCC] Debug: Party object is removed: p:0000000000000000,00000000 n:17016:
@22:09:46.3480 [gctm] Party [00660197a04b93c4:17016,s0,tRP,rDST,lINT] deleting.
@22:09:46.3480 [gctmi] Party [00660197a04b93c4:17017,s0,tRP,rDST,lINT] distribute
@22:09:46.3480 [gctmi] Party [00660197a04b93c4:17017,s0,tRP,rDST,lINT] processQueued
@22:09:46.3480 [gctm] Party [00660197a04b93c4:17017,s0,tRP,rDST,lINT] Changing state to 9
@22:09:46.3480 [ISCC] Debug: Party added [ssp view]:
@ c:00660197a04b93c4,017ec9b0 @ m:0000000000000000,00000000,0000000000000000 p:1 i:000016cb nw:00000000:000116cb488498f1 t:2
+ p:01beb0b8 @ c:00660197a04b93c4,017ec9b0 r:2 t:0 s:0 n:17017
@22:09:46.3480 [ISCC] Debug: Party added:
@ c:00660197a04b93c4,017ec9b0 @ m:0000000000000000,00000000 p:1 i:000016cb nw:000116cb488498f1 t:2
+ p:0000000000000000,01beb0b8 @ c:00660197a04b93c4,017ec9b0 r:2 ------ n:17017:
@22:09:46.3480 [0] 7.5.009.00 distribute_event: message EventQueued
AttributeEventSequenceNumber 000000000000d4f8
AttributeTimeinuSecs 348000
AttributeTimeinSecs 1216649386 (22:09:46)
AttributeExtensions [19] 00 01 02 00..
'UCID' bin: F1 98 84 48.. (len=8)
AttributeOtherDNRole 1
AttributeOtherDN '0123606395'
AttributeThisDNRole 2
AttributeThisDN '17017'
AttributeThisTrunk 65557
AttributeANI '0123606395'
AttributeDNIS '3000'
AttributeUserData [414] 00 11 00 00..
'RVQID' ''
'RTargetTypeSelected' '100'
'RTargetRuleSelected' ''
'RTargetObjectSelected' ''
'RTargetAgentSelected' ''
'RTargetPlaceSelected' ''
'RTenant' 'Resources'
'RStrategyName' 'CLIRouteToRP_test'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
AttributeCallUUID '29FN0B80GH0NFB3GIDAVMT2M7G0006CB'
AttributeConnID 00660197a04b93c4
AttributeCallID 5835
AttributeCallType 2
AttributeNetworkCallID 1216649457
AttributeThisQueue '17017'
AttributeCallState 0
@22:09:46.3480 [ISCC] Debug: Translate: '0123606395' -> ''; result 1 ()
22:09:46.348 Int 04544 Interaction message "EventQueued" generated
22:09:46.348 Trc 04542 EventQueued sent to [448] (00000039 reporting_statserver 10.9.2.195:2393)
22:09:46.348 Trc 04542 EventQueued sent to [396] (00000002 routing_statserver 10.9.2.194:2437)
22:09:46.348 Trc 04542 EventQueued sent to [472] (0000002f ccpulse_statserver 10.9.2.195:2706)
22:09:46.348 Trc 04542 EventQueued sent to [432] (00000004 bpi_statserver 10.9.2.194:2451)
@22:09:46.3790 [<<] 08 00 00 2A 08 02 BA 4F 62 96 1C 22 91 A1 1F 02 01 02 02 01 95 40 17 08 02 81 E5 0C 06 80 23 23 23 23 23 10 02 16 CB 96 44 01 81 47 01 84
TP_AsaiData
FACILITY CRV:ba4f
Facility: INVOKE
InvokeId: 2
Operation: EventReport
Cause: 101
ConnectedNum[1]: (unknown),'#####'
CallID[1]: 5835
PartyId[1]: 1
Event[1]: Disconnect
@22:09:46.3790 [asai] (processEvReportDisconnect)
@22:09:46.3790 [gctmi] TMsg [EventReleased()] distributing to model
@22:09:46.3790 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] distributing EventReleased
@22:09:46.3790 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] processReleased
@22:09:46.3790 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] EvRelease ignored for non-exist party.
@22:09:46.3940 [<<] 08 00 00 1B 08 02 BA 4F 62 96 1C 13 91 A1 10 02 01 02 02 01 BB 40 08 08 02 81 90 10 02 16 CB
TP_AsaiData
FACILITY CRV:ba4f
Facility: INVOKE
InvokeId: 2
Operation: TP_CallEnded
Cause: C_NORMAL
CallID[1]: 5835
@22:09:46.3940 [asai] (processOperCallEnded)
@22:09:46.3940 [gctmi] TMsg [EventCallEnded()] (re)distributing to model in 500mS
@22:09:46.8950 [gctmi] TMsg [EventCallEnded()] distributing to model
@22:09:46.8950 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] distributing EventCallEnded
@22:09:46.8950 [gctmi] Call [00660197a04b93c4/16cb,sOG,tOG,l1] processCallEnded
@22:09:46.8950 [gctmi] Party [00660197a04b93c4:17017,s9,tRP,rDST,lINT] processReleased
@22:09:46.8950 [gctm] Party [00660197a04b93c4:17017,s9,tRP,rDST,lINT] sending abandoned, not released
@22:09:46.8950 [gctm] Party [00660197a04b93c4:17017,s9,tRP,rDST,lINT] Changing state to 0
@22:09:46.8950 [0] 7.5.009.00 distribute_event: message EventAbandoned
AttributeEventSequenceNumber 000000000000d4f9
AttributeTimeinuSecs 895000
AttributeTimeinSecs 1216649386 (22:09:46)
AttributeExtensions [19] 00 01 02 00..
'UCID' bin: F1 98 84 48.. (len=8)
AttributeOtherDNRole 1
AttributeOtherDN '0123606395'
AttributeThisDNRole 2
AttributeThisDN '17017'
AttributeANI '0123606395'
AttributeDNIS '3000'
AttributeUserData [414] 00 11 00 00..
'RVQID' ''
'RTargetTypeSelected' '100'
'RTargetRuleSelected' ''
'RTargetObjectSelected' ''
'RTargetAgentSelected' ''
'RTargetPlaceSelected' ''
'RTenant' 'Resources'
'RStrategyName' 'CLIRouteToRP_test'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
AttributeCallUUID '29FN0B80GH0NFB3GIDAVMT2M7G0006CB'
AttributeConnID 00660197a04b93c4
AttributeCallID 5835
AttributeCallType 2
AttributeNetworkCallID 1216649457
AttributeThisQueue '17017'
AttributeCallState 0
AttributeReliability 0
@22:09:46.8950 [ISCC] Debug: Translate: '0123606395' -> ''; result 1 ()
22:09:46.895 Int 04544 Interaction message "EventAbandoned" generated
22:09:46.895 Trc 04542 EventAbandoned sent to [448] (00000039 reporting_statserver 10.9.2.195:2393)
22:09:46.895 Trc 04542 EventAbandoned sent to [396] (00000002 routing_statserver 10.9.2.194:2437)
22:09:46.895 Trc 04542 EventAbandoned sent to [472] (0000002f ccpulse_statserver 10.9.2.195:2706)
22:09:46.895 Trc 04542 EventAbandoned sent to [432] (00000004 bpi_statserver 10.9.2.194:2451)
@22:09:46.8950 [gctm] Call [00660197a04b93c4/16cb,sOG,tOG,l0] Setting timer to 0M:7000mS
@22:09:46.8950 [ISCC] Debug: Party removed [ssp view]:
@ c:00660197a04b93c4,017ec9b0 @ m:0000000000000000,00000000,0000000000000000 p:1 i:000016cb nw:00000000:000116cb488498f1 t:2
- p:01beb0b8 @ c:00660197a04b93c4,017ec9b0 r:2 t:0 s:0 n:17017
@22:09:46.8950 [ISCC] Debug: Party removed:
@ c:00660197a04b93c4,017ec9b0 @ m:0000000000000000,00000000 p:1 i:000016cb nw:000116cb488498f1 t:2
- p:0000000000000000,01beb0b8 @ c:00660197a04b93c4,017ec9b0 r:2 ------ n:17017:
@22:09:46.8950 [ISCC] Debug: Party object is removed: p:0000000000000000,00000000 n:17017:
@22:09:46.8950 [gctm] Party [00660197a04b93c4:17017,s0,tRP,rDST,lINT] deleting.
@22:09:46.8950 [asai] Call [00660197a04b93c4/16cb,sOG,t0M,l0] (~AsaiCall)
@22:09:46.8950 [0] 7.5.009.00 distribute_event: message EventReleased
AttributeEventSequenceNumber 000000000000d4fa
AttributeTimeinuSecs 895000
AttributeTimeinSecs 1216649386 (22:09:46)
AttributeANI '0123606395'
AttributeDNIS '3000'
AttributeUserData [414] 00 11 00 00..
'RVQID' ''
'RTargetTypeSelected' '100'
'RTargetRuleSelected' ''
'RTargetObjectSelected' ''
'RTargetAgentSelected' ''
'RTargetPlaceSelected' ''
'RTenant' 'Resources'
'RStrategyName' 'CLIRouteToRP_test'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
AttributeCallUUID '29FN0B80GH0NFB3GIDAVMT2M7G0006CB'
AttributeConnID 00660197a04b93c4
AttributeCallID 5835
AttributeCallType 2
AttributeThisDN 'Avaya_Switch::'
@22:09:46.8950 [ISCC] Debug: Translate: '0123606395' -> ''; result 1 ()
@22:09:46.8950 [ISCC] Debug: Party object is removed: p:0000000000000000,00000000 n::
@22:09:46.8950 [ISCC] Warning: No call is associated with the event, skipped
@22:09:46.8950 [ISCC] Warning: No call is associated with the event, skipped
@22:09:46.8950 [ISCC] Warning: No call is associated with the event, skipped
@22:09:46.8950 [ISCC] Warning: No call is associated with the event, skipped
22:09:46.895 Int 04544 Interaction message "EventReleased" generated
22:09:46.895 Trc 04542 EventReleased sent to [448] (00000039 reporting_statserver 10.9.2.195:2393)
22:09:46.895 Trc 04542 EventReleased sent to [472] (0000002f ccpulse_statserver 10.9.2.195:2706)
22:09:46.895 Trc 04542 EventReleased sent to [432] (00000004 bpi_statserver 10.9.2.194:2451)
22:09:46.895 Trc 04542 EventReleased sent to [396] (00000002 routing_statserver 10.9.2.194:2437)
@22:09:46.8950 [ISCC] Debug: Call destroyed:
- c:00660197a04b93c4,017ec9b0 @ m:0000000000000000,00000000 p:0 i:000016cb nw:000116cb488498f1 t:2
@22:09:46.8950 [ISCC] Debug: Call object is removed: c:00660197a04b93c4,00000000
@22:09:46.8950 [gctm] Call [00660197a04b93c4/16cb,sOG,t0M,l0] deleting.
Macca,
'route-thru-queue' is set to false. i'll try and change it to true and test it.