Troubleshoot Cisco Phone 7800/8800 Series Intermittent Registration Issues

Introduction

This document describes troubleshooting process for Cisco Phone 7800 series registered on Cisco Unified Communications Manager (CUCM) intermittent unregistrations caused by network problems.

Versions and Addressing

CUCM 11.0.1

IP Phone 7821, sip78xx.10-3-1-12

CUCM PUB: 10.48.47.143

CUCM SUB: 10.48.47.136

IP Phone: 10.62.153.20

Troubleshoot Cisco Phone 7800 Series Intermittent Registration Issues

Troubleshooting process for phones intermittently unregistering is may be complicated, because of a need to take a packet capture from the unregistered phone.

Solution or rather a workaround to overcome that problem is to try isolating a relatively small group of phones having the issue. Then setup a jump server and SSH to the CLI of all these phones. Ensure that the logs are written to external log files.

Enable Phone SSH Access

In the CUCM Administration page navigate to Device -> Phone. Select the phone you need to troubleshoot and under Product Specific Configuration Layout -> SSH Access set Enable setting. You also need to configure SSH login and password in the Secure Shell Information section as shown below.

Enable Phone Logs

For registration issues troubleshooting specific debug levels must be configured on the phone.

Login to the phone via SSH protocol. You need to put the credentials twice.

First credentials were specified in the configuration Secure Shell Information. In the example it is

login: cisco
password: cisco

Second credentials prompt will appear right after the first one and you need to type the following.

snoopyplus login: debug
password: debug

For registration troubleshooting enable the following debugs.

DEBUG> debug lsm vcm fim fsm gsm sip-messages sip-reg-state sip-adapter snapshot
debugs: sip-adapter fim fsm gsm lsm sip-state sip-messages sip-reg-state ccdefault vcm snapshot

DEBUG> debug jvm SIPCC
DEBUG> Successfully executed the command.

In your SSH Client software set configure Session logging to a text log file.

Start generating the debug entries in the SSH client.

DEBUG> sdump

After typing the above command numerous lines of logs will be generated.

Working Scenario

In this scenario CUCM Publisher (PUB) is working and the only Subscriber (SUB) server deployed has CallManager process shut down.

When analysing phone unregistration scenario first find the last phone successful registration.

See the typical outputs in the phone logs below..

The most important messages are in bold.

1756 DEB Nov 09 12:59:23.444344 JAVA-SIPCC-SIP_STATE: 97/1, sip_reg_sm_change_state: Registration state change: SIP_REG_STATE_REGISTERED ---> SIP_REG_STATE_IDLE

1758 DEB Nov 09 12:59:23.445474 JAVA-SIPCC-SIP_STATE: 97/1, sip_reg_sm_change_state: Registration state change: SIP_REG_STATE_IDLE ---> SIP_REG_STATE_IDLE

1766 NOT Nov 09 12:59:23.447427 JAVA-ccsip_messaging: sipSPIAddContactHeader: CFGID_DEVICE_NAME = SEPC80084AA8721
1767 NOT Nov 09 12:59:23.447580 JAVA-ccsip_messaging: sipSPIAddContactHeader: ccb->call_mode = 0, display_name = 5035
1768 DEB Nov 09 12:59:23.447732 JAVA-SIPCC-PLAT_API: platform_get_mac_address: ActiveMacAddr:from Get Val: c800:84aa:8721

1773 DEB Nov 09 12:59:23.449563 JAVA-sipio-sent---> REGISTER sip:10.48.47.143 SIP/2.0^M
Via: SIP/2.0/TCP 10.62.153.20:51509;branch=z9hG4bK02d4d010^M
From: <sip:5035@10.48.47.143>;tag=c80084aa872100591162d8f8-468984ee^M
To: <sip:5035@10.48.47.143>^M
Call-ID: c80084aa-8721001f-10fda170-17017997@10.62.153.20^M
Max-Forwards: 70^M
Date: Wed, 09 Nov 2016 12:59:23 GMT^M
CSeq: 154 REGISTER^M
User-Agent: Cisco-CP7821/10.3.1^M
Contact: <sip:2fbf6265-bffc-4f99-b8b2-40dce7ed2d19@10.62.153.20:51509;transport=tcp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-c80084aa8721>";+u.sip!devicename.ccm.cisco.com="SEPC80084AA8721";+u.sip!model.ccm.cisco.com="621"^M
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1^M
Content-Length: 0^M
Expires: 3600^M
^M

