[cisco-voip] CME registration issue

Fri Jun 8 09:05:01 EDT 2012

Hard to say.  Any status messages on the phone under the phone menu,
status messages?  I've seen things like really short DHCP leases doing
something similar.

-nick

On Fri, Jun 8, 2012 at 12:55 AM, Leslie Meade <Leslie.Meade at lvs1.com> wrote:
> I have a strange issue that I think I know the issue but do not know how to fix it.
>
> I have a test lab and today I fired up my PSTN router a 3745, and for the past year it was worked with out an issue.
> But today i am getting the phone hanging at "requesting Softkey Template" then it will cycle through again
>
> There has been no changes to the router. When i do a debug tftp events i get the  following
>
> Jun  7 21:35:57.695: New Skinny socket accepted [1] (1 active)
> Jun  7 21:35:57.695: sin_family 2, sin_port 50667, in_addr 10.10.200.21
> Jun  7 21:35:57.695: skinny_add_socket 1 10.10.200.21 50667
> Jun  7 21:35:57.703: %IPPHONE-6-REG_ALARM: 17: Name=SEP0014F26A78CA Load=8.0(9.0) Last=KeepaliveTO
> Jun  7 21:35:57.703: ephone-(3)[2] StationRegisterMessage (1/1/5) from 10.10.200.21
> Jun  7 21:35:57.703: ephone-(3)[2] Register StationIdentifier DeviceName SEP0014F26A78CA
> Jun  7 21:35:57.703: ephone-(3)[2] StationIdentifier Instance 1    deviceType 7
> Jun  7 21:35:57.703: ephone-3[1]:stationIpAddr 10.10.200.21
> Jun  7 21:35:57.703: ephone-3[1][SEP0014F26A78CA]:maxStreams 0
> Jun  7 21:35:57.703: ephone-3[1][SEP0014F26A78CA]:From Phone raw protocol Ver 0x8560000B
> Jun  7 21:35:57.703: ephone-3[1][SEP0014F26A78CA]:protocol Ver 0x8560000B
> Jun  7 21:35:57.703: ephone-3[1][SEP0014F26A78CA]:phone-size 5480 dn-size 688
> Jun  7 21:35:57.703: ephone-(3) Allow any Skinny Server IP address 10.10.250.2
> Jun  7 21:35:57.703: ephone-3[1][SEP0014F26A78CA]:Found entry 2 for 0014F26A78CA
> Jun  7 21:35:57.703: ephone-3[1][SEP0014F26A78CA]:socket change 1 to 2
> Jun  7 21:35:57.703: ephone-3[1][SEP0014F26A78CA]:DisAssociate: Closed socket 1 while REGISTERED
> Jun  7 21:35:57.707: %IPPHONE-6-UNREGISTER_ABNORMAL: ephone-3:SEP0014F26A78CA IP:10.10.200.21 Socket:1 DeviceType:Phone has unregistered abnormally.
> Jun  7 21:35:57.707: ephone-3[-1][SEP0014F26A78CA]:FAILED: CLOSED old socket -1
> Jun  7 21:35:57.707: ephone-3[2][SEP0014F26A78CA]:***Force device subtype to 0
> Jun  7 21:35:57.707: ephone-3[2][SEP0014F26A78CA]:phone SEP0014F26A78CA re-associate OK on socket [2]
> Jun  7 21:35:57.707: %IPPHONE-6-REGISTER: ephone-3:SEP0014F26A78CA IP:10.10.200.21 Socket:2 DeviceType:Phone has registered.
> Jun  7 21:35:57.707: Phone 2 socket 2
> Jun  7 21:35:57.707: Skinny Local IP address = 10.10.250.2 on port 2000
> Jun  7 21:35:57.707: Skinny Phone IP address = 10.10.200.21 50667
> Jun  7 21:35:57.707: ephone-3[2][SEP0014F26A78CA]:Signal protocol ver 8 to phone with ver 11
> Jun  7 21:35:57.707: ephone-3[2][SEP0014F26A78CA]:Date Format M/D/Y
> Jun  7 21:35:57.707: ephone-3[2]:RegisterAck sent to sockettype ephone socket 2: keepalive period 30 use sccp-version 8
> Jun  7 21:35:57.707: ephone-3[2]:CapabilitiesReq sent
> Jun  7 21:35:57.715: ephone-3[2]:MediaPathEventMessage
> Jun  7 21:35:57.715: ephone-3[2]:MediaPathEventMessage
> Jun  7 21:35:57.719: ephone-3[2]:MediaPathEventMessage
> Jun  7 21:35:57.755: ephone-3[2]:MediaPathEventMessage
> Jun  7 21:35:57.759: ephone-3[2]:MediaPathEventMessage
> Jun  7 21:35:57.919: ephone-3[2]:CapabilitiesRes received
> Jun  7 21:35:57.919: ephone-3[2][SEP0014F26A78CA]:Caps list 8
> WideBand_256K  120 ms
> G711Ulaw64k  40 ms
> G711Alaw64k  40 ms
> G729AnnexB  60 ms
> G729AnnexAwAnnexB  60 ms
> G729  60 ms
> G729AnnexA  60 ms
> Unrecognized Media Type 257  4 ms
> Jun  7 21:35:57.919: ephone-3[2]:MediaPathEventMessage
> Jun  7 21:35:57.919: ephone-3[2]:MediaPathEventMessage
> Jun  7 21:35:57.919: ephone-3[2]:ButtonTemplateReqMessage
> Jun  7 21:35:57.919: ephone-3[2][SEP0014F26A78CA]:StationButtonTemplateReqMessage set max presentation to 6
> Jun  7 21:35:57.919: ephone-3[2]:CheckAutoReg
> Jun  7 21:35:57.919: ephone-3[2]:AutoReg is disabled
> Jun  7 21:35:57.919: ephone-3[2][SEP0014F26A78CA]:Setting 6 lines 0 speed-dials on phone (max_line 6)
> Jun  7 21:35:57.919: ephone-3[2][SEP0014F26A78CA]:First Speed Dial Button location is 0 (0)
> Jun  7 21:35:57.919: ephone-3[2][SEP0014F26A78CA]:Configured 0 speed dial buttons
> Jun  7 21:35:57.919: ephone-3[2]:ButtonTemplate lines=6 speed=0 buttons=6 offset=0
> Jun  7 21:35:57.927: ephone-3[2]:StationSoftKeyTemplateReqMessage
> Jun  7 21:35:57.927: ephone-3[2]:StationSoftKeyTemplateResMessage  <-- This is where the Requesting Softkey Template hangs
> Jun  7 21:35:58.115: Bring up DN 1 by SkinnyCheckDnStatus
> Jun  7 21:35:58.591: TFTP: Finished system:/its/XMLDefault7960.cnf.xml, time 00:00:25 for process 154
> Jun  7 21:35:59.115: Bring up DN 2 by SkinnyCheckDnStatus
> Jun  7 21:36:00.115: Bring up DN 3 by SkinnyCheckDnStatus
> Jun  7 21:36:01.115: Bring up DN 4 by SkinnyCheckDnStatus
> Jun  7 21:36:02.115: Bring up DN 5 by SkinnyCheckDnStatus
> Jun  7 21:36:02.623: TFTP: Finished system:/its/XMLDefault7960.cnf.xml, time 00:00:25 for process 156
> Jun  7 21:36:03.115: Bring up DN 6 by SkinnyCheckDnStatus
> Jun  7 21:36:06.619: TFTP: Finished system:/its/XMLDefault7960.cnf.xml, time 00:00:25 for process 171
> Jun  7 21:36:07.115: ephone-3[2]:SkinnyCompleteRegistration
> Jun  7 21:36:10.619: TFTP: Finished system:/its/XMLDefault7960.cnf.xml, time 00:00:25 for process 184
> Jun  7 21:36:14.619: TFTP: Finished system:/its/XMLDefault7960.cnf.xml, time 00:00:25 for process 238
> Jun  7 21:36:18.619: TFTP: Finished system:/its/XMLDefault7960.cnf.xml, time 00:00:25 for process 81
> Jun  7 21:37:32.679: ephone-3[2][SEP0014F26A78CA]:Phone Unregistered on socket [2] SEP0014F26A78CA
> Jun  7 21:37:33.115: Bring up DN 6 by SkinnyCheckDnStatus
> Jun  7 21:37:34.115: Bring up DN 1 by SkinnyCheckDnStatus
> Jun  7 21:37:35.115: Bring up DN 2 by SkinnyCheckDnStatus
> Jun  7 21:37:36.115: Bring up DN 3 by SkinnyCheckDnStatus
> Jun  7 21:37:40.115: Bring up DN 4 by SkinnyCheckDnStatus
> Jun  7 21:37:41.115: Bring up DN 5 by SkinnyCheckDnStatus
>
>
> the system reports that the phone is registered
>
> ephone-3 Mac:0014.F26A.78CA TCP socket:[1] activeLine:0 REGISTERED in SCCP ver 11 and Server in ver 8
> mediaActive:0 offhook:0 ringing:0 reset:0 reset_sent:0 paging 0 debug:0 caps:8
> IP:10.10.200.21 50668 Telecaster 7960  keepalive 3 max_line 6
> button 1: dn 1  number 911 CH1   IDLE         CH2   IDLE
> button 2: dn 2  number 2024678124 CH1   IDLE         CH2   IDLE
> button 3: dn 3  number 4088397263 CH1   IDLE         CH2   IDLE
> button 4: dn 4  number 02077966596 CH1   DOWN
> button 5: dn 5  number 2123942123 CH1   DOWN
> button 6: dn 6  number 916745738932 CH1   IDLE
>
>
> Any ideas ?
>
>
>
>
>
> _______________________________________________
> cisco-voip mailing list
> cisco-voip at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-voip