WAN link does not recovering automatically after ISP connection restored

freedog96150 · Sep 3, 2012, 1:16 AM

I have searched and most likely have missed the answers.

The issue is that after the connection to my ISP (Charter Communications) is restored, PFSense does not restore active status to the WAN link. A shutdown is required to restore connectivity.

Some details -

The WAN link is a typical DHCP via cable modem on Charter Communications network. The cable modem is a Cisco DPC310 Docsis 3 modem and is the third modem in this location in the past year. There is an issue with cabling outside the location (as in beyond the tap) that Charter keep promising to fix but has yet to do. The issue with the cabling causes noise in the cable and the TX can been seen to frequently shoot up to 57db and as soon as it hits this ceiling the modem drops out. These drop outs last on the average 2 minutes and the modem comes back online until the TX shoots beyond this limit. Wash rinse repeat this process about 5-6 times per 24 hours period. Not much I can do here until Charter get this cabling issue fixed.

So the real issue is that once the WAN connection is restored, the PFSense firewall (2.0.1 latest) does not recover or reconnect to the cable modem. I have tried to reset/restart multiple services in the WebGUI such as to release and renew the DHCP lease on the WAN interface, reset states, restart DNS forwarding, and several other services for good measure. None of this cycling brings the WAN interface back up. Here is where this gets strange. If I REBOOT the firewall and it comes back up, the WAN link is still not active. I have to SHUTDOWN the firewall and immediately restart the firewall to get the WAN link working properly.

My question is what is flushed in a shutdown/power-on that is not flushed in a reboot? And does anyone have any ideas on how I can reset the WAN link via the WebGUI without taking the time to perform a complete shutdown?

At this point, I am doing this 5 or more times per day and would love to figure out how to flush and reset necessary services to avoid having to power the computer so many times each day.

Thoughts…comments...questions appreciated!

stephenw10 · Sep 3, 2012, 11:12 AM

When you reboot the NIC may not be powered down and thus the modem may not see the link go down. It nay require this to renew the dhcp lease.
What happens if you physically remove the Ethernet cable?

Steve

freedog96150 · Sep 4, 2012, 6:47 AM

@stephenw10:

What happens if you physically remove the Ethernet cable?

I tried this tonight. I unplugged the ethernet cable, power cycled the cable modem and rebooted the pfSense firewall. No dice. I immediately halted the system, waited about 10 seconds and powered it back on and I regained full connectivity.

Ultimately, Charter Communications needs to fix their issue but I would love to know how to get my pfSense firewall to come back up automatically once the WAN link is restored. Strange.

I may just grab the latest image and do a clean install.

stephenw10 · Sep 4, 2012, 6:25 PM

Another difference between a 'warm' boot and a 'cold' boot is that the NIC may not come up in the same configuration. The initial values of the memory registers in the NIC are set to their default values at power on. The FreeBSD driver will probably then set them to some other state suitable for running. When you warm boot they may or may not be reset.
You might try a different NIC if you have one especially if it uses a different driver.

Steve

wallabybob · Sep 4, 2012, 9:13 PM

@freedog96150:

The issue is that after the connection to my ISP (Charter Communications) is restored, PFSense does not restore active status to the WAN link. A shutdown is required to restore connectivity.

I think it would be worth looking through the pfSense system log to see what dhclient is doing and reporting. If dhclient (the DHCP client program) is exiting due to not getting a response in "reasonable" time and the pfSense WAN link doesn't change state to UP then there will be nothing to kick dhclient back into action to request an IP address.

I don't recall the details (my WAN link uses PPPoE, not DHCP) but I think there was some work done a while ago to restart dhclient if it exited.

