Scenario#45: 7841 SIP phone in Registration loop

I was working on this customer issue last week where they added a new 7841 phone but it was not registering properly or should I say it was registering briefly before unregistering.

Call Manager was 9.1.2.11900-12 which does not support 78XX phones so customer actually applied the device pack cmterm-devicepack9.1.2.12039-1.cop  so that they can add 78XX phones.

Looking at the logs I found that it is registering with Pub and not Sub even though Sub was the Primary CCM in Call Manager group. At Pub I can see something like this:

Pub:

REGISTER sip:192.168.11.2 SIP/2.0
Via: SIP/2.0/TCP 172.18.52.91:51736;branch=z9hG4bK739dd207
From: <sip:49715220XXXXX@192.168.11.2>;tag=544a003629fd000a741be677-22e1dea8
To: <sip:49715220XXXXX@192.168.11.2>
Call-ID: 544a0036-29fd0008-13a9ded8-614a41b9@172.18.52.91
Max-Forwards: 70
Date: Tue, 17 Jun 2014 06:32:10 GMT
CSeq: 104 REGISTER
User-Agent: Cisco-CP7841/10.1.1
Contact: <sip:61131fd1-5eb6-b49e-5d2f-9f9aee1b125c@172.18.52.91:51736;transport=tcp>;+sip.instance=”<urn:uuid:00000000-0000-0000-0000-544a003629fd>”;+u.sip!devicename.ccm.cisco.com=”SEP544A003629FD”;+u.sip!model.ccm.cisco.com=”622″
Supported:

.
.
[Registration Accepted by Publisher]
SIP/2.0 202 Accepted
Via: SIP/2.0/TCP 172.18.52.91:51736;branch=z9hG4bK6c29941b
From: <sip:544a003629fd@172.18.52.91>;tag=544a003629fd000c3890afb1-54d723a2
To: <sip:192.168.11.2>;tag=875713562
Date: Tue, 17 Jun 2014 06:32:10 GMT
Call-ID: 544a0036-29fd0006-22434855-1719a3c1@172.18.52.91
CSeq: 1000 REFER
Contact: <sip:192.168.11.2:5060;transport=tcp>
Content-Length: 0

.
.
.

 

 

But then I noticed this further down:

08:32:16.866 |AppInfo  |SIPStationD(607) – setUaTypeAndCepn: uaType is CISCO_ENHANCED_PHONE

08:32:16.866 |AppInfo  |SIPStationD(607) – Received REGISTER from 4971522036708@172.18.52.91:51736

08:32:16.866 |AppInfo  |SIPStationD(607) – verifyAddressAndPort — Endpoint unregistered (expires=0), old ip: 172.18.52.91, new ip:172.18.52.91

 

08:32:16.866 |AppInfo  |SIPStationD(607) – parseLoad: InactiveLoad= name is: [sip78xx.10-1-1-9.loads]

08:32:16.866 |AppInfo  |SIPStationD(607) – processReasonCode:  Processing phone provided reason code=[105]

08:32:16.866 |AppInfo  |SIPStationD(607) – DevStat-NewState : line 4971522036708: Registered ==> Unregistered

 

While on Subscriber this is what I saw:

Sub:

 

[Registration Request]

REGISTER sip:192.168.11.3 SIP/2.0
Via: SIP/2.0/TCP 172.18.52.91:50358;branch=z9hG4bK5fead06f
From: <sip:49715220XXXXX@192.168.11.3>;tag=544a003629fd00020eea65f9-659c5963
To: <sip:49715220XXXXX@192.168.11.3>
Call-ID: 544a0036-29fd0003-4c3d829b-12a9daae@172.18.52.91
Max-Forwards: 70
Date: Wed, 11 Apr 2012 08:28:24 GMT
CSeq: 101 REGISTER
User-Agent: Cisco-CP7841/10.1.1
Contact: <sip:61131fd1-5eb6-b49e-5d2f-9f9aee1b125c@172.18.52.91:50358;transport=tcp>;+sip.instance=”<urn:uuid:00000000-0000-0000-0000-544a003629fd>”;+u.sip!devicename.ccm.cisco.com=”SEP544A003629FD”;+u.sip!model.ccm.cisco.com=”622″
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-6.0.2,X-cisco-xsi-8.5.1
Reason: SIP;cause=200;text=”cisco-alarm:25 Name=SEP544A003629FD ActiveLoad=sip78xx.10-1-1SR1-4.loads InactiveLoad=sip78xx.10-1-1-9.loads Last=initialized”
Expires: 3600
Content-Type: multipart/mixed; boundary=uniqueBoundary
Mime-Version: 1.0
Content-Length: 1203
.

.

08:31:40.497 |AppInfo  |SIPStationD(684) – setUaTypeAndCepn: uaType is CISCO_ENHANCED_PHONE

08:31:40.497 |AppInfo  |CcmdbStationRegistrationProfileBuilder::init – No typemodel table-entry for device SEP544A003629FD.

08:31:40.497 |AppInfo  |CcmdbStationRegistrationProfileBuilder::getBasicRegistrationProfile::init() – failed rc(1)

08:31:40.497 |AppInfo  |SIPStationD(684) – Registration profile error: Database error, sending registration reject and closing station

08:31:40.497 |AppInfo  |SIPStationD(684) – sendRegisterResp: non-200 response code 404, ccbId 336776, expires 4294967295, warning Database error

08:31:40.497 |AlarmErr |AlarmClass: CallManager, AlarmName: EndPointTransientConnection

.

.

 

So what does it tells us?

Subscriber is not accepting the registration from this 7841 as it does not see that phone type as a legitimate phone.

But hang on did the customer not applied the device pack? yes they did.

A quick phone call with customer revelaed some secrets… Yes they did applied the device pack but rebooted only the Publisher. He questioned me in amazement  “Do we need to reboot Subscribers as well?”

#?#

Anyways, issue was resolved after rebooting the Sub as well. The device pack although applies would not take affect until you reboot it. So remember that if you are going to apply a device pack then:

1. Apply on all nodes
2. Reboot all nodes in cluster starting from Publisher