[cisco-voip] Cisco 7960 woes

[Joseph Mays]

I compared the TFTP debug from the one phone we have that does work to the 
debug for all the other phones that do not. I only see one difference 
(though admittedly I'm looking through a veil of ignorance here). I should 
mention that I also have SCCP debugging turned on.

>From non-working phone --

033377: Jul 15 14:25:07.381: TFTP: Server request for port 51565, socket_id 
0x6454EF2C for process 183
033378: Jul 15 14:25:07.381: TFTP: read request from host 
216.24.24.75(51565) via Ethernet0/0
033379: Jul 15 14:25:07.385: TFTP: Looking for OS79XX.TXT
033380: Jul 15 14:25:07.385: TFTP: Opened slot0:OS79XX.TXT, fd 0, size 13 
for process 183
033381: Jul 15 14:25:07.385: TFTP: Sending block 1 (retry 0), socket_id 
0x6454EF2C
033382: Jul 15 14:25:07.401: TFTP: Received ACK for block 1, socket_id 
0x6454EF2C
033383: Jul 15 14:25:07.401: TFTP: Finished slot0:OS79XX.TXT, time 00:00:00 
for process 183
033384: Jul 15 14:25:08.029: TFTP: Server request for port 51566, socket_id 
0x6454EF2C for process 183
033385: Jul 15 14:25:08.029: TFTP: read request from host 
216.24.24.75(51566) via Ethernet0/0
033386: Jul 15 14:25:08.029: TFTP: Looking for SEP000DED409151.cnf.xml
033387: Jul 15 14:25:08.029: TFTP: Opened 
system:/its/XMLDefault7960.cnf.xml, fd 0, size 790 for process 183
033388: Jul 15 14:25:08.029: TFTP: Sending block 1 (retry 0), socket_id 
0x6454EF2C
033389: Jul 15 14:25:08.053: TFTP: Received ACK for block 1, socket_id 
0x6454EF2C
033390: Jul 15 14:25:08.053: TFTP: Sending block 2 (retry 0), socket_id 
0x6454EF2C
033391: Jul 15 14:25:08.073: TFTP: Received ACK for block 2, socket_id 
0x6454EF2C
033392: Jul 15 14:25:08.073: TFTP: Finished 
system:/its/XMLDefault7960.cnf.xml, time 00:00:00 for process 183


>From working phone --

033410: Jul 15 14:25:30.453: TFTP: Server request for port 52940, socket_id 
0x6454EF2C for process 183
033411: Jul 15 14:25:30.453: TFTP: read request from host 
216.24.33.79(52940) via Ethernet0/0
033412: Jul 15 14:25:30.453: TFTP: Looking for OS79XX.TXT
033413: Jul 15 14:25:30.453: TFTP: Opened slot0:OS79XX.TXT, fd 0, size 13 
for process 183
033414: Jul 15 14:25:30.453: TFTP: Sending block 1 (retry 0), socket_id 
0x6454EF2C
033415: Jul 15 14:25:30.465: TFTP: Received ACK for block 1, socket_id 
0x6454EF2C
033416: Jul 15 14:25:30.465: TFTP: Finished slot0:OS79XX.TXT, time 00:00:00 
for process 183
033417: Jul 15 14:25:31.089: TFTP: Server request for port 52941, socket_id 
0x6454EF2C for process 183
033418: Jul 15 14:25:31.089: TFTP: read request from host 
216.24.33.79(52941) via Ethernet0/0
033419: Jul 15 14:25:31.089: TFTP: Looking for SEP000DED24D5F4.cnf.xml
033420: Jul 15 14:25:31.093: TFTP: Opened 
system:/its/XMLDefault7960.cnf.xml, fd 0, size 790 for process 183
033421: Jul 15 14:25:31.093: TFTP: Sending block 1 (retry 0), socket_id 
0x6454EF2C
033422: Jul 15 14:25:31.105: TFTP: Received ACK for block 1, socket_id 
0x6454EF2C
033423: Jul 15 14:25:31.105: TFTP: Sending block 2 (retry 0), socket_id 
0x6454EF2C
033424: Jul 15 14:25:31.113: TFTP: Received ACK for block 2, socket_id 
0x6454EF2C
033425: Jul 15 14:25:31.113: TFTP: Finished 
system:/its/XMLDefault7960.cnf.xml, time 00:00:00 for process 183
033426: Jul 15 14:25:32.017: %IPPHONE-6-REG_ALARM: 25: Name=SEP000DED24D5F4 
Load=5.0(3.0) Last=Initialized
033427: Jul 15 14:25:32.021: %IPPHONE-6-REGISTER: ephone-2:SEP000DED24D5F4 
IP:216.24.33.79 Socket:2 DeviceType:Phone has registered.
033428: Jul 15 14:25:34.345: TFTP: Server request for port 52942, socket_id 
0x6454EF2C for process 183
033429: Jul 15 14:25:34.345: TFTP: read request from host 
216.24.33.79(52942) via Ethernet0/0
033430: Jul 15 14:25:34.345: TFTP: Looking for SEP000DED24D5F4.cnf.xml
033431: Jul 15 14:25:34.345: TFTP: Opened 
system:/its/XMLDefault7960.cnf.xml, fd 0, size 790 for process 183
033432: Jul 15 14:25:34.345: TFTP: Sending block 1 (retry 0), socket_id 
0x6454EF2C
033433: Jul 15 14:25:34.349: TFTP: Server request for port 52943, socket_id 
0x6483F140 for process 184
033434: Jul 15 14:25:34.349: TFTP: read request from host 
216.24.33.79(52943) via Ethernet0/0
033435: Jul 15 14:25:34.349: TFTP: Looking for RINGLIST.XML
033436: Jul 15 14:25:34.349: TFTP: Sending error 1 No such file
033437: Jul 15 14:25:34.357: TFTP: Received ACK for block 1, socket_id 
0x6454EF2C
033438: Jul 15 14:25:34.361: TFTP: Sending block 2 (retry 0), socket_id 
0x6454EF2C
033439: Jul 15 14:25:34.365: TFTP: Server request for port 52944, socket_id 
0x63E7C288 for process 184
033440: Jul 15 14:25:34.365: TFTP: read request from host 
216.24.33.79(52944) via Ethernet0/0
033441: Jul 15 14:25:34.365: TFTP: Looking for DISTINCTIVERINGLIST.XML
033442: Jul 15 14:25:34.365: TFTP: Sending error 1 No such file
033443: Jul 15 14:25:34.369: TFTP: Received ACK for block 2, socket_id 
0x6454EF2C
033444: Jul 15 14:25:34.369: TFTP: Finished 
system:/its/XMLDefault7960.cnf.xml, time 00:00:00 for process 183

It APPEARS that the working phone requests the xml file just like the 
others, but then registration occurs, and then the phone requests the xml 
file again. So perhaps the problem is not tftp at all, but that for some 
reason the phones are not registering -- maybe not even requesting 
registration. Does that make sense?