- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-03-2014 04:22 AM - edited 03-16-2019 09:59 PM
I got a complaint for a user that a few phones at one of my SRST sites rebooted unexpectedly. This one particularly rebooted during an active call. Here's what I could find in the Call Manager logs via RTMT: (The phone is - SEPD0C789D7E6D6)
16:30:31.174 |RouteListControl::idle_CcSetupReq - RouteList(LYN-PSTN-RL), numberSetup=0 numberMember=1 vmEnabled=0|2,100,13,10100482.7625^10.93.79.6^SEPD0C789D7E6D6
16:30:31.354 |LineControl TEST DEBUGS: Number of entries in CallTable is = 1
|2,100,13,9987045.90003^10.93.81.4^SEP1CAA0710C02F
16:30:31.355 |!!ERROR!! -MediaManager-(71915)::wait_AuDisconnectRequest, mCleanupPreallocatedMTP=0|2,100,13,9987045.90003^10.93.81.4^SEP1CAA0710C02F
16:30:31.360 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1 videoCapable=0, party 2 videocapable=0|2,100,21,21867.9^10.93.81.250^Port 56110
16:30:31.360 |ViprUtils: Number has no +, not a valid E164 [7300]|2,100,21,21867.9^10.93.81.250^Port 56110
16:30:31.361 |ForwardManager - wait_SsDataInd mInterceptTable - ERROR - No entry found for ForwardKey= 0x25, callkey= 0x73F2 |2,100,21,21867.9^10.93.81.250^Port 56110
16:30:31.371 |H225D: Call Reference and Connection PID does not correspond to any active H225Cdpc process|2,100,13,10110455.6^10.93.81.253^*
16:30:59.852 |LineControl TEST DEBUGS: Number of entries in CallTable is = 1
|2,100,13,10100482.7634^10.93.79.6^SEPD0C789D7E6D6
16:30:59.852 |SdiStats: #Lines: 14 Free HWM: 4 Free HWM(total): 76|*^*^*
16:30:59.853 |!!ERROR!! -MediaManager-(71926)::wait_AuDisconnectRequest, mCleanupPreallocatedMTP=0|2,100,13,10100482.7634^10.93.79.6^SEPD0C789D7E6D6
16:30:59.853 |MediaTerminationPointControl(49)::star_MediaExchangeAgenaCloseLogicalChannel -- Could not delete. PortReq not found in the list|2,100,13,10100482.7634^10.93.79.6^SEPD0C789D7E6D6
16:30:59.853 |MediaTerminationPointControl(49)::star_MediaExchangeAgenaCloseLogicalChannel -- Could not delete. PortReq not found in the list|2,100,13,10100482.7634^10.93.79.6^SEPD0C789D7E6D6
16:30:59.920 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1 videoCapable=0, party 2 videocapable=0|2,100,21,21871.7^10.93.81.250^Port 43977
16:30:59.920 |ViprUtils: Number has no +, not a valid E164 [90689092816]|2,100,21,21871.7^10.93.81.250^Port 43977
16:30:59.976 |H225D: Call Reference and Connection PID does not correspond to any active H225Cdpc process|2,100,13,10110469.18^10.93.80.249^*
16:31:09.795 |DbMobility: can't find remdest 90677037881 in map|*^*^*
16:31:09.795 |SdiStats: #Lines: 8 Free HWM: 3 Free HWM(total): 76|*^*^*
16:31:09.796 |RouteListControl::idle_CcSetupReq - RouteList(LYN-PSTN-RL), numberSetup=0 numberMember=1 vmEnabled=0|2,100,13,10100482.7640^10.93.79.6^SEPD0C789D7E6D6
16:31:12.381 |DeviceTransientConnection - A device attempted to register but did not complete registration Connecting Port:2000 Device Name:AN416AFCE970002 Device IP Address:10.93.81.253 Device type:30027 Reason Code:3 Protocol:SCCP IPAddressAttributes:2 UNKNOWN_PARAMNAME:LastSignalReceived:StationRegister UNKNOWN_PARAMNAME:StationState:wait_register App ID:Cisco CallManager Cluster ID:StandAloneCluster Node ID:mrn-cucm01|AlarmAN416AFCE970002^*^AN416AFCE970002
16:31:12.380 |CcmCcmdbStationRegistrationProfile - For device AN416AFCE970002: No Device/EmccDynamic Record for deviceName = AN416AFCE970002. Auto-registration not enabled for this device's type.|*^*^*
16:31:12.380 |CcmdbStationRegistrationProfileBuilder::getBasicRegistrationProfile::init() - failed rc(2)|*^*^*
16:31:12.380 |StationD: (10065306) Error, ccmdbGetStationRegistrationProfile (not configured)|0,0,0,0.0^10.93.81.253^AN416AFCE970002
16:31:12.383 |StationInit: TCPPid = [2.100.13.10110472]Socket Broken. DeviceName=AN416AFCE970002,IPAddr=10.93.81.253, Port=0xa1e7, Device Controller=[2,57,10065306]|0,0,0,0.0^10.93.81.253^AN416AFCE970002
16:31:13.871 |Forwarding - getMaskedDn - maskedDn=[7000] dn=[302] mask=[7000]|*^*^*
16:31:13.875 |RouteListControl::idle_CcSetupReq - RouteList(France Voice Mail), numberSetup=0 numberMember=18 vmEnabled=1|2,100,13,10089065.18486^10.93.78.17^SEPD0C789D775F3
16:31:13.878 |CcmCcmdbHelper::buildLineStructGivenLiteDnData - getCallForwardDynamicRecordGivenNumPlanPkid() FAILED for device name(MRN-Unity1-VI1), numplan pkid(86d8cd0f-286b-f689-4a3c-fea64a7d2c03) --> IGNORING|*^*^*
16:31:13.880 |!!ERROR!! -ConnectionManager- wait_AuDisconnectRequest :CI NOT FOUND IN TABLE,CI(44856055,0),discType=1,IFCreated(0,0),PID(0-0,0-0),IFHandling(0,0),MCNode(0,0)|2,100,13,10089065.18486^10.93.78.17^SEPD0C789D775F3
16:31:13.880 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1 videoCapable=0, party 2 videocapable=0|2,100,13,10089065.18486^10.93.78.17^SEPD0C789D775F3
16:31:13.881 |LineControl TEST DEBUGS: Number of entries in CallTable is = 1
|2,100,13,10089065.18486^10.93.78.17^SEPD0C789D775F3
16:31:13.902 |MmmanService - ERROR Too many calls to decrementTotalNumberOfRegisteredCallingEntities, Already at zero.|*^*^*
16:31:16.883 |LineControl TEST DEBUGS: Number of entries in CallTable is = 1
|2,100,13,10089065.18495^10.93.78.17^SEPD0C789D775F3
16:31:16.883 |SdiStats: #Lines: 14 Free HWM: 3 Free HWM(total): 76|*^*^*
16:31:16.885 |ForwardManager - wait_SsDataInd mInterceptTable - ERROR - No entry found for ForwardKey= 0x25, callkey= 0x73F7 |2,100,13,10089065.18495^10.93.78.17^SEPD0C789D775F3
16:31:16.885 |!!ERROR!! -MediaManager-(71927)::wait_AuDisconnectRequest, mCleanupPreallocatedMTP=0|2,100,13,10089065.18495^10.93.78.17^SEPD0C789D775F3
16:31:16.887 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1 videoCapable=0, party 2 videocapable=0|2,100,13,10089065.18495^10.93.78.17^SEPD0C789D775F3
16:31:16.888 |LineControl TEST DEBUGS: Number of entries in CallTable is = 1
|2,100,13,10089065.18495^10.93.78.17^SEPD0C789D775F3
16:31:39.421 |LineControl TEST DEBUGS: Number of entries in CallTable is = 1
|2,100,13,10100482.7653^10.93.79.6^SEPD0C789D7E6D6
16:31:39.421 |SdiStats: #Lines: 6 Free HWM: 4 Free HWM(total): 76|*^*^*
16:31:39.423 |!!ERROR!! -MediaManager-(71928)::wait_AuDisconnectRequest, mCleanupPreallocatedMTP=0|2,100,13,10100482.7653^10.93.79.6^SEPD0C789D7E6D6
16:31:39.423 |MediaTerminationPointControl(49)::star_MediaExchangeAgenaCloseLogicalChannel -- Could not delete. PortReq not found in the list|2,100,13,10100482.7653^10.93.79.6^SEPD0C789D7E6D6
16:31:39.423 |MediaTerminationPointControl(49)::star_MediaExchangeAgenaCloseLogicalChannel -- Could not delete. PortReq not found in the list|2,100,13,10100482.7653^10.93.79.6^SEPD0C789D7E6D6
Solved! Go to Solution.
- Labels:
-
CUCM
Accepted Solutions
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-04-2014 07:03 AM
Hi Jacob,
I believe that the phone did not failover to the secondary or SRST because this failover process takes time. The phone will try to reach the primary call manager thrice before declaring the link as dead and then try to register with its secondary server. My guess is that it reset during this time, and when it came back up, realized that connectivity to the primary call agent is there. It then registers to the primary call agent.
This doc talks about the IP Phone behavior. You can refer to the "Delayed Failover for SCCP phones" section.
https://supportforums.cisco.com/docs/DOC-19066
Thanks
Sree
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-03-2014 04:41 AM
Hi Jacob,
It would be better to look at the Event Viewer - System and Event Viewer - Application logs for this event. These logs will show the phone reboot along with the reason for the reboot. Pull these logs from all servers in the cluster.
Thanks
Sree
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-03-2014 06:04 AM
Thanks for your reply. Here's what I found:
: 20921573: mrn-cucm01 Feb 28 2014 21:35:24 UTC : %UC_CALLMANAGER-6-StationConnectionError: %[DeviceName=SEPD0C789D7E6D6][ReasonCode=8][ClusterID=StandAloneCluster][NodeID=mrn-cucm01]: Station device is closing the connection |
: 20921574: mrn-cucm01 Feb 28 2014 21:35:24 UTC : %UC_CALLMANAGER-3-EndPointUnregistered: %[DeviceName=SEPD0C789D7E6D6][IPAddress=10.93.79.6][Protocol=SCCP][DeviceType=434][Description=XXX_XXXX_XXXX][Reason=6][IPAddrAttributes=3][ClusterID=StandAloneCluster][NodeID=mrn-cucm01]: An endpoint has unregistered |
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-03-2014 06:10 AM
Do you also see an entry for the ReasonForOutOfService parameter for this phone?
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-03-2014 06:17 AM
Here's the guide to the System Error messages on CUCM.
http://www.cisco.com/c/en/us/td/docs/voice_ip_comm/cucm/err_msgs/8_x/ccmalarms851.html
Using this, we can try to find out what happened. You will need to look for the alarm type first, which is
EndPointUnregistered. Under this, we will need to find the meaning of the reason code.
Reason=6 is:
6 ConnectivityError - Network communication between the device and Unified CM has been interrupted. Possible causes include device power outage, network power outage, network configuration error, network delay, packet drops, and packet corruption. It is also possible to get this error if the Unified CM node is experiencing high CPU usage. Verify that the device is powered up and operating, verify that network connectivity exists between the device and Unified CM, and verify that the CPU utilization is in the safe range (you can monitor this via the CPU Pegging Alert in RTMT).
So it looks like it lost connectivity to the CUCM for a small period of time causing the reset.
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-03-2014 07:10 AM
Hi Sreekanth,
Thanks for the reply. There have been circuit issues at the site of the Call Manager subscriber that this phone registers to, but there are 2 more nodes in the Call Manager Group that the phone should be able to fail over to. Also, this is an SRST site and I don't see any phone registrations to the router. Shouldn't the phone register to one of these other options before rebooting?
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-04-2014 07:03 AM
Hi Jacob,
I believe that the phone did not failover to the secondary or SRST because this failover process takes time. The phone will try to reach the primary call manager thrice before declaring the link as dead and then try to register with its secondary server. My guess is that it reset during this time, and when it came back up, realized that connectivity to the primary call agent is there. It then registers to the primary call agent.
This doc talks about the IP Phone behavior. You can refer to the "Delayed Failover for SCCP phones" section.
https://supportforums.cisco.com/docs/DOC-19066
Thanks
Sree
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-04-2014 08:16 AM
Thanks for your help.
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
03-04-2014 08:23 AM
You're welcome Jacob!
