[cisco-voip] 1751-V with 12.4(15)T7 CME 4.0 Problems with 7920 and 7960

Tue Sep 9 02:54:16 EDT 2008

I haven't had any experience with the 7920 on a CME router, however if you suspect that it maybe DHCP related can you move the 7920 to a new VLAN and subnet?

________________________________
From: cisco-voip-bounces at puck.nether.net [cisco-voip-bounces at puck.nether.net] On Behalf Of Jose Mujica [embeleco at gmail.com]
Sent: Tuesday, 9 September 2008 11:58 AM
To: ciscovoip
Subject: [cisco-voip] 1751-V with 12.4(15)T7 CME 4.0 Problems with 7920 and 7960

[Long Post - Sorry]

Hi. I posted this a while back probably last year and didn't had a chance to follow-up so I still have the problem below.

I had a 1751-V running without problems with 7940,7960 and 7912 phones.. I
configured a new 7920 in the system and when the 7920 register with the CME
all the 7940 and 7960 IP Phones unregister from the router and they only came
back if I turn off the 7920.The 7912 IP Phones are always up. I don't know if
it is something related to CME or to DHCP. THe router is also the DHCP
server.. On the dhcp debugs it seems that when the router allocates an IP
Address for the 7920 phone.. then 7940 and 7960 phones send a DHCP Release
message to the router and after that they are completly out of the network.
When I turn off the 7920 then a couple of minutes later they are up and
running again.. Router is running latest 12.4(15)T7 SP Services and Phone Loads are latest as well on that particular IOS.

Attach debugs and snip configs from the router

telephony-service
 fxo hook-flash
 load 7960-7940 P00308000400
 load 7920 cmterm_7920.4.0-02-00
 load 7970 TERM70.7-0-3-0S
 load 7912 CP7912080001SCCP051117A
 max-ephones 10
 max-dn 20
 ip source-address 192.168.1.50<http://192.168.1.50> port 2000
 timeouts interdigit 4
 timeouts ringing 30
 time-zone 14
 max-conferences 8 gain -6
 moh music-on-hold.au
 transfer-system full-consult
 create cnf-files version-stamp 7960 Sep 08 2008 22:22:17
!

ephone  1
 mac-address 000D.288E.6681
 type 7920
 button  1o9,3,4
!
!
!
ephone  2
 mac-address 000B.FDCD.B486
 paging-dn 8
 type 7960
 button  1o2,3,4 6:5
 pin 12345

debugs:

