Issues with WAN Gateway
-
So I've been experiencing some issues with my pfsense box over the past month, specifically with the WAN gateway. Now This did not use to happen when I was on 2.0 i386 a few months back but ever since upgrading to 2.0.2 and 2.0.3, it has not been working correctly at all. I've even done a few fresh installs again hoping it was some bad upgrades.
What seems to happen is that every so often the WAN gateway loses connection to the internet. I've ruled out bad hardware, because I've switched Gateway NICs and the issue's still persist. I've ruled out the Modem, because I've setup a WRT54G router before my pfsense and that was still able to ping the internet. I'm almost ruling out the fact that I'm using realtek NICs as well, because it was working fine months ago. But now I'm constantly having this issue.
From checking the forums I'm coming to the conclusion that when the Modem IP's lease time refreshes, pfsense doesn't properly handle this and that's when it loses it's connection to the internet.
Rebooting solves the issue, or release and renewing the Gateway IP also solves the issue, which leads me to believe the above.
I currently have a cronjob in place to check for being unable to ping on the wan interface and will bounce the Gateway if it can't ping google, but I'm hoping to find the root of this issue.
Any ideas or what else I should do to troubleshoot?
I'm attaching the logs from last night as it looks like it went down a few times.
Jan 29 05:19:46 dnsmasq[33393]: ignoring nameserver 127.0.0.1 - local interface Jan 29 05:19:46 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:46 apinger: Starting Alarm Pinger, apinger(19694) Jan 29 05:19:46 check_reload_status: Reloading filter Jan 29 05:19:46 php: : DynDns: updatedns() starting Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:47 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:48 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:49 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:50 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:51 check_reload_status: Linkup starting rl0 Jan 29 05:19:51 kernel: rl0: link state changed to DOWN Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:52 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:53 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 php: : DEVD Ethernet detached event for wan Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 dhclient[52763]: connection closed Jan 29 05:19:54 dhclient[52763]: connection closed Jan 29 05:19:54 dhclient[52763]: exiting. Jan 29 05:19:54 dhclient[52763]: exiting. Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:54 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: Failed to get IP for interface rl0 Jan 29 05:19:55 miniupnpd[200]: Failed to get IP for interface rl0 Jan 29 05:19:55 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: cannot get public IP address, stopping Jan 29 05:19:55 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: cannot get public IP address, stopping Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:19:55 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:55 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:55 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:55 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:55 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:55 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:55 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:56 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:57 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:57 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:57 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:57 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:58 kernel: arpresolve: can't allocate llinfo for 72.225.16.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:19:59 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:00 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:01 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:01 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:01 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:01 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:01 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:01 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:01 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:02 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:03 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:03 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:03 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:03 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:03 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:03 check_reload_status: Linkup starting rl0 Jan 29 05:20:03 kernel: rl0: link state changed to UP Jan 29 05:20:04 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:04 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:04 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:04 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:06 php: : DEVD Ethernet attached event for wan Jan 29 05:20:06 php: : HOTPLUG: Configuring interface wan Jan 29 05:20:06 dhclient: PREINIT Jan 29 05:20:06 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 29 05:20:06 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 29 05:20:06 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:06 check_reload_status: Reloading filter Jan 29 05:20:06 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 Jan 29 05:20:07 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:08 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:09 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:09 php: : Dyndns debug information: Could not resolve checkip.dyndns.org to ip using interface ip 192.168.100.10. Jan 29 05:20:09 php: : DynDns: Current WAN IP could not be determined, skipping update process. Jan 29 05:20:09 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 29 05:20:10 php: : DynDns: updatedns() starting Jan 29 05:20:10 php: : Dyndns debug information: Could not resolve checkip.dyndns.org to ip using interface ip 192.168.100.10. Jan 29 05:20:10 php: : DynDns: Current WAN IP could not be determined, skipping update process. Jan 29 05:20:10 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 29 05:20:11 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:13 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:16 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:16 php: : Resyncing OpenVPN instances for interface WAN. Jan 29 05:20:16 kernel: ovpns1: link state changed to DOWN Jan 29 05:20:16 check_reload_status: Reloading filter Jan 29 05:20:16 php: : Creating rrd update script Jan 29 05:20:17 php: : pfSense package system has detected an ip change 72.225.22.218 -> ... Restarting packages. Jan 29 05:20:17 check_reload_status: Starting packages Jan 29 05:20:18 ntpdate[57866]: can't find host 0.north-america.pool.ntp.org Jan 29 05:20:18 ntpdate[57866]: can't find host 1.north-america.pool.ntp.org Jan 29 05:20:18 ntpdate[57866]: can't find host 2.north-america.pool.ntp.org Jan 29 05:20:18 ntpdate[57866]: can't find host 3.north-america.pool.ntp.org Jan 29 05:20:18 ntpdate[57866]: no servers can be used, exiting Jan 29 05:20:19 php: : Restarting/Starting all packages. Jan 29 05:20:21 dhclient[24656]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 2 Jan 29 05:20:23 dhclient[24656]: DHCPDISCOVER on rl0 to 255.255.255.255 port 67 interval 5 Jan 29 05:20:23 dhclient[24656]: DHCPOFFER from 10.243.128.1 Jan 29 05:20:23 dhclient: ARPSEND Jan 29 05:20:24 ntpdate[1791]: can't find host 0.north-america.pool.ntp.org Jan 29 05:20:24 ntpdate[1791]: can't find host 1.north-america.pool.ntp.org Jan 29 05:20:24 ntpdate[1791]: can't find host 2.north-america.pool.ntp.org Jan 29 05:20:24 ntpdate[1791]: can't find host 3.north-america.pool.ntp.org Jan 29 05:20:24 ntpdate[1791]: no servers can be used, exiting Jan 29 05:20:25 dhclient: ARPCHECK Jan 29 05:20:25 dhclient[24656]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 29 05:20:25 dhclient[24656]: DHCPACK from 10.243.128.1 Jan 29 05:20:25 dhclient: BOUND Jan 29 05:20:25 dhclient: Deleting old routes Jan 29 05:20:25 dhclient: Starting add_new_address() Jan 29 05:20:25 dhclient: ifconfig rl0 inet 72.225.22.218 netmask 255.255.248.0 broadcast 255.255.255.255 Jan 29 05:20:25 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:20:25 miniupnpd[200]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Jan 29 05:20:25 miniupnpd[200]: Failed to get IP for interface rl0 Jan 29 05:20:25 miniupnpd[200]: Failed to get IP for interface rl0 Jan 29 05:20:25 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: cannot get public IP address, stopping Jan 29 05:20:25 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: cannot get public IP address, stopping Jan 29 05:20:25 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 29 05:20:25 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 29 05:20:25 dhclient: New IP Address (rl0): 72.225.22.218 Jan 29 05:20:25 dhclient: New Subnet Mask (rl0): 255.255.248.0 Jan 29 05:20:25 dhclient: New Broadcast Address (rl0): 255.255.255.255 Jan 29 05:20:25 dhclient: New Routers (rl0): 72.225.16.1 Jan 29 05:20:25 dhclient: Adding new routes to interface: rl0 Jan 29 05:20:25 dhclient: /sbin/route add default 72.225.16.1 Jan 29 05:20:25 dhclient: Creating resolv.conf Jan 29 05:20:25 check_reload_status: rc.newwanip starting rl0 Jan 29 05:20:25 dhclient[24656]: bound to 72.225.22.218 -- renewal in 19742 seconds. Jan 29 05:20:25 kernel: rl1: promiscuous mode disabled Jan 29 05:20:27 php: : rc.newwanip: Informational is starting rl0. Jan 29 05:20:27 php: : rc.newwanip: on (IP address: 72.225.22.218) (interface: wan) (real interface: rl0). Jan 29 05:20:28 kernel: rl1: promiscuous mode enabled Jan 29 05:20:28 php: : ROUTING: setting default route to 72.225.16.1 Jan 29 05:20:28 php: : Removing static route for monitor 8.8.8.8 and adding a new route through 72.225.16.1 Jan 29 05:20:28 apinger: Exiting on signal 15. Jan 29 05:20:28 php: : Not calling package sync code for dependency squidreverse of squid3 because some include files are missing. Jan 29 05:20:29 dnsmasq[33393]: reading /etc/resolv.conf Jan 29 05:20:29 dnsmasq[33393]: using nameserver 8.8.4.4#53 Jan 29 05:20:29 dnsmasq[33393]: using nameserver 8.8.8.8#53 Jan 29 05:20:29 dnsmasq[33393]: ignoring nameserver 127.0.0.1 - local interface Jan 29 05:20:29 dnsmasq[33393]: ignoring nameserver 127.0.0.1 - local interface Jan 29 05:20:29 check_reload_status: Reloading filter Jan 29 05:20:29 php: : DynDns: updatedns() starting Jan 29 05:20:29 php: : DynDns debug information: 72.225.22.218 extracted from local system. Jan 29 05:20:29 php: : DynDns: Current WAN IP: 72.225.22.218 Cached IP: 72.225.22.218 Jan 29 05:20:29 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 29 05:20:29 apinger: Starting Alarm Pinger, apinger(15130) Jan 29 05:20:30 php: : DynDns: updatedns() starting Jan 29 05:20:30 php: : DynDns debug information: 72.225.22.218 extracted from local system. Jan 29 05:20:30 php: : DynDns: Current WAN IP: 72.225.22.218 Cached IP: 72.225.22.218 Jan 29 05:20:30 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 29 05:20:30 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:30 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:32 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:34 ntpdate[16282]: adjust time server 63.251.89.141 offset -0.015391 sec Jan 29 05:20:35 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:36 php: : Resyncing OpenVPN instances for interface WAN. Jan 29 05:20:36 php: : Creating rrd update script Jan 29 05:20:36 php: : pfSense package system has detected an ip change 192.168.100.10 -> ... Restarting packages. Jan 29 05:20:36 kernel: ovpns1: link state changed to UP Jan 29 05:20:36 check_reload_status: Starting packages Jan 29 05:20:36 check_reload_status: rc.newwanip starting ovpns1 Jan 29 05:20:38 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:38 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:38 radiusd[4432]: Loaded virtual server <default> Jan 29 05:20:38 radiusd[5046]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:38 radiusd[5046]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:38 php: : Restarting/Starting all packages. Jan 29 05:20:39 php: : rc.newwanip: Informational is starting ovpns1. Jan 29 05:20:39 php: : rc.newwanip: on (IP address: 10.0.8.1) (interface: ) (real interface: ovpns1). Jan 29 05:20:39 php: : pfSense package system has detected an ip change -> ... Restarting packages. Jan 29 05:20:40 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:42 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:42 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:42 radiusd[35589]: Loaded virtual server <default> Jan 29 05:20:42 radiusd[35909]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:42 radiusd[35909]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:43 ntpdate[22957]: adjust time server 63.251.89.141 offset -0.009081 sec Jan 29 05:20:44 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:45 kernel: rl1: promiscuous mode disabled Jan 29 05:20:46 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:47 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:47 kernel: rl1: promiscuous mode enabled Jan 29 05:20:47 radiusd[50351]: Loaded virtual server <default> Jan 29 05:20:47 radiusd[50418]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:47 radiusd[50418]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:47 php: : Not calling package sync code for dependency squidreverse of squid3 because some include files are missing. Jan 29 05:20:49 radiusd[55372]: Loaded virtual server <default> Jan 29 05:20:49 radiusd[55645]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:49 radiusd[55645]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:49 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:49 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:51 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:54 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:55 radiusd[22468]: Loaded virtual server <default> Jan 29 05:20:55 radiusd[22860]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:55 radiusd[22860]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:56 radiusd[25969]: Loaded virtual server <default> Jan 29 05:20:56 radiusd[27146]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:56 radiusd[27146]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:20:56 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:56 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:20:58 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:21:00 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:21:02 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:21:05 php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Jan 29 05:21:07 radiusd[62413]: Loaded virtual server <default> Jan 29 05:21:07 radiusd[62638]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:21:07 radiusd[62638]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:21:13 radiusd[9264]: Loaded virtual server <default> Jan 29 05:21:13 radiusd[10374]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:21:13 radiusd[10374]: The server is not configured to listen on any ports. Cannot start. Jan 29 05:21:29 apinger: Error while feeding rrdtool: Broken pipe Jan 29 05:22:29 apinger: rrdtool respawning too fast, waiting 300s. Jan 29 05:47:34 apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 29 05:47:44 check_reload_status: Reloading filter Jan 29 05:49:07 dhclient[10006]: My address (72.225.22.218) was deleted, dhclient exiting Jan 29 05:49:07 dhclient[10006]: My address (72.225.22.218) was deleted, dhclient exiting Jan 29 05:49:07 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 05:49:07 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 05:49:07 dhclient: FAIL Jan 29 05:49:07 dhclient[24725]: connection closed Jan 29 05:49:07 dhclient[24725]: connection closed Jan 29 05:49:07 dhclient[24725]: exiting. Jan 29 05:49:07 dhclient[24725]: exiting. Jan 29 05:49:17 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 05:49:17 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 05:49:18 apinger: alarm canceled: WAN(8.8.8.8) *** down *** Jan 29 05:49:28 check_reload_status: Reloading filter Jan 29 07:48:58 apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 29 07:49:08 check_reload_status: Reloading filter Jan 29 07:52:07 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 07:52:07 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 07:52:17 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 07:52:17 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 07:52:18 apinger: alarm canceled: WAN(8.8.8.8) *** down *** Jan 29 07:52:28 check_reload_status: Reloading filter Jan 29 08:39:45 miniupnpd[200]: upnp_event_send: send(): Broken pipe Jan 29 08:39:45 miniupnpd[200]: upnp_event_send: send(): Broken pipe Jan 29 10:48:36 dnsmasq[33393]: failed to send packet: Host is down Jan 29 10:48:36 dnsmasq[33393]: failed to send packet: Host is down Jan 29 10:48:36 dnsmasq[33393]: failed to send packet: Host is down Jan 29 10:48:36 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:01:19 apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 29 11:01:29 check_reload_status: Reloading filter Jan 29 11:04:07 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 11:04:07 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 11:04:17 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 11:04:17 miniupnpd[200]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): Network is down Jan 29 11:04:18 apinger: alarm canceled: WAN(8.8.8.8) *** down *** Jan 29 11:04:28 check_reload_status: Reloading filter Jan 29 11:30:07 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:07 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:10 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:10 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:12 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:12 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:15 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:15 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:17 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:17 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:20 dnsmasq[33393]: failed to send packet: Host is down Jan 29 11:30:20 dnsmasq[33393]: failed to send packet: Host is down</default></default></default></default></default></default></default></default> -
It looks like dhclient just stopped. When you lose connectivity, is dhclient running at all? (check ps uxawww | grep dhclient)
-
I'd say the real problem is here:
Jan 29 05:47:34 apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 29 05:47:44 check_reload_status: Reloading filter Jan 29 05:49:07 dhclient[10006]: My address (72.225.22.218) was deleted, dhclient exiting Jan 29 05:49:07 dhclient[10006]: My address (72.225.22.218) was deleted, dhclient exiting Jan 29 05:49:07 dhclient: FAIL Jan 29 05:49:07 dhclient[24725]: connection closed Jan 29 05:49:07 dhclient[24725]: connection closed Jan 29 05:49:07 dhclient[24725]: exiting. Jan 29 05:49:07 dhclient[24725]: exiting.There isn't any indication exactly what happened to delete that IP, but the previous log message from check_reload_status was over a minute before so it isn't likely from that.
Something must have removed the IP, as the only way I can replicate that error message is by manually removing the IP from the interface with ifconfig.
-
Do you happen to have any virtual IPs configured on that interface, by chance?
-
Hey Jimp, that's for helping me with this.
In that instance, I might have Released and Renewed the IP manually from the Interface Panel.
Also to answer your question about Virtual IPs, I do not currently have any configured on Pfsense.
I'll have to check if the dhclient is running when it happens again.
-
So it just happened again.
[2.0.3-PRERELEASE][root@pfsense.sin.local]/root(2): ps uxawww | grep dhclient root 13998 0.0 0.1 1848 856 0 RL+ 1:24AM 0:00.00 grep dhclientAlso another thing that happens when the WAN connection goes down is that the pfsense router site takes a long time to load. Not sure if that's an indication of anything else.
-
Also another thing that happens when the WAN connection goes down is that the pfsense router site takes a long time to load.
Not sure what you mean by "pfSense router site". You mean it takes a "long" time to get response to an access attempt to your pfSense web GUI?
How long is "long"? 10 seconds? 10 minutes? And when does the clock for this start and end?
-
Yeah, I meant the Web UI, I don't know why I couldn't think of that word. lol
Loading the login page for the WebUI is quick and I can login quick. But just loading the any page after logging in takes 10-20 seconds. It doesn't time out, but there is a very noticible delay, when I go from the Dashboard page to the Interface Page to release and renew my WAN. This slow down only happens when I've lost connection on my WAN Gateway.
-
When dhclient stopped, what was in the system log around it?
If you don't have WAN connectivity some parts of the GUI will be slow because it can't reach DNS servers.
-
This is what I grab around that time from the system logs around that time.
Jan 31 00:40:55 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 00:41:05 pfsense check_reload_status: Reloading filter Jan 31 00:41:27 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 00:41:37 pfsense check_reload_status: Reloading filter Jan 31 00:43:00 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 00:43:10 pfsense check_reload_status: Reloading filter Jan 31 00:43:36 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 00:43:46 pfsense check_reload_status: Reloading filter Jan 31 00:44:51 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 00:45:00 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 00:45:01 pfsense check_reload_status: Reloading filter Jan 31 00:51:31 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 00:51:41 pfsense check_reload_status: Reloading filter Jan 31 00:52:07 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 00:52:17 pfsense check_reload_status: Reloading filter Jan 31 00:52:29 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 00:52:39 pfsense check_reload_status: Reloading filter Jan 31 00:53:33 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 00:53:43 pfsense check_reload_status: Reloading filter Jan 31 00:54:32 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 00:54:42 pfsense check_reload_status: Reloading filter Jan 31 00:55:49 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 00:55:59 pfsense check_reload_status: Reloading filter Jan 31 01:01:01 pfsense php: : DynDns: updatedns() starting Jan 31 01:01:01 pfsense php: : DynDns debug information: 74.67.172.72 extracted from local system. Jan 31 01:01:01 pfsense php: : DynDns: Current WAN IP: 74.67.172.72 Cached IP: 74.67.172.72 Jan 31 01:01:01 pfsense php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 31 01:01:01 pfsense php: : DynDns: updatedns() starting Jan 31 01:01:01 pfsense php: : DynDns debug information: 74.67.172.72 extracted from local system. Jan 31 01:01:01 pfsense php: : DynDns: Current WAN IP: 74.67.172.72 Cached IP: 74.67.172.72 Jan 31 01:01:01 pfsense php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 31 01:01:02 pfsense php: : DynDns: updatedns() starting Jan 31 01:01:02 pfsense php: : DynDns debug information: 74.67.172.72 extracted from local system. Jan 31 01:01:02 pfsense php: : DynDns: Current WAN IP: 74.67.172.72 Cached IP: 74.67.172.72 Jan 31 01:01:02 pfsense php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 31 01:01:02 pfsense php: : DynDns: updatedns() starting Jan 31 01:01:02 pfsense php: : DynDns debug information: 74.67.172.72 extracted from local system. Jan 31 01:01:02 pfsense php: : DynDns: Current WAN IP: 74.67.172.72 Cached IP: 74.67.172.72 Jan 31 01:01:02 pfsense php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Jan 31 01:05:31 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:05:41 pfsense check_reload_status: Reloading filter Jan 31 01:06:03 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:06:13 pfsense check_reload_status: Reloading filter Jan 31 01:06:24 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:06:34 pfsense check_reload_status: Reloading filter Jan 31 01:07:28 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:07:38 pfsense check_reload_status: Reloading filter Jan 31 01:07:51 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:08:01 pfsense check_reload_status: Reloading filter Jan 31 01:08:14 pfsense apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 31 01:08:24 pfsense check_reload_status: Reloading filter Jan 31 01:23:08 pfsense sshd[19381]: error: PAM: authentication error for root from 192.168.70.201 Jan 31 01:23:08 pfsense sshd[19381]: error: PAM: authentication error for root from 192.168.70.201 Jan 31 01:23:11 pfsense sshd[19381]: Accepted keyboard-interactive/pam for root from 192.168.70.201 port 55504 ssh2 Jan 31 01:27:19 pfsense dhclient: PREINIT Jan 31 01:27:19 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:19 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:19 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:19 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:19 pfsense dhclient[39038]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 31 01:27:20 pfsense dhclient[39038]: DHCPREQUEST on rl0 to 255.255.255.255 port 67 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:20 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172.1 Jan 31 01:27:21 pfsense dhclient[39038]: DHCPACK from 10.243.128.1 Jan 31 01:27:21 pfsense dhclient: REBOOT Jan 31 01:27:21 pfsense dhclient: Starting add_new_address() Jan 31 01:27:21 pfsense dhclient: ifconfig rl0 inet 74.67.172.72 netmask 255.255.254.0 broadcast 255.255.255.255 Jan 31 01:27:21 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:21 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:21 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:21 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Jan 31 01:27:21 pfsense dhclient: New IP Address (rl0): 74.67.172.72 Jan 31 01:27:21 pfsense dhclient: New Subnet Mask (rl0): 255.255.254.0 Jan 31 01:27:21 pfsense dhclient: New Broadcast Address (rl0): 255.255.255.255 Jan 31 01:27:21 pfsense dhclient: New Routers (rl0): 74.67.172.1 Jan 31 01:27:21 pfsense dhclient: Adding new routes to interface: rl0 Jan 31 01:27:21 pfsense dhclient: /sbin/route add default 74.67.172.1 Jan 31 01:27:21 pfsense dhclient: Creating resolv.conf Jan 31 01:27:21 pfsense check_reload_status: rc.newwanip starting rl0 Jan 31 01:27:21 pfsense dhclient[39038]: bound to 74.67.172.72 -- renewal in 13527 seconds. Jan 31 01:27:22 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** down *** Jan 31 01:27:23 pfsense php: : rc.newwanip: Informational is starting rl0. Jan 31 01:27:23 pfsense php: : rc.newwanip: on (IP address: 74.67.172.72) (interface: wan) (real interface: rl0). Jan 31 01:27:23 pfsense php: : ROUTING: setting default route to 74.67.172.1 Jan 31 01:27:23 pfsense php: : Removing static route for monitor 8.8.8.8 and adding a new route through 74.67.172.1 Jan 31 01:27:23 pfsense apinger: Exiting on signal 15. Jan 31 01:27:23 pfsense check_reload_status: Reloading filter Jan 31 01:27:24 pfsense dnsmasq[48840]: reading /etc/resolv.conf Jan 31 01:27:24 pfsense dnsmasq[48840]: using nameserver 8.8.4.4#53 Jan 31 01:27:24 pfsense dnsmasq[48840]: using nameserver 8.8.8.8#53 Jan 31 01:27:24 pfsense dnsmasq[48840]: ignoring nameserver 127.0.0.1 - local interface Jan 31 01:27:24 pfsense dnsmasq[48840]: ignoring nameserver 127.0.0.1 - local interface Jan 31 01:27:24 pfsense apinger: Starting Alarm Pinger, apinger(49039) Jan 31 01:27:57 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:28:07 pfsense check_reload_status: Reloading filter Jan 31 01:28:24 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:28:34 pfsense check_reload_status: Reloading filter Jan 31 01:28:47 pfsense apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 31 01:28:57 pfsense check_reload_status: Reloading filter Jan 31 01:30:51 pfsense check_reload_status: Syncing firewall Jan 31 01:32:27 pfsense php: /index.php: XMLRPC communication error: php_network_getaddresses: getaddrinfo failed: hostname nor servname provide d, or not known -
Are you sure that's everything? I don't see any messages logged from dhclient about it stopping/exiting, just starting.
-
Here is more. By the end of it, I either manually rebooted or my reboot script kicked in.
Jan 31 01:32:44 pfsense dhclient[39268]: connection closed Jan 31 01:32:44 pfsense dhclient[39268]: connection closed Jan 31 01:32:44 pfsense dhclient[39268]: exiting. Jan 31 01:32:44 pfsense dhclient[39268]: exiting. Jan 31 01:32:45 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:45 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:46 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:46 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:46 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:46 pfsense dhclient: PREINIT Jan 31 01:32:46 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 01:32:46 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 01:32:46 pfsense dhclient[54206]: DHCPREQUEST on rl0 to 255.255.255.255 p ort 67 Jan 31 01:32:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 01:32:47 pfsense dhclient[54206]: DHCPACK from 10.243.128.1 Jan 31 01:32:47 pfsense dhclient: REBOOT Jan 31 01:32:47 pfsense dhclient: Starting add_new_address() Jan 31 01:32:47 pfsense dhclient: ifconfig rl0 inet 74.67.172.72 netmask 255.255 .254.0 broadcast 255.255.255.255 Jan 31 01:32:47 pfsense miniupnpd[1378]: ioctl(s, SIOCGIFADDR, ...): Can't assig n requested address Jan 31 01:32:47 pfsense miniupnpd[1378]: ioctl(s, SIOCGIFADDR, ...): Can't assig n requested address Jan 31 01:32:47 pfsense miniupnpd[1378]: Failed to get IP for interface rl0 Jan 31 01:32:47 pfsense miniupnpd[1378]: Failed to get IP for interface rl0 Jan 31 01:32:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: cannot get public IP address, stopping Jan 31 01:32:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: cannot get public IP address, stopping Jan 31 01:32:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 01:32:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 01:32:47 pfsense dhclient: New IP Address (rl0): 74.67.172.72 Jan 31 01:32:47 pfsense dhclient: New Subnet Mask (rl0): 255.255.254.0 Jan 31 01:32:47 pfsense dhclient: New Broadcast Address (rl0): 255.255.255.255 Jan 31 01:32:47 pfsense dhclient: New Routers (rl0): 74.67.172.1 Jan 31 01:32:47 pfsense dhclient: Adding new routes to interface: rl0 Jan 31 01:32:47 pfsense dhclient: /sbin/route add default 74.67.172.1 Jan 31 01:32:47 pfsense dhclient: Creating resolv.conf Jan 31 01:32:47 pfsense check_reload_status: rc.newwanip starting rl0 Jan 31 01:32:48 pfsense dhclient[54206]: bound to 74.67.172.72 -- renewal in 133 64 seconds. Jan 31 01:32:49 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** down *** Jan 31 01:32:50 pfsense php: : rc.newwanip: Informational is starting rl0. Jan 31 01:32:50 pfsense php: : rc.newwanip: on (IP address: 74.67.172.72) (inter face: wan) (real interface: rl0). Jan 31 01:32:50 pfsense php: : ROUTING: setting default route to 74.67.172.1 Jan 31 01:32:50 pfsense php: : Removing static route for monitor 8.8.8.8 and add ing a new route through 74.67.172.1 Jan 31 01:32:50 pfsense apinger: Exiting on signal 15. Jan 31 01:32:50 pfsense check_reload_status: Reloading filter Jan 31 01:32:50 pfsense dnsmasq[48840]: reading /etc/resolv.conf Jan 31 01:32:50 pfsense dnsmasq[48840]: using nameserver 8.8.4.4#53 Jan 31 01:32:50 pfsense dnsmasq[48840]: using nameserver 8.8.8.8#53 Jan 31 01:32:50 pfsense dnsmasq[48840]: ignoring nameserver 127.0.0.1 - local in terface Jan 31 01:32:50 pfsense dnsmasq[48840]: ignoring nameserver 127.0.0.1 - local in terface Jan 31 01:32:51 pfsense apinger: Starting Alarm Pinger, apinger(2003) Jan 31 01:33:36 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:33:46 pfsense check_reload_status: Reloading filter Jan 31 01:33:51 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:34:01 pfsense check_reload_status: Reloading filter Jan 31 01:43:46 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:43:56 pfsense check_reload_status: Reloading filter Jan 31 01:43:59 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:44:09 pfsense check_reload_status: Reloading filter Jan 31 01:47:16 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:47:26 pfsense check_reload_status: Reloading filter Jan 31 01:47:36 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:47:46 pfsense check_reload_status: Reloading filter Jan 31 01:51:08 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:51:18 pfsense check_reload_status: Reloading filter Jan 31 01:52:12 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:52:22 pfsense check_reload_status: Reloading filter Jan 31 01:52:34 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:52:44 pfsense check_reload_status: Reloading filter Jan 31 01:53:01 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:53:11 pfsense check_reload_status: Reloading filter Jan 31 01:53:33 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:53:42 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:53:43 pfsense check_reload_status: Reloading filter Jan 31 01:54:17 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:54:27 pfsense check_reload_status: Reloading filter Jan 31 01:54:29 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:54:39 pfsense check_reload_status: Reloading filter Jan 31 01:54:53 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 01:55:03 pfsense check_reload_status: Reloading filter Jan 31 01:55:06 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 01:55:16 pfsense check_reload_status: Reloading filter Jan 31 02:01:55 pfsense apinger: ALARM: WAN(8.8.8.8) *** delay *** Jan 31 02:02:05 pfsense check_reload_status: Reloading filter Jan 31 02:02:16 pfsense apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 31 02:02:26 pfsense check_reload_status: Reloading filter Jan 31 02:02:49 pfsense php: /index.php: Successful webConfigurator login for us er 'admin' from 192.168.70.203 Jan 31 02:02:49 pfsense php: /index.php: Successful webConfigurator login for us er 'admin' from 192.168.70.203 Jan 31 02:03:03 pfsense sshd[29025]: Accepted keyboard-interactive/pam for root from 192.168.70.203 port 52152 ssh2 Jan 31 02:04:19 pfsense dhclient[60861]: My address (74.67.172.72) was deleted, dhclient exiting Jan 31 02:04:19 pfsense dhclient[60861]: My address (74.67.172.72) was deleted, dhclient exiting Jan 31 02:04:19 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): Network is down Jan 31 02:04:19 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): Network is down Jan 31 02:04:19 pfsense dhclient: FAIL Jan 31 02:04:19 pfsense dhclient[54382]: connection closed Jan 31 02:04:19 pfsense dhclient[54382]: connection closed Jan 31 02:04:19 pfsense dhclient[54382]: exiting. Jan 31 02:04:19 pfsense dhclient[54382]: exiting. Jan 31 02:04:19 pfsense dhclient[54382]: exiting. Jan 31 02:04:30 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** down *** Jan 31 02:04:40 pfsense check_reload_status: Reloading filter Jan 31 02:05:06 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** delay *** Jan 31 02:05:16 pfsense check_reload_status: Reloading filter Jan 31 02:05:28 pfsense apinger: ALARM: WAN(8.8.8.8) *** down *** Jan 31 02:05:38 pfsense check_reload_status: Reloading filter Jan 31 02:06:46 pfsense dhclient: PREINIT Jan 31 02:06:46 pfsense miniupnpd[1378]: ioctl(s, SIOCGIFADDR, ...): Can't assig n requested address Jan 31 02:06:46 pfsense miniupnpd[1378]: ioctl(s, SIOCGIFADDR, ...): Can't assig n requested address Jan 31 02:06:46 pfsense miniupnpd[1378]: Failed to get IP for interface rl0 Jan 31 02:06:46 pfsense miniupnpd[1378]: Failed to get IP for interface rl0 Jan 31 02:06:46 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: cannot get public IP address, stopping Jan 31 02:06:46 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: cannot get public IP address, stopping Jan 31 02:06:46 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 02:06:46 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 02:06:46 pfsense dhclient[17897]: DHCPREQUEST on rl0 to 255.255.255.255 p ort 67 Jan 31 02:06:46 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 02:06:46 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 02:06:47 pfsense dhclient[17897]: DHCPREQUEST on rl0 to 255.255.255.255 p ort 67 Jan 31 02:06:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 02:06:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 02:06:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 02:06:47 pfsense kernel: arpresolve: can't allocate llinfo for 74.67.172. 1 Jan 31 02:06:47 pfsense dhclient[17897]: DHCPACK from 10.243.128.1 Jan 31 02:06:47 pfsense dhclient: REBOOT Jan 31 02:06:47 pfsense dhclient: Starting add_new_address() Jan 31 02:06:47 pfsense dhclient: ifconfig rl0 inet 74.67.172.72 netmask 255.255 .254.0 broadcast 255.255.255.255 Jan 31 02:06:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 02:06:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 02:06:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 02:06:47 pfsense miniupnpd[1378]: SendNATPMPPublicAddressChangeNotificati on: sendto(s_udp=14): No route to host Jan 31 02:06:47 pfsense dhclient: New IP Address (rl0): 74.67.172.72 Jan 31 02:06:47 pfsense dhclient: New Subnet Mask (rl0): 255.255.254.0 Jan 31 02:06:47 pfsense dhclient: New Broadcast Address (rl0): 255.255.255.255 Jan 31 02:06:47 pfsense dhclient: New Routers (rl0): 74.67.172.1 Jan 31 02:06:47 pfsense dhclient: Adding new routes to interface: rl0 Jan 31 02:06:47 pfsense dhclient: /sbin/route add default 74.67.172.1 Jan 31 02:06:47 pfsense dhclient: Creating resolv.conf Jan 31 02:06:47 pfsense check_reload_status: rc.newwanip starting rl0 Jan 31 02:06:47 pfsense dhclient[17897]: bound to 74.67.172.72 -- renewal in 123 44 seconds. Jan 31 02:06:48 pfsense apinger: alarm canceled: WAN(8.8.8.8) *** down *** Jan 31 02:06:48 pfsense shutdown: reboot by root: -
I think I have narrowed this down between this thread and another similar one:
https://redmine.pfsense.org/issues/2792 -
Thanks Jimp. I guess I'll keep an eye on this bug to see if/when it gets fixed.
-
There is a potential fix in 2.0.3 and 2.1 snapshots for this now, so it's worth a try to upgrade and see if it works.
-
Well I'm already on the 2.0.3 Pre-release since I thought that might help my situation, I may try the 2.1 beta at some point over the weekend to see how it fairs.
-
The "prerelease" images of 2.0.3 are snapshots. If yours isn't dated yesterday or today, you don't have the fix.
-
I applied the latest one from Feb 6th last night and still had issues. (http://snapshots.pfsense.org/FreeBSD_RELENG_8_1/i386/pfSense_RELENG_2_0/updates/) unless that is not the correct update link?
I came home and checked the system log and found two instances in which the issue still occurred.
-
It may have been in the snapshot just after you updated, it's still worth updating and checking again.
-
It may have been in the snapshot just after you updated, it's still worth updating and checking again.
I didn't want to create a new topic for this, but I'm having the exact same problem in 2.0.3-RELEASE
(same scenario, same symptoms)
Did the bug fix not make it into the release version?
Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.