1776 DEB Nov 09 12:59:23.449899 JAVA-[[MESSAGE_1.0]]: [SIPCC] --> REGISTER sip:10.48.47.143 SIP/2.0() --> [10.48.47.143] :
1777 DEB Nov 09 12:59:23.450082 JAVA-SIPCC-SIP_MSG_SEND: ccsip_store_send_msg_for_alarm: Sent:REGISTER sip:10.48.47.143 SIP/2.0 Cseq:154 REGISTER CallId:c80084aa-8721001f-10fda170-17017997@10.62.153.20
1778 DEB Nov 09 12:59:23.450296 JAVA-SIPCC-SIP_STATE: 97/1, sip_reg_sm_change_state: Registration state change: SIP_REG_STATE_IDLE ---> SIP_REG_STATE_REGISTERING

1780 DEB Nov 09 12:59:23.486646 JAVA-sipio-recv<--- SIP/2.0 100 Trying^M
Via: SIP/2.0/TCP 10.62.153.20:51509;branch=z9hG4bK02d4d010^M
From: <sip:5035@10.48.47.143>;tag=c80084aa872100591162d8f8-468984ee^M
To: <sip:5035@10.48.47.143>^M
Date: Wed, 09 Nov 2016 12:59:24 GMT^M
Call-ID: c80084aa-8721001f-10fda170-17017997@10.62.153.20^M
CSeq: 154 REGISTER^M
Content-Length: 0^M
^M
1782 DEB Nov 09 12:59:23.486890 JAVA-[[MESSAGE_1.0]]: [10.48.47.143] --> SIP/2.0 100 Trying() --> [SIPCC] :

1788 DEB Nov 09 12:59:23.490033 JAVA-sipio-recv<--- SIP/2.0 200 OK^M
Via: SIP/2.0/TCP 10.62.153.20:51509;branch=z9hG4bK02d4d010^M
From: <sip:5035@10.48.47.143>;tag=c80084aa872100591162d8f8-468984ee^M
To: <sip:5035@10.48.47.143>;tag=1785778723^M
Date: Wed, 09 Nov 2016 12:59:24 GMT^M
Call-ID: c80084aa-8721001f-10fda170-17017997@10.62.153.20^M
Server: Cisco-CUCM11.0^M
CSeq: 154 REGISTER^M
Expires: 120^M
Contact: <sip:2fbf6265-bffc-4f99-b8b2-40dce7ed2d19@10.62.153.20:51509;transport=tcp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-c80084aa8721>";+u.sip!devicename.ccm.cisco.com="SEPC80084AA8721";+u.sip!model.ccm.cisco.com="621"^M
Supported: X-cisco-srtp-fallback,X-cisco-sis-8.0.0^M
Content-Length: 0^M
^M

1790 DEB Nov 09 12:59:23.490247 JAVA-[[MESSAGE_1.0]]: [10.48.47.143] --> SIP/2.0 200 OK() --> [SIPCC] :
1791 DEB Nov 09 12:59:23.490400 JAVA-SIPCC-SIP_MSG_SEND: ccsip_store_rcvd_msg_for_alarm: Rcvd:SIP/2.0 200 OK Cseq:154 REGISTER CallId:c80084aa-8721001f-10fda170-17017997@10.62.153.20
1792 DEB Nov 09 12:59:23.490949 JAVA-SIPCC-SIP_BRANCH: sip_sm_ccb_match_branch_cseq: Matched branch_id & CSeq
1793 DEB Nov 09 12:59:23.491773 JAVA-SIPCC-SIP_RESP: sipSPICheckResponse: Response match: callid=c80084aa-8721001f-10fda170-17017997@10.62.153.20, cseq=154, cseq_method=REGISTER
1794 DEB Nov 09 12:59:23.491956 JAVA-SIPCC-SIP_REG_BULK: 97/0, ccsip_handle_ev_2xx: bulk_reg_status: BULK_REG_SUCCESS, bulk_reg_resp_code: 200