000080: Sep 9 02:36:21.457 UTC: ephone-2[1][SEP000BFDCDB486]:CallPrompt line 0 ref 0: PBX Powered by Cisco 000081: Sep 9 02:36:21.457 UTC: ephone-2[1][SEP000BFDCDB486]:SkinnyCheckPendingCallBackPhone scan 6 lines 000082: Sep 9 02:36:21.457 UTC: ephone-4[2][SEP00131A4D3FC9]:CallPrompt line 0 ref 0: PBX Powered by Cisco 000083: Sep 9 02:36:21.461 UTC: ephone-4[2][SEP00131A4D3FC9]:SkinnyCheckPendingCallBackPhone scan 2 lines 000084: Sep 9 02:36:31.738 UTC: DHCPD: DHCPDISCOVER received from client 000d.288e.6681 on interface FastEthernet0/0. 000085: Sep 9 02:36:31.738 UTC: DHCPD: Sending DHCPOFFER to client 000d.288e.6681 (192.168.1.101<http://192.168.1.101>). 000086: Sep 9 02:36:31.738 UTC: DHCPD: broadcasting BOOTREPLY to client 000d.288e.6681. 000087: Sep 9 02:36:31.758 UTC: DHCPD: DHCPREQUEST received from client 000d.288e.6681. 000088: Sep 9 02:36:31.758 UTC: DHCPD: Appending system default domain 000089: Sep 9 02:36:31.762 UTC: DHCPD: Using hostname 'SEP000D288E6681' for dynamic update (from hostname option) 000090: Sep 9 02:36:31.762 UTC: DHCPD: Sending DHCPACK to client 000d.288e.6681 (192.168.1.101<http://192.168.1.101>). 000091: Sep 9 02:36:31.762 UTC: DHCPD: broadcasting BOOTREPLY to client 000d.288e.6681. 000092: Sep 9 02:36:33.738 UTC: New Skinny socket accepted [1] (2 active) 000093: Sep 9 02:36:33.738 UTC: sin_family 2, sin_port 1024, in_addr 192.168.1.101<http://192.168.1.101> 000094: Sep 9 02:36:33.738 UTC: skinny_add_socket 1 192.168.1.101<http://192.168.1.101> 1024 000095: Sep 9 02:36:33.750 UTC: %IPPHONE-6-REG_ALARM: 25: Name=SEP000D288E6681 Load=4.0(02.00) Last=Initialized 000096: Sep 9 02:36:33.750 UTC: Skinny StationAlarmMessage on socket [3] 192.168.1.101<http://192.168.1.101> SEP000D288E6681 000097: Sep 9 02:36:33.750 UTC: severityInformational p1=2049 [0x801] p2=1234 [0x4D2] 000098: Sep 9 02:36:33.750 UTC: 25: Name=SEP000D288E6681 Load=4.0(02.00) Last=Initialized 000099: Sep 9 02:36:33.754 UTC: ephone-(1)[3] StationRegisterMessage (2/3/10) from 192.168.1.101<http://192.168.1.101> 000100: Sep 9 02:36:33.754 UTC: ephone-(1)[3] Register StationIdentifier DeviceName SEP000D288E6681 000101: Sep 9 02:36:33.754 UTC: ephone-(1)[3] StationIdentifier Instance 1 deviceType 30002 000102: Sep 9 02:36:33.754 UTC: ephone-1[-1]:stationIpAddr 192.168.1.101<http://192.168.1.101> 000103: Sep 9 02:36:33.754 UTC: ephone-1[-1][SEP000D288E6681]:maxStreams 20 000104: Sep 9 02:36:33.754 UTC: ephone-1[-1][SEP000D288E6681]:From Phone raw protocol Ver 0x5000005 000105: Sep 9 02:36:33.754 UTC: ephone-1[-1][SEP000D288E6681]:protocol Ver 0x5000005 000106: Sep 9 02:36:33.758 UTC: ephone-1[-1][SEP000D288E6681]:phone-size 5464 dn-size 688 000107: Sep 9 02:36:33.758 UTC: ephone-(1) Allow any Skinny Server IP address 192.168.1.50<http://192.168.1.50> 000108: Sep 9 02:36:33.758 UTC: ephone-1[-1][SEP000D288E6681]:Found entry 0 for 000D288E6681 000109: Sep 9 02:36:33.758 UTC: ephone-1[-1][SEP000D288E6681]:socket change -1 to 3 000110: Sep 9 02:36:33.758 UTC: ephone-1[-1][SEP000D288E6681]:FAILED: CLOSED old socket -1 000111: Sep 9 02:36:33.758 UTC: ephone-1[-1][SEP000D288E6681]: bulk_speeddial_init_ephone: 0 000112: Sep 9 02:36:33.758 UTC: ephone-1[-1]:SkinnyVideoParmsUpdate: phone: 0, action: 2, dn_index: -1 000113: Sep 9 02:36:33.758 UTC: ephone-1[3][SEP000D288E6681]:phone SEP000D288E6681 re-associate OK on socket [3] 000114: Sep 9 02:36:33.762 UTC: %IPPHONE-6-REGISTER: ephone-1:SEP000D288E6681 IP:192.168.1.101<http://192.168.1.101> Socket:3 DeviceType:Phone has registered. 000115: Sep 9 02:36:33.762 UTC: Phone 0 socket 3 000116: Sep 9 02:36:33.762 UTC: Skinny Local IP address = 192.168.1.50<http://192.168.1.50> on port 2000 000117: Sep 9 02:36:33.762 UTC: Skinny Phone IP address = 192.168.1.101<http://192.168.1.101> 1024 000118: Sep 9 02:36:33.762 UTC: ephone-1[3]:SkinnyVideoParmsUpdate: phone: 0, action: 2, dn_index: -1 000119: Sep 9 02:36:33.762 UTC: ephone-1[3][SEP000D288E6681]:Signal protocol ver 8 to phone with ver 5 000120: Sep 9 02:36:33.762 UTC: ephone-1[3][SEP000D288E6681]:Date Format M/D/Y 000121: Sep 9 02:36:33.766 UTC: ephone-1[3]:RegisterAck sent to sockettype ephone socket 3: keepalive period 30 use sccp-version 5 000122: Sep 9 02:36:33.766 UTC: ephone-1[3]:CapabilitiesReq sent 000123: Sep 9 02:36:33.838 UTC: ephone-1[3][SEP000D288E6681]:Skinny IP port 46794 set for socket [3] 000124: Sep 9 02:36:33.882 UTC: ephone-1[3]:HeadsetStatusMessage OFF 000125: Sep 9 02:36:33.882 UTC: ephone-1[3]:HeadsetStatusMessage 000126: Sep 9 02:36:33.934 UTC: ephone-1[3]:VersionReq received 000127: Sep 9 02:36:33.934 UTC: ephone-1[3][SEP000D288E6681]:Req Version deviceType 30002 is P00308000400 [max 16 chars] 000128: Sep 9 02:36:33.934 UTC: ephone-1[3]:Version Message sent 000129: Sep 9 02:36:33.986 UTC: ephone-1[3]:CapabilitiesRes received 000130: Sep 9 02:36:33.986 UTC: ephone-1[3][SEP000D288E6681]:Caps list 6 G711Ulaw64k 40 ms G711Alaw64k 40 ms G729 60 ms G729AnnexA 60 ms G729AnnexB 60 ms G729AnnexAwAnnexB 60 ms 000131: Sep 9 02:36:34.002 UTC: ephone-1[3]:ButtonTemplateReqMessage 000132: Sep 9 02:36:34.002 UTC: ephone-1[3][SEP000D288E6681]:StationButtonTemplateReqMessage set max presentation to 2 000133: Sep 9 02:36:34.002 UTC: ephone-1[3]:CheckAutoReg 000134: Sep 9 02:36:34.002 UTC: ephone-1[3]:AutoReg is disabled 000135: Sep 9 02:36:34.002 UTC: ephone-1[3][SEP000D288E6681]:Setting 6 lines 0 speed-dials on phone (max_line 6) 000136: Sep 9 02:36:34.002 UTC: ephone-1[3][SEP000D288E6681]:First Speed Dial Button location is 0 (0) 000137: Sep 9 02:36:34.002 UTC: ephone-1[3][SEP000D288E6681]:Configured 0 speed dial buttons 000138: Sep 9 02:36:34.006 UTC: ephone-1[3]:ButtonTemplate lines=6 speed=0 buttons=6 offset=0 000139: Sep 9 02:36:34.050 UTC: ephone-1[3]:StationSoftKeyTemplateReqMessage 000140: Sep 9 02:36:34.050 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 1 Redial 000141: Sep 9 02:36:34.050 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 2 NewCall 000142: Sep 9 02:36:34.050 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 3 Hold 000143: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 4 Trnsfer 000144: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 5 CFwdAll 000145: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 6 CFwdBusy 000146: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 7 CFwdNoAnswer 000147: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 8 << 000148: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 9 EndCall 000149: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 10 Resume 000150: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 11 Answer 000151: Sep 9 02:36:34.054 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 12 Info 000152: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 13 Confrn 000153: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 14 Park 000154: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 15 Join 000155: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 16 MeetMe 000156: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 17 PickUp 000157: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 18 GPickUp 000158: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 19 RmLstC 000159: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 20 CallBack 000160: Sep 9 02:36:34.058 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 21 Barge 000161: Sep 9 02:36:34.062 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 22 DnD 000162: Sep 9 02:36:34.062 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 23 Acct 000163: Sep 9 02:36:34.062 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 24 Flash 000164: Sep 9 02:36:34.062 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 25 Login 000165: Sep 9 02:36:34.062 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 26 HLog 000166: Sep 9 02:36:34.062 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 27 ConfList 000167: Sep 9 02:36:34.062 UTC: ephone-1[3][SEP000D288E6681]:SoftKeys: 28 Select 000168: Sep 9 02:36:34.062 UTC: ephone-1[3]:StationSoftKeyTemplateResMessage 000169: Sep 9 02:36:34.102 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 1 000170: Sep 9 02:36:34.102 UTC: ephone-1[3]:StationLineStatReqMessage ephone line 1 DN 9 = 304 desc = <removed> label = JJ-304 000171: Sep 9 02:36:34.102 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatResMessage sent to ephone (1 of 6) 000172: Sep 9 02:36:34.126 UTC: ephone-1[3][SEP000D288E6681]:CallPrompt line 0 ref 0: ITS 000173: Sep 9 02:36:34.154 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 2 000174: Sep 9 02:36:34.154 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 2 Invalid DN -1 000175: Sep 9 02:36:34.154 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatResMessage sent to ephone (2 of 6) 000176: Sep 9 02:36:34.202 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 3 000177: Sep 9 02:36:34.202 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 3 Invalid DN -1 000178: Sep 9 02:36:34.202 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatResMessage sent to ephone (3 of 6) 000179: Sep 9 02:36:34.250 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 4 000180: Sep 9 02:36:34.250 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 4 Invalid DN -1 000181: Sep 9 02:36:34.254 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatResMessage sent to ephone (4 of 6) 000182: Sep 9 02:36:34.310 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 5 000183: Sep 9 02:36:34.314 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 5 Invalid DN -1 000184: Sep 9 02:36:34.314 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatResMessage sent to ephone (5 of 6) 000185: Sep 9 02:36:34.350 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 6 000186: Sep 9 02:36:34.354 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatReqMessage from ephone line 6 Invalid DN -1 000187: Sep 9 02:36:34.354 UTC: ephone-1[3][SEP000D288E6681]:StationLineStatResMessage sent to ephone (6 of 6) 000188: Sep 9 02:36:34.354 UTC: ephone-1[3]:SkinnyCompleteRegistration 000189: Sep 9 02:36:34.354 UTC: ephone-1[3][SEP000D288E6681]:ClearCallPrompt line 0 ref 0 000190: Sep 9 02:36:34.354 UTC: ephone-1[3]:SelectPhoneSoftKeys set 0 mask FFBF for line 0 ref 0 000191: Sep 9 02:36:34.354 UTC: ephone-1[3][SEP000D288E6681]:CallPrompt line 0 ref 0: PBX Powered by Cisco 000192: Sep 9 02:36:34.358 UTC: ephone-1[3][SEP000D288E6681]:SkinnyCheckPendingCallBackPhone scan 6 lines 000193: Sep 9 02:36:34.358 UTC: ephone-1[3][SEP000D288E6681]: DN in-service for DN 9 chan 1 000194: Sep 9 02:36:34.358 UTC: SkinnyGetCallState for DN 9 chan 1 IDLE 000195: Sep 9 02:36:34.358 UTC: called DN -1 chan 1, calling DN -1 chan 1 phone -1 s2s:0 000196: Sep 9 02:36:34.358 UTC: ephone-1[3][SEP000D288E6681]: DN in-service for DN 9 chan 2 000197: Sep 9 02:36:34.358 UTC: SkinnyGetCallState for DN 9 chan 2 IDLE 000198: Sep 9 02:36:34.358 UTC: called DN -1 chan 1, calling DN -1 chan 1 phone -1 s2s:0 000199: Sep 9 02:36:34.362 UTC: Skinny DN 9 chan 1 state change to UP 000200: Sep 9 02:36:34.362 UTC: Skinny DN 9 chan 2 state change to UP 000201: Sep 9 02:36:34.402 UTC: ephone-1[3]:StationSoftKeySetReqMessage 000202: Sep 9 02:36:34.402 UTC: ephone-1[3]:GetSoftkeysetIdle: Default Template 000203: Sep 9 02:36:34.402 UTC: ephone-1[3]:GetSoftkeysetConnected:Default Template 000204: Sep 9 02:36:34.402 UTC: ephone-1[3]:GetSoftkeysetHold: Default Template 000205: Sep 9 02:36:34.406 UTC: ephone-1[3]:GetSoftkeysetRinging: Default Template 000206: Sep 9 02:36:34.406 UTC: ephone-1[3]:GetSoftkeysetSeized:Default Template 000207: Sep 9 02:36:34.406 UTC: ephone-1[3]:GetSoftkeysetAlerting:Default Template 000208: Sep 9 02:36:34.406 UTC: ephone-1[3]:StationSoftKeySetResMessage 000209: Sep 9 02:36:34.410 UTC: DHCPD: DHCPRELEASE message received from client 0100.0bfd.cdb4.86 (192.168.1.113<http://192.168.1.113>). 000210: Sep 9 02:36:34.414 UTC: DHCPD: Finding a relay for client 0100.0bfd.cdb4.86 on interface FastEthernet0/0. 000211: Sep 9 02:36:34.418 UTC: ephone-2[1][SEP000BFDCDB486]: DN out-of-service for DN 2 chan 1 000212: Sep 9 02:36:34.418 UTC: SkinnyGetCallState for DN 2 chan 1 IDLE 000213: Sep 9 02:36:34.418 UTC: called DN -1 chan 1, calling DN -1 chan 1 phone -1 s2s:0 000214: Sep 9 02:36:34.418 UTC: ephone-2[1][SEP000BFDCDB486]: DN out-of-service for DN 2 chan 2 000215: Sep 9 02:36:34.418 UTC: SkinnyGetCallState for DN 2 chan 2 IDLE 000216: Sep 9 02:36:34.418 UTC: called DN -1 chan 1, calling DN -1 chan 1 phone -1 s2s:0 000217: Sep 9 02:36:34.422 UTC: Bring down DN 2 chan 1 (302) with the following traceback -Traceback= 0x803102AC 0x803104BC 0x8031EC60 0x8033BF38 0x8030B874 0x806FF184 0x80702C90 000218: Sep 9 02:36:34.422 UTC: Skinny DN 2 chan 1 state change to DOWN 000219: Sep 9 02:36:34.422 UTC: Bring down DN 2 chan 2 (302) with the following traceback -Traceback= 0x803102AC 0x803104BC 0x8031EC60 0x8033BF38 0x8030B874 0x806FF184 0x80702C90 000220: Sep 9 02:36:34.426 UTC: Skinny DN 2 chan 2 state change to DOWN 000221: Sep 9 02:36:34.426 UTC: ephone-2[1][SEP000BFDCDB486]: DN out-of-service for DN 5 chan 1 000222: Sep 9 02:36:34.426 UTC: SkinnyGetCallState for DN 5 chan 1 IDLE 000223: Sep 9 02:36:34.426 UTC: called DN -1 chan 1, calling DN -1 chan 1 phone -1 s2s:0 000224: Sep 9 02:36:34.426 UTC: Bring down DN 5 chan 1 (A310) with the following traceback -Traceback= 0x803102AC 0x803104BC 0x8031EC60 0x8033BF38 0x8030B874 0x806FF184 0x80702C90 000225: Sep 9 02:36:34.430 UTC: Skinny DN 5 chan 1 state change to DOWN 000226: Sep 9 02:36:34.430 UTC: ephone-2[1][SEP000BFDCDB486]:Phone Unregistered on socket [1] SEP000BFDCDB486 000227: Sep 9 02:36:34.434 UTC: ephone-2[1]:UnregisterAck sent on socket [1] (2/3/10) 000228: Sep 9 02:36:34.434 UTC: %IPPHONE-6-UNREGISTER_NORMAL: ephone-2:SEP000BFDCDB486 IP:192.168.1.113<http://192.168.1.113> Socket:1 DeviceType:Phone has unregistered normally. 000229: Sep 9 02:36:34.454 UTC: ephone-1[3]:TimeDateReqMessage

Any ideas?
Thanks in advanced,
-Jose
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20080909/da1916b1/attachment-0001.html>