WAN DHCP issues Telenet, arpresolve: can't allocate llinfo
-
Hi,
It's me again with an update on the issue I reported a while ago: http://forum.pfsense.org/index.php/topic,42473
I'm totally stuck on this for a long time now, if I can't figure it out, I will try replacing the boxes and see if that helps. (but I doubt that)
In the night (2-3 times/week) the boxes lose their internet connection, I configured syslog to log to a linux syslog server on the LAN so we could at least catch the logs after the on-site person power cycles the firewall. (the boxes are remote)
The loss of connection started around 5:10am and lasted until the reboot at 09.00am. The last dhcp RENEW before 05.10 was at 04.52 and went "normal".
Is there anything else I need to check or that I can do to troubleshoot?
Tech specs:
2.0.1-RELEASE (i386) - built on Mon Dec 12 19:00:03 EST 2011 - FreeBSD 8.1-RELEASE-p6
The internet connection is cable and IPs are issued by DHCP.
WAN (wan) -> vr1 -> 81.82.xxx.xxx (DHCP)
LAN (lan) -> vr0 -> 192.168.10.254
OPT1 (opt1) -> vr2 -> NONEI attached some logs, if you need more, let me know, I can grab them easily.
kern:
kern Jul 13 05:10:35 192.168.10.254 kernel: vr1: link state changed to DOWN Jul 13 05:10:55 192.168.10.254 kernel: vr1: link state changed to UP Jul 13 05:11:04 192.168.10.254 kernel: vr1: link state changed to DOWN Jul 13 05:11:06 192.168.10.254 kernel: vr1: link state changed to UP Jul 13 05:52:29 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:52:31 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:52:36 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:52:44 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:52:52 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:53:05 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:53:17 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:53:46 192.168.10.254 kernel: arprequest: cannot find matching address Jul 13 05:53:46 192.168.10.254 kernel: arprequest: cannot find matching address ... Jul 13 05:56:35 192.168.10.254 kernel: arprequest: cannot find matching address Jul 13 05:56:35 192.168.10.254 kernel: arprequest: cannot find matching address Jul 13 05:56:37 192.168.10.254 kernel: arpresolve: can't allocate llinfo for 81.82.192.1 Jul 13 05:56:38 192.168.10.254 kernel: arprequest: cannot find matching address Jul 13 05:56:38 192.168.10.254 kernel: arprequest: cannot find matching address Jul 13 05:56:40 192.168.10.254 kernel: arprequest: cannot find matching address ... Repeats until reboot
Jul 13 04:52:29 192.168.10.254 dhclient: RENEW Jul 13 04:52:29 192.168.10.254 dhclient: Creating resolv.conf Jul 13 05:10:10 192.168.10.254 apinger: ALARM: WAN(81.82.192.1) *** down *** Jul 13 05:10:20 192.168.10.254 check_reload_status: Reloading filter Jul 13 05:10:35 192.168.10.254 check_reload_status: Linkup starting vr1 Jul 13 05:10:41 192.168.10.254 php: : DEVD Ethernet detached event for wan Jul 13 05:10:55 192.168.10.254 check_reload_status: Linkup starting vr1 Jul 13 05:11:01 192.168.10.254 php: : DEVD Ethernet attached event for wan Jul 13 05:11:01 192.168.10.254 php: : HOTPLUG: Configuring interface wan Jul 13 05:11:01 192.168.10.254 dhclient: PREINIT Jul 13 05:11:04 192.168.10.254 check_reload_status: Linkup starting vr1 Jul 13 05:11:06 192.168.10.254 check_reload_status: Linkup starting vr1 Jul 13 05:11:09 192.168.10.254 php: : DEVD Ethernet detached event for wan Jul 13 05:11:10 192.168.10.254 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf vr1 > /tmp/vr1_output > /tmp/vr1_error_output' returned exit code '15', the output was '' Jul 13 05:11:12 192.168.10.254 php: : DEVD Ethernet attached event for wan Jul 13 05:11:12 192.168.10.254 php: : HOTPLUG: Configuring interface wan Jul 13 05:11:12 192.168.10.254 dhclient: PREINIT Jul 13 05:12:24 192.168.10.254 dhclient: TIMEOUT Jul 13 05:12:24 192.168.10.254 dhclient: Starting add_new_address() Jul 13 05:12:24 192.168.10.254 dhclient: ifconfig vr1 inet 81.82.xxx.xxxnetmask 255.255.192.0 broadcast 255.255.255.255 Jul 13 05:12:24 192.168.10.254 dhclient: New IP Address (vr1): 81.82.xxx.xxx Jul 13 05:12:24 192.168.10.254 dhclient: New Subnet Mask (vr1): 255.255.192.0 Jul 13 05:12:24 192.168.10.254 dhclient: New Broadcast Address (vr1): 255.255.255.255 Jul 13 05:12:24 192.168.10.254 dhclient: New Routers (vr1): 81.82.192.1 Jul 13 05:12:25 192.168.10.254 dhclient: New Routers (vr1): 81.82.192.1 Jul 13 05:12:36 192.168.10.254 dhclient: Deleting old routes Jul 13 05:53:45 192.168.10.254 dhclient: RENEW Jul 13 05:53:45 192.168.10.254 dhclient: Creating resolv.conf Jul 13 06:55:03 192.168.10.254 dhclient: RENEW Jul 13 06:55:03 192.168.10.254 dhclient: Creating resolv.conf Jul 13 07:56:06 192.168.10.254 dhclient: RENEW Jul 13 07:56:07 192.168.10.254 dhclient: Creating resolv.conf Jul 13 08:57:07 192.168.10.254 dhclient: RENEW Jul 13 08:57:07 192.168.10.254 dhclient: Creating resolv.conf Jul 13 09:00:39 192.168.10.254 apinger: Starting Alarm Pinger, apinger(36434) Jul 13 09:00:43 192.168.10.254 php: : ROUTING: setting default route to 81.82.192.1 Jul 13 09:00:45 192.168.10.254 check_reload_status: Updating all dyndns Jul 13 09:00:49 192.168.10.254 php: : OpenNTPD is starting up. Jul 13 09:00:49 192.168.10.254 php: : rc.newwanip: Informational is starting vr1. Jul 13 09:00:49 192.168.10.254 php: : rc.newwanip: on (IP address: 81.82.xxx.xxx) (interface: wan) (real interface: vr1). Jul 13 09:00:50 192.168.10.254 php: : ROUTING: setting default route to 81.82.192.1 Jul 13 09:00:50 192.168.10.254 apinger: Exiting on signal 15. Jul 13 09:00:51 192.168.10.254 check_reload_status: rc.newwanip starting ovpnc1 Jul 13 09:00:51 192.168.10.254 check_reload_status: Reloading filter Jul 13 09:00:51 192.168.10.254 apinger: Starting Alarm Pinger, apinger(5223) Jul 13 09:00:51 192.168.10.254 check_reload_status: Restarting ipsec tunnels Jul 13 09:00:56 192.168.10.254 php: : Resyncing OpenVPN instances for interface WAN. Jul 13 09:00:56 192.168.10.254 php: : Creating rrd update script
The hardware is from applianceshop:
http://www.applianceshop.eu/index.php/firewalls/opnsense/opnsense-desktop-and-wallmountable/opnsense-pfsense-appliance.htmlThanks in advance for any reply
Kristof
-
The "arpresolve: can't allocate llinfo" generally means it's trying to ARP something that isn't on a local subnet. The "New Broadcast Address (vr1): 255.255.255.255" is odd, as well as the fact the NIC loses link twice, and once it regains it that's part of the lease it gets. Suspect that's somehow related (getting a bunk lease?), but not sure how exactly from that.
-
@cmb:
The "arpresolve: can't allocate llinfo" generally means it's trying to ARP something that isn't on a local subnet. The "New Broadcast Address (vr1): 255.255.255.255" is odd, as well as the fact the NIC loses link twice, and once it regains it that's part of the lease it gets. Suspect that's somehow related (getting a bunk lease?), but not sure how exactly from that.
I'm not sure if the "can't allocate llinfo" has anything to do with it but it seems strange to me that the lease gets renewed at 5.12 but the internet connection is not working.
It seems indeed we get an "invalid lease" that seems to be ok but does not work correctly. (= can't allocate llinfo for 81.82.192.1)
Any ideas on how to workaround this? Or "detecting" that this is happening and forcing a release/renew or something alike?
regards,
Kristof. -
It could be a situation like I get here:
- Cable modem loses sync, modem hands out 192.168.x.x address to WAN
- WAN gets some states routing traffic via the 192.168.x.x. gateway
- Cable modem regains sync, modem passes on public IP lease
- WAN states start going to the right gateway
If some states are still around on the bad/stale gateway, I get the arpresolve error. If I reset the states going via that gateway (pfctl -b x.x.x.x) or reset the whole state table, it clears up.
This is a bit better on 2.1 these days but it's been a while since I tested it out.
-
I don't really think it's something with a 192.168.x.x address as I don't find anything (at all) about that in the logfiles.
But I'm willing to try a somewhat stable 2.1 snapshot, can you point me to where I can find them?
-
http://snapshots.pfsense.org/