DHCP renewal problem with Windows 7
-
Sorry about the slow reply, but I was very busy with work.
Well, I checked the DHCP logs before I posted and I don't see any unusual entries in there. From what I can see on screen the troubleshooter is doing an ipconfig /renew to "fix" the problem and, yes, it also disables and enables the adapter.
I also asked my wife and she did not encounter this issue with her laptop. This makes me wonder if the problem is caused by the workstation using two network adapters in bridged mode which is recommended by MS to increase bandwidth. However, it is possible that my wife did not encounter the issue because she simply doesn't spend much time in front of the pc as I do… ;)
I guess I will keep monitoring it for a while and try to gather additional information when it happens again. On the plus side it did not happen again today when the DHCP lease expired. Hmmm, I did upgrade to the latest pre-build version yesterday. I mean I don't think that the version change made any differences, but I am wondering if the reboot did...
Thanks for getting back to me. I will keep you posted.
Best regards,
Jens -
Ok. I guess I was too optimistic. It just happened again… :(
This time I tried the following things:
1. ipconfig /release /renew
Both complete, but still no internet...2. Manual bridge reset
That reconnects me...The log of pfSense also looks quite strange to me.
Nov 21 12:52:34 dhcpd: DHCPDISCOVER from 02:1f:bc:01:6a:a4 (JUPITER) via em0 Nov 21 12:52:35 dhcpd: DHCPOFFER on 192.168.1.252 to 12:1f:bc:51:6a:a4 (JUPITER) via em0 Nov 21 12:52:35 dhcpd: Wrote 28 leases to leases file. Nov 21 12:52:35 dhcpd: DHCPREQUEST for 192.168.1.252 (192.168.1.1) from 12:1f:bc:51:6a:a4 (JUPITER) via em0 Nov 21 12:52:35 dhcpd: DHCPACK on 192.168.1.252 to 12:1f:bc:51:6a:a4 (JUPITER) via em0 Nov 21 12:52:41 dhcpd: DHCPINFORM from 192.168.1.252 via em0 Nov 21 12:52:41 dhcpd: DHCPACK to 192.168.1.252 (12:1f:bc:51:6a:a4) via em0 Nov 21 12:52:44 dhcpd: DHCPINFORM from 192.168.1.252 via em0 Nov 21 12:52:44 dhcpd: DHCPACK to 192.168.1.252 (12:1f:bc:51:6a:a4) via em0 Nov 21 12:53:14 dhcpd: DHCPREQUEST for 192.168.1.252 from 12:1f:bc:51:6a:a4 via em0: lease 192.168.1.252 unavailable. Nov 21 12:53:14 dhcpd: DHCPNAK on 192.168.1.252 to 12:1f:bc:51:6a:a4 via em0 Nov 21 12:53:14 dhcpd: DHCPREQUEST for 192.168.1.252 from 12:1f:bc:51:6a:a4 via em0: lease 192.168.1.252 unavailable. Nov 21 12:53:14 dhcpd: DHCPNAK on 192.168.1.252 to 12:1f:bc:51:6a:a4 via em0 Nov 21 12:53:14 dhcpd: DHCPDISCOVER from 12:1f:bc:51:6a:a4 via em0 Nov 21 12:53:15 dhcpd: DHCPOFFER on 192.168.1.248 to 12:1f:bc:51:6a:a4 (JUPITER) via em0 Nov 21 12:53:15 dhcpd: DHCPREQUEST for 192.168.1.248 (192.168.1.1) from 12:1f:bc:51:6a:a4 (JUPITER) via em0 Nov 21 12:53:15 dhcpd: DHCPACK on 192.168.1.248 to 12:1f:bc:51:6a:a4 (JUPITER) via em0 Nov 21 12:53:15 dhcpd: DHCPREQUEST for 192.168.1.248 (192.168.1.1) from 12:1f:bc:51:6a:a4 (JUPITER) via em0 Nov 21 12:53:15 dhcpd: DHCPACK on 192.168.1.248 to 12:1f:bc:51:6a:a4 (JUPITER) via em0
I am guessing that the issue is caused by the line showing "… lease 192.168.1.252 unavailable.", but I don't know how to resolve it.
Thanks,
Jens -
I'd guess your issue is probably with bridging two NICs together on the same LAN. It is probably causing issues with broadcast traffic in general, including DHCP. You need a switch with proper LACP/LAGG support to really pull that off, not just two network cards.
-
Hmmm, I do have a managed switch between pfSense and the local network. I also have a server running Windows 2008 R2 with the same network configuration. Only difference is that the server is using a static IP.
I can check the configuration on the switch, but I am confused. If DHCP comes from pfSense what has the switch to do with that? It is also my understanding that MS bridged network cards in Windows 7 are transparent meaning that they should behave as a single NIC. The same machine previously used Vista x64 and DHCP ran with bridged network cards without a problem…
Anyhow, I will play around some more and report back if I can find a solution.
Thanks,
Jens -
Ok. I spent some more time on this and I made the following observations:
1. DHCP lease report shows changed MAC on renewal
I found that the DHCP lease report shows me two different MAC addresses for the same pc. Here is what I am seeing:192.168.1.252 02:1f:bc:01:6a:a4 JUPITER 2009/11/30 10:17:21 2009/12/01 10:17:21 online active 192.168.1.254 02:1f:bc:01:6a:a5 JUPITER 2009/11/29 12:03:06 2009/11/30 12:03:06 offline active
I am guessing that this is causing the problem in the end… It appears that windows "randomly" uses one MAC address after a reboot.
2. System Log
The System Log shows the following:Nov 29 11:29:21 dnsmasq[568]: reading /var/dhcpd/var/db/dhcpd.leases Nov 29 12:03:06 dnsmasq[568]: reading /var/dhcpd/var/db/dhcpd.leases Nov 29 12:03:06 miniupnpd[917]: sendto(udp): No buffer space available Nov 29 12:03:06 last message repeated 1710 times Nov 29 20:29:05 dnsmasq[568]: reading /var/dhcpd/var/db/dhcpd.leases
Why is it reading the dhcp leases so often? I also notice the "No buffer space available" error related to Upnp. I mainly use Upnp for my XBox and I don't see any other client using it when I check the log for the service. What does the error message mean? I am mainly curious because it happened while I encountered the DHCP renewal problem and my XBox was off during that time…
3. System Log - DHCP tab
The DHCP tab in the system log shows the following:Nov 29 12:02:13 dhcpd: DHCPINFORM from 192.168.1.252 via em0 Nov 29 12:02:13 dhcpd: DHCPACK to 192.168.1.252 (02:1f:bc:01:6a:a4) via em0 Nov 29 12:02:16 dhcpd: DHCPINFORM from 192.168.1.252 via em0 Nov 29 12:02:16 dhcpd: DHCPACK to 192.168.1.252 (02:1f:bc:01:6a:a4) via em0 Nov 29 12:03:05 dhcpd: DHCPREQUEST for 192.168.1.252 from 02:1f:bc:01:6a:a5 via em0: lease 192.168.1.252 unavailable. Nov 29 12:03:05 dhcpd: DHCPNAK on 192.168.1.252 to 02:1f:bc:01:6a:a5 via em0 Nov 29 12:03:05 dhcpd: DHCPREQUEST for 192.168.1.252 from 02:1f:bc:01:6a:a5 via em0: lease 192.168.1.252 unavailable. Nov 29 12:03:05 dhcpd: DHCPNAK on 192.168.1.252 to 02:1f:bc:01:6a:a5 via em0 Nov 29 12:03:05 dhcpd: DHCPDISCOVER from 02:1f:bc:01:6a:a5 via em0 Nov 29 12:03:06 dhcpd: DHCPOFFER on 192.168.1.254 to 02:1f:bc:01:6a:a5 (JUPITER) via em0 Nov 29 12:03:06 dhcpd: DHCPREQUEST for 192.168.1.254 (192.168.1.1) from 02:1f:bc:01:6a:a5 (JUPITER) via em0 Nov 29 12:03:06 dhcpd: DHCPACK on 192.168.1.254 to 02:1f:bc:01:6a:a5 (JUPITER) via em0 Nov 29 12:03:06 dhcpd: DHCPREQUEST for 192.168.1.254 (192.168.1.1) from 02:1f:bc:01:6a:a5 (JUPITER) via em0 Nov 29 12:03:06 dhcpd: DHCPACK on 192.168.1.254 to 02:1f:bc:01:6a:a5 (JUPITER) via em0 Nov 29 12:03:12 dhcpd: DHCPINFORM from 192.168.1.254 via em0 Nov 29 12:03:12 dhcpd: DHCPACK to 192.168.1.254 (02:1f:bc:01:6a:a5) via em0
Looking at the log I am guessing that the renewal failed because of the changed MAC address. Is that correct?
4. Ignored Lease Time
During my testing I decided to "reduce" the problem by increasing the lease time (default lease time = 604800) to 7 days. Unfortunately, as we can see above, this is being ignored and it is still at 24 hours. Is there a maximum lease time?Ok, I think that is quite a lot of data gathered and I am hoping that it will be possible to find a solution for this problem. I can somehow see that MS made a mistake by assuming that it is OK to use "any" MAC address when a pc gets rebooted. Is there a standard (RFC?) for that? Is MS at fault?
If this is not fully regulated by any standard, maybe we could have a "looser" rule for the renewal?
I am obviously not an expert in this area, but I will happily do some more testing if needed.
Thanks,
Jens -
I doubt there is any way to "loosen" the renewal as the DHCP daemon has no way to know that is really the same PC and not someone trying to steal the lease.
As for the other issues:
1. As the saying goes "well there's your problem". :)2. That is the DNS forwarder reading the leases to gather DHCP hostnames so they can be resolved with DNS. I'm not sure if that runs on a timer or every time the leases file changes.
Even if you only configured UPnP it for the purpose of your xbox, it is likely that some software on the windows box is querying the router to check. Windows 7 (and Vista) show upnp-aware routers when you browse the network, it is likely OS related. It might be related to the DHCP error but I'm not really sure.
3. Yes, that is consistent with the other messages, the DHCP request is coming from the "wrong" network card. It believes it is a separate PC attempting to clobber the lease and (rightfully) ignores it.
4. There are boxes for both the Default and Maximum lease times on my 1.2.3-RC3 install.
-
Thanks for getting back to me. :)
Yeah. I figured that it wouldn't be possible to "loosen" the renewal rules for the reason you listed.
Well, I am happy that I found my problem, but I guess I will have to wait on Windows 8 now to get it fixed… ;)
Yes, you are right about the UPnP. I checked Windows and it shows pfSense as a UPnP router. So, these entries make sense and should be there.
What about the UPnP error?
Nov 29 12:03:06 miniupnpd[917]: sendto(udp): No buffer space available
Well, I did increase the Default lease time to one week in the configuration box, but it still expires after one day… Did I hit a field limit or something like that? Maybe one week in seconds is too big of a number? Not sure why that didn't work.
In any case I got the issue twice today. It seems that Windows 7 is just kind of funky with DHCP when you have two bridged network adapters... MS still recommends bridging for multiple adapters according to their web page...
I might switch DHCP to the Windows 7 server to see if that makes any difference...
Thanks,
Jens -
I'm not sure what is going on with that upnp error. I've not seen that one before. You might start a new thread for that, but it would first be worth testing if that still happens when you only use one network card. It may be a similar issue to the DHCP one.
-
I will check on that.
What about the issue with not being able to increase the DHCP lease time? I tried a smaller period (2 days) and it works just fine. However 7 days appears to be a no go…
I also upgraded my network card driver to see if that will make any difference.
Thanks,
Jens -
Just a quick update:
The initial driver update did not fix the problem. However, I got another driver update through Windows Update in the first week of December which resolved the problem. :)
Thanks,
Jens