1798 DEB Nov 09 12:59:23.493726 JAVA-SIPCC-SIP_STATE: 97/1, sip_reg_sm_change_state: Registration state change: SIP_REG_STATE_REGISTERING ---> SIP_REG_STATE_REGISTERED
1799 DEB Nov 09 12:59:23.493848 JAVA-SIPCC-UI_API: ui_set_sip_registration_state: LINE 1: REGISTERED
1800 DEB Nov 09 12:59:23.493940 JAVA-SIPCC-UI_API: ui_set_sip_registration_state: reset DND.
1801 ERR Nov 09 12:59:23.494215 JAVA-SIPCC-SIP_CC_PROV: ccappFeatureUpdated: REG_STATE event:line=1,state=1
1802 DEB Nov 09 12:59:23.494367 JAVA-SIPCC-SIP_REG_STATE: ccsip_handle_ev_2xx: Bulk_reg=false. Setting Reg state to TRUE for line=1
1803 DEB Nov 09 12:59:23.494550 JAVA-SIPCC-SIP_TIMER: 97/1, ccsip_handle_ev_2xx: Starting expires timer (115 sec)

Phone Unregistration after CUCM

In this scenario UCS server with CUCM PUB crashed and the only SUB server has CallManager process shut down.

Note: There is no explicit message that phone lost TCP connection.

After the phone unsuccessfully tries to establish TCP connection to the primary node the phone starts trying to create a connection to the secondary CUCM.

Here CUCM SUB CallManager process is stopped therefore socket can not be created and registration fallback fails.

There are couple of registration attempts made to the SUB node.

1826 NOT Nov 09 13:00:44.003142 JAVA-SIPCC-SIP_FALLBACK: sip_regmgr_ev_tmr_ack_retry: In SIP_REG_STATE_IN_FALLBACK trying to create connection to send REG

1829 NOT Nov 09 13:00:44.003813 JAVA-SIP : sip_tcp_get_free_conn_entry : returned index=1
1830 ERR Nov 09 13:00:44.104500 JAVA-SIPCC-SIP_CC_CONN: sip_tcp_create_connection: socket connect failed cpr_errno: 1 ipaddr: 10.48.47.136, port: 5060
1831 ERR Nov 09 13:00:44.104653 JAVA-SIPCC-SIP_TRANS: sip_tcp_detach_socket: Max TCP connections reached.
1832 NOT Nov 09 13:00:44.104836 JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_purge_entry: Socket fd: 53 closed for connid 1 with address: 1, remote port: 170930056
1833 ERR Nov 09 13:00:44.104927 JAVA-SIPCC-SIP_CC_CONN: sip_transport_setup_cc_conn: <PRIMARY_CCM>:tcp channel create error server addr=10.48.47.136, server port=5060 failed.
1834 DEB Nov 09 13:00:44.105263 JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: g_deviceInfo.ins_state=1
1835 DEB Nov 09 13:00:44.105385 JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->sis_name=X-cisco-sis-
1836 DEB Nov 09 13:00:44.105477 JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: reference pointer=b31141c0
1837 DEB Nov 09 13:00:44.105568 JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->ins_state=1
1838 DEB Nov 09 13:00:44.105629 JAVA-SIPCC-SIP_CC_PROV: ccsnap_gen_deviceEvent: g_deviceInfo.ins_state=1

1854 DEB Nov 09 13:00:44.107949 JAVA-SIPCC-SIP_TRANS: sip_get_local_ip_addr: dst_addr: 10.48.47.143
1855 DEB Nov 09 13:00:44.108040 JAVA-SIPCC-SIP_TRANS: sip_get_local_ip_addr: src_addr: 10.62.153.20
1856 DEB Nov 09 13:00:44.108101 JAVA-SIPCC-SIP_TRANS: sip_transport_getaddrinfo: 10.48.47.136 is already an IPv4 address

