DHCP on WAN suddenly started failing
-
Well I'm pretty sure the time of failure was 8 am and the snippet I pasted you was the output from tail, thus the most recent. However given that it is the first thing in the morning I may be mistaken about it actually working.
Here are some other noteworthy logs I saw:
Jan 31 02:52:23 pfsense kernel: rl1: link state changed to DOWN
Jan 31 02:52:23 pfsense check_reload_status: Linkup starting rl1Jan 31 02:52:24 pfsense php: : DEVD Ethernet attached event for wan
Jan 31 02:52:24 pfsense php: : HOTPLUG: Configuring interface wanJan 31 02:52:24 pfsense check_reload_status: Reloading filter
Jan 31 02:52:25 pfsense kernel: rl1: link state changed to UP
Jan 31 02:52:25 pfsense dhclient: PREINITJan 31 02:52:25 pfsense dhclient[21193]: DHCPREQUEST on rl1 to 255.255.255.255 port 67
Jan 31 02:52:26 pfsense dhclient[21193]: DHCPREQUEST on rl1 to 255.255.255.255 port 67Jan 31 02:52:30 pfsense dhclient[21193]: DHCPREQUEST on rl1 to 255.255.255.255 port 67
Jan 31 02:52:30 pfsense php: : DEVD Ethernet detached event for wan
Jan 31 02:52:30 pfsense dhclient[21722]: connection closed
Jan 31 02:52:30 pfsense dhclient[21722]: connection closed
Jan 31 02:52:30 pfsense dhclient[21722]: exiting.
Jan 31 02:52:30 pfsense dhclient[21722]: exiting.
Jan 31 02:52:30 pfsense php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf rl1 > /tmp/rl1_output > /tmp/rl1_error_output' returned exit code '15', the output was ''Note that I have omitted the lines from arpresolve only.
-
And here are the details from ifconfig, so you can see which interface is what:
rl0: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500
options=8 <vlan_mtu>ether 00:01:c0:03:dc:77
inet 192.168.0.254 netmask 0xffffff00 broadcast 192.168.0.255
inet6 fe80::201:c0ff:fe03:dc77%rl0 prefixlen 64 scopeid 0x1
nd6 options=43 <performnud,accept_rtadv>media: Ethernet autoselect (100baseTX <full-duplex>)
status: active
rl1: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500
options=8 <vlan_mtu>ether 00:01:c0:03:d3:dc
inet6 fe80::201:c0ff:fe03:d3dc%rl1 prefixlen 64 scopeid 0x2
inet 72.208.12.250 netmask 0xfffff800 broadcast 72.208.15.255
nd6 options=43 <performnud,accept_rtadv>media: Ethernet autoselect (100baseTX <full-duplex>)
status: active</full-duplex></performnud,accept_rtadv></vlan_mtu></up,broadcast,running,simplex,multicast></full-duplex></performnud,accept_rtadv></vlan_mtu></up,broadcast,running,simplex,multicast> -
Odd that if you look at the log, it appears that the devd events are reversed for what they should be.
Jan 31 02:52:23 pfsense kernel: rl1: link state changed to DOWN Jan 31 02:52:24 pfsense php: : DEVD Ethernet attached event for wan Jan 31 02:52:24 pfsense php: : HOTPLUG: Configuring interface wan Jan 31 02:52:25 pfsense kernel: rl1: link state changed to UP Jan 31 02:52:30 pfsense php: : DEVD Ethernet detached event for wan
Though when I test that on my VM with em NICs, it gets it right.
Can you watch the log and see if when you unplug the NIC it does the same thing each time?
When you unplug it should log an "ethernet detached" event.
When you plug it in, it should log an "ethernet attached" event. -
It's happening to me as well on 2.0.3 (just as it is on 2.1). Log below is in reverse time order:
Feb 3 11:19:21 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:14 kernel: em0: link state changed to UP Feb 3 11:19:14 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' Feb 3 11:19:14 dhclient[40067]: exiting. Feb 3 11:19:14 dhclient[40067]: exiting. Feb 3 11:19:14 dhclient[40067]: connection closed Feb 3 11:19:14 dhclient[40067]: connection closed Feb 3 11:19:14 php: : DEVD Ethernet detached event for wan Feb 3 11:19:12 kernel: em0: link state changed to DOWN Feb 3 11:19:12 check_reload_status: Linkup starting em0 Feb 3 11:19:12 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:19:10 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 Feb 3 11:19:10 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:10 dhclient: PREINIT Feb 3 11:19:10 php: : HOTPLUG: Configuring interface wan Feb 3 11:19:10 php: : DEVD Ethernet attached event for wan
-
I suspect @swinn:
Feb 3 11:19:14 kernel: em0: link state changed to UP
should have triggered a restart of dhclient. There is no sign of that happening, but that might be because you didn't show enough of the log file.
Because the previous incarnation of dhclient exited and dhclient (apparently) wasn't restarted it appears there is no running dhclient to issue a DHCP request for configuration.
MAYBE there are too many link state transitions in too short a period.
-
Here is the log from the time the interface went down to the time I logged in and pressed the renew dhcp button. This is in reverse order again:
Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:13:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 14:13:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:06:46 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 14:06:46 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:12 miniupnpd[53901]: upnp_event_send: send(): Broken pipe Feb 3 13:52:12 miniupnpd[53901]: upnp_event_send: send(): Broken pipe Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:51:03 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 13:51:03 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 13:51:02 kernel: em0: link state changed to UP Feb 3 13:51:02 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' Feb 3 13:51:02 dhclient[50586]: exiting. Feb 3 13:51:02 dhclient[50586]: exiting. Feb 3 13:51:02 dhclient[50586]: connection closed Feb 3 13:51:02 dhclient[50586]: connection closed Feb 3 13:51:02 php: : DEVD Ethernet detached event for wan Feb 3 13:51:00 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 13:50:59 kernel: em0: link state changed to DOWN Feb 3 13:50:59 check_reload_status: Linkup starting em0 Feb 3 13:50:59 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 13:50:58 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 13:50:57 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 13:50:57 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 13:50:57 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 13:50:57 dhclient: PREINIT Feb 3 13:50:57 php: : HOTPLUG: Configuring interface wan Feb 3 13:50:57 php: : DEVD Ethernet attached event for wan Feb 3 13:50:55 kernel: em0: link state changed to UP Feb 3 13:50:55 check_reload_status: Linkup starting em0 Feb 3 13:50:44 php: : DEVD Ethernet detached event for wan Feb 3 13:50:42 kernel: em0: link state changed to DOWN Feb 3 13:50:42 check_reload_status: Linkup starting em0 Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:38:45 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 13:38:45 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 13:38:33 dnsmasq[37297]: read /etc/hosts - 21 addresses Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:32:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 13:32:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:36:14 dnsmasq[37297]: read /etc/hosts - 21 addresses Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerSpamhausEDrop does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerBluetackDShield does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerBluetackHijacked does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerZeusBlocklist does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerDShieldAttackers does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerSpamhausDrop does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerTopSpammers does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerEurope does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerAsia does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerAfrica does not need updated. Feb 3 12:30:54 php: : /etc/rc.update_urltables: Starting URL table alias updates Feb 3 12:30:00 php: : /etc/rc.update_urltables: Sleeping for 54 seconds. Feb 3 12:30:00 php: : /etc/rc.update_urltables: Starting up. Feb 3 12:28:19 miniupnpd[53901]: HTTP Connection closed unexpectedly Feb 3 12:28:19 miniupnpd[53901]: HTTP Connection closed unexpectedly Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:47:31 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:47:31 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:47:30 kernel: em0: link state changed to UP Feb 3 11:47:30 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' Feb 3 11:47:30 dhclient[21788]: exiting. Feb 3 11:47:30 dhclient[21788]: exiting. Feb 3 11:47:30 dhclient[21788]: connection closed Feb 3 11:47:30 dhclient[21788]: connection closed Feb 3 11:47:30 php: : DEVD Ethernet detached event for wan Feb 3 11:47:29 dhclient[21773]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:47:28 kernel: em0: link state changed to DOWN Feb 3 11:47:28 check_reload_status: Linkup starting em0 Feb 3 11:47:27 dhclient[21773]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:47:26 dhclient[21773]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:47:26 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:47:26 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:47:26 dhclient: PREINIT Feb 3 11:47:26 php: : HOTPLUG: Configuring interface wan Feb 3 11:47:26 php: : DEVD Ethernet attached event for wan Feb 3 11:47:23 kernel: em0: link state changed to UP Feb 3 11:47:23 check_reload_status: Linkup starting em0 Feb 3 11:47:12 php: : DEVD Ethernet detached event for wan Feb 3 11:47:10 kernel: em0: link state changed to DOWN Feb 3 11:47:10 check_reload_status: Linkup starting em0 Feb 3 11:36:38 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:36:38 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:30:21 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:30:21 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:30:20 kernel: em0: link state changed to UP Feb 3 11:30:20 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' Feb 3 11:30:20 dhclient[32235]: exiting. Feb 3 11:30:20 dhclient[32235]: exiting. Feb 3 11:30:20 dhclient[32235]: connection closed Feb 3 11:30:20 dhclient[32235]: connection closed Feb 3 11:30:20 php: : DEVD Ethernet detached event for wan Feb 3 11:30:19 dhclient[31973]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:30:18 kernel: em0: link state changed to DOWN Feb 3 11:30:18 check_reload_status: Linkup starting em0 Feb 3 11:30:17 dhclient[31973]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:30:16 dhclient[31973]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:30:16 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:30:16 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:30:16 dhclient: PREINIT Feb 3 11:30:16 php: : HOTPLUG: Configuring interface wan Feb 3 11:30:16 php: : DEVD Ethernet attached event for wan Feb 3 11:30:13 kernel: em0: link state changed to UP Feb 3 11:30:13 check_reload_status: Linkup starting em0 Feb 3 11:30:03 php: : DEVD Ethernet detached event for wan Feb 3 11:30:00 kernel: em0: link state changed to DOWN Feb 3 11:30:00 check_reload_status: Linkup starting em0 Feb 3 11:25:20 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:24:16 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:23:12 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:22:35 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:22:32 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:22:32 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:22:31 dnsmasq[37297]: read /etc/hosts - 20 addresses Feb 3 11:22:08 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:21:47 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:21:04 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:21:03 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:21:03 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:21:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:21:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:20:59 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:20:14 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:20:11 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:20:10 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:50 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:49 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:36 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:30 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:30 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:26 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:23 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:23 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:22 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:21 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:21 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:21 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:21 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:21 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:21 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:14 kernel: em0: link state changed to UP Feb 3 11:19:14 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' Feb 3 11:19:14 dhclient[40067]: exiting. Feb 3 11:19:14 dhclient[40067]: exiting. Feb 3 11:19:14 dhclient[40067]: connection closed Feb 3 11:19:14 dhclient[40067]: connection closed Feb 3 11:19:14 php: : DEVD Ethernet detached event for wan Feb 3 11:19:12 kernel: em0: link state changed to DOWN Feb 3 11:19:12 check_reload_status: Linkup starting em0 Feb 3 11:19:12 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:19:10 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:19:10 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host Feb 3 11:19:10 dhclient: PREINIT Feb 3 11:19:10 php: : HOTPLUG: Configuring interface wan Feb 3 11:19:10 php: : DEVD Ethernet attached event for wan Feb 3 11:19:09 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:09 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:09 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:09 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:08 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:08 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:07 kernel: em0: link state changed to UP Feb 3 11:19:07 check_reload_status: Linkup starting em0 Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:03 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:03 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:19:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:19:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:18:59 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx Feb 3 11:18:59 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:18:59 miniupnpd[53901]: Failed to get ip address for interface em0 Feb 3 11:18:59 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:18:59 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Feb 3 11:18:56 dhclient[4995]: exiting. Feb 3 11:18:56 dhclient[4995]: exiting. Feb 3 11:18:56 dhclient[4995]: connection closed Feb 3 11:18:56 dhclient[4995]: connection closed Feb 3 11:18:56 php: : DEVD Ethernet detached event for wan Feb 3 11:18:54 kernel: em0: link state changed to DOWN Feb 3 11:18:54 check_reload_status: Linkup starting em0 Feb 3 11:18:47 check_reload_status: Reloading filter Feb 3 11:18:37 apinger: ALARM: WAN(75.131.xxx.xxx) *** down ***
-
I flipped these log entries around because trying to follow the flow of messages in reverse-order logs is bothersome…
Feb 3 11:19:12 kernel: em0: link state changed to DOWN Feb 3 11:19:14 php: : DEVD Ethernet detached event for wan Feb 3 11:19:14 kernel: em0: link state changed to UP
If I had to guess I'd say that the link cycled too fast and either DEVD did not fire the event to bring it back up or the event was lost somewhere in between devd and check_reload_status.
Are you spoofing a MAC on that interface? Or setting any other custom values other than the interface name and setting it for DHCP?
-
No MAC spoofing or anything unusual. It is a very basic home setup.
-
Could be something sketchy happening at the modem then…
Ermal is looking into a fix, I started a ticket here: https://redmine.pfsense.org/issues/2792
-
It looks like anytime the cable goes out or I get a T4 error (causes modem reboot), it happens. It's a Motorola 6120. We had an all out outage yesterday which caused the log I posted above. Sometimes I'll get a T4 error which causes the modem to reboot and pfSense doesn't recover. pfSense 2.0.1 would recover just fine.
I'm actually going to buy a new modem today in hopes it will fix something. If not I'll go back to 2.0.1 but wanted to remain on the newer versions to help fix it. I can't have the wife with no Internet while I'm at work - I get nasty calls :)
-
OK, snaps up now should have a potential fix in for this.
2.0.3 snaps can be found here: http://forum.pfsense.org/index.php/topic,58203.msg311614.html#msg311614
2.1 snaps are on http://snapshots.pfsense.org/ -
It's awful bug! But to install a "snap" it's much more unsafely IMHO.
You can use my temp solution:
Repeat every minute by cron smth like this$ cat /root/renew-ip.sh #!/bin/sh GW=`netstat -rn | grep default | egrep -o "[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}"` lan_inf="em1" ping -c 5 -i 0.1 -q $GW >/dev/null if [ $? != 0 ]; then logger "GW:$GW sucks" ping -c 5 -q ya.ru >/dev/null if [ $? != 0 ]; then /sbin/dhclient $lan_inf logger "GW:$GW Crash!" sleep 30 fi fi exit 1
It works for me since 2.0.2 upgrade comes
-
2.0.3 snaps are safe. Releases are just snapshots we deemed worthy of being called releases.
The only thing holding back 2.0.3 from release right now is that we're waiting on FreeBSD to issue an OpenSSL security advisory any time now, and we have to account for that once it comes out.
-
I upgraded to the latest snap image today (Feb 13 1243), and I am still having the problem that originally started this thread.
-
Gather the info again (the syslog logs, etc) and post it again from the new snapshot.
-
Just to be clear: my interface was not going up/down. That seems like a different issue than the one I initially reported. My issue is that dhclient never got an IP address to begin with – it didn't exit, but kept trying forever to get a lease. Each time, it would eventually timeout and say that it hadn't received any DHCP offers. Please re-read my first post on this thread.
The behavior has now changed. dhclient is now re-launching every few seconds, and the link status (according to pfsense) is flapping. dhclient is now exiting every 1-2 seconds and re-trying. This is new. The link itself is not flapping, however. Here's a bunch of the logs; you can see multiple iterations of the flapping:
Feb 16 15:01:07 kernel: sk0: link state changed to DOWN Feb 16 15:01:07 check_reload_status: Linkup starting sk0 Feb 16 15:01:07 php: : HOTPLUG: Configuring interface wan Feb 16 15:01:07 php: : DEVD Ethernet attached event for wan Feb 16 15:01:06 kernel: arpresolve: can't allocate llinfo for 10.0.2.1 Feb 16 15:01:05 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf sk0 > /tmp/sk0_output > /tmp/sk0_error_output' returned exit code '15', the output was '' Feb 16 15:01:05 dhclient[20134]: exiting. Feb 16 15:01:05 dhclient[20134]: exiting. Feb 16 15:01:05 dhclient[20134]: connection closed Feb 16 15:01:05 dhclient[20134]: connection closed Feb 16 15:01:05 php: : DEVD Ethernet detached event for wan Feb 16 15:01:04 dhclient[19667]: DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 2 Feb 16 15:01:04 dhclient[19667]: DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 1 Feb 16 15:01:04 dhclient: PREINIT Feb 16 15:01:04 dhclient: Deleting old routes Feb 16 15:01:04 dhclient: EXPIRE Feb 16 15:01:04 dhclient: PREINIT Feb 16 15:01:04 kernel: sk0: link state changed to UP Feb 16 15:01:04 check_reload_status: Linkup starting sk0 Feb 16 15:01:02 kernel: sk0: link state changed to DOWN Feb 16 15:01:02 check_reload_status: Linkup starting sk0 Feb 16 15:01:02 php: : HOTPLUG: Configuring interface wan Feb 16 15:01:02 php: : DEVD Ethernet attached event for wan Feb 16 15:01:01 kernel: arpresolve: can't allocate llinfo for 10.0.2.1 Feb 16 15:01:00 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf sk0 > /tmp/sk0_output > /tmp/sk0_error_output' returned exit code '15', the output was '' Feb 16 15:01:00 dhclient[14425]: exiting. Feb 16 15:01:00 dhclient[14425]: exiting. Feb 16 15:01:00 dhclient[14425]: connection closed Feb 16 15:01:00 dhclient[14425]: connection closed Feb 16 15:01:00 php: : DEVD Ethernet detached event for wan Feb 16 15:01:00 dhclient[13908]: DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 5 Feb 16 15:01:00 dhclient[13908]: DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 2 Feb 16 15:01:00 dhclient: PREINIT Feb 16 15:01:00 check_reload_status: Linkup starting sk0 Feb 16 15:01:00 dhclient: Deleting old routes Feb 16 15:01:00 dhclient: EXPIRE Feb 16 15:01:00 kernel: sk0: link state changed to UP Feb 16 15:01:00 dhclient: PREINIT Feb 16 15:00:58 kernel: sk0: link state changed to DOWN Feb 16 15:00:58 check_reload_status: Linkup starting sk0 Feb 16 15:00:58 php: : HOTPLUG: Configuring interface wan Feb 16 15:00:58 php: : DEVD Ethernet attached event for wan Feb 16 15:00:56 dhclient[8419]: exiting. Feb 16 15:00:56 dhclient[8419]: exiting. Feb 16 15:00:56 dhclient[8419]: connection closed Feb 16 15:00:56 dhclient[8419]: connection closed Feb 16 15:00:56 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf sk0 > /tmp/sk0_output > /tmp/sk0_error_output' returned exit code '15', the output was '' Feb 16 15:00:56 php: : DEVD Ethernet detached event for wan Feb 16 15:00:56 kernel: arpresolve: can't allocate llinfo for 10.0.2.1 Feb 16 15:00:56 dhclient[7818]: DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 2
Here's a sample of output from /tmp/sk0_error_output (sk0_output and sk0_default_gateway always remain empty):
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 1 DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 1 DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 2 sk0: no link .... got link dhclient: PREINIT
sk0_error_output keeps getting overwritten every time dhclient gets run; the output is essentially the same every time.
-
The link was flapping in the logs you posted in the OP of this thread. It showed sk0's link state going up/down which is the link flapping. If it's still happening, there may be something else going on that is completely unrelated to dhclient itself.
Are you spoofing a MAC address on WAN or setting any other interface parameters?
-
No, I'm not spoofing or anything like that.
It's just a plain, vanilla DHCP from upstream. Is there any config or something I can share so you can see my specific setup?
The first logs I posted were from an initial boot of pfsense – the DOWN state was the initial state, and then the UP state was where it stayed. IIRC (it's been a little while now), it would run forever trying to get an address, and periodically report timeout -- it got no DHOFFERS. Then it would start trying again.
-
Seeing pretty much the same problem. I've tried going to a 2.1 snap, and am now back on 2.0.1 and seem to still be seeing the issue now and then. I've swapped out the Cablemodem (needed to upgrade to DOCSIS 3.0 anyway…), the SiiG USB Ethernet adaptor, and the ethernet cable. Waiting now to see if it happens again. I've removed all installed packages. The only remnant really of the other versions is that I used a config backup from 2.1 to restore from after I did a clean (nanobsd) install of 2.0.1.
Next step I guess will be to try 2.0.3 if the problem happens again.
(ISP is Comcast BTW - this has been happening for me about a week now I guess. It's possible it may have started after I upgraded to 2.0.2, but I didn't keep notes on that... :-[
-
Well, 2.0.3 snapshot seems to be a bust as well.
system.log output from when things go per shaped (first few iterations, it'll go on like this forever):
Feb 28 02:40:48 gw dnsmasq[59395]: read /etc/hosts - 26 addresses
Feb 28 02:46:12 gw dnsmasq[59395]: read /etc/hosts - 26 addresses
Feb 28 02:51:33 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:33 gw kernel: ue0: link state changed to DOWN
Feb 28 02:51:33 gw kernel: ue0: link state changed to UP
Feb 28 02:51:33 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:35 gw php: : DEVD Ethernet detached event for wan
Feb 28 02:51:35 gw dhclient[7830]: connection closed
Feb 28 02:51:35 gw dhclient[7830]: connection closed
Feb 28 02:51:35 gw dhclient[7830]: exiting.
Feb 28 02:51:35 gw dhclient[7830]: exiting.
Feb 28 02:51:35 gw php: : DEVD Ethernet attached event for wan
Feb 28 02:51:35 gw php: : HOTPLUG: Configuring interface wan
Feb 28 02:51:35 gw kernel: ue0: link state changed to DOWN
Feb 28 02:51:35 gw dhclient: PREINIT
Feb 28 02:51:36 gw kernel: ue0: link state changed to DOWN
Feb 28 02:51:36 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:36 gw dhclient[26875]: DHCPREQUEST on ue0 to 255.255.255.255 port 67
Feb 28 02:51:36 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:36 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:37 gw dhclient[26875]: DHCPREQUEST on ue0 to 255.255.255.255 port 67
Feb 28 02:51:37 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:37 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:38 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:38 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:38 gw kernel: ue0: link state changed to UP
Feb 28 02:51:38 gw php: : DEVD Ethernet detached event for wan
Feb 28 02:51:38 gw dhclient[26886]: connection closed
Feb 28 02:51:38 gw dhclient[26886]: connection closed
Feb 28 02:51:38 gw dhclient[26886]: exiting.
Feb 28 02:51:38 gw dhclient[26886]: exiting.
Feb 28 02:51:38 gw php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf ue0 > /tmp/ue0_output > /tmp/ue0_error_output' returned exit code '15', the output was ''
Feb 28 02:51:38 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:39 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:39 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:39 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:40 gw php: : DEVD Ethernet attached event for wan
Feb 28 02:51:40 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:40 gw php: : HOTPLUG: Configuring interface wan
Feb 28 02:51:41 gw dhclient: PREINIT
Feb 28 02:51:41 gw kernel: ue0: link state changed to DOWN
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:41 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:41 gw kernel: ue0: link state changed to DOWN
Feb 28 02:51:41 gw dhclient[29928]: DHCPREQUEST on ue0 to 255.255.255.255 port 67
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:41 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:42 gw dhclient[29928]: DHCPREQUEST on ue0 to 255.255.255.255 port 67
Feb 28 02:51:42 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:42 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:43 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:43 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:43 gw kernel: ue0: link state changed to UP
Feb 28 02:51:43 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:43 gw php: : DEVD Ethernet detached event for wan
Feb 28 02:51:43 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:43 gw dhclient[30147]: connection closed
Feb 28 02:51:43 gw dhclient[30147]: connection closed
Feb 28 02:51:43 gw dhclient[30147]: exiting.
Feb 28 02:51:43 gw dhclient[30147]: exiting.
Feb 28 02:51:43 gw php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf ue0 > /tmp/ue0_output > /tmp/ue0_error_output' returned exit code '15', the output was ''
Feb 28 02:51:43 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:44 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:44 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:44 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:44 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:45 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:45 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:45 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:45 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:45 gw php: : DEVD Ethernet attached event for wan
Feb 28 02:51:45 gw php: : HOTPLUG: Configuring interface wan
Feb 28 02:51:45 gw apinger: ALARM: COMCAST(76.21.128.1) *** down ***
Feb 28 02:51:45 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:45 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:45 gw dhclient: PREINIT
Feb 28 02:51:45 gw kernel: ue0: link state changed to DOWN
Feb 28 02:51:46 gw dhclient[32914]: DHCPREQUEST on ue0 to 255.255.255.255 port 67
Feb 28 02:51:46 gw kernel: ue0: link state changed to DOWN
Feb 28 02:51:46 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:46 gw dhclient[32914]: DHCPREQUEST on ue0 to 255.255.255.255 port 67
Feb 28 02:51:46 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:47 gw dhclient[32914]: DHCPREQUEST on ue0 to 255.255.255.255 port 67
Feb 28 02:51:47 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:47 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:47 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:47 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:47 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:48 gw kernel: arpresolve: can't allocate llinfo for 68.48.154.1
Feb 28 02:51:48 gw check_reload_status: Linkup starting ue0
Feb 28 02:51:48 gw kernel: ue0: link state changed to UP
Feb 28 02:51:48 gw php: : DEVD Ethernet detached event for wan
Feb 28 02:51:48 gw dhclient[33032]: connection closedAnd some tcpdump on the WAN interface while this is happening:
3:07:08.179613 ARP, Request who-has 96.159.231.104 tell 96.159.224.1, length 46
03:07:08.255915 ARP, Request who-has 69.255.98.63 tell 69.255.98.1, length 46
03:07:08.265409 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ffd8:3eae: ICMP6, neighbor solicitation, who has fe80::103a:146a:c8d8:3eae, length 32
03:07:08.281166 ARP, Request who-has 68.33.165.136 tell 68.33.164.1, length 46
03:07:08.332951 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ff0f:3169: ICMP6, neighbor solicitation, who has fe80::20d:56ff:fe0f:3169, length 32
03:07:08.354737 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354746 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354751 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354755 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354760 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354765 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354770 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354776 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354781 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.354786 IP 68.48.155.52.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:50:b6:59:70:f5 (oui Unknown), length 300
03:07:08.376346 IP 73.129.106.1.bootps > 68.48.155.52.bootpc: BOOTP/DHCP, Reply, length 310
03:07:08.399605 ARP, Request who-has 73.135.29.90 tell 73.135.28.1, length 46
03:07:08.442380 ARP, Request who-has 76.21.131.12 tell 76.21.128.1, length 46
03:07:08.516027 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ffe8:585e: ICMP6, neighbor solicitation, who has fe80::f4f2:2722:9e8:585e, length 32
03:07:08.517774 ARP, Request who-has 69.251.11.67 tell 69.251.11.1, length 46
03:07:08.556795 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ffb3:1451: ICMP6, neighbor solicitation, who has fe80::c2c1:c0ff:feb3:1451, length 32
03:07:08.674110 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ffa0:1a00: ICMP6, neighbor solicitation, who has fe80::3ed9:2bff:fea0:1a00, length 32
03:07:08.684109 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ffb8:7ab6: ICMP6, neighbor solicitation, who has fe80::8d76:e28f:41b8:7ab6, length 32
03:07:08.696366 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ff78:d9e: ICMP6, neighbor solicitation, who has fe80::748e:b8b7:3278:d9e, length 32
03:07:08.836688 ARP, Request who-has 73.132.81.206 tell 73.132.80.1, length 46
03:07:08.914100 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ff93:f82e: ICMP6, neighbor solicitation, who has fe80::221:5aff:fe93:f82e, length 32
03:07:08.915224 ARP, Request who-has 76.100.105.141 tell 76.100.105.1, length 46
03:07:08.928980 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ff47:f53a: ICMP6, neighbor solicitation, who has fe80::9989:14eb:6747:f53a, length 32
ç03:07:09.011660 IP6 fe80::201:5cff:fe22:1281 > ff02::1:ff0e:e6ef: ICMP6, neighbor solicitation, who has fe80::dd8a:aba8:7a0e:e6ef, length 32