MR PIM Active But Showing Socket Errors
- Stop EAAS process
- Rename user.cisco.cmb to user.cisco.cmbb
- Cycle MR PG on both sides
Intermittent routing issues have been observed. MR PIM shows ACTIVE, but is disconnecting due to socket errors.
Note: With Windows 2008 R2, these process windows would not be seen. Instead, the above would be observed using EMSMON or by dumping logs to text files.
In a normal startup, the MR PIM should follow the below flow:
- Routing Client successfully ACTIVATED
In this case, we are seeing:
The MR is never registering the ECC Variables.
The EAAS logs will provide guidance as to where the failure is occurring.
2011-06-05 23:16:08.080 GMT-0400 <@> ERROR <@> [788:Thread-369] <@> ProcessId:4184 <@> PID:1 <@> UID:12 <@> HttpSessionId: <@> com.cisco.ipcc.mr.ECCVariableRegistrar <@> checkICMMandatoryECCVariables <@> Please check/correct at ICM the spelling of the following ecc variables and restart EAAS process and instance.user.cisco.cmb <@> 2011-06-05 23:16:08.080 GMT-0400 <@> ERROR <@> [788:Thread-369] <@> ProcessId:4184 <@> PID:1 <@> UID:12 <@> HttpSessionId: <@> com.cisco.ipcc.mr.SessionManager <@> handleOpenRequest() <@> Failure in handling OPEN_REQ from MR session will be terminated sessionId=362 EAASInstanceId=1008 <@> java.lang.NullPointerException
EAAS is unable to register user.cisco.cmb, which explains what we saw in the MR PIM logs.
ECC Variable Naming
By default, EIM/WIM looks for ECC Variables with specific names. These variables are set on the File Server in C:\CIM\eService\config\ipcc\egicm_ecc_variables_name.properties
# Name of ECC Variables used for Blended Collaboration and Callback queues # Structure of this file is ecc variable name = unique identifier in CIM Code user.cim.activity.id = 1 user.wim.customer.name = 2 user.cisco.cmb = 3 user.cisco.cmb.callclass = 4
We know that EAAS is looking for user.cisco.cmb correctly, so the issue must be on the UCCE side.
Navigate to Configuration Manager > Expanded Call Variable List and look for user.cisco.cmb. Here we can see that the variable name has been typed incorrectly as "user.cisco.cmbb". Remove the extra "b" and save.
The EAAS process must be restarted once the ECC Variable names in UCCE have been updated.
23:58:28:603 pg2A-pim2 Attempting to connect to MR application at IP address 10.77.30.32 port 38101. 23:58:28:603 pg2A-pim2 Trace: Transport: Making connection attempt to host1: 43srvc port: 38101 23:58:28:603 pg2A-pim2 Connection to MR application established. 23:58:28:603 pg2A-pim2 Trace: PG->Application: Message = OPEN_REQ; Length = 20 bytes InvokeID = (66403500) Hex 03f53cac HeartbeatInterval = (5000) Hex 00001388 MsgInterfaceRev = (1) Hex 00000001 Hostname: icm751 VersionNumber: 23:58:28:713 pg2A-pim2 Trace: Application->PG: Message = OPEN_RESP; Length = 25 bytes Invoke ID = (66403500) Hex 03f53cac Prior Failure = (0) Hex 00000000 Status = (0) Hex 00000000 Hostname: VersionNumber: 126.96.36.199 23:58:28:713 pg2A-pim2 Peripheral 5006 sending OPC PIM_OK_ACK acknowledgment for command PIM_SET_ACTIVE_REQ (TransID=0). 23:58:28:713 pg2A-pim2 ProcessPIMSetActiveReq: Peripheral 5006 ACTIVATED. 23:58:28:713 pg2A-pim2 Attempting to ACTIVATE Peripheral's Routing Client. 23:58:28:713 pg2A-pim2 Failed an attempt to ACTIVATE the Peripheral's Routing Client. Will retry. 23:58:28:791 pg2A-pim2 Trace: Application->PG: Message = MR_REGISTER_VARIABLES_REQ; Length = 136 bytes InvokeID = (1) Hex 00000001 Call Variable Mask: (1023) Hex 000003ff NumberOfVariables = (5) Hex 00000005 NumberOfArrayElements = (0) Hex 00000000 ECC Variable Name: user.cim.activity.id Value: ECC Variable Name: user.wim.customer.name Value: ECC Variable Name: user.cisco.cmb Value: ECC Variable Name: user.cisco.cmb.callclass Value: ECC Variable Name: user.cim.activity.priority Value: 23:58:28:791 pg2A-pim2 Trace: Media Routing Application registered ECC variable: "user.cim.activity.id" 23:58:28:791 pg2A-pim2 Trace: Media Routing Application registered ECC variable: "user.wim.customer.name" 23:58:28:791 pg2A-pim2 Trace: Media Routing Application registered ECC variable: "user.cisco.cmb" 23:58:28:791 pg2A-pim2 Trace: Media Routing Application registered ECC variable: "user.cisco.cmb.callclass" 23:58:28:791 pg2A-pim2 Trace: Media Routing Application registered ECC variable: "user.cim.activity.priority" 23:58:28:791 pg2A-pim2 Trace: ICM->Application: Message = MR_REGISTER_VARIABLES_RESP; Length = 8 bytes Invoke ID = (1) Hex 00000001 Status = (0) Hex 00000000 23:58:29:994 pg2A-pim2 Trace: MR_Peripheral::ProcessThisINRCMessage. INRC message: 2. 23:58:29:994 pg2A-pim2 Peripheral's Routing Client successfully ACTIVATED. 23:58:29:994 pg2A-pim2 Trace: MR_Peripheral::On_OPC_RoutingEnabledEvent: ROUTING_ENABLED_EVENT RCID=0 PID=0 23:58:29:994 pg2A-pim2 Trace: PG->Application: Message = ROUTING_ENABLED_EVENT; Length = 0 bytes 23:58:30:041 pg2A-pim2 Trace: MR_Peripheral::ProcessThisINRCMessage. INRC message: 2. 23:58:30:041 pg2A-pim2 Peripheral's Routing Client successfully ACTIVATED.
Impact to CMB
How does this impact CMB? Place a callback request and observe that this fails as well.
This scenario stressed the importance of items being configured as documented. Items such as Media Classes, Media Routing Domains, and ECC variables must be configured correctly for the integrated connections to come up properly.
The log message in the initial problem statement was misleading, as the root cause is something far from a socket error.