DHCPREQUEST does not complete?
-
Apr 12 09:23:22 dhclient[31366]: DHCPREQUEST on fxp0 to 82.143.192.8 port 67
Apr 12 09:23:57 last message repeated 4 times
Apr 12 09:25:57 last message repeated 6 times
Apr 12 09:35:15 last message repeated 18 times
Apr 12 09:37:24 last message repeated 2 times
Apr 12 09:39:56 dhclient[31366]: DHCPREQUEST on fxp0 to 255.255.255.255 port 67
Apr 12 09:39:56 dhclient[31366]: DHCPACK from 82.143.207.2
Apr 12 09:39:57 dhclient[31366]: bound to 82.143.207.X – renewal in 1419 seconds.
Apr 12 09:40:07 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is - 82.143.207.X.If I read the log file correctly it seems like pfSense is very patient about recieving a DHCP address on the WAN interface. I believe this leaves my internet connection down for minuttes at the time untill it times out and broadcasts instead.
-
I still have this problem.
pfSense cant directly access the DHCP server, but needs to broadcast (or order to get the router to forward the DHCP request). Since pfSense is very patient the IP eventually times out and pfSense is left without internet access.
Cant pfSense be changed to not trying so many times directly to the server and broadcast after eg. 5 direct tries.
I cant possibly be the only one that have this problem.
-
What is the subnet mask of 82.143.192.8 ?
It almost appears as your ISP has misconfigured their subnet masks.
-
What is the subnet mask of 82.143.192.8 ?
That's not a subnet mask. It's trying to renew its existing IP from the DHCP server it got its lease from. Then once the lease expires, it drops the old lease, switches over to broadcasting, and discovers a new DHCP server.
I'd like to see DHCP logs over a much longer timeframe to make sure this is really what's happening. If so, I can't imagine any OS's DHCP client acting differently than this. DHCP RFC 2131 states that you must renew the DHCP lease via unicast to the original server, as you see dhclient doing. After it can't renew the lease (for whatever reason), it drops the IP at the end of the lease, then goes to broadcasting.
What you're seeing seems to be normal, proper behavior for any DHCP client, per RFC 2131, and your ISP seems to be doing something incredibly stupid with DHCP (like changing the server's IP every few minutes?? shrug). What exactly is hard to say without more logs from DHCP.
-
I wasn't implying that was a subnet mask, I was asking WHAT IS the subnet mask of the server.
It's obvious from the logs he has received an IP from that server and that server is no longer reachable (server on a different subnet mask, etc).
-
@cmb:
What is the subnet mask of 82.143.192.8 ?
I'd like to see DHCP logs over a much longer timeframe to make sure this is really what's happening. If so, I can't imagine any OS's DHCP client acting differently than this. DHCP RFC 2131 states that you must renew the DHCP lease via unicast to the original server, as you see dhclient doing. After it can't renew the lease (for whatever reason), it drops the IP at the end of the lease, then goes to broadcasting.
What you're seeing seems to be normal, proper behavior for any DHCP client, per RFC 2131, and your ISP seems to be doing something incredibly stupid with DHCP (like changing the server's IP every few minutes?? shrug). What exactly is hard to say without more logs from DHCP.
I believe they have shielded their DHCP server behind a firewall, so I cant renew the address directly. When pfSense eventually broadcasts the request their router relayes the request to the DHCP server - but it leaves me with down time for up to 30-60 seconds each time.
Jul 14 21:07:25 php: : Creating rrd update script
Jul 14 21:07:25 php: : Creating rrd graph index
Jul 14 21:07:27 php: : FTP proxy disabled for interface LAN - ignoring.
Jul 14 21:07:46 php: : Informational: services_dyndns_configure() is starting.
Jul 14 21:07:47 php: : DynDns: Running updatedns()
Jul 14 21:07:47 php: : DynDns: updatedns() starting
Jul 14 21:07:47 php: : DynDns: _detectChange() starting.
Jul 14 21:07:47 php: : DynDns: Current WAN IP: 82.143.207.120
Jul 14 21:07:47 php: : DynDns: Cached IP: 82.143.207.120
Jul 14 21:07:47 php: : phpDynDNS: No Change In My IP Address and/or 25 Days Has Not Past. Not Updating Dynamic DNS Entry.
Jul 14 21:08:31 dnsmasq[862]: reading /etc/resolv.conf
Jul 14 21:08:31 dnsmasq[862]: using nameserver 82.143.192.21#53
Jul 14 21:08:31 dnsmasq[862]: using nameserver 82.143.192.40#53
Jul 14 21:08:31 dnsmasq[862]: using nameserver 82.143.192.20#53
Jul 14 21:16:39 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 21:29:48 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 21:32:01 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 14 21:32:35 last message repeated 2 times
Jul 14 21:34:28 last message repeated 4 times
Jul 14 21:35:46 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 14 21:36:55 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 21:37:14 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 14 21:37:44 last message repeated 3 times
Jul 14 21:39:45 last message repeated 8 times
Jul 14 21:49:26 last message repeated 16 times
Jul 14 21:50:27 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 14 21:52:15 dhclient[270]: DHCPREQUEST on em0 to 255.255.255.255 port 67
Jul 14 21:52:15 dhclient[270]: DHCPACK from 82.143.207.3
Jul 14 21:52:16 dhclient[270]: bound to 82.143.207.120 – renewal in 1800 seconds.
Jul 14 21:52:20 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is - 82.143.207.120.
Jul 14 21:52:20 php: : Creating rrd update script
Jul 14 21:52:20 php: : Creating rrd graph index
Jul 14 21:52:22 php: : FTP proxy disabled for interface LAN - ignoring.
Jul 14 21:52:41 php: : Informational: services_dyndns_configure() is starting.
Jul 14 21:52:42 php: : DynDns: Running updatedns()
Jul 14 21:52:42 php: : DynDns: updatedns() starting
Jul 14 21:52:42 php: : DynDns: _detectChange() starting.
Jul 14 21:52:42 php: : DynDns: Current WAN IP: 82.143.207.120
Jul 14 21:52:42 php: : DynDns: Cached IP: 82.143.207.120
Jul 14 21:52:42 php: : phpDynDNS: No Change In My IP Address and/or 25 Days Has Not Past. Not Updating Dynamic DNS Entry.
Jul 14 21:57:12 dnsmasq[862]: reading /etc/resolv.conf
Jul 14 21:57:12 dnsmasq[862]: using nameserver 82.143.192.21#53
Jul 14 21:57:12 dnsmasq[862]: using nameserver 82.143.192.40#53
Jul 14 21:57:12 dnsmasq[862]: using nameserver 82.143.192.20#53
Jul 14 22:22:15 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.8 port 67
Jul 14 22:22:38 last message repeated 2 times
Jul 14 22:24:38 last message repeated 4 times
Jul 14 22:29:50 last message repeated 9 times
Jul 14 22:30:14 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 22:30:24 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.8 port 67
Jul 14 22:32:06 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.8 port 67
Jul 14 22:34:13 last message repeated 5 times
Jul 14 22:37:22 last message repeated 4 times
Jul 14 22:37:52 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 22:37:53 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.8 port 67
Jul 14 22:38:45 last message repeated 2 times
Jul 14 22:40:35 last message repeated 8 times
Jul 14 22:44:31 last message repeated 5 times
Jul 14 22:45:05 dhclient[270]: DHCPREQUEST on em0 to 255.255.255.255 port 67
Jul 14 22:45:05 dhclient[270]: DHCPACK from 82.143.207.2
Jul 14 22:45:06 dhclient[270]: bound to 82.143.207.120 – renewal in 1349 seconds.
Jul 14 22:45:15 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is - 82.143.207.120.
Jul 14 22:45:16 php: : Creating rrd update script
Jul 14 22:45:16 dnsmasq[862]: reading /etc/resolv.conf
Jul 14 22:45:16 dnsmasq[862]: using nameserver 82.143.192.21#53
Jul 14 22:45:16 dnsmasq[862]: using nameserver 82.143.192.40#53
Jul 14 22:45:16 dnsmasq[862]: using nameserver 82.143.192.20#53
Jul 14 22:45:16 php: : Creating rrd graph index
Jul 14 22:45:18 php: : FTP proxy disabled for interface LAN - ignoring.
Jul 14 22:45:40 php: : Informational: services_dyndns_configure() is starting.
Jul 14 22:45:41 php: : DynDns: Running updatedns()
Jul 14 22:45:41 php: : DynDns: updatedns() starting
Jul 14 22:45:41 php: : DynDns: _detectChange() starting.
Jul 14 22:45:41 php: : DynDns: Current WAN IP: 82.143.207.120
Jul 14 22:45:41 php: : DynDns: Cached IP: 82.143.207.120
Jul 14 22:45:41 php: : phpDynDNS: No Change In My IP Address and/or 25 Days Has Not Past. Not Updating Dynamic DNS Entry.
Jul 14 23:07:34 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 14 23:08:18 last message repeated 4 times
Jul 14 23:09:30 last message repeated 2 times
Jul 14 23:16:15 last message repeated 17 times
Jul 14 23:16:37 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 23:16:55 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 14 23:17:40 last message repeated 2 times
Jul 14 23:19:50 last message repeated 6 times
Jul 14 23:23:28 last message repeated 5 times
Jul 14 23:24:44 dhclient[270]: DHCPREQUEST on em0 to 255.255.255.255 port 67
Jul 14 23:24:44 dhclient[270]: DHCPACK from 82.143.207.3
Jul 14 23:24:44 dhclient[270]: bound to 82.143.207.120 – renewal in 1115 seconds.
Jul 14 23:24:49 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is - 82.143.207.120.
Jul 14 23:24:50 php: : Creating rrd update script
Jul 14 23:24:50 php: : Creating rrd graph index
Jul 14 23:24:52 php: : FTP proxy disabled for interface LAN - ignoring.
Jul 14 23:25:01 dnsmasq[862]: reading /etc/resolv.conf
Jul 14 23:25:01 dnsmasq[862]: using nameserver 82.143.192.21#53
Jul 14 23:25:01 dnsmasq[862]: using nameserver 82.143.192.40#53
Jul 14 23:25:01 dnsmasq[862]: using nameserver 82.143.192.20#53
Jul 14 23:25:14 php: : Informational: services_dyndns_configure() is starting.
Jul 14 23:25:15 php: : DynDns: Running updatedns()
Jul 14 23:25:15 php: : DynDns: updatedns() starting
Jul 14 23:25:15 php: : DynDns: _detectChange() starting.
Jul 14 23:25:15 php: : DynDns: Current WAN IP: 82.143.207.120
Jul 14 23:25:15 php: : DynDns: Cached IP: 82.143.207.120
Jul 14 23:25:15 php: : phpDynDNS: No Change In My IP Address and/or 25 Days Has Not Past. Not Updating Dynamic DNS Entry.
Jul 14 23:28:59 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 23:35:55 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 14 23:43:20 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.8 port 67
Jul 14 23:43:36 last message repeated 2 times
Jul 14 23:45:44 last message repeated 5 times
Jul 14 23:55:37 last message repeated 20 times
Jul 14 23:56:23 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.8 port 67
Jul 14 23:58:11 dhclient[270]: DHCPREQUEST on em0 to 255.255.255.255 port 67
Jul 14 23:58:11 dhclient[270]: DHCPACK from 82.143.207.2
Jul 14 23:58:12 dhclient[270]: bound to 82.143.207.120 – renewal in 1511 seconds.
Jul 14 23:58:18 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is - 82.143.207.120.
Jul 14 23:58:18 php: : Creating rrd update script
Jul 14 23:58:18 php: : Creating rrd graph index
Jul 14 23:58:20 php: : FTP proxy disabled for interface LAN - ignoring.
Jul 14 23:58:21 dnsmasq[862]: reading /etc/resolv.conf
Jul 14 23:58:21 dnsmasq[862]: using nameserver 82.143.192.21#53
Jul 14 23:58:21 dnsmasq[862]: using nameserver 82.143.192.40#53
Jul 14 23:58:21 dnsmasq[862]: using nameserver 82.143.192.20#53
Jul 14 23:58:42 php: : Informational: services_dyndns_configure() is starting.
Jul 14 23:58:43 php: : DynDns: Running updatedns()
Jul 14 23:58:43 php: : DynDns: updatedns() starting
Jul 14 23:58:43 php: : DynDns: _detectChange() starting.
Jul 14 23:58:43 php: : DynDns: Current WAN IP: 82.143.207.120
Jul 14 23:58:43 php: : DynDns: Cached IP: 82.143.207.120
Jul 14 23:58:43 php: : phpDynDNS: No Change In My IP Address and/or 25 Days Has Not Past. Not Updating Dynamic DNS Entry.
Jul 15 00:23:22 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 15 00:23:42 last message repeated 3 times
Jul 15 00:25:30 last message repeated 6 times
Jul 15 00:30:04 last message repeated 9 times
Jul 15 00:30:14 dnsmasq[862]: reading /var/dhcpd/var/db/dhcpd.leases
Jul 15 00:30:19 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 15 00:30:32 dhclient[270]: DHCPREQUEST on em0 to 82.143.192.7 port 67
Jul 15 00:31:57 last message repeated 2 times -
This is not valid behavior for an ISP. I would call them and ask them why they do this.
I would even dare to say they are breaking RFC but I cannot recite the info at the moment as I am too lazy to look it up.
-
This is not valid behavior for an ISP. I would call them and ask them why they do this.
I would even dare to say they are breaking RFC but I cannot recite the info at the moment as I am too lazy to look it up.
I read parts of the RFC yesterday (and when I initially wrote the first message). There isnt no doubt in my mind that they dont follow the RFC.
BUT I also know the response from the generel outsourced helpdesk.
1: boot your machine
2: We only support Windows XP.
3: Remove your firewall.
4: What is FreeBSD?
5: Reinstall your machine.But I will try eventhou it puts great pressure on my patience :-)
My problem is that it works with Windows XP directly connected (it probably isnt very patient and broadcasts before the lease runs out) and the old firewall I used had the same behaviour (hardware firewall that is Linux based).
-
I believe they have shielded their DHCP server behind a firewall, so I cant renew the address directly.
This is ridiculous behavior. I'd suggest finding an ISP that actually knows how to run a network.
But, I will say the new dhclient in FreeBSD 6.x doesn't exactly seem to be the best DHCP client in the world, though most of the quirks seem to be worked out. It's from OpenBSD though, and OpenBSD's response to this would be "your ISP is broken" and they wouldn't even attempt to implement a work around. Windows and Linux would be much more likely to put in hacks to work around broken networks.
If you can find some info on changing this behavior in FreeBSD, I'm sure we would consider implementing it somehow in the future (and maybe there's a hack you can use in the mean time).
-
Take a look at this thread, please:
http://forum.pfsense.org/index.php/topic,1651.0.html