Because you might need to go back a way in the system log I suggest you use the pfSense shell command```

clog /var/log/system.log | grep dhclient

ps ax | grep dhclient

freedog96150 · Sep 4, 2012, 9:37 PM

I checked the system.log as Wallabybob recommended. Not much in there that shed any light on this issue. The only entries were from the TWO power cycles manually performed today.

Sep 4 09:12:59 firewall dhclient: RENEW
Sep 4 09:12:59 firewall dhclient: Creating resolv.conf
Sep 4 12:57:41 firewall dhclient: RENEW
Sep 4 12:57:41 firewall dhclient: Creating resolv.conf

And as to dhclient running

8960 ?? Is 0:00.01 dhclient: re0 [priv] (dhclient)
18605 ?? Ss 0:00.22 dhclient: re0 (dhclient)
2938 0 R+ 0:00.00 grep dhclient

Looks like dhclient is running.

Thanks for the info so far! Very appreciated.

stephenw10 · Sep 4, 2012, 10:28 PM

So that implies the DHCP client is not attempting to renew the lease after the WAN comes back up, only when you power cycle the machine.
Try manually disconnecting/reconnecting by whatever means and compare the logs.

Unfortunately my own connections are also PPPoE so I have no reference to compare.

Steve

dhatz · Sep 5, 2012, 12:08 AM

Check if this has any relevance to your issue: http://redmine.pfsense.org/issues/2615

freedog96150 · Sep 5, 2012, 12:39 AM

@dhatz:

Check if this has any relevance to your issue: http://redmine.pfsense.org/issues/2615

I would say this is close except that I am using 2.0.1-release and not 2.1. Maybe this issue was evident in earlier versions. I am now convinced that the issue is related to dhclient after reading posts above and some STF on keyword dhclient. I can see that others have experienced the same issue.

The plan is to do a killall -9 dhclient at the CLI next time the connection drops and comes back then simply run dhclient re0 to initiate a new instance. I would still be surprised to see this work as I am sure that a warm boot performs these very actions and I can attest that warm boots do not reconnect the WAN interface.

I assume that I have not really encountered this before as prior to this past few weeks of poor connectivity from the ISP I had experienced a reasonably long period of solid connectivity. Now that connectivity goes down upwards of 5 times per 24 hour period this issue has become evident.

dhatz · Sep 5, 2012, 12:53 AM

The behavior of dhclient has just been changed in FreeBSD just a few days ago, so dhclient under pfSense 2.1 (which is based on FreeBSD 8.3) will exhibit the same behavior as 2.0.1, unless one backports the latest dhclient version from FreeBSD-HEAD

You may want to check the discussion at FreeBSD mailing list to verify that this is indeed the issue you're seeing.

wallabybob · Sep 5, 2012, 1:01 AM

Here is an extract of dhcleint reports from an old system log showing successful dhclient lease acquisition and renewal. (From a 2.1 snapshot build but 2.0.x shouldn't be very different.)

Jul 22 06:25:27 pfsense2 dhclient[60117]: DHCPDISCOVER on vr0 to 255.255.255.255 port 67 interval 1
Jul 22 06:25:28 pfsense2 dhclient[60117]: DHCPDISCOVER on vr0 to 255.255.255.255 port 67 interval 2
Jul 22 06:25:30 pfsense2 dhclient[60117]: DHCPDISCOVER on vr0 to 255.255.255.255 port 67 interval 2
Jul 22 06:25:32 pfsense2 dhclient[60117]: DHCPDISCOVER on vr0 to 255.255.255.255 port 67 interval 5
Jul 22 06:25:37 pfsense2 dhclient[60117]: DHCPDISCOVER on vr0 to 255.255.255.255 port 67 interval 11
Jul 22 06:25:48 pfsense2 dhclient[60117]: DHCPDISCOVER on vr0 to 255.255.255.255 port 67 interval 21
Jul 22 06:25:48 pfsense2 dhclient[60117]: DHCPOFFER from 192.168.211.173
Jul 22 06:25:48 pfsense2 dhclient: ARPSEND
Jul 22 06:25:50 pfsense2 dhclient: ARPCHECK
Jul 22 06:25:50 pfsense2 dhclient[60117]: DHCPREQUEST on vr0 to 255.255.255.255 port 67
Jul 22 06:25:50 pfsense2 dhclient[60117]: DHCPACK from 192.168.211.173
Jul 22 06:25:50 pfsense2 dhclient: BOUND
Jul 22 06:25:50 pfsense2 dhclient: Starting add_new_address()
Jul 22 06:25:50 pfsense2 dhclient: ifconfig vr0 inet 192.168.211.217 netmask 255.255.255.128 broadcast 192.168.211.255
Jul 22 06:25:50 pfsense2 dhclient: New IP Address (vr0): 192.168.211.217
Jul 22 06:25:50 pfsense2 dhclient: New Subnet Mask (vr0): 255.255.255.128
Jul 22 06:25:50 pfsense2 dhclient: New Broadcast Address (vr0): 192.168.211.255
Jul 22 06:25:51 pfsense2 dhclient: New Routers (vr0): 192.168.211.173
Jul 22 06:25:51 pfsense2 dhclient: Adding new routes to interface: vr0
Jul 22 06:25:51 pfsense2 dhclient: /sbin/route add default 192.168.211.173
Jul 22 06:25:51 pfsense2 dhclient: Creating resolv.conf
Jul 22 06:25:52 pfsense2 dhclient[60117]: bound to 192.168.211.217 – renewal in 3600 seconds.
Jul 22 07:25:50 pfsense2 dhclient[60117]: DHCPREQUEST on vr0 to 192.168.211.173 port 67
Jul 22 07:25:50 pfsense2 dhclient[60117]: DHCPACK from 192.168.211.173
Jul 22 07:25:50 pfsense2 dhclient: RENEW
Jul 22 07:25:50 pfsense2 dhclient: Creating resolv.conf
Jul 22 07:25:50 pfsense2 dhclient[60117]: bound to 192.168.211.217 – renewal in 3600 seconds.
Jul 22 08:25:50 pfsense2 dhclient[60117]: DHCPREQUEST on vr0 to 192.168.211.173 port 67
Jul 22 08:25:50 pfsense2 dhclient[60117]: DHCPACK from 192.168.211.173

I would be interesting to see what is reported in your pfSense system log at around the time the link "goes out" and the modem drops offine. Is the "offline" status reported to pfSense through a transition of the WAN link state? Or only in an indicator on the modem?

freedog96150 · Sep 5, 2012, 1:16 AM

I see chatter like that on logs having to do with dhcpd but not dhclient. I will be sure to view the system logs before I do any power cycling next time. As to indications - The VOIP box is normally the first hint I have of a dropped WAN link. By the time I check the modem lights to confirm, I can normally see the same state reflected in the WebGUI. No amount of clicking on the renew button in the WebGUI resets the WAN interface.

miles267 · Nov 2, 2012, 3:19 PM

@freedog96150:

I see chatter like that on logs having to do with dhcpd but not dhclient. I will be sure to view the system logs before I do any power cycling next time. As to indications - The VOIP box is normally the first hint I have of a dropped WAN link. By the time I check the modem lights to confirm, I can normally see the same state reflected in the WebGUI. No amount of clicking on the renew button in the WebGUI resets the WAN interface.

What was your fix for this? I'm experiencing the same issue. Where nothing I appear to do from within the WebUI is truly resetting my WAN connection. My WAN does not have any connection to the internet.

Yet, if I connect my laptop directly into my cable modem I am able to get to the internet so my ISP is online and working.

Thanks!

freedog96150 · Nov 2, 2012, 4:08 PM

Miles267 I never came up with any fix nor any CLI commands that fully reset my firewall. Charter did come out and fix their wiring issues and my connectivity is much better. But when the cable modem drops out (about once a week now) the firewall does not recover. I have to actually power off the machine, power cycle the cable modem then power the machine back up and all is good. I am beginning to think this MUST be hardware, that is, network card related. I did have to replace one of the cards earlier in the year. I used what was quickly available from Newegg and the off-brand card uses the Realtek chipset. It is a cheap card, but it seemed to work. I am thinking that I need to replace with an Intel card or something that uses a different chipset such as a Broadcom or Atheros chipset before I fiddle with the firewall any further.

I did try to upgrade to the 2.1 branch, but my setup is pretty complex with various VPN tunnels, certificates, etc for client access and all of that broke during the upgrade. I finally restored back to 2.0.1 and restored my backup to regain full functionality. for me, the 2.1 branch is not ready for use.

Whatever is happening I can verify that a reboot does not restore connectivity, only a complete shutdown and cold boot does the trick.

netdragon · Feb 21, 2013, 8:36 AM

Any updates on this issue for anyone else seeing it?

I just installed pfsense a couple weeks back and have Charter and I'm seeing the same issues. A poweroff and power back on resolves the issue. Otherwise sometimes waiting a long time resolves it, and sometimes things come back up momentarily and then fail again. I have on and off connectivity to 192.168.100.1 (docsys modem) page throughout. The cable between router and modem is a manufactured cable, so I doubt it's acting up.

Let me just say that Charter tends to cause a lot of problems for me and routers, and a lot of people nearby that I know. They are a horrible ISP. I just replaced a belkin router with this pfsense firewall because of that.

In case it helps, here's the sys logs between the fail and the poweroff of the router. You can see my manual disconnect of the cable and you can see my poweroff of the cable modem which momentarily restored the connection. Ultimately, only powering off the router and powering it back on solved the issue.

To save space, I used elipses to denote repeats of previous lines for massively repeating lines.

This mystartantiphishing thing in the beginning looks provocative, but due to the time delay I don't think it's related. Anyone know what it is, though?

Feb 20 16:32:40 dnsmasq[38323]: possible DNS-rebind attack detected: mystartantiphishing.com
Feb 20 16:32:40 dnsmasq[38323]: possible DNS-rebind attack detected: mystartantiphishing.com
Feb 20 19:07:19 dnsmasq[38323]: read /etc/hosts - 11 addresses
Feb 20 19:07:19 dnsmasq[38323]: read /etc/hosts - 11 addresses
Feb 20 19:57:29 dhclient: RENEW
Feb 20 19:57:29 dhclient: Creating resolv.conf
Feb 20 21:07:19 dnsmasq[38323]: read /etc/hosts - 11 addresses

… Repeats 5 times

Feb 20 23:57:30 dhclient: RENEW
Feb 20 23:57:30 dhclient: Creating resolv.conf
Feb 20 23:59:45 dnsmasq[38323]: read /etc/hosts - 11 addresses

… Repeats 3 times

Feb 21 01:01:01 php: : DynDns: updatedns() starting
Feb 21 01:01:01 php: : DynDns debug information: 66.190.88.144 extracted from local system.
Feb 21 01:01:01 php: : DynDns: Current WAN IP: 66.190.88.144 Cached IP: 66.190.88.144
Feb 21 01:01:01 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Feb 21 01:50:48 dnsmasq[38323]: read /etc/hosts - 11 addresses
Feb 21 01:50:48 dnsmasq[38323]: read /etc/hosts - 11 addresses
Feb 21 01:57:30 dhclient: RENEW
Feb 21 01:57:30 dhclient: Creating resolv.conf
Feb 21 01:59:45 dnsmasq[38323]: read /etc/hosts - 11 addresses
Feb 21 02:57:30 dhclient: RENEW
Feb 21 02:57:30 dhclient: Creating resolv.conf

… RENEW/Creating repeats 3 times

Feb 21 06:53:21 dnsmasq[38323]: possible DNS-rebind attack detected: mystartantiphishing.com
Feb 21 06:53:21 dnsmasq[38323]: possible DNS-rebind attack detected: mystartantiphishing.com
Feb 21 06:57:32 dhclient: RENEW
Feb 21 06:57:32 dhclient: Creating resolv.conf

*** NOTICE 1 hour passes. Internet was working in between since I was using it

Feb 21 07:47:11 apinger: ALARM: WAN(66.190.88.1) *** down ***
Feb 21 07:47:21 check_reload_status: Reloading filter
Feb 21 07:58:28 check_reload_status: Linkup starting rl0
Feb 21 07:58:28 kernel: rl0: link state changed to DOWN
Feb 21 07:58:31 check_reload_status: Linkup starting rl0
Feb 21 07:58:31 kernel: rl0: link state changed to UP
Feb 21 07:58:31 php: : DEVD Ethernet detached event for wan
Feb 21 07:58:31 dhclient[6791]: connection closed
Feb 21 07:58:31 dhclient[6791]: connection closed
Feb 21 07:58:31 dhclient[6791]: exiting.
Feb 21 07:58:31 dhclient[6791]: exiting.
Feb 21 07:58:34 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 07:58:34 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 07:58:34 php: : DEVD Ethernet attached event for wan
Feb 21 07:58:34 php: : HOTPLUG: Configuring interface wan
Feb 21 07:58:34 dhclient: PREINIT
Feb 21 07:58:34 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 07:58:34 dhclient[45478]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 07:58:36 dhclient[45478]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 07:58:36 kernel: arpresolve: can't allocate llinfo for 66.190.88.1

… The four above alternate in different combinations for a while

Feb 21 07:58:52 dhclient[45478]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 2
Feb 21 07:58:52 dhclient[45478]: DHCPOFFER from 10.232.0.1
Feb 21 07:58:52 dhclient: ARPSEND
Feb 21 07:58:54 dhclient: ARPCHECK
Feb 21 07:58:54 dhclient[45478]: DHCPREQUEST on rl0 to 255.255.255.255 port 67

… Repeats 3 times

Feb 21 07:59:08 dhclient[45478]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 1
Feb 21 07:59:09 dhclient[45478]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 1
Feb 21 07:59:10 dhclient[45478]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 2

… Repeats about 5 times, interval changes

Feb 21 07:59:31 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 07:59:31 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 07:59:41 dhclient[45478]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 13
Feb 21 07:59:42 kernel: arpresolve: can't allocate llinfo for 66.190.88.1

… Repeats 3 times

Feb 21 07:59:54 dhclient[45478]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 15
Feb 21 08:00:09 dhclient[45478]: No DHCPOFFERS received.
Feb 21 08:00:09 dhclient[45478]: Trying recorded lease 66.190.88.144
Feb 21 08:00:09 dhclient: TIMEOUT
Feb 21 08:00:09 dhclient: Starting add_new_address()
Feb 21 08:00:09 dhclient: ifconfig rl0 inet 66.190.88.144 netmask 255.255.248.0 broadcast 255.255.255.255
Feb 21 08:00:09 dhclient: New IP Address (rl0): 66.190.88.144
Feb 21 08:00:09 dhclient: New Subnet Mask (rl0): 255.255.248.0
Feb 21 08:00:09 dhclient: New Broadcast Address (rl0): 255.255.255.255
Feb 21 08:00:09 dhclient: New Routers (rl0): 66.190.88.1
Feb 21 08:00:10 dhclient: New Routers (rl0): 66.190.88.1
Feb 21 08:00:21 dhclient: Deleting old routes
Feb 21 08:00:21 dhclient[45478]: bound: immediate renewal.
Feb 21 08:00:21 dhclient[45478]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:00:21 dhclient[18938]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:00:21 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 08:00:21 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 08:00:26 dhclient[18938]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:00:26 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 08:00:34 dhclient[18938]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:00:34 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 08:00:46 dhclient[18938]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:00:46 kernel: arpresolve: can't allocate llinfo for 66.190.88.1

… The two above repeats about 20 times

Feb 21 08:05:20 kernel: rl0: link state changed to DOWN
Feb 21 08:05:20 check_reload_status: Linkup starting rl0
Feb 21 08:05:24 php: : DEVD Ethernet detached event for wan
Feb 21 08:05:24 dhclient[45495]: connection closed
Feb 21 08:05:24 dhclient[45495]: connection closed
Feb 21 08:05:24 dhclient[45495]: exiting.
Feb 21 08:05:24 dhclient[45495]: exiting.
Feb 21 08:05:44 check_reload_status: Linkup starting rl0
Feb 21 08:05:44 kernel: rl0: link state changed to UP
Feb 21 08:05:47 php: : DEVD Ethernet attached event for wan
Feb 21 08:05:47 php: : HOTPLUG: Configuring interface wan
Feb 21 08:05:47 dhclient: PREINIT
Feb 21 08:05:47 dhclient[13418]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:05:48 dhclient[13418]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:05:49 dhclient[13418]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:05:49 dhclient[13418]: DHCPNAK from 192.168.100.1
Feb 21 08:05:49 dhclient[13418]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 1
Feb 21 08:05:49 dhclient[13418]: DHCPOFFER from 192.168.100.1
Feb 21 08:05:49 dhclient: ARPSEND
Feb 21 08:05:51 dhclient: ARPCHECK
Feb 21 08:05:51 dhclient[13418]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:05:52 dhclient[13418]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:05:53 dhclient[13418]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:05:54 dhclient[13418]: DHCPACK from 192.168.100.1
Feb 21 08:05:54 dhclient: BOUND
Feb 21 08:05:54 dhclient: Starting add_new_address()
Feb 21 08:05:54 dhclient: ifconfig rl0 inet 192.168.100.10 netmask 255.255.255.0 broadcast 192.168.100.255
Feb 21 08:05:54 dhclient: New IP Address (rl0): 192.168.100.10
Feb 21 08:05:54 dhclient: New Subnet Mask (rl0): 255.255.255.0
Feb 21 08:05:54 dhclient: New Broadcast Address (rl0): 192.168.100.255
Feb 21 08:05:54 dhclient: New Routers (rl0): 192.168.100.1
Feb 21 08:05:54 dhclient: Adding new routes to interface: rl0
Feb 21 08:05:54 dhclient: /sbin/route add default 192.168.100.1
Feb 21 08:05:54 dhclient: Creating resolv.conf
Feb 21 08:05:54 check_reload_status: rc.newwanip starting rl0
Feb 21 08:05:54 dhclient[13418]: bound to 192.168.100.10 – renewal in 30 seconds.
Feb 21 08:05:58 php: : rc.newwanip: Informational is starting rl0.
Feb 21 08:05:58 php: : rc.newwanip: on (IP address: 192.168.100.10) (interface: wan) (real interface: rl0).
Feb 21 08:05:58 php: : ROUTING: setting default route to 192.168.100.1
Feb 21 08:05:58 apinger: Exiting on signal 15.
Feb 21 08:05:59 apinger: Starting Alarm Pinger, apinger(28139)
Feb 21 08:05:59 php: : DynDns: updatedns() starting
Feb 21 08:05:59 check_reload_status: Reloading filter
Feb 21 08:06:02 dnsmasq[38323]: reading /etc/resolv.conf
Feb 21 08:06:02 dnsmasq[38323]: ignoring nameserver 127.0.0.1 - local interface
Feb 21 08:06:02 dnsmasq[38323]: ignoring nameserver 127.0.0.1 - local interface
Feb 21 08:06:04 php: : Dyndns debug information: Could not resolve checkip.dyndns.org to ip using interface ip 192.168.100.10.
Feb 21 08:06:04 php: : DynDns: Current WAN IP could not be determined, skipping update process.
Feb 21 08:06:04 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Feb 21 08:06:10 php: : Resyncing OpenVPN instances for interface WAN.
Feb 21 08:06:11 kernel: ovpns1: link state changed to DOWN
Feb 21 08:06:11 check_reload_status: Reloading filter
Feb 21 08:06:11 php: : Creating rrd update script
Feb 21 08:06:11 kernel: ovpns1: link state changed to UP
Feb 21 08:06:11 php: : pfSense package system has detected an ip change 66.190.88.144 -> … Restarting packages.
Feb 21 08:06:11 check_reload_status: Starting packages
Feb 21 08:06:11 check_reload_status: rc.newwanip starting ovpns1
Feb 21 08:06:12 ntpdate[7880]: can't find host 0.pfsense.pool.ntp.org
Feb 21 08:06:12 ntpdate[7880]: no servers can be used, exiting
Feb 21 08:06:14 check_reload_status: Linkup starting rl0
Feb 21 08:06:14 kernel: rl0: link state changed to DOWN
Feb 21 08:06:15 php: : Restarting/Starting all packages.
Feb 21 08:06:16 check_reload_status: Linkup starting rl0
Feb 21 08:06:16 kernel: rl0: link state changed to UP
Feb 21 08:06:17 kernel: rl0: link state changed to DOWN
Feb 21 08:06:18 php: : DEVD Ethernet detached event for wan
Feb 21 08:06:18 dhclient[13595]: connection closed
Feb 21 08:06:18 dhclient[13595]: connection closed
Feb 21 08:06:18 dhclient[13595]: exiting.
Feb 21 08:06:18 dhclient[13595]: exiting.
Feb 21 08:06:18 ntpdate[20297]: can't find host 0.pfsense.pool.ntp.org
Feb 21 08:06:18 ntpdate[20297]: no servers can be used, exiting
Feb 21 08:06:19 php: : DEVD Ethernet attached event for wan
Feb 21 08:06:19 php: : HOTPLUG: Configuring interface wan
Feb 21 08:06:22 php: : rc.newwanip: Informational is starting ovpns1.
Feb 21 08:06:22 php: : rc.newwanip: on (IP address: 192.168.170.1) (interface: ) (real interface: ovpns1).
Feb 21 08:06:22 check_reload_status: Reloading filter
Feb 21 08:06:22 php: : pfSense package system has detected an ip change -> … Restarting packages.
Feb 21 08:06:22 check_reload_status: Starting packages
Feb 21 08:06:23 ntpdate[28434]: can't find host 0.pfsense.pool.ntp.org
Feb 21 08:06:23 ntpdate[28434]: no servers can be used, exiting
Feb 21 08:06:27 php: : Restarting/Starting all packages.
Feb 21 08:06:27 apinger: ALARM: WAN(192.168.100.1) *** down ***
Feb 21 08:06:29 ntpdate[35480]: can't find host 0.pfsense.pool.ntp.org
Feb 21 08:06:29 ntpdate[35480]: no servers can be used, exiting
Feb 21 08:06:29 check_reload_status: Linkup starting rl0
Feb 21 08:06:29 kernel: rl0: link state changed to UP
Feb 21 08:06:29 dhclient: PREINIT
Feb 21 08:06:29 dhclient[26110]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:06:30 dhclient[26110]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 2
Feb 21 08:06:31 dhclient[26110]: DHCPOFFER from 10.232.0.1
Feb 21 08:06:31 dhclient: ARPSEND
Feb 21 08:06:32 php: : DEVD Ethernet attached event for wan
Feb 21 08:06:32 php: : HOTPLUG: Configuring interface wan
Feb 21 08:06:33 dhclient: PREINIT
Feb 21 08:06:33 dhclient: ARPCHECK
Feb 21 08:06:33 dhclient[26110]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:06:33 dhclient[41851]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:06:35 dhclient[26110]: DHCPACK from 10.232.0.1
Feb 21 08:06:35 dhclient: BOUND
Feb 21 08:06:35 dhclient[41851]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:06:35 dhclient: Deleting old routes
Feb 21 08:06:35 dhclient: Starting add_new_address()
Feb 21 08:06:35 dhclient: ifconfig rl0 inet 71.92.48.139 netmask 255.255.252.0 broadcast 255.255.255.255
Feb 21 08:06:35 dhclient: New IP Address (rl0): 71.92.48.139
Feb 21 08:06:35 dhclient: New Subnet Mask (rl0): 255.255.252.0
Feb 21 08:06:35 dhclient: New Broadcast Address (rl0): 255.255.255.255
Feb 21 08:06:35 dhclient: New Routers (rl0): 71.92.48.1
Feb 21 08:06:35 dhclient: Adding new routes to interface: rl0
Feb 21 08:06:35 dhclient: /sbin/route add default 71.92.48.1
Feb 21 08:06:35 dhclient: Creating resolv.conf
Feb 21 08:06:35 dhclient[26110]: bound to 71.92.48.139 – renewal in 1800 seconds.
Feb 21 08:06:35 check_reload_status: rc.newwanip starting rl0
Feb 21 08:06:35 ntpdate[50810]: can't find host 0.pfsense.pool.ntp.org
Feb 21 08:06:35 ntpdate[50810]: no servers can be used, exiting
Feb 21 08:06:37 dhclient[41851]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:06:37 check_reload_status: Reloading filter
Feb 21 08:06:38 php: : rc.newwanip: Informational is starting rl0.
Feb 21 08:06:38 php: : rc.newwanip: on (IP address: 71.92.48.139) (interface: wan) (real interface: rl0).
Feb 21 08:06:38 php: : ROUTING: setting default route to 71.92.48.1
Feb 21 08:06:38 apinger: Exiting on signal 15.
Feb 21 08:06:39 apinger: Starting Alarm Pinger, apinger(56290)
Feb 21 08:06:39 php: : DynDns: updatedns() starting
Feb 21 08:06:40 php: : DynDns debug information: 71.92.48.139 extracted from local system.
Feb 21 08:06:40 php: : DynDns: Current WAN IP: 71.92.48.139 Cached IP: 66.190.88.144
Feb 21 08:06:40 php: : DynDns debug information: DynDns: cacheIP != wan_ip. Updating. Cached IP: 66.190.88.144 WAN IP: 71.92.48.139
Feb 21 08:06:40 php: : DynDns: DynDns _update() starting.
Feb 21 08:06:40 dnsmasq[38323]: reading /etc/resolv.conf
Feb 21 08:06:40 dnsmasq[38323]: using nameserver 24.217.201.67#53
Feb 21 08:06:40 dnsmasq[38323]: using nameserver 71.92.29.130#53
Feb 21 08:06:40 dnsmasq[38323]: using nameserver 97.81.22.195#53
Feb 21 08:06:40 dnsmasq[38323]: ignoring nameserver 127.0.0.1 - local interface
Feb 21 08:06:40 dnsmasq[38323]: ignoring nameserver 127.0.0.1 - local interface
Feb 21 08:06:40 ntp: Giving up on time sync after 3 attempts.
Feb 21 08:06:41 dhclient[41851]: DHCPREQUEST on rl0 to 255.255.255.255 port 67
Feb 21 08:06:45 php: : DynDns: DynDns _checkStatus() starting.
Feb 21 08:06:45 php: : DynDns: Current Service: dyndns
Feb 21 08:06:45 php: : DynDns debug information: 71.92.48.139 extracted from local system.
Feb 21 08:06:45 php: : phpDynDNS: updating cache file /conf/dyndns_wandyndns'thenetdragon.dnsalias.net'.cache: 71.92.48.139
Feb 21 08:06:45 php: : phpDynDNS: (Success) IP Address Changed Successfully! (71.92.48.139)
Feb 21 08:06:51 php: : Resyncing OpenVPN instances for interface WAN.
Feb 21 08:06:51 kernel: ovpns1: link state changed to DOWN
Feb 21 08:06:51 check_reload_status: Reloading filter
Feb 21 08:06:51 php: : Creating rrd update script
Feb 21 08:06:51 kernel: ovpns1: link state changed to UP
Feb 21 08:06:51 php: : pfSense package system has detected an ip change 192.168.100.10 -> … Restarting packages.
Feb 21 08:06:51 check_reload_status: Starting packages
Feb 21 08:06:52 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 1
Feb 21 08:06:52 check_reload_status: rc.newwanip starting ovpns1
Feb 21 08:06:53 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 2
Feb 21 08:06:54 ntpdate[34894]: adjust time server 108.61.73.243 offset -0.001538 sec
Feb 21 08:06:55 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 3
Feb 21 08:06:56 php: : Restarting/Starting all packages.
Feb 21 08:06:56 php: : rc.newwanip: Informational is starting ovpns1.
Feb 21 08:06:56 php: : rc.newwanip: on (IP address: 192.168.170.1) (interface: ) (real interface: ovpns1).
Feb 21 08:06:56 php: : pfSense package system has detected an ip change -> … Restarting packages.
Feb 21 08:06:58 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 4
Feb 21 08:06:58 ntpdate[47171]: adjust time server 108.61.73.243 offset 0.000278 sec
Feb 21 08:07:02 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 11
Feb 21 08:07:13 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 21
Feb 21 08:07:34 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 12
Feb 21 08:07:39 apinger: Error while feeding rrdtool: Broken pipe
Feb 21 08:07:46 dhclient[41851]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 7
Feb 21 08:07:53 dhclient[41851]: No DHCPOFFERS received.
Feb 21 08:07:53 dhclient[41851]: Trying recorded lease 66.190.88.144
Feb 21 08:07:53 dhclient: TIMEOUT
Feb 21 08:07:53 dhclient: Starting add_new_address()
Feb 21 08:07:53 dhclient: ifconfig rl0 inet 66.190.88.144 netmask 255.255.248.0 broadcast 255.255.255.255
Feb 21 08:07:53 dhclient[50735]: My address (71.92.48.139) was deleted, dhclient exiting
Feb 21 08:07:53 dhclient[50735]: My address (71.92.48.139) was deleted, dhclient exiting
Feb 21 08:07:53 dhclient: FAIL
Feb 21 08:07:53 dhclient[36068]: connection closed
Feb 21 08:07:53 dhclient[36068]: connection closed
Feb 21 08:07:53 dhclient[36068]: exiting.
Feb 21 08:07:53 dhclient[36068]: exiting.
Feb 21 08:07:53 dhclient: New IP Address (rl0): 66.190.88.144
Feb 21 08:07:53 dhclient: New Subnet Mask (rl0): 255.255.248.0
Feb 21 08:07:53 dhclient: New Broadcast Address (rl0): 255.255.255.255
Feb 21 08:07:53 dhclient: New Routers (rl0): 66.190.88.1
Feb 21 08:07:54 dhclient: New Routers (rl0): 66.190.88.1
Feb 21 08:08:01 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:02 kernel: arpresolve: can't allocate llinfo for 71.92.48.1

… Repeats dozens of times

Feb 21 08:08:03 apinger: ALARM: WAN(71.92.48.1) *** down ***
Feb 21 08:08:04 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:04 kernel: arpresolve: can't allocate llinfo for 71.92.48.1

... Repeats dozens of times

Feb 21 08:08:05 dhclient: Deleting old routes
Feb 21 08:08:05 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:05 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:05 dhclient[41851]: bound: immediate renewal.
Feb 21 08:08:05 dhclient[41851]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:05 dhclient[41851]: send_packet: No route to host
Feb 21 08:08:05 dhclient[41851]: send_packet: No route to host
Feb 21 08:08:05 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:05 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:05 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:05 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:06 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:06 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:06 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:06 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:06 kernel: arpresolve: can't allocate llinfo for 71.92.48.1

… Repeats 9 times

Feb 21 08:08:08 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:08 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:08 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:08 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:09 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:09 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:09 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:10 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:10 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:10 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:10 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:10 kernel: arpresolve: can't allocate llinfo for 71.92.48.1

… Repeats 9 times

Feb 21 08:08:13 check_reload_status: Reloading filter
Feb 21 08:08:14 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:14 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:14 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:14 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:14 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:16 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:18 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:18 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:18 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:23 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:23 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:23 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:23 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:23 kernel: arpresolve: can't allocate llinfo for 71.92.48.1

… Repeats 4 times

Feb 21 08:08:30 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:30 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:30 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:32 kernel: arpresolve: can't allocate llinfo for 71.92.48.1

… Repeats 4 times

Feb 21 08:08:39 apinger: rrdtool respawning too fast, waiting 300s.
Feb 21 08:08:42 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:08:44 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:44 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:44 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:51 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:09:01 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:09:03 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:09:03 dhclient[63516]: send_packet: No route to host
Feb 21 08:09:03 dhclient[63516]: send_packet: No route to host
Feb 21 08:09:26 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:09:26 dhclient[63516]: send_packet: No route to host
Feb 21 08:09:26 dhclient[63516]: send_packet: No route to host
Feb 21 08:09:48 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:09:48 dhclient[63516]: send_packet: No route to host
Feb 21 08:09:48 dhclient[63516]: send_packet: No route to host

… The above 3 messages repeat a few more times

Feb 21 08:10:18 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:10:19 kernel: arpresolve: can't allocate llinfo for 71.92.48.1

... Repeats 9 times

Feb 21 08:10:26 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:10:26 dhclient[63516]: send_packet: No route to host
Feb 21 08:10:26 dhclient[63516]: send_packet: No route to host
Feb 21 08:10:28 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:10:31 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:10:37 kernel: arpresolve: can't allocate llinfo for 71.92.48.1
Feb 21 08:10:58 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:10:58 dhclient[63516]: send_packet: No route to host
Feb 21 08:10:58 dhclient[63516]: send_packet: No route to host
Feb 21 08:11:32 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:11:32 dhclient[63516]: send_packet: No route to host
Feb 21 08:11:32 dhclient[63516]: send_packet: No route to host
Feb 21 08:11:41 syslogd: exiting on signal 15
Feb 21 08:13:13 syslogd: kernel boot file is /boot/kernel/kernel
Feb 21 08:13:13 kernel: Copyright 1992-2010 The FreeBSD Project.
Feb 21 08:13:13 kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Feb 21 08:13:13 kernel: The Regents of the University of California. All rights reserved.
Feb 21 08:13:13 kernel: FreeBSD is a registered trademark of The FreeBSD Foundation.
Feb 21 08:13:13 kernel: FreeBSD 8.1-RELEASE-p13 #0: Fri Dec 7 16:51:57 EST 2012

wallabybob · Feb 21, 2013, 10:39 AM

@netdragon:

This mystartantiphishing thing in the beginning looks provocative, but due to the time delay I don't think it's related. Anyone know what it is, though?

I also don't think the DNS-rebind has anything to do with the WAN problem. A search of the pfSense forums for "DNS-rebind attack" might turn up an explanation of this message.

@netdragon:

Feb 21 07:47:11 apinger: ALARM: WAN(66.190.88.1) *** down ***

The gateway (next system between you and the Internet) has stopped responding.

@netdragon:

Feb 21 07:58:34 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 07:58:34 kernel: arpresolve: can't allocate llinfo for 66.190.88.1

I suspect something is trying to access 66.190.88.1 (your previous gateway). Since this is 11 minutes after the gateway was declared down I think it is unlikely to be apinger. The interval is long enough for the ARP cache to have expired and I expect there is no interface with an address such that 66.190.88.1 is on the same network, which would make to difficult to send the ARP can't be sent. But something seems to have a memory that the system HAD an address on the same network, else the datagram destined to 66.190.88.1 should be dropped (no route) or sent to the defult gateway (but there probably isn't a default gateway).

@netdragon:

Feb 21 07:58:34 php: : DEVD Ethernet attached event for wan
Feb 21 07:58:34 php: : HOTPLUG: Configuring interface wan
Feb 21 07:58:34 dhclient: PREINIT
Feb 21 07:58:34 kernel: arpresolve: can't allocate llinfo for 66.190.88.1
Feb 21 07:58:34 dhclient[45478]: DHCPREQUEST on rl0 to 255.255.255.255 port 67

Looks like the WAN interface has come "UP" again.

@netdragon:

Feb 21 08:00:09 dhclient[45478]: No DHCPOFFERS received.
Feb 21 08:00:09 dhclient[45478]: Trying recorded lease 66.190.88.144

Looks like dhclient didn't receive a "valid" DHCP offer to its going to attempt to reuse its previous lease (which presumably hasn't yet expired).

@netdragon:

Feb 21 08:05:54 dhclient[13418]: bound to 192.168.100.10 – renewal in 30 seconds.

Looks like the WAN link to the modem is now "UP" but the the lease is for a private address (192.168.x.x) and the lease time is short (30 secs). Probably this is a lDHCP lease from the modem.

@netdragon:

Feb 21 08:06:04 php: : Dyndns debug information: Could not resolve checkip.dyndns.org to ip using interface ip 192.168.100.10.

Since the DHCP lease apparently came from the modem, that suggests the modem can't see "upstream" so DNS names can't be resolved to addresses (unless you have a suitable override in DNS forwarder!)

@netdragon:

Feb 21 08:06:35 dhclient: ifconfig rl0 inet 71.92.48.139 netmask 255.255.252.0 broadcast 255.255.255.255

Now dhclient has been allocated a public IP address

@netdragon:

Feb 21 08:06:35 dhclient[26110]: bound to 71.92.48.139 – renewal in 1800 seconds.

and with a reasonable lease time.

@netdragon:

Feb 21 08:06:37 dhclient[41851]: DHCPREQUEST on rl0 to 255.255.255.255 port 67

Note the pid of this dhclient (41851) is different from the pid of the previously reporting dhclient. Are there now two active dhclients on rl0?

@netdragon:

Feb 21 08:06:41 dhclient[41851]: DHCPREQUEST on rl0 to 255.255.255.255 port 67

That second dhclient is still running.

@netdragon:

Feb 21 08:07:53 dhclient[41851]: Trying recorded lease 66.190.88.144

Now it looks like that spurious dhclient is going to mess with the system.

@netdragon:

Feb 21 08:07:53 dhclient[50735]: My address (71.92.48.139) was deleted, dhclient exiting

Where did this dhclient with a new pid come from?

@netdragon:

Feb 21 08:08:05 dhclient[41851]: bound: immediate renewal.
Feb 21 08:08:05 dhclient[41851]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:05 dhclient[41851]: send_packet: No route to host
Feb 21 08:08:05 dhclient[41851]: send_packet: No route to host
Feb 21 08:08:05 dhclient[63516]: DHCPREQUEST on rl0 to 68.114.38.210 port 67
Feb 21 08:08:05 dhclient[63516]: send_packet: No route to host
Feb 21 08:08:05 dhclient[63516]: send_packet: No route to host

This looks very wrong, yet another dhclient trying to get a lease! And two dhclients concurrently requesting a lease!

Thanks for posting the log. The multiple dhclients requesting on the same interface concurrently doesn't look right to me.

stephenw10 · Feb 21, 2013, 11:19 PM

I know there has been some work done recently on DHCP WAN connections not renewing correctly.
What version are you running?

Perhaps try either the 2.0.3 or 2.1 snapshots that will have these recent changes.

http://snapshots.pfsense.org/

Looks like the 2.0.3 snapshots have disappeared. It should be released shortly though.

Steve

Edit: This is what I had in mind: https://redmine.pfsense.org/issues/2792
Looks like it may not be related though.

bogomips · Mar 6, 2013, 11:48 AM

I'm experiencing this behavior too on 2.0.2 but also previous versions (unfortunately I don't remember when it first appear), the main configuration is still the same though (except for rules obviously).

The modem is queried via dhcp, after a modem reboot the pfsense dashboard show the wan's ip address as 0.0.0.0, to regain an up and running internet connection I just need to go into the wan properties and click the save button and then confirm changes to have the wan back.

I haven't searched the dhcp logs yet because free time is hard to find and the situation is not critical.

priller · Mar 8, 2013, 3:12 PM

I'm seeing the same problem. When the cable goes out and the modem reboots, pfsense is not recovering when the dhcp address changes from the modem's internal dhcp 192.168.100.x address to the network one.

Not sure how relevant it is, but I found the timing of the two "system has detected an ip change" restarting messages interesting.

Note that at 07:19:06 the public IP has been acquired and packages restart. Then 1 second later, there is another restart triggered by a 'false' change back to the cable modem issued address.

At this point, I can't pass traffic and just reboot the whole thing.

Is this even relevant? Possibly some kind of timing issue? I've used everything from Cisco ASA's to Mikrotik and consumer routers and have never experienced this type of problem.

07:19:09 php: : Restarting/Starting all packages.
07:19:07 php: : pfSense package system has detected an ip change 69.31.172.170 -> 192.168.100.10 … Restarting packages.
07:19:06 php: : pfSense package system has detected an ip change 192.168.100.10 -> 69.31.172.170 ... Restarting packages.

07:18:43 check_reload_status: rc.newwanip starting re1
07:18:43 dhclient: ifconfig re1 inet 69.31.172.170 netmask 255.255.255.0 broadcast 255.255.255.255
07:18:43 dhclient[30792]: DHCPACK from 73.199.197.1
07:18:16 dhclient[30792]: DHCPDISCOVER on re1 to 255.255.255.255 port 67 interval 2

07:17:46 dhclient[21057]: bound to 192.168.100.10 – renewal in 30 seconds.
07:17:46 dhclient: ifconfig re1 inet 192.168.100.10 netmask 255.255.255.0 broadcast 192.168.100.255
07:17:46 dhclient[21057]: DHCPREQUEST on re1 to 255.255.255.255 port 67

–-

2.1-BETA1 (amd64)
built on Sun Mar 3 22:04:59 EST 2013
FreeBSD 8.3-RELEASE-p6

Paul47 · Mar 10, 2013, 12:38 AM

DHCP was created for admin convenience, but all this thrashing about does not look very convenient! :) Maybe it's time for at least some of you to go back to old-fashioned static addresses?