1861 NOT Nov 09 13:00:44.108803 JAVA-SIP : sip_tcp_get_free_conn_entry : returned index=1
1862 ERR Nov 09 13:00:44.209551 JAVA-SIPCC-SIP_CC_CONN: sip_tcp_create_connection: socket connect failed cpr_errno: 1 ipaddr: 10.48.47.136, port: 5060
1863 ERR Nov 09 13:00:44.209704 JAVA-SIPCC-SIP_TRANS: sip_tcp_detach_socket: Max TCP connections reached.
1864 NOT Nov 09 13:00:44.209887 JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_purge_entry: Socket fd: 53 closed for connid 1 with address: 1, remote port: 170930056
1865 ERR Nov 09 13:00:44.209978 JAVA-SIPCC-SIP_CC_CONN: sip_transport_setup_cc_conn: <PRIMARY_CCM>:tcp channel create error server addr=10.48.47.136, server port=5060 failed.

1875 ERR Nov 09 13:00:44.211413 JAVA-SIPCC-SIP_TRANS: sip_transport_init_ti_addr: CCM unprovisioned
1876 DEB Nov 09 13:00:44.211474 JAVA-SIPCC-SIP_FALLBACK: 120/1, sip_regmgr_retry_timer_start: Starting fallback timer (120 sec)

After 115 seconds the phone sends another REGISTER message towards primary CUCM.

1900 DEB Nov 09 13:01:18.688599 JAVA-SIPCC-MSG_SEND_REQ: sipSPIBuildRegisterHeaders: Sending REGISTER...

1904 NOT Nov 09 13:01:18.689667 JAVA-ccsip_messaging: sipSPIAddContactHeader: CFGID_DEVICE_NAME = SEPC80084AA8721

1910 DEB Nov 09 13:01:18.691132 JAVA-SIPCC-SIP_TRANS: sipTransportSendMessage: Sip msg sent handle=<49>,length=<876>, message=
1911 DEB Nov 09 13:01:18.691804 JAVA-sipio-sent---> REGISTER sip:10.48.47.143 SIP/2.0^M
Via: SIP/2.0/TCP 10.62.153.20:51509;branch=z9hG4bK1eebbfed^M
From: <sip:5035@10.48.47.143>;tag=c80084aa8721005a4c0eda93-3da49275^M
To: <sip:5035@10.48.47.143>^M
Call-ID: c80084aa-8721001f-10fda170-17017997@10.62.153.20^M
Max-Forwards: 70^M
Date: Wed, 09 Nov 2016 13:01:18 GMT^M
CSeq: 155 REGISTER^M
User-Agent: Cisco-CP7821/10.3.1^M
Contact: <sip:2fbf6265-bffc-4f99-b8b2-40dce7ed2d19@10.62.153.20:51509;transport=tcp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-c80084aa8721>";+u.sip!devicename.ccm.cisco.com="SEPC80084AA8721";+u.sip!model.ccm.cisco.com="621"^M
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1^M
Content-Length: 0^M
Expires: 3600^M
^M

1914 DEB Nov 09 13:01:18.692139 JAVA-[[MESSAGE_1.0]]: [SIPCC] --> REGISTER sip:10.48.47.143 SIP/2.0() --> [10.48.47.143] :
1915 DEB Nov 09 13:01:18.692322 JAVA-SIPCC-SIP_MSG_SEND: ccsip_store_send_msg_for_alarm: Sent:REGISTER sip:10.48.47.143 SIP/2.0 Cseq:155 REGISTER CallId:c80084aa-8721001f-10fda170-17017997@10.62.153.20
1916 DEB Nov 09 13:01:18.692536 JAVA-SIPCC-SIP_STATE: 97/1, sip_reg_sm_change_state: Registration state change: SIP_REG_STATE_IDLE ---> SIP_REG_STATE_REGISTERING

The message "CUCM closed TCP connection" here is for SUB node.

1917 DEB Nov 09 13:01:22.523575 JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_read_socket: CUCM closed TCP connection.
1918 ERR Nov 09 13:01:22.523758 JAVA-SIP : sip_tcp_read_socket : socket error=110

1923 DEB Nov 09 13:01:22.524613 JAVA-SIPCC-SIP_TRANS: sip_transport_destroy_cc_conn: CC <SECONDARY_CCM>: closing the TCP connection

