4. Issues with WAN Gateway

Issues with WAN Gateway

  • S

    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>
    0
  • Rebel Alliance Developer Netgate

    It looks like dhclient just stopped. When you lose connectivity, is dhclient running at all? (check ps uxawww | grep dhclient)

    0
  • Rebel Alliance Developer Netgate

    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.

    0
  • Rebel Alliance Developer Netgate

    Do you happen to have any virtual IPs configured on that interface, by chance?

    0
  • S

    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.

    0
  • S

    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 dhclient

    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 if that's an indication of anything else.

    0
  • W

    @sinicide:

    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?

    0
  • S

    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.

    0
  • Rebel Alliance Developer Netgate

    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.

    0
  • S

    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
    0
  • Rebel Alliance Developer Netgate

    Are you sure that's everything? I don't see any messages logged from dhclient about it stopping/exiting, just starting.

    0
  • S

    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:
    0
  • Rebel Alliance Developer Netgate

    I think I have narrowed this down between this thread and another similar one:
    https://redmine.pfsense.org/issues/2792

    0
  • S

    Thanks Jimp. I guess I'll keep an eye on this bug to see if/when it gets fixed.

    0
  • Rebel Alliance Developer Netgate

    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.

    0
  • S

    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.

    0
  • Rebel Alliance Developer Netgate

    The "prerelease" images of 2.0.3 are snapshots. If yours isn't dated yesterday or today, you don't have the fix.

    0
  • S

    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.

    0
  • Rebel Alliance Developer Netgate

    It may have been in the snapshot just after you updated, it's still worth updating and checking again.

    0
  • T

    @jimp:

    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?

    0
  • Rebel Alliance Developer Netgate

    The fix mentioned earlier in the thread did. It's possible you're hitting a different error/condition that the previous fix didn't correct. Probably best to start a fresh thread.

    0
  • T

    Ok, I'll have to wait until tonight so I can grab the full log.
    (It was in the middle of occuring when I tried to login to verify the namecheap dns settings for the other topic >.< )

    0
Log in to reply
 

Products

Services

Support

News

Resources

Company

Our Mission

We provide leading-edge network security at a fair price - regardless of organizational size or network sophistication. We believe that an open-source security model offers disruptive pricing along with the agility required to quickly address emerging threats.

Subscribe to our Newsletter

Product information, software announcements, and special offers. See our newsletter archive for past announcements.

© Copyright 2019 Rubicon Communications, LLC | Privacy Policy