cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
1076
Views
10
Helpful
11
Replies

Cisco IP Phone on Call Manager Express Issue

Kaushik Ray
Level 1
Level 1

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

1 Accepted Solution

Accepted Solutions

yes this was the issue.

If the problem is resolved,kindly close the thread.

View solution in original post

11 Replies 11

Simerpreet Singh
Cisco Employee
Cisco Employee

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

techguy
Level 4
Level 4

Start debugging

debug ephone register mac-address H.H.H

also paste your telephony-service configuration.

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

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

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.

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

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.

could you please send me the gateway configuration

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

yes this was the issue.

If the problem is resolved,kindly close the thread.

thanks

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: