[cisco-voip] IPCC - Unable to Route Call to Agent
Ivan Zhitianov
jiteto at gmail.com
Mon Oct 2 08:55:21 EDT 2006
I have done that, but i really don't know what to looking for and what the
errors mean.
This is a smaple output:
168841: Oct 02 15:34:27.622 EEST %MIVR-SS_RM-7-UNK:Agent izhitiyanov
.removeAssociatedContact(Contact:3476512/1
168842: Oct 02 15:34:27.622 EEST %MIVR-SS_RM-7-UNK:Agent izhitiyanov
.removeAssociatedContact(Contact:3476512/1
168843: Oct 02 15:34:27.622 EEST %MIVR-SS_RM-7-UNK:Rsrc: izhitiyanov
Contacts:Contact ID:20253722 [3476506/1] Contact Class:NON IAQ App Contact
Id:120
168844: Oct 02 15:34:27.622 EEST %MIVR-SS_RM-7-UNK:Rsrc: izhitiyanov
PrevState: UNAVAILABLE PrevStateSet:true
168845: Oct 02 15:34:27.622 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ:
168846: Oct 02 15:34:27.622 EEST %MIVR-SS_RM-7-UNK:Processing msg:
SessionInvalidMsg (ID:3476512/1)
168847: Oct 02 15:34:27.622 EEST
%MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476512/1)
returns 20253728 [3476512/1]
168848: Oct 02 15:34:27.622 EEST %MIVR-APP_MGR-3-EXCEPTION: at
com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.handleConsultFailure
(TAPIPortGroup.java:6362)
168849: Oct 02 15:34:27.622 EEST %MIVR-APP_MGR-3-EXCEPTION: at
com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.access$6200
(TAPIPortGroup.java:5018)
168850: Oct 02 15:34:27.622 EEST %MIVR-APP_MGR-3-EXCEPTION: at
com.cisco.wf.subsystems.jtapi.TAPIPortGroup$7.run(TAPIPortGroup.java:6211)
168851: Oct 02 15:34:27.622 EEST %MIVR-SS_RM-7-UNK:session is null in
SessionInvalidMsg for RmCm contact 20253728 and App FW contact 127, so not
removing mapping ID
168852: Oct 02 15:34:27.622 EEST %MIVR-SS_CM-7-UNK:Processing msg: class
com.cisco.wf.subsystems.rmcm.msgs.CMFireContactDisconnectedEventReqMsgContact127
168853: Oct 02 15:34:27.622 EEST %MIVR-APP_MGR-3-EXCEPTION: at
com.cisco.app.impl.ApplicationManagerImpl$TaskImpl$ActionImpl.run(
ApplicationManagerImpl.java:7687)
168854: Oct 02 15:34:27.622 EEST %MIVR-SS_CM-7-UNK:ContactEventsGenerator:
session is null in RsrcMgr.cleanup and App FW contact 127, so not removing
mapping ID
168855: Oct 02 15:34:27.622 EEST %MIVR-APP_MGR-3-EXCEPTION: at
com.cisco.app.impl.ApplicationManagerImpl$TaskImpl.doInterruptible(
ApplicationManagerImpl.java:7490)
168856: Oct 02 15:34:27.622 EEST %MIVR-SS_CM-7-UNK:
ContactMgr.removeRmCmContact(3476512/1)
168857: Oct 02 15:34:27.622 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID:
[3476512/1] 20253728 ContactEventsGenerator: Posting the
ContactDisconnectedEvent contact type IAQ_CONSULT_CONTACT, session
5000000156, session seq num 7, rejReason 2, abortReason null
168858: Oct 02 15:34:27.622 EEST %MIVR-APP_MGR-3-EXCEPTION: at
com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.waitForConsultState
(TAPIPortGroup.java:6074)
168859: Oct 02 15:34:27.622 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: got
contactDisconnected. CONNECTIONDEVICEID=201
<output omite>
168889: Oct 02 15:34:27.622 EEST %MIVR-APP_MGR-6-ABORTING_CONTACT:Aborting
contact: Application=ICD,Task id=18000000128,Contact id=120,Contact
implementation id=3476506/1,Contact Class=com.cisco.call.CallContact,Contact
Type=Cisco JTAPI Call,Exception=com.cisco.channel.ChannelExecutionException:
Contact id: 120, Channel id: 1, Reason: UNCAUGHT_EXCEPTION, Too many
transfer failures
The result from that on the operator and calling station is that the
operator is chaging from Rady to Not Ready other operators change form Ready
to Reserved. I hear a MoH and cliping and the the error message.
I suppose that I'm missing something with the associations of devices, users
and CTI ports. But I'm following the guide and 5 times reconfigure
everything from scratch and the result is just the same.
So here is what I do and know for sure:
- Calling searching spaces are 100% OK.
- IP Phone is controlled by RM JTAPI user and end-user
- end-user has a pripary extension 359 and IPCC ext 200 for example
- End-user has controll over CTI port 200
- Teams are configured
- Resources are configured
- CSQ is configured
- JTAPI Group is configured
- Cisco Media Group is configured
I pretty despered about that. So I will be glad to here any suggestions or
hints.
PS: I'm attaching the whole conversation MIVR log.
Thanks in advance!
- Ivan
On 10/2/06, Ryan Ratliff <rratliff at cisco.com> wrote:
>
> Turn up debugs in IPCC and look at the MIVR logs. It sounds like
> it's failing to redirect the call to the agent for some reason.
>
> -Ryan
>
> On Sep 30, 2006, at 2:46 PM, Ivan Zhitianov wrote:
>
> Hi all,
> I'm trying to get ICD working on IPCC Express 4.5.
>
> Everything seems fine but when I dial defined for the ICD Route Point
> I get MOH followed by an error message that service is not running OK
> or just that there are no free agents at the moment. Route Point and
> CTI Ports are registered to Call Manger. All of the phones and CTI
> ports are in one Calling Searching Space. RM JTAPI User and End-user
> has a control over Phone and CTI Port.
>
> Mean while on the IP Phone agent and/or Desktop Agent I get status
> changing from Ready to Reserved again Ready and Reserved till I here
> the error message.
>
> What I'm missing?!
>
> Thanks in advance!
>
> Best Regards,
> Ivan
>
> _______________________________________________
> cisco-voip mailing list
> cisco-voip at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-voip
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: https://puck.nether.net/pipermail/cisco-voip/attachments/20061002/d29aebeb/attachment-0001.html
-------------- next part --------------
172842: Oct 02 15:47:58.068 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39373, agentID=oper }
172843: Oct 02 15:47:58.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
172844: Oct 02 15:47:58.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39373, agentID=oper, callsInQueue=0, oldestCallInQueue=0 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
172845: Oct 02 15:47:58.068 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
172846: Oct 02 15:48:01.052 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476420/1) returns null
172847: Oct 02 15:48:01.052 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476398/1) returns null
172848: Oct 02 15:48:01.052 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476377/1) returns null
172849: Oct 02 15:48:03.756 EEST %MIVR-ICD_CTI-7-UNK:Received message HEARTBEAT_REQ
Message dump, excluding msg header (Length = 4 bytes):
0 0 12 f4
172850: Oct 02 15:48:03.756 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52492,localport=42027] Msg is {length=4 type=HEARTBEAT_REQ,invokeId=4852 }
172851: Oct 02 15:48:03.756 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { HEARTBEAT_CONF }
172852: Oct 02 15:48:03.756 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=HEARTBEAT_CONF,invokeId=4852 to socket: Socket[addr=10.90.201.3,port=52492,localport=42027] }
172853: Oct 02 15:48:03.756 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { HEARTBEAT_CONF to Socket[addr=10.90.201.3,port=52492,localport=42027] }
172854: Oct 02 15:48:09.068 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 ce c2 5 o p e r 0
172855: Oct 02 15:48:09.068 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39374, agentID=oper }
172856: Oct 02 15:48:09.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
172857: Oct 02 15:48:09.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39374, agentID=oper, callsInQueue=0, oldestCallInQueue=0 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
172858: Oct 02 15:48:09.068 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
172859: Oct 02 15:48:15.021 EEST %MIVR-SS_TEL-7-UNK:Route Connection=[303:/(P1-jtapi_crs_1_1_1) GCID=(1,3476527)->ACTIVE]->OFFERED, reason=1, Event= CallCtlConnOfferedEv, cause=100, metacode=128, isMaster=true
172860: Oct 02 15:48:15.021 EEST %MIVR-SS_CM-7-UNK:RmCm contact -1[null] .setAppContact(139) from null
172861: Oct 02 15:48:15.021 EEST %MIVR-SS_TEL-7-UNK:Call.received() JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=null,session=null,seq num=-1,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=null
172862: Oct 02 15:48:15.021 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactSessionChanged received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
172863: Oct 02 15:48:15.021 EEST %MIVR-SS_CM-7-UNK:Ignoring contactSessionChanged because either the new or old session is null
172864: Oct 02 15:48:15.037 EEST %MIVR-SS_TEL-7-UNK:Route Connection: [303:/(P1-jtapi_crs_1_1_1) GCID=(1,3476527)->ACTIVE]->OFFERED, CTI Port selected: TP[id=0,implId=202,state=IN_USE]
172865: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:Call.associated() JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=null,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
172866: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:Route Connection: [303:/(P1-jtapi_crs_1_1_1) GCID=(1,3476527)->ACTIVE]->OFFERED has 1 current sessions active.
172867: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:CallID: 139, MediaID: 3476527/1 CallCtlConnOfferedEv received for CTI Port: 202, lastRedirectedAddress: 303
172868: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:RP[num=303], conn=[303:/(P1-jtapi_crs_1_1_1) GCID=(1,3476527)->ACTIVE]->DISCONNECTED, event=CallCtlConnDisconnectedEv, cause=CAUSE_NORMAL[100], meta=META_CALL_REMOVING_PARTY[131]
172869: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:CallID: 139, MediaID: 3476527/1 Accepting call for CTI Route Point: 303 on CTI Port: 202, ciscoCause=31
172870: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:Call.accepted() JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=null,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
172871: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1, TerminalConnection to Terminal: CTI_202 is RINGING, [202:IPCC/(P1-jtapi_crs_1_1_1) GCID=(1,3476527)->ACTIVE]->ALERTING
172872: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 com.cisco.jtapi.CiscoTermInServiceEvImpl received
172873: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:Call.attributed() JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=null,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
172874: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactAttributed received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
172875: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:check Attrib : isAdapterActive set to true
172876: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:Successfully obtained a CTIPort as handler for SessionMsgs
172877: Oct 02 15:48:15.052 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionOfferedMsg (Rsrc:null ID:0 Type:IAQ)
172878: Oct 02 15:48:15.052 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 associated with Task ID: 18000000140
172879: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:ContactMgr.addResourceToContact(3476527/1, 202)
172880: Oct 02 15:48:15.052 EEST %MIVR-SS_RM-7-UNK:RsrcMgr.addContactToCTIPort, port: 202 contact ID: 3476527/1
172881: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns null
172882: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:adding RmCm contact with call ID 3476527/1 (20253743) to session 5000000169
172883: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:ContactMgr.addRmCmContact(3476527/1, 20253743 [3476527/1])
172884: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactCreatedEventReqMsg Contact139
172885: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactCreatedEvent contact type IAQ session 5000000169 session seq num 0
172886: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactPresentedEventReqMsg Contact139
172887: Oct 02 15:48:15.052 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactPresentedEvent Resource 202 contact type IAQ Secondary call ID 20253743 session 5000000169 session seq num 0 isRedirectFromWF false
172888: Oct 02 15:48:15.052 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {BEGIN_CALL_EVENT: Socket:Socket: null monitoredDeviceDN:null, connectionCallID: 20253743, callType: 1, connDeviceID: 202, ani: 353, dnis: 303, dialedNumber: 303, callerEnteredDigits: null, callVar_1: null, callVar_2: null, callVar_3: null, callVar_4: null, callVar_5: null, callVar_6: null, callVar_7: null, callVar_8: null, callVar_9: null, callVar_10: null, wrapupData: null } to outboundQ
172889: Oct 02 15:48:15.052 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { BEGIN_CALL_EVENT }
172890: Oct 02 15:48:15.052 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=BEGIN_CALL_EVENT, monitorID: 0, peripheralID: 1, peripheralType: 21, numCTIClients: 0, numNamedVars: 0, numNamedArrays: 0, callType: 1, connectionDeviceIDType: 0, connectionCallID: 20253743, calledPartyDisposition: 0, connectionDeviceID: 202, ani: 353, dnis: 303, dialedNumber: null, callerEnteredDigits: null, callVar1: null, callVar2: null, callVar3: null, callVar4: null, callVar5: null, callVar6: null, callVar7: null, callVar8: null, callVar9: null, callVar10: null, wrapupData: null to various sockets }
172891: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: got contactPresented from CTI port
172892: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { BEGIN_CALL_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CID: 20253743 }
172893: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_DELIVERED_EVENT: Socket:Socket: null monitoredDeviceDN:202, connectionCallID: 20253743, skillGroupNumber: -1, serviceNumber: 1, alertingDeviceType: 73, callingDeviceType: 0, calledDeviceType: 73, lastRedirectDeviceType: 65535, localConnectionState: 2, eventCause: 22, connectionDeviceID: 202, alertingDeviceID: 202, callingDeviceID: 353, calledDeviceID: 202, lastRedirectDeviceID: null, secondaryCallID: 0, ani: 353, dnis: 303, userToUserInfo: null, dialedNumber: 303, callerEnteredDigits: null, callVar1: null, callVar2: null, callVar3: null, callVar4: null, callVar5: null, callVar6: null, callVar7: null, callVar8: null, callVar9: null, callVar10: null, wrapupData: null } to outboundQ
172894: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_DELIVERED_EVENT }
172895: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_DELIVERED_EVENT, monitorID: 0, peripheralID: 1, peripheralType: 21, connectionDeviceIDType: 0, connectionCallID: 20253743, lineHandle: 65535, lineType: 3, serviceNumber: 1, serviceID: -1, skillGroupNumber: -1, skillGroupID: -1, skillGroupPriority: 0, alertingDeviceType: 73, callingDeviceType: 0, calledDeviceType: 73, lastRedirectDeviceType: 65535, localConnectionState: 2, eventCause: 22, connectionDeviceID: 202, alertingDeviceID: 202, callingDeviceID: 353, calledDeviceID: 202, lastRedirectDeviceID: null, secondaryConnectionCallID: 0, ani: 353, dnis: 303, userToUserInfo: null, dialedNumber: 303, callerEnteredDigits: null, callVar1: null, callVar2: null, callVar3: null, callVar4: null, callVar5: null, callVar6: null, callVar7: null, callVar8: null, callVar9: null, callVar10: null, wrapupData: null to various sockets }
172896: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DELIVERED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CID: 20253743 }
172897: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DELIVERED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CID: 20253743 }
172898: Oct 02 15:48:15.068 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is ACTIVE
172899: Oct 02 15:48:15.068 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactAccepted received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
172900: Oct 02 15:48:15.068 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
172901: Oct 02 15:48:15.068 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionActiveMsg (Rsrc:null ID:3476527/1 Type:IAQ)
172902: Oct 02 15:48:15.068 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
172903: Oct 02 15:48:15.068 EEST %MIVR-SS_TEL-7-UNK:Call.answered() JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
172904: Oct 02 15:48:15.068 EEST %MIVR-SS_RM-7-UNK:RsrcMgr.removeContactFromCTIPort, port: 202
172905: Oct 02 15:48:15.068 EEST %MIVR-SS_CM-7-UNK:ContactMgr.addResourceToContact(3476527/1, 202)
172906: Oct 02 15:48:15.068 EEST %MIVR-SS_RM-7-UNK:RsrcMgr.addContactToCTIPort, port: 202 contact ID: 3476527/1
172907: Oct 02 15:48:15.068 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactConnectedEventReqMsg Contact139
172908: Oct 02 15:48:15.068 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactConnectedEvent Resource 202 contact type IAQ session 5000000169 session seq num 0
172909: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:EventHandler:got contactConnected from CTI port
172910: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:CRACTIEventHandler: for CallEstablishedEventMsg get EventReasonCode from CallEventData (-1)
172911: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_ESTABLISHED_EVENT: Socket:Socket: null monitoredDeviceDN:202, connectionCallID: 20253743, monitoredDeviceDN: 202, eventReasonCode: 22, serviceNumber: 1, skillGroupNumber: -1, answeringDeviceID: 202, callingDeviceID: 353, calledDeviceID: 202, lastRedirectDeviceID: null, answeringDeviceType: 73, callingDeviceType: 0, calledDeviceType: 73, lastRedirectDeviceType: 65535 } to outboundQ
172912: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_ESTABLISHED_EVENT }
172913: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_ESTABLISHED_EVENT, monitorID: 0, peripheralID: 1, peripheralType: 21, connectionDeviceIDType: 0, ConnectionCallID: 20253743, lineHandle: 65535, lineType: 3, serviceNumber: 1, serviceID: -1, skillGroupNumber: -1, skillGroupID: -1, skillGroupPriority: 0, answeringDeviceType: 73, callingDeviceType: 0, calledDeviceType: 73, lastRedirectDeviceType: 65535, localConnectionState: 3, eventCause: 22, monitoredDeviceDN: 202, answeringDeviceID: 202, calledDeviceID: 202, callingDeviceID: 353, lastRedirectDeviceID: null to various sockets }
172914: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_ESTABLISHED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CID: 20253743 }
172915: Oct 02 15:48:15.068 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_ESTABLISHED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CID: 20253743 }
172916: Oct 02 15:48:15.084 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStartedEvImpl received
172917: Oct 02 15:48:15.224 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStartedEvImpl received
172918: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:ESD 2 CSQ .allocateRsrc(20253743 [3476527/1])
172919: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:Processing msg: AllocateRsrcMsg (ESD:2 Contact ID:139 CallID:3476527/1)
172920: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:ESD.processAllocateRsrcMsg(AllocateRsrcMsg (ESD:2 Contact ID:139 CallID:3476527/1))
172921: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .enqueue(2)
172922: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .enqueue(2)(Queue ID:41)
172923: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.QueueContactReqMsg Contact139
172924: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_ALLOCATED) from NOT_IN_QUEUE
172925: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:Agent oper.allocateRsrc(20253743)
172926: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(oper)
172927: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:Agent oper .addAssociatedContact(Contact:RmCm contact 20253743[3476527/1] (139)
172928: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .addAssociatedResource(oper)
172929: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:RESERVED Old State:AVAILABLE Reason code:0
172930: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:Agent oper .setWrapupData(3476527/1, null)
172931: Oct 02 15:48:16.302 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ:
172932: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactQueuedEvent contact type IAQ session 5000000169 session seq num 0
172933: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = RESERVED, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
172934: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
172935: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set true, call contact: 3476527/1
172936: Oct 02 15:48:16.302 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(false)
172937: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=8, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=RESERVED, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
172938: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
172939: Oct 02 15:48:16.302 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer(200, 12000, ACKNOWLEDGED)
172940: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
172941: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_QUEUED_EVENT: Socket:Socket: null monitoredDeviceDN:null, connectionCallID: 20253743, callingDeviceType: 0, calledDeviceType: 74, lastRedirectDeviceType: 65535, eventCause: 65535, serviceNumber: 1, CSDID: 2, callingDeviceID: 353, calledDeviceID: 303 } to outboundQ
172942: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_QUEUED_EVENT }
172943: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_QUEUED_EVENT, monitorID: 0, peripheralID: 1, peripheralType: 21, connectionDeviceIDType: 0, ConnectionCallID: 20253743, serviceNumber: 1, serviceID: -1, queueDeviceType: 77, callingDeviceType: 0, calledDeviceType: 74, lastRedirectDeviceType: 65535, numQueued: 0, numSkillGroups: 1, localConnectionState: 5, eventCause: 65535, connectionDeviceID: 202, queueDeviceID: 2, calledDeviceID: 303, callingDeviceID: 353, lastRedirectDeviceID: null, skillGroupNumber: 2, skillGroupID: -1, skillGroupPriority: 0, CSDID: 2 to various sockets }
172944: Oct 02 15:48:16.302 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_QUEUED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CID: 20253743 }
172945: Oct 02 15:48:16.318 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStoppedEvImpl received
172946: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
172947: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is HELD
172948: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConsultCallActive
172949: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
172950: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnConnectedEv
172951: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnInitiatedEv
172952: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnCreatedEv CTI_202
172953: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnActiveEv CTI_202
172954: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlTermConnTalkingEv CTI_202
172955: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDialingEv
172956: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnEstablishedEv
172957: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
172958: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnInProgressEv
172959: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:CallID: ?, MediaID: 3476528/1 CallCtlConnOfferedEv received for CTI Port: 200, lastRedirectedAddress: null
172960: Oct 02 15:48:16.349 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call:20253744 [3476528/1], address 202, calling party 202, and called party 200
172961: Oct 02 15:48:16.349 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call 20253744 [3476528/1] and agent tdobrev being ignored because orig isn't a logged in agent
172962: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-3-NULL_LAST_REDIRECTED_ADDR:Got a Null Last Redirected Address: Call id=?,Media id=3476528/1,CTI Port=200
172963: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnOfferedEv
172964: Oct 02 15:48:16.349 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallInvalidEv received for call:20253744 [3476528/1]
172965: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnDisconnectedEv
172966: Oct 02 15:48:16.349 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionInvalidMsg (ID:3476528/1)
172967: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDisconnectedEv
172968: Oct 02 15:48:16.349 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476528/1) returns null
172969: Oct 02 15:48:16.349 EEST %MIVR-SS_RM-7-UNK:RsrcMgrMsgProcessor: SessionInvalidMsg received for contactID:3476528/1] being ignored because RmCm contact is null
172970: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnFailedEv
172971: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnFailedEv
172972: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver FAILED, cause: 100, callctl cause: 100
172973: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver():Received msg from original call Interrupted
172974: Oct 02 15:48:16.349 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallObservationEndedEv
172975: Oct 02 15:48:16.365 EEST %MIVR-SS_TEL-7-UNK:Call.transferFailed(200, UNKNOWN) JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
172976: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactConnectFailed received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
172977: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionNotAnsweredMsg
172978: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
172979: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:The Resource to which the transfer failed is oper in CTIPort 202 .processSessionNotAnsweredMsg (139, 20253743 [3476527/1])
172980: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionCancelledMsg (Rsrc:3476527/1 Cause:SESSION_CANCELLED_CAUSE_OTHER)
172981: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactNotAnsweredEventReqMsg Contact139
172982: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
172983: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactNotAnsweredEvent Resource Rsrc Name: Operator ID:oper IAQ Extn:200 contact type PRIMARY CONSULT session 5000000169 session seq num 0
172984: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .removeConnectedResource(oper)
172985: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Agent oper .removeAssociatedContact(Contact:3476527/1
172986: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(null)
172987: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
172988: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_DIVERTED_EVENT: Socket:Socket: null monitoredDeviceDN:null, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 } to outboundQ
172989: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:AVAILABLE Old State:RESERVED Reason code:0
172990: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_QUEUED_EVENT }
172991: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_ALLOCATED) from QUEUED_WAITING
172992: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
172993: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_DIVERTED_EVENT, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 to various sockets }
172994: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = AVAILABLE, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
172995: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
172996: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CId: 20253743 }
172997: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=3, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=AVAILABLE, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
172998: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
172999: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173000: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning null
173001: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CId: 20253743 }
173002: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:returning null from ContactMgr.offerResource(oper) because there are no waiting contacts
173003: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173004: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173005: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173006: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173007: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning 20253743 [3476527/1]
173008: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(oper)
173009: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:returning 20253743 [3476527/1] CSQ:Name:CSQ ID:2 from ContactMgr.offerResource(oper)
173010: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Agent oper .addAssociatedContact(Contact:RmCm contact 20253743[3476527/1] (139)
173011: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .addAssociatedResource(oper)
173012: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:RESERVED Old State:AVAILABLE Reason code:0
173013: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Ready to interrupt the Application task. [Resource = Rsrc Name: Operator ID:oper IAQ Extn:200, Selected Esd = 2, Contact = 3476527/1]
173014: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = RESERVED, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173015: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .sessionCancelledExecuted
173016: Oct 02 15:48:16.365 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(true)
173017: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Start interrupting the task.
173018: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173019: Oct 02 15:48:16.365 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer interrupted, Resource Available Interruption: Rsrc Name: Operator ID:oper IAQ Extn:200, available on ESD: 2
173020: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=8, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=RESERVED, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173021: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173022: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper Contacts:Contact ID:20253743 [3476527/1] Contact Class:IAQ App Contact Id:139
173023: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper PrevState: AVAILABLE PrevStateSet:true
173024: Oct 02 15:48:16.365 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ:
173025: Oct 02 15:48:16.365 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173026: Oct 02 15:48:16.927 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 cf c2 5 o p e r 0
173027: Oct 02 15:48:16.927 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39375, agentID=oper }
173028: Oct 02 15:48:16.927 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
173029: Oct 02 15:48:16.927 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39375, agentID=oper, callsInQueue=1, oldestCallInQueue=625 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173030: Oct 02 15:48:16.927 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173031: Oct 02 15:48:17.130 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
173032: Oct 02 15:48:17.130 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStartedEvImpl received
173033: Oct 02 15:48:17.334 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStartedEvImpl received
173034: Oct 02 15:48:17.334 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173035: Oct 02 15:48:17.334 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .waitUntilProcessSessionCancelledHasExecuted - returning right away
173036: Oct 02 15:48:17.334 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173037: Oct 02 15:48:17.334 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Interrupting the task has been successful.
173038: Oct 02 15:48:17.334 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set true, call contact: 3476527/1
173039: Oct 02 15:48:17.334 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(false)
173040: Oct 02 15:48:17.334 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer(200, 12000, ACKNOWLEDGED)
173041: Oct 02 15:48:17.349 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStoppedEvImpl received
173042: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
173043: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is HELD
173044: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConsultCallActive
173045: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173046: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnConnectedEv
173047: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnInitiatedEv
173048: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnCreatedEv CTI_202
173049: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnActiveEv CTI_202
173050: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlTermConnTalkingEv CTI_202
173051: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDialingEv
173052: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnEstablishedEv
173053: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173054: Oct 02 15:48:17.380 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call:20253745 [3476529/1], address 202, calling party 202, and called party 200
173055: Oct 02 15:48:17.380 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call 20253745 [3476529/1] and agent tdobrev being ignored because orig isn't a logged in agent
173056: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnInProgressEv
173057: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:CallID: ?, MediaID: 3476529/1 CallCtlConnOfferedEv received for CTI Port: 200, lastRedirectedAddress: null
173058: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnOfferedEv
173059: Oct 02 15:48:17.380 EEST %MIVR-SS_TEL-3-NULL_LAST_REDIRECTED_ADDR:Got a Null Last Redirected Address: Call id=?,Media id=3476529/1,CTI Port=200
173060: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallInvalidEv received for call:20253745 [3476529/1]
173061: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnDisconnectedEv
173062: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDisconnectedEv
173063: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionInvalidMsg (ID:3476529/1)
173064: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476529/1) returns null
173065: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:RsrcMgrMsgProcessor: SessionInvalidMsg received for contactID:3476529/1] being ignored because RmCm contact is null
173066: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnFailedEv
173067: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnFailedEv
173068: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver FAILED, cause: 100, callctl cause: 100
173069: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver():Received msg from original call Interrupted
173070: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallObservationEndedEv
173071: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:Call.transferFailed(200, UNKNOWN) JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173072: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactConnectFailed received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
173073: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionNotAnsweredMsg
173074: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173075: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:The Resource to which the transfer failed is oper in CTIPort 202 .processSessionNotAnsweredMsg (139, 20253743 [3476527/1])
173076: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionCancelledMsg (Rsrc:3476527/1 Cause:SESSION_CANCELLED_CAUSE_OTHER)
173077: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactNotAnsweredEventReqMsg Contact139
173078: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173079: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactNotAnsweredEvent Resource Rsrc Name: Operator ID:oper IAQ Extn:200 contact type PRIMARY CONSULT session 5000000169 session seq num 0
173080: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .removeConnectedResource(oper)
173081: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Agent oper .removeAssociatedContact(Contact:3476527/1
173082: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(null)
173083: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173084: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_DIVERTED_EVENT: Socket:Socket: null monitoredDeviceDN:null, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 } to outboundQ
173085: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:AVAILABLE Old State:RESERVED Reason code:0
173086: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_QUEUED_EVENT }
173087: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_ALLOCATED) from QUEUED_WAITING
173088: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_DIVERTED_EVENT, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 to various sockets }
173089: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = AVAILABLE, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173090: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173091: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=3, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=AVAILABLE, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173092: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CId: 20253743 }
173093: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173094: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173095: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CId: 20253743 }
173096: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173097: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173098: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning null
173099: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:returning null from ContactMgr.offerResource(oper) because there are no waiting contacts
173100: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173101: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173102: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173103: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning 20253743 [3476527/1]
173104: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(oper)
173105: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:returning 20253743 [3476527/1] CSQ:Name:CSQ ID:2 from ContactMgr.offerResource(oper)
173106: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Agent oper .addAssociatedContact(Contact:RmCm contact 20253743[3476527/1] (139)
173107: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .addAssociatedResource(oper)
173108: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:RESERVED Old State:AVAILABLE Reason code:0
173109: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Ready to interrupt the Application task. [Resource = Rsrc Name: Operator ID:oper IAQ Extn:200, Selected Esd = 2, Contact = 3476527/1]
173110: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .sessionCancelledExecuted
173111: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Start interrupting the task.
173112: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = RESERVED, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173113: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173114: Oct 02 15:48:17.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer interrupted, Resource Available Interruption: Rsrc Name: Operator ID:oper IAQ Extn:200, available on ESD: 2
173115: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=8, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=RESERVED, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173116: Oct 02 15:48:17.396 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(true)
173117: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173118: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper Contacts:Contact ID:20253743 [3476527/1] Contact Class:IAQ App Contact Id:139
173119: Oct 02 15:48:17.396 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173120: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper PrevState: AVAILABLE PrevStateSet:true
173121: Oct 02 15:48:17.396 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ:
173122: Oct 02 15:48:17.443 EEST %MIVR-SS_TEL-7-UNK:Running CTI Port recovery 'MIVR_SS_TEL_RECOVERY_0_-48-0' @ 1159793297443
173123: Oct 02 15:48:17.443 EEST %MIVR-SS_TEL-7-UNK:... CTI Port recovery 'MIVR_SS_TEL_RECOVERY_0_-48-0' @ 1159793297443 done.
173124: Oct 02 15:48:17.974 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 d0 c2 5 o p e r 0
173125: Oct 02 15:48:17.974 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39376, agentID=oper }
173126: Oct 02 15:48:17.974 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
173127: Oct 02 15:48:17.974 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39376, agentID=oper, callsInQueue=1, oldestCallInQueue=1672 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173128: Oct 02 15:48:17.974 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173129: Oct 02 15:48:18.162 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
173130: Oct 02 15:48:18.162 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStartedEvImpl received
173131: Oct 02 15:48:18.349 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStartedEvImpl received
173132: Oct 02 15:48:18.349 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173133: Oct 02 15:48:18.349 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .waitUntilProcessSessionCancelledHasExecuted - returning right away
173134: Oct 02 15:48:18.349 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173135: Oct 02 15:48:18.349 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Interrupting the task has been successful.
173136: Oct 02 15:48:18.349 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set true, call contact: 3476527/1
173137: Oct 02 15:48:18.349 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(false)
173138: Oct 02 15:48:18.349 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer(200, 12000, ACKNOWLEDGED)
173139: Oct 02 15:48:18.365 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStoppedEvImpl received
173140: Oct 02 15:48:18.365 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
173141: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is HELD
173142: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConsultCallActive
173143: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173144: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnConnectedEv
173145: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnInitiatedEv
173146: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnCreatedEv CTI_202
173147: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnActiveEv CTI_202
173148: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlTermConnTalkingEv CTI_202
173149: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDialingEv
173150: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnEstablishedEv
173151: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173152: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnInProgressEv
173153: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnOfferedEv
173154: Oct 02 15:48:18.396 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call:20253746 [3476530/1], address 202, calling party 202, and called party 200
173155: Oct 02 15:48:18.396 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call 20253746 [3476530/1] and agent tdobrev being ignored because orig isn't a logged in agent
173156: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:CallID: ?, MediaID: 3476530/1 CallCtlConnOfferedEv received for CTI Port: 200, lastRedirectedAddress: null
173157: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-3-NULL_LAST_REDIRECTED_ADDR:Got a Null Last Redirected Address: Call id=?,Media id=3476530/1,CTI Port=200
173158: Oct 02 15:48:18.396 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallInvalidEv received for call:20253746 [3476530/1]
173159: Oct 02 15:48:18.396 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionInvalidMsg (ID:3476530/1)
173160: Oct 02 15:48:18.396 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476530/1) returns null
173161: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnDisconnectedEv
173162: Oct 02 15:48:18.396 EEST %MIVR-SS_RM-7-UNK:RsrcMgrMsgProcessor: SessionInvalidMsg received for contactID:3476530/1] being ignored because RmCm contact is null
173163: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDisconnectedEv
173164: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnFailedEv
173165: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnFailedEv
173166: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver FAILED, cause: 100, callctl cause: 100
173167: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallObservationEndedEv
173168: Oct 02 15:48:18.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver():Received msg from original call Interrupted
173169: Oct 02 15:48:18.412 EEST %MIVR-SS_TEL-7-UNK:Call.transferFailed(200, UNKNOWN) JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173170: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactConnectFailed received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
173171: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionNotAnsweredMsg
173172: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173173: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:The Resource to which the transfer failed is oper in CTIPort 202 .processSessionNotAnsweredMsg (139, 20253743 [3476527/1])
173174: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionCancelledMsg (Rsrc:3476527/1 Cause:SESSION_CANCELLED_CAUSE_OTHER)
173175: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactNotAnsweredEventReqMsg Contact139
173176: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173177: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactNotAnsweredEvent Resource Rsrc Name: Operator ID:oper IAQ Extn:200 contact type PRIMARY CONSULT session 5000000169 session seq num 0
173178: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .removeConnectedResource(oper)
173179: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Agent oper .removeAssociatedContact(Contact:3476527/1
173180: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(null)
173181: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_DIVERTED_EVENT: Socket:Socket: null monitoredDeviceDN:null, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 } to outboundQ
173182: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173183: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_QUEUED_EVENT }
173184: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:AVAILABLE Old State:RESERVED Reason code:0
173185: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_DIVERTED_EVENT, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 to various sockets }
173186: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = AVAILABLE, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173187: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173188: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CId: 20253743 }
173189: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=3, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=AVAILABLE, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173190: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CId: 20253743 }
173191: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_ALLOCATED) from QUEUED_WAITING
173192: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173193: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173194: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173195: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173196: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning null
173197: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:returning null from ContactMgr.offerResource(oper) because there are no waiting contacts
173198: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173199: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173200: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173201: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning 20253743 [3476527/1]
173202: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(oper)
173203: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:returning 20253743 [3476527/1] CSQ:Name:CSQ ID:2 from ContactMgr.offerResource(oper)
173204: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Agent oper .addAssociatedContact(Contact:RmCm contact 20253743[3476527/1] (139)
173205: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .addAssociatedResource(oper)
173206: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:RESERVED Old State:AVAILABLE Reason code:0
173207: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Ready to interrupt the Application task. [Resource = Rsrc Name: Operator ID:oper IAQ Extn:200, Selected Esd = 2, Contact = 3476527/1]
173208: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = RESERVED, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173209: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Start interrupting the task.
173210: Oct 02 15:48:18.412 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer interrupted, Resource Available Interruption: Rsrc Name: Operator ID:oper IAQ Extn:200, available on ESD: 2
173211: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173212: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .sessionCancelledExecuted
173213: Oct 02 15:48:18.412 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(true)
173214: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=8, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=RESERVED, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173215: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper Contacts:Contact ID:20253743 [3476527/1] Contact Class:IAQ App Contact Id:139
173216: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173217: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper PrevState: AVAILABLE PrevStateSet:true
173218: Oct 02 15:48:18.412 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173219: Oct 02 15:48:18.412 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ:
173220: Oct 02 15:48:18.974 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 d1 c2 5 o p e r 0
173221: Oct 02 15:48:18.974 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39377, agentID=oper }
173222: Oct 02 15:48:18.974 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
173223: Oct 02 15:48:18.974 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39377, agentID=oper, callsInQueue=1, oldestCallInQueue=2672 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173224: Oct 02 15:48:18.974 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173225: Oct 02 15:48:19.162 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
173226: Oct 02 15:48:19.177 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStartedEvImpl received
173227: Oct 02 15:48:19.427 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStartedEvImpl received
173228: Oct 02 15:48:19.427 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173229: Oct 02 15:48:19.427 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .waitUntilProcessSessionCancelledHasExecuted - returning right away
173230: Oct 02 15:48:19.427 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173231: Oct 02 15:48:19.427 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Interrupting the task has been successful.
173232: Oct 02 15:48:19.427 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set true, call contact: 3476527/1
173233: Oct 02 15:48:19.427 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(false)
173234: Oct 02 15:48:19.427 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer(200, 12000, ACKNOWLEDGED)
173235: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStoppedEvImpl received
173236: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
173237: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is HELD
173238: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConsultCallActive
173239: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173240: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnConnectedEv
173241: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnInitiatedEv
173242: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnCreatedEv CTI_202
173243: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnActiveEv CTI_202
173244: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlTermConnTalkingEv CTI_202
173245: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDialingEv
173246: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnEstablishedEv
173247: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173248: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:CallID: ?, MediaID: 3476531/1 CallCtlConnOfferedEv received for CTI Port: 200, lastRedirectedAddress: null
173249: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-3-NULL_LAST_REDIRECTED_ADDR:Got a Null Last Redirected Address: Call id=?,Media id=3476531/1,CTI Port=200
173250: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnInProgressEv
173251: Oct 02 15:48:19.505 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnOfferedEv
173252: Oct 02 15:48:19.505 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call:20253747 [3476531/1], address 202, calling party 202, and called party 200
173253: Oct 02 15:48:19.505 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call 20253747 [3476531/1] and agent tdobrev being ignored because orig isn't a logged in agent
173254: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallInvalidEv received for call:20253747 [3476531/1]
173255: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnDisconnectedEv
173256: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionInvalidMsg (ID:3476531/1)
173257: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDisconnectedEv
173258: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476531/1) returns null
173259: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:RsrcMgrMsgProcessor: SessionInvalidMsg received for contactID:3476531/1] being ignored because RmCm contact is null
173260: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnFailedEv
173261: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnFailedEv
173262: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver FAILED, cause: 100, callctl cause: 100
173263: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver():Received msg from original call Interrupted
173264: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallObservationEndedEv
173265: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:Call.transferFailed(200, UNKNOWN) JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173266: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactConnectFailed received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
173267: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionNotAnsweredMsg
173268: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173269: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:The Resource to which the transfer failed is oper in CTIPort 202 .processSessionNotAnsweredMsg (139, 20253743 [3476527/1])
173270: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionCancelledMsg (Rsrc:3476527/1 Cause:SESSION_CANCELLED_CAUSE_OTHER)
173271: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173272: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .removeConnectedResource(oper)
173273: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Agent oper .removeAssociatedContact(Contact:3476527/1
173274: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(null)
173275: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactNotAnsweredEventReqMsg Contact139
173276: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173277: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactNotAnsweredEvent Resource Rsrc Name: Operator ID:oper IAQ Extn:200 contact type PRIMARY CONSULT session 5000000169 session seq num 0
173278: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:AVAILABLE Old State:RESERVED Reason code:0
173279: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_DIVERTED_EVENT: Socket:Socket: null monitoredDeviceDN:null, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 } to outboundQ
173280: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_ALLOCATED) from QUEUED_WAITING
173281: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173282: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_QUEUED_EVENT }
173283: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173284: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_DIVERTED_EVENT, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 to various sockets }
173285: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning null
173286: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:returning null from ContactMgr.offerResource(oper) because there are no waiting contacts
173287: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173288: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173289: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CId: 20253743 }
173290: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173291: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CId: 20253743 }
173292: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning 20253743 [3476527/1]
173293: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = AVAILABLE, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173294: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(oper)
173295: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:returning 20253743 [3476527/1] CSQ:Name:CSQ ID:2 from ContactMgr.offerResource(oper)
173296: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173297: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Agent oper .addAssociatedContact(Contact:RmCm contact 20253743[3476527/1] (139)
173298: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .addAssociatedResource(oper)
173299: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:RESERVED Old State:AVAILABLE Reason code:0
173300: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=3, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=AVAILABLE, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173301: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Ready to interrupt the Application task. [Resource = Rsrc Name: Operator ID:oper IAQ Extn:200, Selected Esd = 2, Contact = 3476527/1]
173302: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173303: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = RESERVED, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173304: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .sessionCancelledExecuted
173305: Oct 02 15:48:19.521 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(true)
173306: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Start interrupting the task.
173307: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173308: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173309: Oct 02 15:48:19.521 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer interrupted, Resource Available Interruption: Rsrc Name: Operator ID:oper IAQ Extn:200, available on ESD: 2
173310: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=8, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=RESERVED, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173311: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper Contacts:Contact ID:20253743 [3476527/1] Contact Class:IAQ App Contact Id:139
173312: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173313: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper PrevState: AVAILABLE PrevStateSet:true
173314: Oct 02 15:48:19.521 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173315: Oct 02 15:48:19.521 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ:
173316: Oct 02 15:48:20.099 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 d2 c2 5 o p e r 0
173317: Oct 02 15:48:20.099 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39378, agentID=oper }
173318: Oct 02 15:48:20.099 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
173319: Oct 02 15:48:20.099 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39378, agentID=oper, callsInQueue=1, oldestCallInQueue=3797 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173320: Oct 02 15:48:20.099 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173321: Oct 02 15:48:20.271 EEST %MIVR-ICD_CTI-7-UNK:Received message HEARTBEAT_REQ
Message dump, excluding msg header (Length = 4 bytes):
0 0 2 81
173322: Oct 02 15:48:20.271 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=192.168.168.39,port=1202,localport=42027] Msg is {length=4 type=HEARTBEAT_REQ,invokeId=641 }
173323: Oct 02 15:48:20.271 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { HEARTBEAT_CONF }
173324: Oct 02 15:48:20.271 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=HEARTBEAT_CONF,invokeId=641 to socket: Socket[addr=192.168.168.39,port=1202,localport=42027] }
173325: Oct 02 15:48:20.271 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { HEARTBEAT_CONF to Socket[addr=192.168.168.39,port=1202,localport=42027] }
173326: Oct 02 15:48:20.287 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
173327: Oct 02 15:48:20.287 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStartedEvImpl received
173328: Oct 02 15:48:20.568 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStartedEvImpl received
173329: Oct 02 15:48:20.568 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173330: Oct 02 15:48:20.568 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .waitUntilProcessSessionCancelledHasExecuted - returning right away
173331: Oct 02 15:48:20.568 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173332: Oct 02 15:48:20.568 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Interrupting the task has been successful.
173333: Oct 02 15:48:20.568 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set true, call contact: 3476527/1
173334: Oct 02 15:48:20.568 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(false)
173335: Oct 02 15:48:20.568 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer(200, 12000, ACKNOWLEDGED)
173336: Oct 02 15:48:20.584 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStoppedEvImpl received
173337: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
173338: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is HELD
173339: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConsultCallActive
173340: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173341: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnConnectedEv
173342: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnInitiatedEv
173343: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnCreatedEv CTI_202
173344: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnActiveEv CTI_202
173345: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlTermConnTalkingEv CTI_202
173346: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDialingEv
173347: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnEstablishedEv
173348: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173349: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnInProgressEv
173350: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnOfferedEv
173351: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:CallID: ?, MediaID: 3476532/1 CallCtlConnOfferedEv received for CTI Port: 200, lastRedirectedAddress: null
173352: Oct 02 15:48:20.615 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call:20253748 [3476532/1], address 202, calling party 202, and called party 200
173353: Oct 02 15:48:20.615 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call 20253748 [3476532/1] and agent tdobrev being ignored because orig isn't a logged in agent
173354: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-3-NULL_LAST_REDIRECTED_ADDR:Got a Null Last Redirected Address: Call id=?,Media id=3476532/1,CTI Port=200
173355: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnDisconnectedEv
173356: Oct 02 15:48:20.615 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDisconnectedEv
173357: Oct 02 15:48:20.615 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallInvalidEv received for call:20253748 [3476532/1]
173358: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionInvalidMsg (ID:3476532/1)
173359: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476532/1) returns null
173360: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:RsrcMgrMsgProcessor: SessionInvalidMsg received for contactID:3476532/1] being ignored because RmCm contact is null
173361: Oct 02 15:48:20.630 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnFailedEv
173362: Oct 02 15:48:20.630 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnFailedEv
173363: Oct 02 15:48:20.630 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver FAILED, cause: 100, callctl cause: 100
173364: Oct 02 15:48:20.630 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver():Received msg from original call Interrupted
173365: Oct 02 15:48:20.630 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallObservationEndedEv
173366: Oct 02 15:48:20.630 EEST %MIVR-SS_TEL-7-UNK:Call.transferFailed(200, UNKNOWN) JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173367: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactConnectFailed received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
173368: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionNotAnsweredMsg
173369: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173370: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:The Resource to which the transfer failed is oper in CTIPort 202 .processSessionNotAnsweredMsg (139, 20253743 [3476527/1])
173371: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionCancelledMsg (Rsrc:3476527/1 Cause:SESSION_CANCELLED_CAUSE_OTHER)
173372: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactNotAnsweredEventReqMsg Contact139
173373: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173374: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactNotAnsweredEvent Resource Rsrc Name: Operator ID:oper IAQ Extn:200 contact type PRIMARY CONSULT session 5000000169 session seq num 0
173375: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .removeConnectedResource(oper)
173376: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Agent oper .removeAssociatedContact(Contact:3476527/1
173377: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(null)
173378: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_DIVERTED_EVENT: Socket:Socket: null monitoredDeviceDN:null, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 } to outboundQ
173379: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173380: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:AVAILABLE Old State:RESERVED Reason code:0
173381: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_QUEUED_EVENT }
173382: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_ALLOCATED) from QUEUED_WAITING
173383: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173384: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_DIVERTED_EVENT, monitorId: 0, peripheralId: 1, peripheralType: 21, connectionDeviceIdType: 0, connectionCallId: 20253743, serviceNumber: 1, serviceId: -1, divertingDeviceType: 73, calledDeviceType: 73, localConnectionState: 6, eventCause: 10, connectionDeviceId: 200, divertingDeviceId: 200, calledDeviceId: 200 to various sockets }
173385: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = AVAILABLE, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173386: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173387: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173388: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=3, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=AVAILABLE, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173389: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning null
173390: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CId: 20253743 }
173391: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_DIVERTED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CId: 20253743 }
173392: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173393: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173394: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:returning null from ContactMgr.offerResource(oper) because there are no waiting contacts
173395: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(QUEUED_WAITING) from QUEUED_ALLOCATED
173396: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173397: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173398: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning 20253743 [3476527/1]
173399: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(oper)
173400: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:returning 20253743 [3476527/1] CSQ:Name:CSQ ID:2 from ContactMgr.offerResource(oper)
173401: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Agent oper .addAssociatedContact(Contact:RmCm contact 20253743[3476527/1] (139)
173402: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .addAssociatedResource(oper)
173403: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:RESERVED Old State:AVAILABLE Reason code:0
173404: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Ready to interrupt the Application task. [Resource = Rsrc Name: Operator ID:oper IAQ Extn:200, Selected Esd = 2, Contact = 3476527/1]
173405: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .sessionCancelledExecuted
173406: Oct 02 15:48:20.630 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(true)
173407: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper Contacts:Contact ID:20253743 [3476527/1] Contact Class:IAQ App Contact Id:139
173408: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper PrevState: AVAILABLE PrevStateSet:true
173409: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Start interrupting the task.
173410: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = RESERVED, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173411: Oct 02 15:48:20.630 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ:
173412: Oct 02 15:48:20.630 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer interrupted, Resource Available Interruption: Rsrc Name: Operator ID:oper IAQ Extn:200, available on ESD: 2
173413: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173414: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=8, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=RESERVED, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173415: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173416: Oct 02 15:48:20.630 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173417: Oct 02 15:48:21.209 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 d3 c2 5 o p e r 0
173418: Oct 02 15:48:21.209 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39379, agentID=oper }
173419: Oct 02 15:48:21.209 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
173420: Oct 02 15:48:21.209 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39379, agentID=oper, callsInQueue=1, oldestCallInQueue=4907 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173421: Oct 02 15:48:21.209 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173422: Oct 02 15:48:21.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
173423: Oct 02 15:48:21.396 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStartedEvImpl received
173424: Oct 02 15:48:21.599 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStartedEvImpl received
173425: Oct 02 15:48:21.599 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173426: Oct 02 15:48:21.599 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .waitUntilProcessSessionCancelledHasExecuted - returning right away
173427: Oct 02 15:48:21.599 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173428: Oct 02 15:48:21.599 EEST %MIVR-SS_RM-7-UNK:Task: 18000000140 Interrupting the task has been successful.
173429: Oct 02 15:48:21.599 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set true, call contact: 3476527/1
173430: Oct 02 15:48:21.599 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(false)
173431: Oct 02 15:48:21.599 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, transfer(200, 12000, ACKNOWLEDGED)
173432: Oct 02 15:48:21.615 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStoppedEvImpl received
173433: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
173434: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is HELD
173435: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConsultCallActive
173436: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173437: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnConnectedEv
173438: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnInitiatedEv
173439: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnCreatedEv CTI_202
173440: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= TermConnActiveEv CTI_202
173441: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlTermConnTalkingEv CTI_202
173442: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDialingEv
173443: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnEstablishedEv
173444: Oct 02 15:48:21.646 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call:20253749 [3476533/1], address 202, calling party 202, and called party 200
173445: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnCreatedEv
173446: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:CallID: ?, MediaID: 3476533/1 CallCtlConnOfferedEv received for CTI Port: 200, lastRedirectedAddress: null
173447: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnInProgressEv
173448: Oct 02 15:48:21.646 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallCtlConnEstablishedEv received for call 20253749 [3476533/1] and agent tdobrev being ignored because orig isn't a logged in agent
173449: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnOfferedEv
173450: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-3-NULL_LAST_REDIRECTED_ADDR:Got a Null Last Redirected Address: Call id=?,Media id=3476533/1,CTI Port=200
173451: Oct 02 15:48:21.646 EEST %MIVR-SS_RM-7-UNK:RIMgrAddressCallObserver: CallInvalidEv received for call:20253749 [3476533/1]
173452: Oct 02 15:48:21.646 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionInvalidMsg (ID:3476533/1)
173453: Oct 02 15:48:21.646 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476533/1) returns null
173454: Oct 02 15:48:21.646 EEST %MIVR-SS_RM-7-UNK:RsrcMgrMsgProcessor: SessionInvalidMsg received for contactID:3476533/1] being ignored because RmCm contact is null
173455: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnDisconnectedEv
173456: Oct 02 15:48:21.646 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnDisconnectedEv
173457: Oct 02 15:48:21.662 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= ConnFailedEv
173458: Oct 02 15:48:21.662 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallCtlConnFailedEv
173459: Oct 02 15:48:21.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver FAILED, cause: 100, callctl cause: 100
173460: Oct 02 15:48:21.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, ConsultCallObserver():Received msg from original call Interrupted
173461: Oct 02 15:48:21.662 EEST %MIVR-SS_TEL-7-UNK:OrigCall=CallID:139 MediaId:3476527/1 Task:18000000140, ConsultEvent= CallObservationEndedEv
173462: Oct 02 15:48:21.662 EEST %MIVR-SS_TEL-3-MULT_XFER_FAIL:Multiple transfer failures: All Call ids=CallID:139 MediaId:3476527/1 Task:18000000140
173463: Oct 02 15:48:21.662 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173464: Oct 02 15:48:21.662 EEST %MIVR-SS_CM-7-UNK:ConnectingFlag is set false, call contact: 3476527/1
173465: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-TASK_ABORTED:Application task aborted: Application=App[name=ICD,type=Cisco Script Application,id=1,desc=ICD,enabled=true,max=10,valid=true,cfg=[ApplicationConfig[schema=ApplicationConfig,time=Thu Sep 28 19:27:45 EEST 2006,recordId=11,desc=ICD,name=ICD,type=Cisco Script Application,id=1,enabled=true,sessions=10,script=SSCRIPT[icd.aef],defaultScript=,vars=[<java.lang.String CSQ>],defaultVars=[]]]],Application Trigger=ContactApplicationTrigger[time=1159793295052,locale=en_US,cfg=JTAPITriggerConfig[schema=ApplicationTriggerConfig,time=Sat Sep 30 23:12:18 EEST 2006,recordId=46,desc=Cisco JTAPI Trigger,name=303,type=Cisco JTAPI Trigger,appName=ICD,enabled=true,sessions=10,idleTimeout=5000,locale=en_US,parms={},taskGroups=[],controlClass=class com.cisco.call.CallControlChannel,controlGroupId=0,contactGroups=[GroupInfo[class=com.cisco.dialog.DialogChannel,id=0]],dn=303,cmDeviceName=RP_303,cmDeviceInvalid=false,cmDescription=RP_303,cmDevicePoolUUID={285DBBBB-1A1A-6E76-D45E-45A99CFFD35D},cmDevicePoolName=IPCC,cmCallingSearchSpaceUUID={4CBCB16D-3B69-CCA9-F870-B9F9C0084893},cmCallingSearchSpaceName=Local Phones,cmLocationUUID={29C5C1C4-8871-4D1E-8394-0B9181E8C54D},cmLocationName=Hub_None,cmPartitionUUID=,cmPartitionName=None,cmVoiceMailProfileUUID=,cmVoiceMailProfileName=None,cmCallPickUpGroupUUID=,cmCallPickUpGroupName=None,cmDisplay=,cmExternalPhNumMask=,cmFwdBusyVM=false,cmFwdBusyDest=,cmFwdBusyCSSUUID=,cmFwdBusyCSSName=None,cmAlertingNameAscii=303,cmPresenceGroupUUID=ad243d17-98b4-4118-8feb-5ff2e1b781ac,cmPresenceGroupName=Standard Presence group],contact=JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]],Task id=18000000140,Task Class=class com.cisco.app.impl.WFWorkflowAppDebugTaskWrapper,Exception=com.cisco.channel.ChannelExecutionException: Contact id: 139, Channel id: 0, Reason: UNCAUGHT_EXCEPTION, Too many transfer failures
173466: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION:com.cisco.channel.ChannelExecutionException: Contact id: 139, Channel id: 0, Reason: UNCAUGHT_EXCEPTION, Too many transfer failures
173467: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.handleConsultFailure(TAPIPortGroup.java:6362)
173468: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.access$6200(TAPIPortGroup.java:5018)
173469: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$7.run(TAPIPortGroup.java:6211)
173470: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.app.impl.ApplicationManagerImpl$TaskImpl$ActionImpl.run(ApplicationManagerImpl.java:7687)
173471: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.app.impl.ApplicationManagerImpl$TaskImpl.doInterruptible(ApplicationManagerImpl.java:7490)
173472: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.waitForConsultState(TAPIPortGroup.java:6074)
173473: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.transfer(TAPIPortGroup.java:7246)
173474: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port.connect(TAPIPortGroup.java:3598)
173475: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.steps.iaq.SelectResourceStep.execute(SelectResourceStep.java:569)
173476: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wf.steps.iaq.SelectResourceStep.execute(SelectResourceStep.java:252)
173477: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.obj.WFBeanStep.executeImpl(WFBeanStep.java:141)
173478: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.obj.WFStep.execute(WFStep.java:174)
173479: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.obj.WFWorkflowTask.executeStep(WFWorkflowTask.java:494)
173480: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.engine.core.WFEngineWorkflowTask.executeStep(WFEngineWorkflowTask.java:122)
173481: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.app.impl.WFWorkflowAppDebugTaskWrapper.executeStep(WFWorkflowAppDebugTaskWrapper.java:382)
173482: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.obj.WFWorkflowTask.execute(WFWorkflowTask.java:360)
173483: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.engine.core.WFEngineWorkflowTask.execute(WFEngineWorkflowTask.java:77)
173484: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.app.impl.WFWorkflowAppDebugTaskWrapper.execute(WFWorkflowAppDebugTaskWrapper.java:702)
173485: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.engine.core.TaskManager.runTaskNormally(TaskManager.java:416)
173486: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.engine.core.TaskManager.runTask(TaskManager.java:371)
173487: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.wfframework.engine.core.TaskManager$RunnableTask.run(TaskManager.java:589)
173488: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.runCommand(ExecutorStubImpl.java:690)
173489: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:486)
173490: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:762)
173491: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:776)
173492: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.executor.impl.PooledExecutorStubImpl$1$WorkerImpl.run(PooledExecutorStubImpl.java:99)
173493: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-3-EXCEPTION: at com.cisco.util.ThreadPoolFactory$ThreadImpl.run(ThreadPoolFactory.java:777)
173494: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-ABORTING_CONTACT:Aborting contact: Application=ICD,Task id=18000000140,Contact id=139,Contact implementation id=3476527/1,Contact Class=com.cisco.call.CallContact,Contact Type=Cisco JTAPI Call,Exception=com.cisco.channel.ChannelExecutionException: Contact id: 139, Channel id: 0, Reason: UNCAUGHT_EXCEPTION, Too many transfer failures
173495: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION:com.cisco.channel.ChannelExecutionException: Contact id: 139, Channel id: 0, Reason: UNCAUGHT_EXCEPTION, Too many transfer failures
173496: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.handleConsultFailure(TAPIPortGroup.java:6362)
173497: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.access$6200(TAPIPortGroup.java:5018)
173498: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$7.run(TAPIPortGroup.java:6211)
173499: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.app.impl.ApplicationManagerImpl$TaskImpl$ActionImpl.run(ApplicationManagerImpl.java:7687)
173500: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.app.impl.ApplicationManagerImpl$TaskImpl.doInterruptible(ApplicationManagerImpl.java:7490)
173501: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.waitForConsultState(TAPIPortGroup.java:6074)
173502: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port$InCallObserverImpl.transfer(TAPIPortGroup.java:7246)
173503: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.subsystems.jtapi.TAPIPortGroup$Port.connect(TAPIPortGroup.java:3598)
173504: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.steps.iaq.SelectResourceStep.execute(SelectResourceStep.java:569)
173505: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wf.steps.iaq.SelectResourceStep.execute(SelectResourceStep.java:252)
173506: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.obj.WFBeanStep.executeImpl(WFBeanStep.java:141)
173507: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.obj.WFStep.execute(WFStep.java:174)
173508: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.obj.WFWorkflowTask.executeStep(WFWorkflowTask.java:494)
173509: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.engine.core.WFEngineWorkflowTask.executeStep(WFEngineWorkflowTask.java:122)
173510: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.app.impl.WFWorkflowAppDebugTaskWrapper.executeStep(WFWorkflowAppDebugTaskWrapper.java:382)
173511: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.obj.WFWorkflowTask.execute(WFWorkflowTask.java:360)
173512: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.engine.core.WFEngineWorkflowTask.execute(WFEngineWorkflowTask.java:77)
173513: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.app.impl.WFWorkflowAppDebugTaskWrapper.execute(WFWorkflowAppDebugTaskWrapper.java:702)
173514: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.engine.core.TaskManager.runTaskNormally(TaskManager.java:416)
173515: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.engine.core.TaskManager.runTask(TaskManager.java:371)
173516: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.wfframework.engine.core.TaskManager$RunnableTask.run(TaskManager.java:589)
173517: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.runCommand(ExecutorStubImpl.java:690)
173518: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:486)
173519: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:762)
173520: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:776)
173521: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.executor.impl.PooledExecutorStubImpl$1$WorkerImpl.run(PooledExecutorStubImpl.java:99)
173522: Oct 02 15:48:21.662 EEST %MIVR-APP_MGR-6-EXCEPTION: at com.cisco.util.ThreadPoolFactory$ThreadImpl.run(ThreadPoolFactory.java:777)
173523: Oct 02 15:48:22.427 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
173524: Oct 02 15:48:22.427 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStartedEvImpl received
173525: Oct 02 15:48:22.630 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStartedEvImpl received
173526: Oct 02 15:48:22.630 EEST %MIVR-SS_TEL-7-UNK:Call.transferring(UNRECOV_ERROR) JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173527: Oct 02 15:48:22.630 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, Applying audio treatment: UNRECOV_ERROR to JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173528: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:Received message HEARTBEAT_REQ
Message dump, excluding msg header (Length = 4 bytes):
0 0 99 d4
173529: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:Received message HEARTBEAT_REQ
Message dump, excluding msg header (Length = 4 bytes):
0 0 8 a2
173530: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=4 type=HEARTBEAT_REQ,invokeId=39380 }
173531: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52470,localport=42027] Msg is {length=4 type=HEARTBEAT_REQ,invokeId=14498 }
173532: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { HEARTBEAT_CONF }
173533: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=HEARTBEAT_CONF,invokeId=39380 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173534: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { HEARTBEAT_CONF }
173535: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { HEARTBEAT_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173536: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=HEARTBEAT_CONF,invokeId=14498 to socket: Socket[addr=10.90.201.3,port=52470,localport=42027] }
173537: Oct 02 15:48:23.693 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { HEARTBEAT_CONF to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173538: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPInputStoppedEvImpl received
173539: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
173540: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 gets TermConnDroppedEv, meta code:132, cause code:100
173541: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, TerminalConnection to Terminal: CTI_202 is DROPPED, 3476527/1
173542: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:Call.abandoned() - isAborting JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173543: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 is (re)added to call session mapping in Session[id=001-0x12a05f2a9,parent=null,active=true,state=SESSION_IN_USE,time=1159793295021]
173544: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter 139 : ContactAborted received for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
173545: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ICDContactAdapter:contactAborted - This call was aborted. The exception is com.cisco.app.ApplicationTaskInactiveException
173546: Oct 02 15:48:25.662 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionTerminatedMsg (Rsrc:3476527/1 ID:null Type:IAQ Cause:DROPPED Abort Exception:com.cisco.app.ApplicationTaskInactiveException)
173547: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173548: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ContactMgr.removeContactResourceTuple(3476527/1) removing resource 202
173549: Oct 02 15:48:25.662 EEST %MIVR-SS_RM-7-UNK:RsrcMgr.removeContactFromCTIPort, port: 202
173550: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173551: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .removeConnectedResource(202)
173552: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .dequeueAll(CONTACT_ABORTED)
173553: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(null)
173554: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:rsrc is:oper in CTIPort 0 .processSessionTerminatedMsg() for App FW contact 139, iefSourceContact is 20253743 [3476527/1] (139)
173555: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:Call.aborted() JTAPICallContact[id=139,implId=3476527/1,inbound=true,App name=ICD,task=18000000140,session=5000000169,seq num=0,cn=303,dn=303,cgn=353,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=303,route=RP[num=303],TP=202]
173556: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:rsrc is null in ICDContactAdapter 0 .cancelSessionForContact(20253743 [3476527/1])
173557: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140, released TP[type=Cisco CTI Port,id=0,implId=202,active=false,state=IDLE] from 303, and releasing udpPort 25362
173558: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireRsrcDisconnectedEventReqMsg Contact139
173559: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactRsrcDisconnectedEvent Resource 202 contact type IAQ session 5000000169 session seq num 0
173560: Oct 02 15:48:25.662 EEST %MIVR-SS_TEL-7-UNK:CallID:139 MediaId:3476527/1 Task:18000000140 com.cisco.jtapi.TermObservationEndedEvImpl received
173561: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_CONNECTION_CLEARED_EVENT: Socket:Socket: null monitoredDeviceDN:202, connectionCallID: 20253743, monitoredDeviceDN: 202, releasingDeviceID: 202, releasingDeviceType: 73 } to outboundQ
173562: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_CLEARED_EVENT }
173563: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireRsrcDisconnectedEventReqMsg Contact139
173564: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_CONNECTION_CLEARED_EVENT, monitorID: 0, peripheralID: 1, peripheralType: 21, connectionDeviceIDType: 0, connectionCallID: 20253743, releasingDeviceType: 73, localConnectionState: 65535, eventCause: 28, monitoredDeviceDN: 202, releasingDeviceID: 202 to various sockets }
173565: Oct 02 15:48:25.662 EEST %MIVR-SS_RM-7-UNK:Processing msg: SessionCancelledMsg (Rsrc:3476527/1 Cause:SESSION_CANCELLED_CAUSE_CONTACT_DROPPED)
173566: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactRsrcDisconnectedEvent Resource Rsrc Name: Operator ID:oper IAQ Extn:200 contact type PRIMARY CONSULT session 5000000169 session seq num 0
173567: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactDisconnectedEventReqMsg Contact139
173568: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ContactEventsGenerator: session 5000000169 .getParent() is null contactId= 139
173569: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ContactMgr.removeRmCmContact(3476527/1)
173570: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactDisconnectedEvent contact type IAQ, session 5000000169, session seq num 0, rejReason 4, abortReason com.cisco.app.ApplicationTaskInactiveException
173571: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.DequeueContactReqMsg Contact139
173572: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_CONNECTION_CLEARED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CID: 20253743 }
173573: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(NOT_IN_QUEUE) from QUEUED_ALLOCATED
173574: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {CALL_CONNECTION_CLEARED_EVENT: Socket:Socket: null monitoredDeviceDN:200, connectionCallID: 20253743, monitoredDeviceDN: 200, releasingDeviceID: 200, releasingDeviceType: 73 } to outboundQ
173575: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(NOT_IN_QUEUE) from NOT_IN_QUEUE
173576: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK: IEF Contact ID: [3476527/1] 20253743 ContactEventsGenerator: Posting the ContactDequeuedAllEvent reason code CONTACT_ABORTED contact type IAQ session 5000000169 session seq num 0
173577: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_CONNECTION_CLEARED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CID: 20253743 }
173578: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:conferenceQueued flag is: false call contact: 3476527/1
173579: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { CALL_CLEARED_EVENT }
173580: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: got contactDisconnected. returning because resource is null
173581: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=CALL_CONNECTION_CLEARED_EVENT, monitorID: 0, peripheralID: 1, peripheralType: 21, connectionDeviceIDType: 0, connectionCallID: 20253743, releasingDeviceType: 73, localConnectionState: 65535, eventCause: 65535, monitoredDeviceDN: 200, releasingDeviceID: 200 to various sockets }
173582: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_CONNECTION_CLEARED_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] CID: 20253743 }
173583: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_CONNECTION_CLEARED_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CID: 20253743 }
173584: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(3476527/1) returns 20253743 [3476527/1]
173585: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .removeConnectedResource(oper)
173586: Oct 02 15:48:25.662 EEST %MIVR-SS_RM-7-UNK:Agent oper .removeAssociatedContact(Contact:3476527/1
173587: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setAllocatedResource(null)
173588: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setIaqState(NOT_IN_QUEUE) from NOT_IN_QUEUE
173589: Oct 02 15:48:25.662 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper New State:AVAILABLE Old State:RESERVED Reason code:0
173590: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173591: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:200, agentDN:200, agentID:oper, monitorID = 200, stateDuration = 0, agentstate = AVAILABLE, eventreasoncode = 0, agentID = oper, agentExtension = 200, agentID_Long = oper } to outboundQ
173592: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { AGENT_STATE_EVENT }
173593: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=AGENT_STATE_EVENT, monitorID=200, peripheralID=1, sessionID=0, peripheralType=21, skillGroupState=3, stateDuration=0, skillGroupNumber=-1, skillGroupID=-1, skillGroupPriority=0, agentstate=AVAILABLE, eventReasonCode=0, MRDid=1, numTasks=0, agentMode=0, maxTaskLimit=0, ICMAgentID=0, agentAvailabilityStatus=1, numFltSkillGroups=0, CTIClientSignature=null, agentID=oper, agentExtension=200, agentInstrument=null, agentID_Long=oper, duration=-1, nextAgentState=-1 to various sockets }
173594: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] }
173595: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { AGENT_STATE_EVENT to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173596: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:Processing msg: class com.cisco.wf.subsystems.rmcm.msgs.CMFireContactEndedEventReqMsg Contact139
173597: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173598: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:EventHandler: posting {END_CALL_EVENT: Socket:Socket: null monitoredDeviceDN:null, connectionCallID: 20253743 } to outboundQ
173599: Oct 02 15:48:25.662 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning null
173600: Oct 02 15:48:25.662 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { END_CALL_EVENT }
173601: Oct 02 15:48:25.662 EEST %MIVR-SS_CM-7-UNK:returning null from ContactMgr.offerResource(oper) because there are no waiting contacts
173602: Oct 02 15:48:25.677 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=END_CALL_EVENT, monitorID: 0, peripheralID: 1, peripheralType: 21, connectionDeviceIDType: 0, connectionCallID: 20253743, connectionDeviceID: to various sockets }
173603: Oct 02 15:48:25.677 EEST %MIVR-SS_CM-7-UNK:ContactMgr.offerResource(oper)
173604: Oct 02 15:48:25.677 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { END_CALL_EVENT to Socket[addr=10.90.201.3,port=52470,localport=42027] CID: 20253743 }
173605: Oct 02 15:48:25.677 EEST %MIVR-SS_CM-7-UNK:Processing msg: OfferRsrcReqMsg (Rsrc:oper)
173606: Oct 02 15:48:25.677 EEST %MIVR-SS_RM-7-UNK:ESD 2 .getHighestPriorityContact() returning null
173607: Oct 02 15:48:25.677 EEST %MIVR-SS_CM-7-UNK:returning null from ContactMgr.offerResource(oper) because there are no waiting contacts
173608: Oct 02 15:48:25.677 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .sessionCancelledExecuted
173609: Oct 02 15:48:25.677 EEST %MIVR-SS_CM-7-UNK:RmCm contact 20253743[3476527/1] (139) .setProcessSessionCancelledExecuted(true)
173610: Oct 02 15:48:25.677 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper Contacts:
173611: Oct 02 15:48:25.677 EEST %MIVR-SS_RM-7-UNK:Rsrc: oper PrevState: AVAILABLE PrevStateSet:false
173612: Oct 02 15:48:25.677 EEST %MIVR-SS_RM-7-UNK:Rsrcs in ARL of ESD CSQ: (CSQ oper Order:1)
173613: Oct 02 15:48:26.240 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 d5 c2 5 o p e r 0
173614: Oct 02 15:48:26.240 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39381, agentID=oper }
173615: Oct 02 15:48:26.240 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
173616: Oct 02 15:48:26.240 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39381, agentID=oper, callsInQueue=0, oldestCallInQueue=0 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173617: Oct 02 15:48:26.240 EEST %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { QUERY_AGENT_QUEUE_STATISTICS_CONF to Socket[addr=10.90.201.3,port=52474,localport=42027] }
173618: Oct 02 15:48:37.068 EEST %MIVR-ICD_CTI-7-UNK:Received message QUERY_AGENT_QUEUE_STATISTICS_REQ
Message dump, excluding msg header (Length = 11 bytes):
0 0 99 d6 c2 5 o p e r 0
173619: Oct 02 15:48:37.068 EEST %MIVR-ICD_CTI-7-UNK:ClientConnMgr: Processing msg on socket:Socket[addr=10.90.201.3,port=52474,localport=42027] Msg is {length=11 type=QUERY_AGENT_QUEUE_STATISTICS_REQ,invokeId=39382, agentID=oper }
173620: Oct 02 15:48:37.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMsgProcessor: got message: { QUERY_AGENT_QUEUE_STATISTICS_CONF }
173621: Oct 02 15:48:37.068 EEST %MIVR-ICD_CTI-7-UNK:OutboundMessageprocessor : sending msg : { length=-1 type=QUERY_AGENT_QUEUE_STATISTICS_CONF,invokeId=39382, agentID=oper, callsInQueue=0, oldestCallInQueue=0 to socket: Socket[addr=10.90.201.3,port=52474,localport=42027] }
173622: Oct 02 15:48:37.068 EEST %MI
More information about the cisco-voip
mailing list