I'm attempting to turn up a new remote property and am having issues with tftp.
I'm currently sitting in the DHCP server using tcpdump to watch a modem try and boot. I can see the full DHCP handshake and the request from the modem for the config file. I can see the server sending the file...but it never makes it back to the modem. Here is the tcpdump log:
[code]
listening on eth0:0, link-type EN10MB (Ethernet), capture size 96 bytes
17:28:06.193141 IP 172.16.48.9.bootpc > 172.16.0.7.bootps: BOOTP/DHCP, Request from 00:01:cb:20:01:29 (oui Unknown), length 319
17:28:06.249468 IP Zuul.bns > 172.16.53.239: ICMP echo request, id 1194, seq 0, length 28
17:28:07.009589 IP Zuul.bns.bootps > 172.16.48.9.bootps: BOOTP/DHCP, Reply, length 315
17:28:07.191742 IP 172.16.48.9.bootpc > 172.16.0.7.bootps: BOOTP/DHCP, Request from 00:01:cb:20:01:29 (oui Unknown), length 331
17:28:07.226023 IP Zuul.bns.bootps > 172.16.48.9.bootps: BOOTP/DHCP, Reply, length 315
17:28:08.194153 IP 172.16.48.9.bootpc > 172.16.0.7.bootps: BOOTP/DHCP, Request from 00:01:cb:20:01:29 (oui Unknown), length 331
17:28:08.232669 IP Zuul.bns.bootps > 172.16.48.9.bootps: BOOTP/DHCP, Reply, length 315
17:28:10.191109 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:10.192846 IP 172.16.0.7.59055 > 172.16.53.239.24915: UDP, length 516
17:28:11.190602 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:11.192222 IP 172.16.0.7.60941 > 172.16.53.239.24915: UDP, length 516
17:28:12.290593 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:12.292145 IP 172.16.0.7.47914 > 172.16.53.239.24915: UDP, length 516
17:28:13.491254 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:13.493032 IP 172.16.0.7.32960 > 172.16.53.239.24915: UDP, length 516
17:28:14.791101 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:14.792851 IP 172.16.0.7.41842 > 172.16.53.239.24915: UDP, length 516
17:28:15.192898 IP 172.16.0.7.59055 > 172.16.53.239.24915: UDP, length 516
17:28:16.190587 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:16.192167 IP 172.16.0.7.58140 > 172.16.53.239.24915: UDP, length 516
17:28:16.192302 IP 172.16.0.7.60941 > 172.16.53.239.24915: UDP, length 516
17:28:17.292198 IP 172.16.0.7.47914 > 172.16.53.239.24915: UDP, length 516
17:28:17.690615 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:17.692186 IP 172.16.0.7.58052 > 172.16.53.239.24915: UDP, length 516
17:28:18.493088 IP 172.16.0.7.32960 > 172.16.53.239.24915: UDP, length 516
17:28:19.290561 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:19.292133 IP 172.16.0.7.51691 > 172.16.53.239.24915: UDP, length 516
17:28:19.792908 IP 172.16.0.7.41842 > 172.16.53.239.24915: UDP, length 516
17:28:20.192950 IP 172.16.0.7.59055 > 172.16.53.239.24915: UDP, length 516
17:28:20.990585 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:20.992133 IP 172.16.0.7.39415 > 172.16.53.239.24915: UDP, length 516
17:28:21.192229 IP 172.16.0.7.58140 > 172.16.53.239.24915: UDP, length 516
17:28:21.192352 IP 172.16.0.7.60941 > 172.16.53.239.24915: UDP, length 516
17:28:22.292249 IP 172.16.0.7.47914 > 172.16.53.239.24915: UDP, length 516
17:28:22.692246 IP 172.16.0.7.58052 > 172.16.53.239.24915: UDP, length 516
17:28:22.790516 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:22.792091 IP 172.16.0.7.51791 > 172.16.53.239.24915: UDP, length 516
17:28:23.493140 IP 172.16.0.7.32960 > 172.16.53.239.24915: UDP, length 516
17:28:24.292223 IP 172.16.0.7.51691 > 172.16.53.239.24915: UDP, length 516
17:28:24.690527 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:24.692127 IP 172.16.0.7.36823 > 172.16.53.239.24915: UDP, length 516
17:28:24.792966 IP 172.16.0.7.41842 > 172.16.53.239.24915: UDP, length 516
17:28:25.193011 IP 172.16.0.7.59055 > 172.16.53.239.24915: UDP, length 516
17:28:25.992240 IP 172.16.0.7.39415 > 172.16.53.239.24915: UDP, length 516
17:28:26.192285 IP 172.16.0.7.58140 > 172.16.53.239.24915: UDP, length 516
17:28:26.192406 IP 172.16.0.7.60941 > 172.16.53.239.24915: UDP, length 516
17:28:26.690111 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:26.691803 IP 172.16.0.7.41680 > 172.16.53.239.24915: UDP, length 516
17:28:27.292302 IP 172.16.0.7.47914 > 172.16.53.239.24915: UDP, length 516
17:28:27.692298 IP 172.16.0.7.58052 > 172.16.53.239.24915: UDP, length 516
17:28:27.792141 IP 172.16.0.7.51791 > 172.16.53.239.24915: UDP, length 516
17:28:28.493194 IP 172.16.0.7.32960 > 172.16.53.239.24915: UDP, length 516
17:28:28.790539 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:28.792103 IP 172.16.0.7.33887 > 172.16.53.239.24915: UDP, length 516
17:28:29.292289 IP 172.16.0.7.51691 > 172.16.53.239.24915: UDP, length 516
17:28:29.692188 IP 172.16.0.7.36823 > 172.16.53.239.24915: UDP, length 516
17:28:29.793018 IP 172.16.0.7.41842 > 172.16.53.239.24915: UDP, length 516
17:28:30.193071 IP 172.16.0.7.59055 > 172.16.53.239.24915: UDP, length 516
17:28:30.990078 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:30.991760 IP 172.16.0.7.37043 > 172.16.53.239.24915: UDP, length 516
17:28:30.992294 IP 172.16.0.7.39415 > 172.16.53.239.24915: UDP, length 516
17:28:31.192345 IP 172.16.0.7.58140 > 172.16.53.239.24915: UDP, length 516
17:28:31.192463 IP 172.16.0.7.60941 > 172.16.53.239.24915: UDP, length 516
17:28:31.691864 IP 172.16.0.7.41680 > 172.16.53.239.24915: UDP, length 516
17:28:32.292358 IP 172.16.0.7.47914 > 172.16.53.239.24915: UDP, length 516
17:28:32.692348 IP 172.16.0.7.58052 > 172.16.53.239.24915: UDP, length 516
17:28:32.792230 IP 172.16.0.7.51791 > 172.16.53.239.24915: UDP, length 516
17:28:33.290521 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:33.292099 IP 172.16.0.7.34697 > 172.16.53.239.24915: UDP, length 516
17:28:33.493244 IP 172.16.0.7.32960 > 172.16.53.239.24915: UDP, length 516
17:28:33.792191 IP 172.16.0.7.33887 > 172.16.53.239.24915: UDP, length 516
17:28:34.292390 IP 172.16.0.7.51691 > 172.16.53.239.24915: UDP, length 516
17:28:34.692246 IP 172.16.0.7.36823 > 172.16.53.239.24915: UDP, length 516
17:28:34.793068 IP 172.16.0.7.41842 > 172.16.53.239.24915: UDP, length 516
17:28:35.690048 IP 172.16.53.239.24915 > 172.16.0.7.tftp: 20 RRQ "platnum.bin" octet
17:28:35.691734 IP 172.16.0.7.38691 > 172.16.53.239.24915: UDP, length 516
17:28:35.991885 IP 172.16.0.7.37043 > 172.16.53.239.24915: UDP, length 516
17:28:35.992337 IP 172.16.0.7.39415 > 172.16.53.239.24915: UDP, length 516
17:28:36.192394 IP 172.16.0.7.58140 > 172.16.53.239.24915: UDP, length 516
17:28:36.691922 IP 172.16.0.7.41680 > 172.16.53.239.24915: UDP, length 516
17:28:37.692402 IP 172.16.0.7.58052 > 172.16.53.239.24915: UDP, length 516
17:28:37.792316 IP 172.16.0.7.51791 > 172.16.53.239.24915: UDP, length 516
17:28:38.292187 IP 172.16.0.7.34697 > 172.16.53.239.24915: UDP, length 516
17:28:38.792279 IP 172.16.0.7.33887 > 172.16.53.239.24915: UDP, length 516
17:28:39.292484 IP 172.16.0.7.51691 > 172.16.53.239.24915: UDP, length 516
17:28:39.692306 IP 172.16.0.7.36823 > 172.16.53.239.24915: UDP, length 516
17:28:40.691797 IP 172.16.0.7.38691 > 172.16.53.239.24915: UDP, length 516
17:28:40.992000 IP 172.16.0.7.37043 > 172.16.53.239.24915: UDP, length 516
17:28:40.992385 IP 172.16.0.7.39415 > 172.16.53.239.24915: UDP, length 516
17:28:41.692001 IP 172.16.0.7.41680 > 172.16.53.239.24915: UDP, length 516
17:28:42.792378 IP 172.16.0.7.51791 > 172.16.53.239.24915: UDP, length 516
17:28:43.292277 IP 172.16.0.7.34697 > 172.16.53.239.24915: UDP, length 516
17:28:43.792366 IP 172.16.0.7.33887 > 172.16.53.239.24915: UDP, length 516
17:28:44.692366 IP 172.16.0.7.36823 > 172.16.53.239.24915: UDP, length 516
17:28:45.691858 IP 172.16.0.7.38691 > 172.16.53.239.24915: UDP, length 516
17:28:45.992105 IP 172.16.0.7.37043 > 172.16.53.239.24915: UDP, length 516
17:28:46.692062 IP 172.16.0.7.41680 > 172.16.53.239.24915: UDP, length 516
17:28:48.292366 IP 172.16.0.7.34697 > 172.16.53.239.24915: UDP, length 516
17:28:48.792453 IP 172.16.0.7.33887 > 172.16.53.239.24915: UDP, length 516
17:28:50.691925 IP 172.16.0.7.38691 > 172.16.53.239.24915: UDP, length 516
17:28:50.992152 IP 172.16.0.7.37043 > 172.16.53.239.24915: UDP, length 516
17:28:53.292418 IP 172.16.0.7.34697 > 172.16.53.239.24915: UDP, length 516
17:28:55.691989 IP 172.16.0.7.38691 > 172.16.53.239.24915: UDP, length 516
[/code]
I know my routes are fine because I can ping the CMTS and the modem (which gets stuck in ip-done) from the dhcp server, and I can ping the dhcp server from the cmts. Syslog shows the same thing. I can see the DHCP handshake, the modem request the file and the file being served...but it never gets there.
[code]
Jun 24 17:29:52 Zuul dhcpd: DHCPDISCOVER from 00:01:cb:20:01:29 via 172.16.48.9
Jun 24 17:29:53 Zuul dhcpd: DHCPOFFER on 172.16.53.239 to 00:01:cb:20:01:29 via 172.16.48.9
Jun 24 17:29:53 Zuul dhcpd: DHCPREQUEST for 172.16.53.239 (172.16.1.7) from 00:01:cb:20:01:29 via 172.16.48.9
Jun 24 17:29:53 Zuul dhcpd: DHCPACK on 172.16.53.239 to 00:01:cb:20:01:29 via 172.16.48.9
Jun 24 17:29:54 Zuul tftpd[6197]: tftpd: trying to get file: platnum.bin
Jun 24 17:29:54 Zuul tftpd[6197]: tftpd: serving file from /dhcpd/tftpboot
[/code]
Here's the REALLY strange part....there are 6 modems on site that will register without a problem. They are all in different parts of the complex and RF levels look fine.
The CMTS (and modems) are separated from the DHCP/TFTP server by an MPLS link. This dhcp/tftp server is currently serving leases and config files to approximately 10 other sites, so I know the server and config files are in working order, and obviously the dhcpd.conf file is fine, because the modem gets an IP and advances to the tftp phase.
Standard ICMP pings between the modem and dhcp server (and modem and dhcp server) show latency of around 40 ms. Dhcp and TFTP traffic is supposed to granted realtime priority over the link to keep this down. Right now, the only thing I can think of that would cause this is a misconfiguration in the router which classifying outbound tftp traffic to a lower class (or a class with very low bandwidth) which is causing latencies high enough to time out the tftp connection. The only problem with this theory is that we have the same router config installed on other sites, and this is the only site having an issue.
Has anyone encountered this sort of thing in the past? My next step is to get a tap out on site and watch for the tftp traffic to see if it's actually making it there, but that's going to have to wait a few days.
You mentioned that six modems are up and registered. Are these six getting the same configuration file, i.e. platnum.bin or something else?
What type of CMTS is this?
yep, all modems are assigned the same file. I even tried changing the assigned file a few times and you can see the change reflected in the logs.
This is an EVR CMTS running Docsis 1.0
The six modems that are registered are they in the same subnet scope?
Do you have a copy of the log file from a modem that fails? Stop me if I'm wrong, but isn' this cmts a bridge? and if so, couldn't it be possible that modems see more than one dhcp server? example, a customer that has a router connected the wrong way and sending dhcp offers out to the whole complex? is there a debug modem you could use?
if you connect a modem directly to the back of the cmts without plant return, does it register?
Just a few thoughts
I'm not on site, so I'll have to try that once someone is.
I'm pretty sure it's not a rogue DHCP server, as I can see all the modems getting an IP in the proper subnet, and I can see all the modems going through the DHCP handshake and tftp request/send in the logs on my DHCP server. If it was a rogue server, I'd expect to see the problem modems getting IP's in other subnets and wouldn't see any activity on my dhcp server. Plus, I'm using DHCP relay and have reflection disabled. So all dhcp traffic fromt he property is being sent unicast to the DHCP server
do you have a network capture from ethereal or wireshark to see what's going on in the network? filter down to a single modem's mac address and then reset a modem that does come back online when reset?
yep. That dump at the top of my first post is the output from tcpdump following a single modem booting. That trace was taken at the DHCP server. I have yet to do it on site, but that is one of my next steps.
I also confirmed that the tftp traffic is being thrown into COS4.
A minor DHCP issue I noticed, you are missing option log-servers 172.16.0.7; even if you do not have a log server some modems, namely older motorola modems will not come online, with symptons similar to yours unless they receive the following dhcp options, routers, time-servers, log-servers, next-server and timing offset. May not be your issue but is a simple fix.
Is there a possibility to run the TFTP server locally, especially for one file, would save you a lot of headaches. If you have a cisco router/cmts you can put it on the slot/disk and add the commands
service udp-small-servers max-servers no-limit
tftp-server slot0:platnum.bin
then your local router is your TFTP server.
thanks,
I'll add that in. We don't supply modems, so it would be one heck of a coincidence if 90% of the customers were using the same model of modem that happened to be susceptible to that. Although the CMTS does have a provisioning testing tool that simulates a modem booting, and it is failing too (it works on other sites).
We are going to install a remote tftp server once we can get someone back up there.
Okay, we figured it out.
The router on site is a managed ATT router ( we didn't configure it) and the guy who provisioned it set it up as a /24 network instead of a /21.
We use a small block of ips at the beginning of the subnet for our equipment, then the modems get the rest, so dhcp worked because the cmts was relaying and had a routable address (within the overlap). The odd modems that were registering just happened to get an IP inside the block of routable ips.
That's why the tftp traffic never made it....we only had 254 actual routable ips. Since our main router at the headend pulls the network info via bgp, most of the Tftp traffic was being routed out to our wan router.
If I hadn't run a mtr on a test modem I wouldn't have found it.