cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
3131
Views
0
Helpful
8
Replies

Unexpected Phone Reboot - CUCM 8.5

Jacob Webb
Level 1
Level 1

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

1 Accepted Solution

Accepted Solutions

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

View solution in original post

8 Replies 8

Sreekanth Narayanan
Cisco Employee
Cisco Employee

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

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

Do you also see an entry for the ReasonForOutOfService parameter for this phone?

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.

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?

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

Thanks for your help.    

You're welcome Jacob!

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: