tftp strangeness | docsis.org

You are here

tftp strangeness

13 posts / 0 new
Last post
bealsm
tftp strangeness
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.
mtntrailseeker
You mentioned that six

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?

bealsm
yep, all modems are assigned

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

mtntrailseeker
The six modems that are

The six modems that are registered are they in the same subnet scope?

bealsm
Yes
Yes Here is the subnet declaration [code] subnet 172.16.48.0 netmask 255.255.248.0 { pool{ range 172.16.48.12 172.16.55.0; option routers 172.16.48.8; option domain-name-servers 216.136.95.2,4.2.2.2,12.127.16.67; option broadcast-address 172.16.55.255; allow members of "cm"; # deny unknown-clients; option tftp-server-name "172.16.0.7"; next-server 172.16.0.7; server-name "172.16.0.7"; default-lease-time 86400; max-lease-time 86400; option time-offset -25200; option time-servers 172.16.0.7; filename "platnum.bin"; option bootfile-name "platnum.bin"; } } [/code] Yea, I know platinum is spelled wrong. That is the way the actual file is spelled.
cmcaldas
Modem log?

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

bealsm
I'm not on site, so I'll

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

cmcaldas
Wireshark

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?

bealsm
yep. That dump at the top

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.

bealsm
I think I may have found
I think I may have found something. I took my tcpdump log from above and broke it down by tftp session: [code] 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:15.192898 IP 172.16.0.7.59055 > 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:25.193011 IP 172.16.0.7.59055 > 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: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:16.192302 IP 172.16.0.7.60941 > 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:26.192406 IP 172.16.0.7.60941 > 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: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:17.292198 IP 172.16.0.7.47914 > 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:27.292302 IP 172.16.0.7.47914 > 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: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:18.493088 IP 172.16.0.7.32960 > 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:28.493194 IP 172.16.0.7.32960 > 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: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:19.792908 IP 172.16.0.7.41842 > 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:29.793018 IP 172.16.0.7.41842 > 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 [/code] All of the session lengths are exactly 20 seconds long. This is telling me that the transfers are timing out before they complete. I have to verify it, but I believe our MPLS QOS classification scheme was completely port based....so it's putting port 69 (the tftp request) in a high priority COS, but the actual transfers are being classified as low priority.
kwesibrunee
Some thoughts.....

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.

bealsm
thanks, I'll add that in.

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.

bealsm
Solution!

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.

Log in or register to post comments