1924 DEB Nov 09 13:01:22.524705 JAVA-SIPCC-SIP_SOCK: sip_tcp_destroy_connection: purge entry, socket is 49, connid is 0
1925 NOT Nov 09 13:01:22.524888 JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_purge_entry: Socket fd: 49 closed for connid 0 with address: 1, remote port: 170930063

1941 DEB Nov 09 13:01:22.527696 JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_createconnfailed_to_spi: Active server going down due to ETIMEDOUT. ip_addr:10.48.47.143

After that the phone generates ALARM message and tries to send it via SIP REFER message.

In this example SIP REFER is not generated, because phone fails to establish TCP socket with CUCM.

1950 NOT Nov 09 13:01:22.529008 JAVA-Thread-5|JPlatUi:updateAlarmInfo - infoType:1, ccmId:0, phonePort:51509, sipMsg:Sent:REGISTER sip:10.48.47.143 SIP/2.0 Cseq:155 REGISTER CallId:c80084aa-8721001f-10fda170-17017997@10.62.153.20
1951 DEB Nov 09 13:01:22.541857 JAVA-SIPCC-SIP_ALARM: update_unregister_alarm_info: Info_type=CC_UNREG_ALARM_SIP_MSG_INFO ccm_id=VISITING_CCM phone_tcp_port=0 sip_info_msg=<?xml version="1.0" encoding="UTF-8" ?>
<x-cisco-alarm>
<Alarm Name="LastOutOfServiceInformation">
<ParameterList>
<String name="DeviceName">SEPC80084AA8721</String>
<String name="DeviceIPv4Address">10.62.153.20 / 0</String>
<String name="IPv4DefaultGateway">10.62.153.17</String>
<String name="DeviceIPv6Address"></String>
<String name="IPv6DefaultGateway"></String>
<String name="ModelNumber">CP-7821</String>
<String name="NeighborIPv4Address">10.62.153.17</String>
<String name="NeighborIPv6Address"></String>
<String name="NeighborDeviceID"></String>
<String name="NeighborPortID">FastEthernet0/1</String>
<Enum name="DHCPv4Status">1</Enum>
<Enum name="DHCPv6Status">3</Enum>
<Enum name="TFTPCfgStatus">1</Enum>
<Enum name="DNSStatusUnifiedCM1">4</Enum>
<Enum name="DNSStatusUnifiedCM2">4</Enum>
<Enum name="DNSStatusUnifiedCM3">3</Enum>
<String name="VoiceVLAN">150</String>
<Strin
1952 DEB Nov 09 13:01:22.542223 JAVA-SIPCC-SIP_ALARM: storeAlarm: stored alarm at index [0].

1958 NOT Nov 09 13:01:22.544024 JAVA-Thread-5|JPlatUi:setUnregReason - old-unregister-reason:25, new unregister-reason:10, cc-server-type:0
1959 NOT Nov 09 13:01:22.544268 JAVA-Thread-5|JPlatUi:isThisFailureFromNewCause - old unregReason =25 newUnregReason=10
1960 NOT Nov 09 13:01:22.549762 JAVA-Thread-5|JPlatUi:setUnregReason - set to unregister-reason:10

Below de-registration reason code 10 is decoded as "LastTimeTCPtimeout".

1961 ERR Nov 09 13:01:22.681060 JAVA-Thread-5 - ================== stonemark5
1962 NOT Nov 09 13:01:22.681701 JAVA-Thread-5|cip.sipcc.SipEnhancedAlarmInfo:setLastDeregistrationReason - new unreg-reason=10(LastTimeTCPtimeout), old unreg-reason=25
1963 WRN Nov 09 13:01:22.689698 JAVA-Thread-5|cip.sipcc.SipEnhancedAlarmInfo:getLastUnregistrationTimeReason - TimeStamp=1478696482681; Reasons =10
1964 ERR Nov 09 13:01:22.814801 JAVA-Thread-5 - ================== stonemark5

