Agent State forced to Reserved/Not Ready when call arrives

Version 1
    This document was generated from CDN thread

    Created by: Kevin Pickard on 27-05-2009 04:08:01 PM
    <!--StartFragment -->
    Hello. We are a Cisco Technology Developer Partner and we are trying to do some testing with our UCCX/CM NFR kit.
     
    We have everything installed and operational for the most part. The problem we are experiencing is as follows. We have CM and UCCX installed and some phones setup. We can place direct calls and all seems to be working fine. We have used the sample Automated Attendant script (aa.aef) that came with the install and it works fine as well with calls being routed correctly in response to selections in the script. So we know CM <--> UCCX communication is working fine and that our application/script can properly route calls (and we get the proper events from both CM and UCCX on their respective protocol streams). We have defined an agent and associated a phone with it as well as with RmCm. The agent is seen properly by UCCX. The agent belongs to a Resource Group and we have a CSQ using the same Resource Group. The agent can successfully log in and go to a Ready state. The GED 188 protocol stream shows all the right events up to this point including the agent state going to Ready. Up to this point everything is fine.
     
    We then setup another application using the sample icd.aef script (setting the CSQ parameter to our CSQ) in order to route a call to an agent on a CSQ. When a call is placed to the trigger DN the script runs fine and plays the "all agents are busy" message. The problem is that as soon as the message starts to play, we get two agent state events showing the agent that *was* logged in and ready now going to a Reserved state followed by Not Ready. The call stays within the script waiting for an agent. If while the call is active we try to set the agent Ready again, we get 3 agent state events...Ready immediately followed by Reserved and then Not Ready again. The call is never routed to the agent. If a call is not placed the agent remains in the Ready state indefinitely. We have not changed the sample icd.aef script and have only set the CSQ parameter to our CSQ name (although the behaviour is the same whether we set this or not).
     
    We have run this test with the Cisco Agent Desktop. We are monitoring the GED-188 stream and are seeing the agent state events described above.
     
    What are we missing in our setup? Any help would be appreciated. Thanks.

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: David Lender on 27-05-2009 04:31:46 PM
    Check the RmCm log for clues as to why the call is not going to the
    agent.  Have you assigned the agent to the Resource Group?  Can you call
    the ResourceGroup extension and have the call go to the agent (as
    opposed to dialing the ICD sample script)?

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Kevin Pickard on 27-05-2009 06:34:32 PM
    Thanks for the response David.
     
    How do you enable/access the RmCm logs? I can not find them anywhere.
     
    Yes the agent has been assigned to the Resource Group although I do not know what you mean by calling the Resource Group extension as it is just a name. I do not see a DN for it anywhere. I can dial the agent extension directly though.
     

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: David Lender on 27-05-2009 07:11:06 PM
    Page 7-12 of the UCCX 7.0 Administrators Guide shows a resource group
    extension assigned to the Resource Group when you configure it.

    For assistance with obtaining RmCm logs, see the Troubleshooting Guide
    here
    http://www.cisco.com/en/US/products/sw/custcosw/ps1846/prod_troubleshoot
    ing_guides_list.html  Chapter 4 on Tracing.

    The UCCX documentation is here
    http://www.cisco.com/en/US/products/sw/custcosw/ps1846/tsd_products_supp
    ort_series_home.html

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Kevin Pickard on 27-05-2009 08:02:19 PM
    Thanks again for your help David.
     
    I had gone through the stuff on page 7-12 before and in looking at it again I think the item you are referring to is actually described incorrectly in the document. This is what I was calling the agent's extension. As this section is describing the Resource Configuration web page (and not the Resource Group Configuration web page) it appears to me to be where you configure information about the agent (Resource) including their extension (Unified CCX Extension) and the Resource Group they belong to. So I believe the description for the field you are referring to should read "Unified CCX Extension assigned to the resource" (with the word group removed). In any case yes that field is configured and it was the agent's extension I referred to earlier that I can dial direct with no problems.
     
    Regarding the RmCm logs, I have gone through the Troubleshooting Guide as you suggested. It appears that the guide and the real web pages are out of sync as what is described in the guide is not what appears when using the Tracing web page. Some of the stuff matches but there are significant differences. Specifically the Trace File Output check box does not exist (although some of the other fields described do), also the section on Displaying a Trace File (pg. 4-8) talks about using the Trace Configuration web page to display the trace. It does not work in the way described. After clicking on Update you get a confirmation dialog announcing "Trace configuration has been updated successfully!!" (as would be expected). You do not get the non-intuitive result as described by the document, namely "The trace file appears in a separate window." especially as it is the Trace Configuration being updated. I was able to confirm though that the RmCm Subsystem (SS_RMCM) debugging was enabled and in fact was already set as such.
     
    I have tried locating the trace files by looking directly on the UCCX box itself and the only RmCm one I can find is called "RmCmMonitor.log" which is located in the "C:\Program Files\wfavvid\log\MIVR" folder. It does not appear to contain any useful information though as it only contains repeated copies of the "Date structures summary" as shown below.
     
    Wed May 27 15:34:09 EDT 2009: Data structures summary
    Size of HRDM.ccdrTable: 0
    Size of HRDM.crdrTable: 0
    Size of HRDM.acdrTable: 0
    Size of HRDM.non_kw_agents: 1
    Size of HRDM.rsrcTable: 0
    Size of HRDM.rsrcStateTable: 1
    Size of IAQRTDM.contactIAQTable: 0
    Size of IAQRTDM.esdIAQTable: 1
    Size of associated contacts for CSQ Support: 0
    Last size of CTIServer.inboundCSMsgQ: 1
    Max size of CTIServer.inboundCSMsgQ: 6
    Last size of CTIServer.outboundCSMsgQ: 1
    Max size of CTIServer.outboundCSMsgQ: 13
    Size of ClientInfoTable.socketToSocketInfo: 5
    Size of ClientInfoTable.agentIDToAgentInfo: 1
    Size of ClientInfoTable.maskToSockets: 4
    Last size of ContactMgr.cmMsgQ: 1
    Max size of ContactMgr.cmMsgQ: 2
    Size of ContactMgr.ContactToResourceTable: 0
    Size of ContactMgr.MappingIdToContactTable: 0
    Last size of RsrcMgr.rmMsgQ: 1
    Max size of RsrcMgr.rmMsgQ: 6
    Size of RsrcMgr.rsrcTable: 1
    Size of RsrcMgr.esdTable: 1
    Size of RsrcMgr.esdNameToIdTable: 1
    Size of RsrcMgr.ctiPortsList: 6
    Size of RIMgr.resIDToRemoteAD: 0
    Size of RIMgr.extnToResID: 1
    Size of RIMgr.openedAddresses: 1
     

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Kevin Pickard on 27-05-2009 08:16:40 PM
    As a further follow-up, I did find another log file "Cisco001MIVR064.log" in that same folder. It contains the following interesting lines.
     
    318415: May 27 16:09:22.876 EDT %MIVR-SS_TEL-7-UNK:Call.transferFailed(7150, RESOURCE_INVALID) JTAPICallContact[id=15,implId=5034/1,state=STATE_ANSWERED_IDX,inbound=true,App name=SupportQueue,task=19000000030,session=5000000030,seq num=0,cn=7304,dn=7304,cgn=9731,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=7304,route=RP,TP=7210]
    318416: May 27 16:09:22.876 EDT %MIVR-SS_CM-7-UNK:ICDContactAdapter 15 : ContactConnectFailed received for App FW contact 15, iefSourceContact is 16782250 [5034/1] (15)
    So it looks as though it was attempting to transfer the call. The agent's extension is 7150 as shown and it can be dialed directly. The DN 7304 is the CSQ trigger and 9731 is the calling number. So it has all the right information regarding the call. So the question I guess is why 7150 is being flagged RESOURCE_INVALID when it is a dialable and working DN on the agent's phone.
     

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: David Lender on 27-05-2009 08:29:46 PM
    Is the agent extension associated with the RmCm Provider?

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Kevin Pickard on 27-05-2009 08:45:00 PM
    The agent's phone device is associated with the RmCm Provider. I do not see any way of associating an individual extension/DN, just the device itself that has the extension. So yes, I would think the all the extensions on the phone would be associated.
     

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Kevin Pickard on 28-05-2009 03:36:30 PM
    I ran another test this morning that was interesting.
     
    I placed a call to the trigger for the sample Auto-Attendant application/script (aa.aef). I then entered the agent's extension (the one getting the failure when using the sample CSQ script (icd.aef)). The call was tranferred without any problems. Which means that the agent's extension as a resource is valid and that scripts can transfer to it. So it appears that the error about an invalid resource regarding 7150 (shown earlier in this thread) is not correct and perhaps something else is going on.
     

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Kevin Pickard on 28-05-2009 06:31:56 PM
    I took a look at the JTAPI stream coming from the Call Manager when this error happens. We have a JTAPI connection with the Call Manager as well. Unfortunately I can not see the JTAPI stream between UCCX and Call Manager. Anyway, it looks as though it is trying to transfer the call to the agent.
     
    I see the original call being held at the CTI Port and then a new call being initiated. It is this new call that is failing. The JTAPI stream does not show where the new call is going but based on the UCCX log earlier that shows 7150 I am guessing that it is placing a call to the agent's extension in response to direction from UCCX. This could be the issue though, as although UCCX is reporting that it is unable to transfer to 7150, it might actually be sending something else to Call Manager. From our JTAPI stream all I can see is that the call is being initiated and is failing with the following cause codes: DEST_NOT_OBTAINABLE and UNALLOCATEDNUMBER. It does not show what DN was being attempted.
     
    Now at no point do I give the 7150 number to UCCX so it is successfully locating the Ready agent and getting the extension they are logged into (based on the fact that 7150 is appearing in the UCCX log). I am guessing that this info is then passed to Call Manager for the transfer (which then fails) but perhaps that is where the problem is occurring. 
     
    I remember in the older IPCC Enterprise system we had to define Labels for any DNs that were to be reachable by ICM. I have not seen any equivalent concept in UCCX. And indeed, the fact that the Auto Attendant script can successfully transfer a call to 7150 would seem to indicate it is not necessary.
     
    So why does the sample Auto Attendant script (aa.aef) have no problems transferring the call to 7150 while the sample CSQ script (icd.aef) reports that 7150 is an invalid resource? Both transfers are initiated by UCCX scripts and both are to the same extension. The only difference is that the one that fails involves a CSQ.
     
     

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Kevin Pickard on 29-05-2009 05:57:39 PM
    Here is a more complete section of the error I am seeing in the UCCX IVR log. Looks like the problems start at 449401 with the JTAPI exception error CTIERR_UNSPECIFIED. I am still trying to figure out how to get equivalent logging on the Call Manager side.
     
    449386: May 29 10:45:21.345 EDT %MIVR-ICD_CTI-7-UNK:MsgHandler : Sent : { CALL_QUEUED_EVENT to Socket  CID: 16782264 }
    449387: May 29 10:45:21.345 EDT %MIVR-ICD_CTI-7-UNK:Executor trace: Action=CMD_DONE,Executor id=SOCKET,Mnemonic=PROCESS_CTI_MGR_EVENT,Executor type=null,Thread=MIVR_ICD_CTI_SOCKET-1127-12,Thread priority=5,Original Thread=null,Original thread priority=null,Time=16,Exception=null
    449388: May 29 10:45:21.345 EDT %MIVR-ICD_CTI-7-UNK:Executor trace: Action=THREAD_RELEASED,Executor id=SOCKET,Mnemonic=null,Executor type=com.cisco.executor.QueuedExecutor,Thread=ExecutorManagerImpl.pool-234,Thread priority=5,Original Thread=MIVR_ICD_CTI_SOCKET-1127-12,Original thread priority=null,Time=null,Exception=null
    449389: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049 com.cisco.jtapi.CiscoRTPOutputStoppedEvImpl received
    449390: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049, TerminalConnection to Terminal: Test_7206 is HELD
    449391: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= ConsultCallActive
    449392: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049 Got ConsultCallActive, ConnCreatedEv, ConnConnectedEv, CallCtlConnInitiatedEv, TermConnCreatedEv Test_7206, TermConnActiveEv Test_7206, CallCtlTermConnTalkingEv Test_7206,  events on the AddressCallObserver.
    449393: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= ConnCreatedEv
    449394: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= ConnConnectedEv
    449395: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= CallCtlConnInitiatedEv
    449396: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= TermConnCreatedEv Test_7206
    449397: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= TermConnActiveEv Test_7206
    449398: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= CallCtlTermConnTalkingEv Test_7206
    449399: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= CallCtlConnDialingEv
    449400: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049 Got CallCtlConnDialingEv,  events on the AddressCallObserver.
    449401: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049 consultWithoutMedia gets CiscoJtapiException: 0x0(CTIERR_UNSPECIFIED)::Unspecified error
    449402: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= ConnFailedEv
    449403: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049 Got ConnFailedEv, CallCtlConnFailedEv,  events on the AddressCallObserver.
    449404: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= CallCtlConnFailedEv
    449405: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049, ConsultCallObserver FAILED, cause: 103, callctl cause: 103
    449406: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNKrigCall=CallID:24 MediaId:5048/1 Task:19000000049, ConsultEvent= CallObservationEndedEv
    449407: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049, ConsultCallObserver():Received msg from original call Interrupted
    449408: May 29 10:45:21.376 EDT %MIVR-SS_TEL-7-UNK:Call.transferFailed(7150, RESOURCE_INVALID) JTAPICallContact[id=24,implId=5048/1,state=STATE_ANSWERED_IDX,inbound=true,App name=SupportQueue,task=19000000049,session=5000000043,seq num=0,cn=7304,dn=7304,cgn=9731,ani=null,dnis=null,clid=null,atype=DIRECT,lrd=null,ocn=7304,route=RP,TP=7206]
    449409: May 29 10:45:21.376 EDT %MIVR-SS_CM-7-UNK:ICDContactAdapter 23 : ContactConnectFailed received for App FW contact 24, iefSourceContact is 16782264 [5048/1] (23)
    449410: May 29 10:45:21.391 EDT %MIVR-SS_TEL-7-UNK:CallID:24 MediaId:5048/1 Task:19000000049 com.cisco.jtapi.CiscoMediaOpenLogicalChannelEvImpl received
    449411: May 29 10:45:21.391 EDT %MIVR-SS_RM-7-UNKrocessing msg: SessionNotAnsweredMsg
    449412: May 29 10:45:21.391 EDT %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(5048/1) returns 16782264 [5048/1]
    449413: May 29 10:45:21.391 EDT %MIVR-SS_CM-7-UNK:The Resource to which the transfer failed is Agent2 in CTIPort 7206 .processSessionNotAnsweredMsg (24, 16782264 [5048/1])
    449414: May 29 10:45:21.391 EDT %MIVR-SS_CM-7-UNK:Not posting ContactNotAnswered as this contact was not presented to this agent - contact: 5048/1 Resource: Agent2 Reason it failed: 6
    449415: May 29 10:45:21.391 EDT %MIVR-SS_RM-7-UNKrocessing msg: SessionCancelledMsg (Rsrc:5048/1 Cause:SESSION_CANCELLED_CAUSE_DEST_INVALID)
    449416: May 29 10:45:21.391 EDT %MIVR-SS_CM-7-UNK:ContactMgr.getRmCmContact(5048/1) returns 16782264 [5048/1]
     
     

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: John Wieland on 29-06-2009 09:36:01 PM
    Kevin,
     
    I had the same symptoms you describe in your problem.  The solution for me was to assign the correct device pool and calling search space in the Cisco Unified CM telephony Call Control Group Configuration screen.
     
    In uccx web gui, go to Subsystems -> Cisco Unified CM Telephony -> Cisco Unified CM Telephony Control Group and select the group you are using in your application.  At the bottom of the screen hit the "Show More..." button and fill in the correct Device Pool and DN Calling Search Space.  This modifies the CIT ports on the call manager that are used to transfer the calls to your agents.  Without the proper Pool and CS, the agent phones go into a "reserve/not ready' state.
     
    Hope this works for you... 

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: AARON NJAGI on 13-07-2009 06:53:34 PM
    YoungLink is right.
     
    if you have already assosiated the IP phone MAC address to Rmcm, then the other thing to check is whether the Calling Search Space assosiated with the Call Control Group has the partition assigned to the agents lines.
     
    So following Younglink's example
    "In uccx web gui, go to Subsystems -> Cisco Unified CM Telephony -> Cisco Unified CM Telephony Control Group and select the group you are using in your application.  At the bottom of the screen hit the "Show More..." button and fill in the correct Device Pool and DN Calling Search Space. "
    My CSS is DALLAS_Css
    I will log into CUCM and check the partition I am assigning the agent's DN. CUCM > Device > Phone . For example, I am assigning HOUSTON_Partition into agent's DN.
     
    Make sure that HOUSTON_Partiion is found in DALLAS_Css. Go to CUCM > Call Routing > Class Of Service > Calling Search Space > DALLAS_Css. Check the selected partitions in this CSS. if not found (most likely), add it.
     
    Now agents will be able to log into CAD and go to Ready State

    Subject: RE: New Message from Kevin Pickard in Unified Contact Center Express CTI (U
    Replied by: Colin Holloway on 08-05-2013 11:52:20 AM
    John,
    Just wanted to say thanks.  Your advice helped me fix this problem
     
    John Wieland:
    Kevin,
     
    I had the same symptoms you describe in your problem.  The solution for me was to assign the correct device pool and calling search space in the Cisco Unified CM telephony Call Control Group Configuration screen.
     
    In uccx web gui, go to Subsystems -> Cisco Unified CM Telephony -> Cisco Unified CM Telephony Control Group and select the group you are using in your application.  At the bottom of the screen hit the "Show More..." button and fill in the correct Device Pool and DN Calling Search Space.  This modifies the CIT ports on the call manager that are used to transfer the calls to your agents.  Without the proper Pool and CS, the agent phones go into a "reserve/not ready' state.
     
    Hope this works for you...