Buy or Renew
Buy or Renew
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
2941
Views
5
Helpful
2
Replies

Cisco 8865 losing SIP connection for an instant and IP Phone loses registration

hankej
Level 1
Level 1

‎08-21-2020 11:49 AM

Recently upgraded from CUCM 11.5.1 to 12.5.1.  Since then I have a report of at least three 8865 phones displaying the registration screen every 2-3 minutes.  So the phone loses its registration with the server and comes back up right away.  I was looking at the logs on one of the phone when this happened and I think it might be a SIP error, but I don't know how to ready the log very well.  I think the portion of the log where the error occurs is below:

 

 

8683 ERR Aug 21 13:26:19.838322 (749-890) JAVA-SIP : reportSockFailure : Socket Error=[110]
8684 DEB Aug 21 13:26:19.838463 (749-890) JAVA-[getDeployMode] deploy-mode:1
8685 DEB Aug 21 13:26:19.838636 (749-890) JAVA-SIPCC-SIP_TRANS: sip_transport_destroy_cc_conn: CC <PRIMARY_CCM>: closing the TCP connection
8686 DEB Aug 21 13:26:19.838681 (749-890) JAVA-SIPCC-SIP_SOCK: sip_tcp_destroy_connection: purge entry, socket is 87, connid is 0
8687 NOT Aug 21 13:26:19.838766 (749-890) JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_purge_entry: Socket fd: 87 closed for connid 0 with address: 10.200.0.12, remote port: 5060
8688 DEB Aug 21 13:26:19.838830 (749-890) JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_createconnfailed_to_spi: Stopping Msg expires timers
8689 DEB Aug 21 13:26:19.838945 (749-890) JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_set_reason_for_active_connfailed: Disconnected from Active Server (10.200.0.12). unRegReason:10 Errno:0, Cause:1, Reason:[ETIMEDOUT / CC_UNREG_REASON_TCP_TIMEOUT]
8690 NOT Aug 21 13:26:19.838970 (749-890) JAVA-SIPCC-PLAT_API: setUnregReason: setting unreg reason to=10
8691 DEB Aug 21 13:26:19.838993 (749-890) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: g_deviceInfo.ins_state=1
8692 DEB Aug 21 13:26:19.839018 (749-890) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->sis_name=X-cisco-sis-
8693 DEB Aug 21 13:26:19.839036 (749-890) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: reference pointer=48d93670
8694 DEB Aug 21 13:26:19.839064 (749-890) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->ins_state=1
8695 DEB Aug 21 13:26:19.839089 (749-890) JAVA-SIPCC-SIP_CC_PROV: 0x48d93670, CCAPI_DeviceInfo_getCUCMMode: returned 00
8696 NOT Aug 21 13:26:19.839108 (749-890) JAVA-SIPCC-PLAT_API: setUnregReason: value of first_oos_alarm_set=0
8697 DEB Aug 21 13:26:19.839191 (749-890) JAVA-SIPCC-SIP_ALARM: platSendUnregAlarmInfo: Info_type=CC_UNREG_ALARM_SIP_MSG_INFO ccm_id=VISITING_CCM phone_tcp_port=50050 sip_info_msg=Sent:REGISTER sip:Callmanager2.mycompany SIP/2.0 Cseq:104 REGISTER CallId:700b4f7b-16340003-42c38d71-4a7fd130@10.200.101.68
8698 NOT Aug 21 13:26:19.839406 (749-890) JAVA-Thread-6|JPlatUi:updateAlarmInfo - infoType:1, ccmId:0, phonePort:50050, sipMsg:Sent:REGISTER sip:Callmanager2.mycompany SIP/2.0 Cseq:104 REGISTER CallId:700b4f7b-16340003-42c38d71-4a7fd130@10.200.101.68
8699 DEB Aug 21 13:26:19.840127 (749-890) 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">SEP700B4F7B1634</String>
<String name="DeviceIPv4Address">10.200.101.68 / 0</String>
<String name="IPv4DefaultGateway">10.200.0.1</String>
<String name="DeviceIPv6Address"></String>
<String name="IPv6DefaultGateway"></String>
<String name="ModelNumber">CP-8865</String>
<String name="NeighborIPv4Address">10.1.250.193</String>
<String name="NeighborIPv6Address"></String>
<String name="NeighborDeviceID"></String>
<String name="NeighborPortID">GigabitEthernet10/2</String>
<Enum name="DHCPv4Status">1</Enum>
<Enum name="DHCPv6Status">3</Enum>
<Enum name="TFTPCfgStatus">1</Enum>
<Enum name="DNSStatusUnifiedCM1">1</Enum>
<Enum name="DNSStatusUnifiedCM2">1</Enum>
<Enum name="DNSStatusUnifiedCM3">1</Enum>
<String name="VoiceVLAN">200</String>
<St
8700 DEB Aug 21 13:26:19.840214 (749-890) JAVA-SIPCC-SIP_ALARM: storeAlarm: stored alarm at index [0].
8701 DEB Aug 21 13:26:19.840259 (749-890) JAVA-[getDeployMode] deploy-mode:1
8702 DEB Aug 21 13:26:19.840343 (749-890) JAVA-SIPCC-SIP_ALARM: sendStoredSIPAlarm: sent stored alarm[0] request_id=4 alarm_ptr=0x48d95bd0
8703 DEB Aug 21 13:26:19.840470 (749-889) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: g_deviceInfo.ins_state=1
8704 NOT Aug 21 13:26:19.840501 (749-890) JAVA-Thread-6|JPlatUi:setUnregReason - old-unregister-reason:25, new unregister-reason:10, cc-server-type:0
8705 NOT Aug 21 13:26:19.840566 (749-890) JAVA-Thread-6|JPlatUi:isThisFailureFromNewCause - old unregReason =25 newUnregReason=10
8706 DEB Aug 21 13:26:19.841041 (749-889) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->sis_name=X-cisco-sis-
8707 DEB Aug 21 13:26:19.841078 (749-889) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: reference pointer=48d96190
8708 DEB Aug 21 13:26:19.841104 (749-889) JAVA-SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->ins_state=1
8709 DEB Aug 21 13:26:19.841123 (749-889) JAVA-SIPCC-SIP_CC_PROV: ccsnap_gen_deviceEvent: g_deviceInfo.ins_state=1
8710 NOT Aug 21 13:26:19.841142 (749-889) JAVA-SIPCC-SIP_CC_PROV: ccsnap_gen_deviceEvent: event type : SERVER_TRANSPORT
8711 DEB Aug 21 13:26:19.841393 (749-889) JAVA-SIPCC-SIP_CC_PROV: ccsnap_gen_deviceEvent: ref_count=1
8712 DEB Aug 21 13:26:19.841413 (749-889) JAVA-SIPCC-SIP_CC_PROV: ccsnap_gen_deviceEvent: name=SEP700B4F7B1634 : privacy=0 : hlog=1 : dnd_state=0 : mwi_lamp=0
8713 DEB Aug 21 13:26:19.841432 (749-889) JAVA-SIPCC-SIP_CC_PROV: ccsnap_gen_deviceEvent: dnd_type=00 : ins_state=01 : cucm_mode=00 : ins_cause=00
8714 DEB Aug 21 13:26:19.841512 (749-889) JAVA-SNAPSHOT-RELEASE: CCAPI_Device_releaseDeviceInfo: reference pointer=48d96190
8715 NOT Aug 21 13:26:19.841876 (749-855) JAVA-configmgr MQThread|cip.cfg.Config: - [propertyChanged()] propName:"device.settings.config.sipprofile.local.sipunregreason"
8716 NOT Aug 21 13:26:19.842890 (749-890) JAVA-Thread-6|JPlatUi:setUnregReason - set to unregister-reason:10
8717 NOT Aug 21 13:26:19.846162 (749-890) JAVA-Thread-6|JPlatUi:setUnregReason - setting unregister-reason socket error code to:0
8718 NOT Aug 21 13:26:19.849015 (749-890) JAVA-Thread-6|cip.sipcc.SipEnhancedAlarmInfo:setLastDeregistrationReason - new unreg-reason=10(LastTimeTCPtimeout), old unreg-reason=25
8719 NOT Aug 21 13:26:19.849555 (749-890) JAVA-Thread-6|cip.sipcc.SipEnhancedAlarmInfo:getLastUnregistrationTimeReason - TimeStamp=1598034379849; Reasons =10
8720 NOT Aug 21 13:26:19.851009 (749-890) JAVA-Thread-6|JPlatUi:setUnregReason - try to send first unreg-alarm after phone registered, unregister-reason:10
8721 NOT Aug 21 13:26:19.851129 (749-890) JAVA-CCAPIDevicesendAlarm: phone-app requesting alarm to be sent
8722 DEB Aug 21 13:26:19.851173 (749-890) JAVA-SIPCC-SIP_ALARM: storeAlarm: stored alarm at index [1].
8723 DEB Aug 21 13:26:19.851219 (749-890) JAVA-[getDeployMode] deploy-mode:1
8724 DEB Aug 21 13:26:19.851305 (749-890) JAVA-SIPCC-SIP_ALARM: sendStoredSIPAlarm: sent stored alarm[1] request_id=5 alarm_ptr=0x48d95370
8725 NOT Aug 21 13:26:19.855421 (749-890) JAVA-Thread-6|cip.sipcc.SipEnhancedAlarmInfo:propertyChanged - name=device.status.lastresetcause2 value=464
8726 NOT Aug 21 13:26:19.857158 (749-881) JAVA-sipcc MQThread|cip.sipcc.SipCcAdapter: - propertyChanged(): device.status.lastresetcause2
8727 DEB Aug 21 13:26:19.858101 (749-890) 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:Callmanager2.mycompany SIP/2.0 Cseq:104 REGISTER CallId:700b4f7b-16340003-42c38d71-4a7fd130@10.200.101.68
8728 DEB Aug 21 13:26:19.858177 (749-890) JAVA-SNAPSHOT-RELEASE: CCAPI_Device_releaseDeviceInfo: reference pointer=48d93670
8729 ERR Aug 21 13:26:19.858206 (749-890) JAVA-SIPCC-SIP_TCP_MSG: sip_tcp_createconnfailed_to_spi: send a SIP_TMR_REG_RETRYmessage so this cucm ip:10.200.0.12 can be put in fallback list

 