1965 NOT Nov 09 13:01:22.821546 JAVA-Thread-5|JPlatUi:setUnregReason - try to send first unreg-alarm after phone registered, unregister-reason:10
1966 INF Nov 09 13:01:22.822003 JAVA-Thread-5|cip.sipcc.SipCcAdapter: - ALarmerIF send alarm( LastOutOfServiceInformation ): DeviceName=SEPC80084AA8721 DeviceIPv4Address=10.62.153.20/29 IPv4DefaultGateway=10.62.153.17 DeviceIPv6Address= IPv6DefaultGateway= ModelNumber=CP-7821 NeighborIPv4Address=10.62.153.17 NeighborIPv6Address= NeighborDeviceID=KPOE-allevich.cisco.com NeighborPortID=FastEthernet0/1 DHCPv4Status=1 DHCPv6Status=3 TFTPCfgStatus=1 DNSStatusUnifiedCM1=4 DNSStatusUnifiedCM2=4 DNSStatusUnifiedCM3=0 DNSv6StatusUnifiedCM1=0 DNSv6StatusUnifiedCM2=0 DNSv6StatusUnifiedCM3=0 VoiceVLAN=150 UnifiedCMIPAddress=10.48.47.143 LocalPort=51509 TimeStamp=1478696482681 ReasonForOutOfService=10 LastProtocolEventSent=Sent:REGISTER sip:10.48.47.143 SIP/2.0 Cseq:155 REGISTER CallId:c80084aa-8721001f-10fda170-17017997@10.62.153.20 LastProtocolEventReceived=Rcvd:SIP/2.0 200 OK Cseq:103 REGISTER CallId:c80084aa-87210003-03fea156-01e00b4a@10.62.153.20

1967 DEB Nov 09 13:01:22.822309 JAVA-SIPCC-SIP_ALARM: storeAlarm: stored alarm at index [1].

1974 DEB Nov 09 13:01:22.857499 JAVA-SIPCC-SIP_ALARM: update_unregister_alarm_info: Info_type=CC_UNREG_ALARM_SIP_MSG_INFO ccm_id=VISITING_CCM phone_tcp_port=0 sip_info_msg=Sent:REGISTER sip:10.48.47.143 SIP/2.0 Cseq:155 REGISTER CallId:c80084aa-8721001f-10fda170-17017997@10.62.153.20

1975 DEB Nov 09 13:01:22.857804 JAVA-SNAPSHOT-RELEASE: CCAPI_Device_releaseDeviceInfo: reference pointer=b3535768
1976 ERR Nov 09 13:01:22.857926 JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_createconnfailed_to_spi: send a SIP_TMR_REG_RETRYmessage so this cucm ip:10.48.47.143 can be put in fallback list
1977 DEB Nov 09 13:01:22.857987 JAVA-SIPCC-SIP_MSG_SEND: ccsip_register_send_msg: cmd=90=SIP_TMR_REG_RETRY ndx=97
1978 ERR Nov 09 13:01:22.858140 JAVA-SIPCC-SIP_TRANS: sip_tcp_detach_socket: Invalid socket
1979 NOT Nov 09 13:01:22.858231 JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_purge_entry: Socket fd: -1 closed for connid 0 with address: 0, remote port: 0

1980 DEB Nov 09 13:01:22.858506 JAVA-SIPCC-MSG_SEND_REQ: SIPSPISendSubscribe: Sending SUBSCRIBE...

1989 NOT Nov 09 13:01:22.860734 JAVA-SIPCC-SIP_MSG_SEND: ccsip_dump_send_msg_info: <10.48.47.143:5060>:REFER s: <sip:10.48.47.143> :1000 REFER::c80084aa-8721001e-25e32e9e-6505ba59@10.62.153.20
1990 ERR Nov 09 13:01:22.860856 JAVA-SIPCC-SIP_TRANS: sipTransportSendMessage: no connection to remote address 10.48.47.143:5060
1991 ERR Nov 09 13:01:22.860917 JAVA-SIPCC-FUNC_CALL: sipTransportCreateSendMessage: Error: sipTransportSendMessage() returned error.
1992 ERR Nov 09 13:01:22.861131 JAVA-SIP : SIPSPISendSubscribe : failed to send message
1993 ERR Nov 09 13:01:22.861222 JAVA-SIP : subsmanager_handle_ev_app_subscribe : failed to send SUBSCRIBE message

2028 NOT Nov 09 13:01:22.869341 JAVA-SIPCC-UI_API: ui_set_ccm_conn_status: ***********CUCM 10.48.47.143 Not connected***********

