Wan dynamic ip laziness could cause problems

[Mistermoonlight]

I have reported in a previous thread
http://forums.smallnetbuilder.com/showthread.php?t=22268 that i got some problems using a thomson dcm475 cable modem with a rt-n66 router and Merlin firm .50beta1 (same problem with a 2 years older firmware).

I attempted to diagnosed with wireshark the router wan/modem transactions at powerup when both devices are powerup at the same time. About half of the time, i could not get a wan address to the router.

I have tried both "normal/agressive mode" in the wan dynamic ip setting. Both settings give problems. To make sure that the router is the problem, i replaced my asus router with an old cheapo dlink router i had. This one can get a dynamic ip 100% of the time in around 45 secs - 50 secs after all devices power up (it is much more aggressive on the dhcp sequence than my asus router).

The problem seems that even in agressive mode, the asus router cannot do it faster than in the 70 secs range. This seems to be a possible critical zone: if the rt-n66 is doing it in say 80 secs for the whole process, most of the time my isp won't give an ip. If it can get it in near 70 secs or faster it will generallly works.

As can be seen in the wireshark trace, the process is divided in 2 main steps:
1- after powerup, the router is getting a local ip in the range 192.168.100.x from the modem (before the cable network is connected and ready to be used, the modem is serving a web server for diagnostic at that time).
2- Then a second dhcp attempt from the router would get a public ip through the cable and from the isp.

For those that want to know, here is dhcp protocol sequence that is getting an address for both steps (4 packets need to be exchange between the router and the modem, i highlighted in bold these 2 X 4 packets that gives a dhcp address):

dhcp discover, dhcp offer, dhcp request and dhcp ack.

Here a filtered packet dump to show the dhcp packet exchange between the router and the modem.

dlink router (100% getting public ip address)
-----------------------------------------

No. Time Source Destination Protocol Length Info
1 0.000000000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x1e35fd4f
2 1.000044000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x959e13e5
3 2.999877000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x6bf7380b
5 6.999551000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0xfbe2b354
7 14.998881000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x9070ecc0
8 14.999842000 192.168.100.1 192.168.100.10 DHCP 342 DHCP Offer - Transaction ID 0x9070ecc0
9 15.000327000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x9070ecc0
11 15.999182000 192.168.100.1 192.168.100.10 DHCP 342 DHCP ACK - Transaction ID 0x9070ecc0
22 30.997821000 192.168.100.10 192.168.100.1 DHCP 342 DHCP Request - Transaction ID 0xe5c15dff
25 31.997619000 192.168.100.10 192.168.100.1 DHCP 342 DHCP Request - Transaction ID 0xb5e9356d
26 33.997456000 192.168.100.10 192.168.100.1 DHCP 342 DHCP Request - Transaction ID 0xbbcc58ba
27 35.997290000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x930b221b
28 36.997316000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0xbbf3b713
29 38.997163000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x6390f128
31 42.996836000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0xb2ae8cd6
33 46.791476000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x663ea217
34 47.791273000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0xa925c966
35 49.791351000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0xf6d9b175
36 49.814203000 10.246.165.129 96.127.193.234 DHCP 342 DHCP Offer - Transaction ID 0xf6d9b175
37 49.814686000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0xf6d9b175
38 49.848993000 10.246.165.129 96.127.193.234 DHCP 342 DHCP ACK - Transaction ID 0xf6d9b175

Asus router with Merlin firm 50Beta1 (dhcp fail)
---------------------------------------------

No. Time Source Destination Protocol Length Info
3 6.363566000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x54f0442e
4 6.364277000 192.168.100.1 192.168.100.10 DHCP 342 DHCP Offer - Transaction ID 0x54f0442e
5 6.433349000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x54f0442e
7 7.430004000 192.168.100.1 192.168.100.10 DHCP 342 DHCP ACK - Transaction ID 0x54f0442e
43 29.909250000 10.54.72.1 255.255.255.255 DHCP 343 DHCP Offer - Transaction ID 0xc09196fc
48 30.990501000 10.54.72.1 255.255.255.255 DHCP 343 DHCP ACK - Transaction ID 0xc09196fc
130 63.248833000 10.54.72.1 255.255.255.255 DHCP 343 DHCP ACK - Transaction ID 0x259103ef
135 64.541683000 10.54.72.1 255.255.255.255 DHCP 343 DHCP ACK - Transaction ID 0x5a681f89
148 67.642717000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x54f0442e
173 74.772628000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x54f0442e
182 77.892627000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x54f0442e
183 78.124401000 10.54.72.1 255.255.255.255 DHCP 342 DHCP Offer - Transaction ID 0xd65d2576
184 78.181309000 10.54.72.1 255.255.255.255 DHCP 342 DHCP ACK - Transaction ID 0xd65d2576
189 79.282526000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x54f0442e
190 79.472499000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x4f7f780e
191 82.552606000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x4f7f780e
192 85.622763000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x4f7f780e
196 108.702212000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0xc0cee96c
197 111.772123000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0xc0cee96c
198 114.842283000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0xc0cee96c
199 137.931727000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x49bcd464
200 140.991917000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x49bcd464
201 144.061830000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x49bcd464
205 167.181418000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x1ff464c
206 170.241603000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x1ff464c
207 173.311504000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x1ff464c
208 196.391208000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x543783d
209 199.451163000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x543783d
210 202.511352000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x543783d

I have highlighted in red the 1st packet send by any router to get the 2nd dhcp address, we can see in these 2 cases that the dlink router is ready to attempt the dhcp discover at around 46 secs after powerup and the asus router at around 79 secs, so more than 30 secs later.

 

[Mistermoonlight]

This example shows a case were the asus router get an ip address correctly for both steps:
----------------------------------

No. Time Source Destination Protocol Length Info
3 5.501688000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0x55c10832
4 5.502389000 192.168.100.1 192.168.100.10 DHCP 342 DHCP Offer - Transaction ID 0x55c10832
5 5.637382000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x55c10832
7 6.630132000 192.168.100.1 192.168.100.10 DHCP 342 DHCP ACK - Transaction ID 0x55c10832
147 62.300839000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x55c10832
162 69.440724000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x55c10832
175 72.580676000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x55c10832
186 73.720785000 192.168.100.10 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0x55c10832
188 73.901722000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Discover - Transaction ID 0xfdd9841f
189 73.923850000 10.246.165.129 173.246.13.101 DHCP 365 DHCP Offer - Transaction ID 0xfdd9841f
190 74.020888000 0.0.0.0 255.255.255.255 DHCP 342 DHCP Request - Transaction ID 0xfdd9841f
191 74.067096000 10.246.165.129 173.246.13.101 DHCP 365 DHCP ACK - Transaction ID 0xfdd9841f



As we can see from the previous example were it failed with the asus router, this time the red line was around 6 seconds faster and the process worked correctly.

This is still an assumption that the problem is related to a timing issue between the isp - modem - router cause i didn't find so far in the trace dumps something that looks as a dhcp bug.