Does anyone have any insight why this might be happening?  I am checking to see if this is phone specific or not by plugging my desk phone into the port the phone having the issue was on.  I change the firmware of the bad phone from:

sip8845_65.12-7-1-0001-393

to 

sip8845_65.12-8-1-0001-455.  This didn't resolve anything.

 

Looking to see if anyone has any possible solutions before opening a TAC case.


Thanks


Joe

1 person had this problem
Labels:
0 Helpful
2 Replies 2

Kaloyan
Cisco Employee
Cisco Employee

‎08-21-2020 07:41 PM

You can focus on this message:

Disconnected from Active Server (10.200.0.12). unRegReason:10 Errno:0, Cause:1, Reason:[ETIMEDOUT / CC_UNREG_REASON_TCP_TIMEOUT]

 

The unregistration reason 10 corresponds to "EndPointUnregistered" RTMT alert and has the following explanation:

 

"DeviceUnregistered - The device has explicitly unregistered. Possible causes include a change in the IP address or port of the device. No action is necessary; the device will re-register automatically."

 

This may be a bit misleading. Based on my experience this is a network related issue, mostly caused by firewalls. If you take a simultaneous  packet capture at the time of the event from the phone and CUCM, you'll see a TCP RST packet sent to the phone and perhaps to CUCM as well at the same time.

 

From CUCM perspective the phone sends the TCP RST, but from phone's perspective it was CUCM sending it. In reality it's the firewall sitting in between. 

OlegPerepichay9226
Level 1
Level 1

‎03-09-2021 05:15 AM

have similar problem. Did you resolve it? how?

0 Helpful
Customers Also Viewed These Support Documents