2072 DEB Nov 09 13:01:22.879687 JAVA-SIPCC-SIP_FAILOVER: sip_regmgr_ccm_get_next: NO CC AVAILABLE. NEED TO REBOOT !

2083 ERR Nov 09 13:01:22.881396 JAVA-SIPCC-SIP_TRANS: sip_transport_get_ti_addr: No active CUCM found using primary CUCM
2084 DEB Nov 09 13:01:22.881488 JAVA-SIPCC-SIP_REG: sip_regmgr_handle_reg_all_fail: All registration attempts failed.
2085 NOT Nov 09 13:01:22.881640 JAVA-SIPCC-UI_API: ui_set_ccm_conn_status: ***********CUCM 10.48.47.136 Not connected***********

2125 DEB Nov 09 13:01:22.892811 JAVA-SIPCC-SIP_TRANS: sip_transport_destroy_cc_conn: CC <PRIMARY_CCM>: connection already closed
2126 NOT Nov 09 13:01:22.892933 JAVA-SIPCC-UI_API: ui_set_ccm_conn_status: ***********CUCM 10.48.47.143 Not connected***********
2127 DEB Nov 09 13:01:22.893116 JAVA-SIPCC-SIP_TRANS: sip_transport_destroy_cc_conn: CC <SECONDARY_CCM>: connection already closed
2128 ERR Nov 09 13:01:22.893238 JAVA-SIPCC-SIP_TRANS: sip_transport_get_ti_addr: No active CUCM found using primary CUCM
2129 ERR Nov 09 13:01:22.893299 JAVA-SIPCC-SIP_TRANS: sip_transport_get_ti_addr: No active CUCM found using primary CUCM
2130 NOT Nov 09 13:01:22.893513 JAVA-SIPCC-UI_API: ui_set_ccm_conn_status: ***********CUCM 10.48.47.136 Not connected***********
2131 DEB Nov 09 13:01:22.893665 JAVA-SIPCC-SIP_TRANS: sip_transport_destroy_cc_conn: CC <TERTIARY_CCM>: connection already closed
2132 ERR Nov 09 13:01:22.893757 JAVA-SIPCC-SIP_TRANS: sip_transport_get_ti_addr: No active CUCM found using primary CUCM
2133 ERR Nov 09 13:01:22.893879 JAVA-SIPCC-SIP_TRANS: sip_transport_get_ti_addr: No active CUCM found using primary CUCM
2134 NOT Nov 09 13:01:22.893971 JAVA-SIPCC-UI_API: ui_set_ccm_conn_status: ***********CUCM 10.48.47.136 Not connected***********
2135 DEB Nov 09 13:01:22.894123 JAVA-SIPCC-SIP_TRANS: sip_transport_destroy_cc_conn: CC <SRST_CCM>: connection already closed
2136 DEB Nov 09 13:01:22.894245 JAVA-SIPCC-UI_API: ui_set_sip_registration_state: LINE 1: UN-REGISTERED

After unsuccessfully trying to register to all nodes the phone restarts and registration will be attempted again.

2288 DEB Nov 09 13:01:22.996946 JAVA-SIPCC-SIP_REG: sip_regmgr_regallfail_timer_callback: Registration Failed. Restarting the System now!
2289 DEB Nov 09 13:01:22.997099 JAVA-SIPCC-SIP_REG: sip_regmgr_send_status: src_id: 1 msg_id: 1

2290 DEB Nov 09 13:01:22.997160 JAVA-SIPCC-UI_API: ui_reg_all_failed: ***********Registration to all CUCMs failed.***********
2291 DEB Nov 09 13:01:22.997313 JAVA-SIPCC-SIP_REG: sip_regmgr_send_status: REG ALL FAILED
2292 NOT Nov 09 13:01:22.998045 JAVA-SIPCC-SIP_DEVICE_MGR: registration_processEvent: Event EV_CC_OOS_REG_ALL_FAILED, current State MGMT_STATE_REGISTERED
2293 NOT Nov 09 13:01:22.998320 JAVA-SIPCC-SIP_DEVICE_MGR: setState: new registration state = MGMT_STATE_OOS_AWAIT_SHUTDOWN_ACK