06-13-2012 07:30 AM - edited 03-16-2019 11:39 AM
Hello
I am having an issue with Cisco IP Phone connected to a Call Manager Express Router ( 2911)
There are 3 X 7942 IP Phones being used for this.
2 of them are registered and can make calls both ways.
One of them is not registering at all.
The version of IOS I am using is: c2900-universalk9-mz.SPA.151-4.M2.bin
The version of Call Manager Express is Version 8.6
I tried two different phone loads for the 7942 i.e load 7942 SCCP42.8-5-2S and load 7942 SCCP42.8-5-2S with identical issues.
I tried to register this phone which is not registering to the Call Manager Express to register to a Call Manager and it works no problem.
I ensured that I have the correct MAC address configured on the ephone and also it is connected to the correct port of the switch with voice vlan.
I tried different ports on the switch with no luck.
The IP Phone is getting an IP address from the DHCP Pool on the Router and I can ping to this IP address from the Router.
I tried to do a factory reset of the IP Phone and since then it is try to upgrade and going back to the Cisco screen.
I put it back onto the Call Manager again and it registers to it straight away.
Any advice will be most welcome.
Thanks
Kaushik
Solved! Go to Solution.
06-13-2012 11:36 AM
yes this was the issue.
If the problem is resolved,kindly close the thread.
06-13-2012 07:38 AM
Can you open the phone web page http://phone_ip_address
Paste status messages
Secondly, on router/CME
do a term mon
debug tftp events
You will see the tftp requests hitting the CME
Paste that output as well.
Also , try this
conft
telephony-service
no create cnf
create cnf
send sh run if possible
06-13-2012 07:40 AM
Start debugging
debug ephone register mac-address H.H.H
also paste your telephony-service configuration.
06-13-2012 07:50 AM
Thanks for the responses.
The telephony-service config is as below:
telephony-service
no auto-reg-ephone
max-ephones 35
max-dn 10
ip source-address xxx.xxx.xxx.xxx port 2000
timeouts interdigit 5
network-locale GB
load 7942 SCCP42.8-5-2S
time-format 24
date-format dd-mm-yy
max-conferences 4 gain -6
call-forward pattern .T
dn-webedit
time-webedit
transfer-system full-consult
create cnf-files version-stamp 7960 Jun 13 2012 10:47:49
The debug shows the following: Although there are two 7942 IP Phones working on the same router and switch:
Jun 13 14:42:06.831 UTC: TFTP: Looking for term42.default.loads
Jun 13 14:42:10.335 UTC: TFTP: Looking for term42.default.loads
Jun 13 14:44:34.235 UTC: TFTP: Looking for term42.default.loads
Jun 13 14:44:37.743 UTC: TFTP: Looking for term42.default.loads
Jun 13 14:47:01.643 UTC: TFTP: Looking for term42.default.loads
Jun 13 14:47:05.147 UTC: TFTP: Looking for term42.default.loads
Regards
06-13-2012 07:56 AM
Router#sh flash | include term42
75 662 Dec 7 2011 11:28:00 +00:00 term42.default.loads
Details of the other phones registered
ephone-2[1] Mac:B8BE.BF9D.9987 TCP socket:[-1] activeLine:0 whisperLine:0 UNREGISTERED
mediaActive:0 whisper_mediaActive:0 startMedia:0 offhook:0 ringing:0 reset:0 reset_sent:0 paging 0 debug:1 caps:0
IP:0.0.0.0* 0 Unknown 0 keepalive 0 max_line 0 available_line 0
Preferred Codec: g729
ephone-3[2] Mac:0023.5EB8.4325 TCP socket:[2] activeLine:0 whisperLine:0 REGISTERED in SCCP ver 20/17 max_streams=5
mediaActive:0 whisper_mediaActive:0 startMedia:0 offhook:0 ringing:0 reset:0 reset_sent:0 paging 0 debug:0 caps:9
IP:xxx.xxx.xxx.xxx * 52229 7942 keepalive 483 max_line 2 available_line 2
button 1: cw:1 ccw:(0)
dn 3 number 202 CH1 IDLE
Preferred Codec: g729
ephone-4[3] Mac:0021.A087.4817 TCP socket:[1] activeLine:0 whisperLine:0 REGISTERED in SCCP ver 20/17 max_streams=5
mediaActive:0 whisper_mediaActive:0 startMedia:0 offhook:0 ringing:0 reset:0 reset_sent:0 paging 0 debug:0 caps:9
IP:xxx.xxx.xxx.xxx * 51243 7942 keepalive 483 max_line 2 available_line 2
button 1: cw:1 ccw:(0)
dn 4 number 203 CH1 IDLE
Preferred Codec: g729
Router#sh ip arp
Protocol Address Age (min) Hardware Addr Type Interface
Internet aaa.aaa.aaa.aaa - 2894.0f6b.0b88 ARPA GigabitEthernet0/0.7
Internet bbb.bbb.bbb.bbb 22 0021.a087.4817 ARPA GigabitEthernet0/0.7
Internet ccc.ccc.ccc.ccc 22 0023.5eb8.4325 ARPA GigabitEthernet0/0.7
Internet xxx.xxx.xxx.xxx 0 b8be.bf9d.9987 ARPA GigabitEthernet0/0.7
Router# ping xxx.xxx.xxx.xxx
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to xxx.xxx.xxx.xxx, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 1/1/4 ms
06-13-2012 07:58 AM
give shutdown command under telephony-service command then no shutdown after some time.
But before doing the above, debug ephone register mac-address H.H.H
Please rate if post is helpful.
06-13-2012 08:10 AM
Router#sh telephony-service | include sh
shutdown
Router#sh debugging
TFTP:
TFTP Event debugging is on
EPHONE registration debugging is enabled
for ephones B8BE.BF9D.9987
Router(config)#telephony-service
Router(config-telephony)#no shut
Router#sh log
Syslog logging: enabled (0 messages dropped, 2 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: level debugging, 27 messages logged, xml disabled,
filtering disabled
Monitor logging: disabled
Buffer logging: level debugging, 84 messages logged, xml disabled,
filtering disabled
Exception Logging: size (4096 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level debugging, 89 message lines logged
Logging Source-Interface: VRF Name:
GigabitEthernet0/0.7
Log Buffer (100000 bytes):
Jun 13 14:59:18.882 UTC: TFTP: Looking for term42.default.loads
Jun 13 14:59:22.386 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:01:46.298 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:01:49.798 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:02:39.318 UTC: %SYS-5-CONFIG_I: Configured from console by admin on console
Jun 13 15:03:05.698 UTC: %SYS-5-CONFIG_I: Configured from console by admin on console
Jun 13 15:03:33.458 UTC: %SYS-5-CONFIG_I: Configured from console by admin on console
Jun 13 15:04:13.722 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:04:15.342 UTC: %SYS-5-CONFIG_I: Configured from console by admin on console
Jun 13 15:04:17.226 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:05:51.510 UTC: %SYS-5-CONFIG_I: Configured from console by admin on console
06-13-2012 08:23 AM
I did a no telephony service and re-inserted the telephony service configs again and here is the debug results below: Thanks for all the help thus far:
Jun 13 15:12:57.670 UTC: %IPPHONE-6-UNREGISTER_NORMAL: ephone-3:SEP00235EB84325 IP:xxx.xxx.xxx.xxx Socket:2 DeviceType:Phone has unregistered normally.
Jun 13 15:12:57.710 UTC: %IPPHONE-6-UNREGISTER_NORMAL: ephone-4:SEP0021A0874817 IP:
xxx.xxx.xxx.xxx
Socket:1 DeviceType:Phone has unregistered normally.
Jun 13 15:13:18.814 UTC: %LINK-3-UPDOWN: Interface ephone_dsp DN 1.1, changed state to up
Jun 13 15:13:19.378 UTC: %LINK-3-UPDOWN: Interface ephone_dsp DN 2.1, changed state to up
Jun 13 15:13:19.962 UTC: %LINK-3-UPDOWN: Interface ephone_dsp DN 3.1, changed state to up
Jun 13 15:13:19.970 UTC: %LINK-3-UPDOWN: Interface ephone_dsp DN 4.1, changed state to up
Jun 13 15:13:25.274 UTC: %SYS-5-CONFIG_I: Configured from console by cas10 on console
Jun 13 15:13:46.970 UTC: TFTP: Looking for CTLSEP0021A0874817.tlv
Jun 13 15:13:47.042 UTC: TFTP: Looking for ITLSEP0021A0874817.tlv
Jun 13 15:13:47.114 UTC: TFTP: Looking for ITLFile.tlv
Jun 13 15:13:47.342 UTC: TFTP: Looking for MusicBox.raw
Jun 13 15:13:47.342 UTC: TFTP: Opened flash0:MusicBox.raw, fd 14, size 12720 for process 140
Jun 13 15:13:47.374 UTC: TFTP: Finished flash0:MusicBox.raw, time 00:00:00 for process 140
Jun 13 15:13:47.462 UTC: TFTP: Looking for Ring4.raw
Jun 13 15:13:47.466 UTC: TFTP: Opened flash0:Ring4.raw, fd 14, size 4000 for process 140
Jun 13 15:13:47.474 UTC: TFTP: Finished flash0:Ring4.raw, time 00:00:00 for process 140
Jun 13 15:13:47.542 UTC: TFTP: Looking for SEP0021A0874817.cnf.xml
Jun 13 15:13:47.766 UTC: TFTP: Looking for CTLSEP00235EB84325.tlv
Jun 13 15:13:47.862 UTC: TFTP: Looking for ITLSEP00235EB84325.tlv
Jun 13 15:13:47.862 UTC: TFTP: Opened system:/its/vrf1/XMLDefault7942.cnf.xml, fd 14, size 1277 for process 140
Jun 13 15:13:47.866 UTC: TFTP: Finished system:/its/vrf1/XMLDefault7942.cnf.xml, time 00:00:00 for process 140
Jun 13 15:13:47.938 UTC: TFTP: Looking for ITLFile.tlv
Jun 13 15:13:48.322 UTC: TFTP: Looking for Classic1.raw
Jun 13 15:13:48.322 UTC: TFTP: Opened flash0:Classic1.raw, fd 14, size 8160 for process 140
Jun 13 15:13:48.346 UTC: TFTP: Finished flash0:Classic1.raw, time 00:00:00 for process 140
Jun 13 15:13:48.422 UTC: TFTP: Looking for Ring7.raw
Jun 13 15:13:48.426 UTC: TFTP: Opened flash0:Ring7.raw, fd 14, size 4000 for process 140
Jun 13 15:13:48.434 UTC: TFTP: Finished flash0:Ring7.raw, time 00:00:00 for process 140
Jun 13 15:13:48.502 UTC: TFTP: Looking for SEP00235EB84325.cnf.xml
Jun 13 15:13:48.502 UTC: TFTP: Opened system:/its/vrf1/XMLDefault7942.cnf.xml, fd 14, size 1277 for process 140
Jun 13 15:13:48.506 UTC: TFTP: Finished system:/its/vrf1/XMLDefault7942.cnf.xml, time 00:00:00 for process 140
Jun 13 15:14:03.594 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:14:07.098 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:14:11.698 UTC: TFTP: Looking for SCCP42.8-5-2S.loads
Jun 13 15:14:11.702 UTC: TFTP: Opened flash0:SCCP42.8-5-2S.loads, fd 14, size 670 for process 140
Jun 13 15:14:11.706 UTC: TFTP: Finished flash0:SCCP42.8-5-2S.loads, time 00:00:00 for process 140
Jun 13 15:14:14.510 UTC: TFTP: Looking for jar42sccp.8-5-2TH1-9.sbn
Jun 13 15:14:14.510 UTC: TFTP: Opened flash0:jar42sccp.8-5-2TH1-9.sbn, fd 14, size 1756248 for process 140
Jun 13 15:14:18.362 UTC: TFTP: Finished flash0:jar42sccp.8-5-2TH1-9.sbn, time 00:00:03 for process 140
Jun 13 15:14:31.078 UTC: TFTP: Looking for cnu42.8-5-2TH1-9.sbn
Jun 13 15:14:31.082 UTC: TFTP: Opened flash0:cnu42.8-5-2TH1-9.sbn, fd 14, size 523964 for process 140
Jun 13 15:14:32.238 UTC: TFTP: Finished flash0:cnu42.8-5-2TH1-9.sbn, time 00:00:01 for process 140
Jun 13 15:14:37.150 UTC: TFTP: Looking for apps42.8-5-2TH1-9.sbn
Jun 13 15:14:37.150 UTC: TFTP: Opened flash0:apps42.8-5-2TH1-9.sbn, fd 14, size 2935993 for process 140
Jun 13 15:14:43.538 UTC: TFTP: Finished flash0:apps42.8-5-2TH1-9.sbn, time 00:00:06 for process 140
Jun 13 15:15:02.610 UTC: TFTP: Looking for dsp42.8-5-2TH1-9.sbn
Jun 13 15:15:02.614 UTC: TFTP: Opened flash0:dsp42.8-5-2TH1-9.sbn, fd 14, size 340383 for process 140
Jun 13 15:15:03.358 UTC: TFTP: Finished flash0:dsp42.8-5-2TH1-9.sbn, time 00:00:00 for process 140
Jun 13 15:15:07.794 UTC: TFTP: Looking for cvm42sccp.8-5-2TH1-9.sbn
Jun 13 15:15:07.794 UTC: TFTP: Opened flash0:cvm42sccp.8-5-2TH1-9.sbn, fd 14, size 2108367 for process 140
Jun 13 15:15:12.386 UTC: TFTP: Finished flash0:cvm42sccp.8-5-2TH1-9.sbn, time 00:00:04 for process 140
Jun 13 15:16:31.322 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:16:34.826 UTC: TFTP: Looking for term42.default.loads
Jun 13 15:17:41.434 UTC: TFTP: Looking for CTLSEP0021A0874817.tlv
Jun 13 15:17:41.610 UTC: TFTP: Looking for MusicBox.raw
Jun 13 15:17:41.610 UTC: TFTP: Opened flash0:MusicBox.raw, fd 14, size 12720 for process 140
Jun 13 15:17:41.642 UTC: TFTP: Finished flash0:MusicBox.raw, time 00:00:00 for process 140
Jun 13 15:17:41.698 UTC: TFTP: Looking for Ring4.raw
Jun 13 15:17:41.698 UTC: TFTP: Opened flash0:Ring4.raw, fd 14, size 4000 for process 140
Jun 13 15:17:41.710 UTC: TFTP: Finished flash0:Ring4.raw, time 00:00:00 for process 140
Jun 13 15:17:41.746 UTC: TFTP: Looking for SEP0021A0874817.cnf.xml
Jun 13 15:17:41.746 UTC: TFTP: Opened system:/its/vrf1/XMLDefault7942.cnf.xml, fd 14, size 1277 for process 140
Jun 13 15:17:41.750 UTC: TFTP: Finished system:/its/vrf1/XMLDefault7942.cnf.xml, time 00:00:00 for process 140
Jun 13 15:17:43.926 UTC: TFTP: Looking for English_United_States/mk-sccp.jar
Jun 13 15:17:44.154 UTC: TFTP: Looking for United_Kingdom/g3-tones.xml
Jun 13 15:17:44.918 UTC: New Skinny socket accepted [2] from 0, sub 1 (0 active)
Jun 13 15:17:44.918 UTC: sin_family 2, sin_port 27371, in_addrxxx.xxx.xxx.xxx
Jun 13 15:17:44.918 UTC: skinny_add_socket 2 xxx.xxx.xxx.xxx 27371
Jun 13 15:17:45.494 UTC: %IPPHONE-6-REG_ALARM: 25: Name=SEP0021A0874817 Load= SCCP42.8-5-2S Last=Initialized
Jun 13 15:17:45.526 UTC: %IPPHONE-6-REGISTER: ephone-4:SEP0021A0874817 IP:xxx.xxx.xxx.xxx Socket:1 DeviceType:Phone has registered.
Jun 13 15:18:01.290 UTC: TFTP: Looking for CTLSEP00235EB84325.tlv
Jun 13 15:18:01.466 UTC: TFTP: Looking for Classic1.raw
Jun 13 15:18:01.466 UTC: TFTP: Opened flash0:Classic1.raw, fd 14, size 8160 for process 140
Jun 13 15:18:01.486 UTC: TFTP: Finished flash0:Classic1.raw, time 00:00:00 for process 140
Jun 13 15:18:01.542 UTC: TFTP: Looking for Ring7.raw
Jun 13 15:18:01.546 UTC: TFTP: Opened flash0:Ring7.raw, fd 14, size 4000 for process 140
Jun 13 15:18:01.554 UTC: TFTP: Finished flash0:Ring7.raw, time 00:00:00 for process 140
Jun 13 15:18:01.590 UTC: TFTP: Looking for SEP00235EB84325.cnf.xml
Jun 13 15:18:01.594 UTC: TFTP: Opened system:/its/vrf1/XMLDefault7942.cnf.xml, fd 14, size 1277 for process 140
Jun 13 15:18:01.594 UTC: TFTP: Finished system:/its/vrf1/XMLDefault7942.cnf.xml, time 00:00:00 for process 140
Jun 13 15:18:04.450 UTC: TFTP: Looking for English_United_States/mk-sccp.jar
Jun 13 15:18:04.678 UTC: TFTP: Looking for United_Kingdom/g3-tones.xml
Jun 13 15:18:05.318 UTC: New Skinny socket accepted [2] from 0, sub 1 (1 active)
Jun 13 15:18:05.318 UTC: sin_family 2, sin_port 25168, in_addr 10.178.254.228
Jun 13 15:18:05.318 UTC: skinny_add_socket 2 10.178.254.228 25168
Jun 13 15:18:05.902 UTC: %IPPHONE-6-REG_ALARM: 25: Name=SEP00235EB84325 Load= SCCP42.8-5-2S Last=Initialized
Jun 13 15:18:05.934 UTC: %IPPHONE-6-REGISTER: ephone-3:SEP00235EB84325 IP:xxx.xxx.xxx.xxx Socket:2 DeviceType:Phone has registered.
06-13-2012 08:55 AM
could you please send me the gateway configuration
06-13-2012 09:03 AM
Hi Omerpal
I just checked the config and saw the button1:2 missing on the ephone2 and i put it in and re entered the telephony service config and see that the phone got registered; could this have been causing the issue.
thanks a lot for the help with this.
regards
Kaushik
06-13-2012 11:36 AM
yes this was the issue.
If the problem is resolved,kindly close the thread.
06-14-2012 07:04 AM
thanks
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide