WAN DHCP IPV4 address gone - can't allocate llinfo
-
The error that came when using Status:Interfaces to release and renew a DHCP address has been fixed -
http://forum.pfsense.org/index.php/topic,52046.0.html
Now, the reason that I ended up using this release/renew button was that I had lost the IPV4 address from my WAN interface. It happened to me again today on:
2.1-BETA0 (i386)
built on Sun Aug 5 18:24:43 EDT 2012
FreeBSD 8.3-RELEASE-p3I had just installed OpenVPN Client Export Utility on my test system. The test system is an Alix with WAN set to DHCP on an internal subnet. The DHCP server is a pfSense Alix router on the internal subnet running the same 2.1-BETA0 release, and that is the gateway to the real internet. I am not trying to do any IPV6 stuff on either box, the default IPV6 functions that come in 2.1 just happen by themselves, so there are fe80 addresses.
It seems that something gets mixed up during all the check_reload_status stuff.
Here is my WAN vr1 when it has the problem (there is no IPV4 setting):vr1: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500 options=8280b <rxcsum,txcsum,vlan_mtu,wol_ucast,wol_magic,linkstate>ether 00:0d:b9:24:58:b5 inet6 fe80::20d:b9ff:fe24:58b5%vr1 prefixlen 64 scopeid 0x2 nd6 options=3 <performnud,accept_rtadv>media: Ethernet autoselect (100baseTX <full-duplex>) status: active</full-duplex></performnud,accept_rtadv></rxcsum,txcsum,vlan_mtu,wol_ucast,wol_magic,linkstate></up,broadcast,running,simplex,multicast>
Here it is after clicking release then renew (IPV4 settings are back):
vr1: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500 options=8280b <rxcsum,txcsum,vlan_mtu,wol_ucast,wol_magic,linkstate>ether 00:0d:b9:24:58:b5 inet6 fe80::20d:b9ff:fe24:58b5%vr1 prefixlen 64 scopeid 0x2 inet 10.49.80.166 netmask 0xffffff00 broadcast 10.49.80.255 nd6 options=3 <performnud,accept_rtadv>media: Ethernet autoselect (100baseTX <full-duplex>) status: active</full-duplex></performnud,accept_rtadv></rxcsum,txcsum,vlan_mtu,wol_ucast,wol_magic,linkstate></up,broadcast,running,simplex,multicast>
Here is some syslog output:
Aug 6 14:25:21 test02 check_reload_status: Syncing firewall Aug 6 14:25:22 test02 php: /pkg_mgr_install.php: Beginning package installation for OpenVPN Client Export Utility . Aug 6 14:26:28 test02 dhclient: RENEW Aug 6 14:26:28 test02 dhclient: Creating resolv.conf Aug 6 14:30:12 test02 check_reload_status: Syncing firewall Aug 6 14:30:15 test02 check_reload_status: Reloading filter Aug 6 14:30:16 test02 kernel: vr1: link state changed to DOWN Aug 6 14:30:19 test02 kernel: vr1: link state changed to UP Aug 6 14:30:24 test02 check_reload_status: Linkup starting vr1 Aug 6 14:30:25 test02 check_reload_status: Linkup starting vr1 Aug 6 14:30:31 test02 php: : DEVD Ethernet detached event for wan Aug 6 14:30:31 test02 php: : Calling interface down for interface wan, destroy is Aug 6 14:30:31 test02 dhclient[6479]: connection closed Aug 6 14:30:31 test02 dhclient[6479]: connection closed Aug 6 14:30:31 test02 dhclient[6479]: exiting. Aug 6 14:30:31 test02 dhclient[6479]: exiting. Aug 6 14:30:31 test02 php: : DEVD Ethernet attached event for wan Aug 6 14:30:32 test02 php: : HOTPLUG: Configuring interface wan Aug 6 14:30:32 test02 php: : Deny router advertisements for interface wan Aug 6 14:30:32 test02 dhclient: PREINIT Aug 6 14:30:32 test02 dhclient[25563]: DHCPREQUEST on vr1 to 255.255.255.255 port 67 Aug 6 14:30:32 test02 dhclient[25563]: DHCPACK from 10.49.80.250 Aug 6 14:30:32 test02 dhclient: REBOOT Aug 6 14:30:32 test02 dhclient: Starting add_new_address() Aug 6 14:30:32 test02 dhclient: ifconfig vr1 inet 10.49.80.166 netmask 255.255.255.0 broadcast 10.49.80.255 Aug 6 14:30:32 test02 dhclient: New IP Address (vr1): 10.49.80.166 Aug 6 14:30:32 test02 dhclient: New Subnet Mask (vr1): 255.255.255.0 Aug 6 14:30:32 test02 dhclient: New Broadcast Address (vr1): 10.49.80.255 Aug 6 14:30:32 test02 dhclient: New Routers (vr1): 10.49.80.250 Aug 6 14:30:32 test02 dhclient: Adding new routes to interface: vr1 Aug 6 14:30:32 test02 dhclient: /sbin/route add default 10.49.80.250 Aug 6 14:30:32 test02 dhclient: Creating resolv.conf Aug 6 14:30:32 test02 dhclient[25563]: bound to 10.49.80.166 -- renewal in 3600 seconds. Aug 6 14:30:32 test02 php: : setting up lan - 0 Aug 6 14:30:32 test02 check_reload_status: rc.newwanip starting vr1 Aug 6 14:30:32 test02 dhcp6c[13846]: check_exit: exiting Aug 6 14:30:33 test02 php: : Accept router advertisements on interface vr1 Aug 6 14:30:33 test02 check_reload_status: Reloading filter Aug 6 14:30:36 test02 dhcp6c[35281]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 6 14:30:36 test02 dhcp6c[35281]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 6 14:30:36 test02 dhcp6c[35281]: client6_init: failed initialize control message authentication Aug 6 14:30:36 test02 dhcp6c[35281]: client6_init: failed initialize control message authentication Aug 6 14:30:36 test02 dhcp6c[35281]: client6_init: skip opening control port Aug 6 14:30:36 test02 dhcp6c[35281]: client6_init: skip opening control port Aug 6 14:30:36 test02 dhcp6c[35281]: cfparse: cfparse: fopen(/var/etc/dhcp6c_wan.conf): No such file or directory Aug 6 14:30:36 test02 dhcp6c[35281]: cfparse: cfparse: fopen(/var/etc/dhcp6c_wan.conf): No such file or directory Aug 6 14:30:36 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:39 test02 php: : rc.newwanip: Informational is starting vr1. Aug 6 14:30:39 test02 php: : rc.newwanip: on (IP address: ) (interface: wan) (real interface: vr1). Aug 6 14:30:39 test02 php: : rc.newwanip: Failed to update wan IP, restarting... Aug 6 14:30:39 test02 check_reload_status: Configuring interface wan Aug 6 14:30:40 test02 php: : Could not find IPv4 gateway for interface (wan). Aug 6 14:30:41 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:44 test02 php: : Deny router advertisements for interface wan Aug 6 14:30:44 test02 dhclient[39507]: dhclient already running, pid: 34230. Aug 6 14:30:44 test02 dhclient[39507]: dhclient already running, pid: 34230. Aug 6 14:30:44 test02 dhclient[39507]: exiting. Aug 6 14:30:44 test02 dhclient[39507]: exiting. Aug 6 14:30:44 test02 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf vr1 > /tmp/vr1_output > /tmp/vr1_error_output' returned exit code '1', the output was '' Aug 6 14:30:44 test02 php: : setting up lan - 0 Aug 6 14:30:44 test02 php: : Accept router advertisements on interface vr1 Aug 6 14:30:44 test02 check_reload_status: Reloading filter Aug 6 14:30:46 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:47 test02 php: : Interface lan configured via wan type dhcp6 Aug 6 14:30:47 test02 dhcp6c[40455]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 6 14:30:47 test02 dhcp6c[40455]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 6 14:30:47 test02 dhcp6c[40455]: client6_init: failed initialize control message authentication Aug 6 14:30:47 test02 dhcp6c[40455]: client6_init: failed initialize control message authentication Aug 6 14:30:47 test02 dhcp6c[40455]: client6_init: skip opening control port Aug 6 14:30:47 test02 dhcp6c[40455]: client6_init: skip opening control port Aug 6 14:30:50 test02 php: : Could not find IPv4 gateway for interface (wan). Aug 6 14:30:51 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:56 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:57 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:58 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:58 test02 php: : Interface lan configured via wan type dhcp6 Aug 6 14:30:58 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:30:59 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:00 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:01 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:02 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:04 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:04 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:05 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:06 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:06 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:07 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:08 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:08 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:08 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:09 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:11 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:11 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:12 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:13 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:16 test02 check_reload_status: Updating all dyndns Aug 6 14:31:16 test02 check_reload_status: Restarting ipsec tunnels Aug 6 14:31:16 test02 check_reload_status: Reloading filter Aug 6 14:31:16 test02 check_reload_status: Restarting OpenVPN tunnels/interfaces Aug 6 14:31:16 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:18 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:18 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:19 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:20 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:21 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:21 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:22 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:24 test02 php: : Resyncing OpenVPN instances. Aug 6 14:31:25 test02 php: : DynDns: updatedns() starting Aug 6 14:31:25 test02 php: : running get_failover_interface for wan. found vr1 Aug 6 14:31:25 test02 php: : There was an error trying to determine the public IP for interface - wan(vr1). Probably interface is not a WAN interface. Aug 6 14:31:25 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:26 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:26 test02 php: : Could not find IPv4 gateway for interface (wan). Aug 6 14:31:26 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 6 14:31:27 test02 check_reload_status: Reloading filter Aug 6 14:31:33 test02 php: : Could not find IPv4 gateway for interface (wan).
"can't allocate llinfo for 10.49.80.250" seems to be the where it gets into trouble.
I don't know if the client6_init and cfparse errors (stuff related to IPV6) cause problems either?
This llinfo message gets a mention in these 2.1 posts and some other 2.0.n posts:
http://forum.pfsense.org/index.php/topic,52263.0.html - WAN Interfaces down (static ones!)
http://forum.pfsense.org/index.php/topic,46738.0.html - a BridgeGW issue
http://forum.pfsense.org/index.php/topic,49811.0.html - arpresolv error and WAN NIC downI have had this problem happen a couple of times in the last week or so on different builds, since changing to using DHCP on my test box WAN interface.
-
I upgraded to:
2.1-BETA0 (i386)
built on Tue Aug 7 18:18:58 EDT 2012
FreeBSD 8.3-RELEASE-p4I have a production pfSense nanobsd on my real internet connection. Then on the internal LAN is my test nanobsd system's WAN port, which uses DHCP to get an internal LAN address and learn the gateway etc out to the real internet. Both systems are on the above snapshot.
I saw that Jim had committed https://github.com/bsdperimeter/pfsense-tools/commit/a5367b9f28b4c92f37fc99bf60a0b51c74c7a097 with some makefile change for dhcp server. So I thought that maybe this might change the behaviour between DHCP server and client.
But my test system WAN IPV4 address went AWOL again today. Had to use Status:Interfaces release/renew button to get it back. I can also get it back by physically disconnecting and reconnecting the WAN cable (I guess that triggers lots of software stuff, including trying to DHCP again).
The DHCP server log on the production system has nothing odd - it simply gives out/renews the address each hour as the requests come in.
The test system DHCP client seems to be the thing that runs into trouble. Here is a chunk of system.log:
Aug 9 13:41:48 test02 dhclient: RENEW Aug 9 13:41:48 test02 dhclient: Creating resolv.conf Aug 9 14:41:49 test02 dhclient: RENEW Aug 9 14:41:49 test02 dhclient: Creating resolv.conf Aug 9 14:47:47 test02 check_reload_status: Linkup starting vr1 Aug 9 14:47:47 test02 kernel: vr1: link state changed to DOWN Aug 9 14:47:49 test02 check_reload_status: Linkup starting vr1 Aug 9 14:47:49 test02 kernel: vr1: link state changed to UP Aug 9 14:47:51 test02 php: : DEVD Ethernet detached event for wan Aug 9 14:47:51 test02 php: : Calling interface down for interface wan, destroy is Aug 9 14:47:51 test02 dhclient[6776]: connection closed Aug 9 14:47:51 test02 dhclient[6776]: connection closed Aug 9 14:47:52 test02 dhclient[6776]: exiting. Aug 9 14:47:52 test02 dhclient[6776]: exiting. Aug 9 14:47:53 test02 dhcp6c[12833]: check_exit: exiting Aug 9 14:47:54 test02 php: : DEVD Ethernet attached event for wan Aug 9 14:47:54 test02 php: : HOTPLUG: Configuring interface wan Aug 9 14:47:54 test02 php: : Deny router advertisements for interface wan Aug 9 14:47:54 test02 dhclient: PREINIT Aug 9 14:47:54 test02 dhclient[45964]: DHCPREQUEST on vr1 to 255.255.255.255 port 67 Aug 9 14:47:54 test02 dhclient[45964]: DHCPACK from 10.49.80.250 Aug 9 14:47:54 test02 dhclient: REBOOT Aug 9 14:47:54 test02 dhclient: Starting add_new_address() Aug 9 14:47:54 test02 dhclient: ifconfig vr1 inet 10.49.80.166 netmask 255.255.255.0 broadcast 10.49.80.255 Aug 9 14:47:54 test02 dhclient: New IP Address (vr1): 10.49.80.166 Aug 9 14:47:54 test02 dhclient: New Subnet Mask (vr1): 255.255.255.0 Aug 9 14:47:54 test02 dhclient: New Broadcast Address (vr1): 10.49.80.255 Aug 9 14:47:54 test02 dhclient: New Routers (vr1): 10.49.80.250 Aug 9 14:47:54 test02 dhclient: Adding new routes to interface: vr1 Aug 9 14:47:54 test02 dhclient: /sbin/route add default 10.49.80.250 Aug 9 14:47:54 test02 dhclient: Creating resolv.conf Aug 9 14:47:55 test02 dhclient[45964]: bound to 10.49.80.166 -- renewal in 3600 seconds. Aug 9 14:47:55 test02 check_reload_status: rc.newwanip starting vr1 Aug 9 14:47:55 test02 php: : setting up lan - 0 Aug 9 14:47:55 test02 php: : Accept router advertisements on interface vr1 Aug 9 14:47:55 test02 check_reload_status: Reloading filter Aug 9 14:47:56 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:47:58 test02 dhcp6c[59614]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 9 14:47:58 test02 dhcp6c[59614]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 9 14:47:58 test02 dhcp6c[59614]: client6_init: failed initialize control message authentication Aug 9 14:47:58 test02 dhcp6c[59614]: client6_init: failed initialize control message authentication Aug 9 14:47:58 test02 dhcp6c[59614]: client6_init: skip opening control port Aug 9 14:47:58 test02 dhcp6c[59614]: client6_init: skip opening control port Aug 9 14:47:58 test02 dhcp6c[59614]: cfparse: cfparse: fopen(/var/etc/dhcp6c_wan.conf): No such file or directory Aug 9 14:47:58 test02 dhcp6c[59614]: cfparse: cfparse: fopen(/var/etc/dhcp6c_wan.conf): No such file or directory Aug 9 14:48:01 test02 php: : rc.newwanip: Informational is starting vr1. Aug 9 14:48:01 test02 php: : rc.newwanip: on (IP address: ) (interface: wan) (real interface: vr1). Aug 9 14:48:01 test02 php: : rc.newwanip: Failed to update wan IP, restarting... Aug 9 14:48:01 test02 check_reload_status: Configuring interface wan Aug 9 14:48:01 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:02 test02 php: : Could not find IPv4 gateway for interface (wan). Aug 9 14:48:06 test02 php: : Deny router advertisements for interface wan Aug 9 14:48:06 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:06 test02 dhclient[9054]: dhclient already running, pid: 58767. Aug 9 14:48:06 test02 dhclient[9054]: dhclient already running, pid: 58767. Aug 9 14:48:06 test02 dhclient[9054]: exiting. Aug 9 14:48:06 test02 dhclient[9054]: exiting. Aug 9 14:48:06 test02 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf vr1 > /tmp/vr1_output > /tmp/vr1_error_output' returned exit code '1', the output was '' Aug 9 14:48:06 test02 php: : setting up lan - 0 Aug 9 14:48:06 test02 php: : Accept router advertisements on interface vr1 Aug 9 14:48:06 test02 check_reload_status: Reloading filter Aug 9 14:48:09 test02 php: : Interface lan configured via wan type dhcp6 Aug 9 14:48:09 test02 dhcp6c[22591]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 9 14:48:09 test02 dhcp6c[22591]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Aug 9 14:48:09 test02 dhcp6c[22591]: client6_init: failed initialize control message authentication Aug 9 14:48:09 test02 dhcp6c[22591]: client6_init: failed initialize control message authentication Aug 9 14:48:09 test02 dhcp6c[22591]: client6_init: skip opening control port Aug 9 14:48:09 test02 dhcp6c[22591]: client6_init: skip opening control port Aug 9 14:48:11 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:13 test02 php: : Could not find IPv4 gateway for interface (wan). Aug 9 14:48:16 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:17 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:18 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:19 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:20 test02 php: : Interface lan configured via wan type dhcp6 Aug 9 14:48:21 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:22 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:25 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:26 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:28 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:29 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:30 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:30 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:31 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:33 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:33 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:34 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:36 test02 check_reload_status: Updating all dyndns Aug 9 14:48:36 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:36 test02 check_reload_status: Restarting ipsec tunnels Aug 9 14:48:36 test02 check_reload_status: Reloading filter Aug 9 14:48:36 test02 check_reload_status: Restarting OpenVPN tunnels/interfaces Aug 9 14:48:38 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:38 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:41 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:44 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:44 test02 php: : Resyncing OpenVPN instances. Aug 9 14:48:45 test02 php: : DynDns: updatedns() starting Aug 9 14:48:45 test02 php: : running get_failover_interface for wan. found vr1 Aug 9 14:48:45 test02 php: : There was an error trying to determine the public IP for interface - wan(vr1). Probably interface is not a WAN interface. Aug 9 14:48:46 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:46 test02 php: : Could not find IPv4 gateway for interface (wan). Aug 9 14:48:46 test02 kernel: arpresolve: can't allocate llinfo for 10.49.80.250 Aug 9 14:48:47 test02 check_reload_status: Reloading filter Aug 9 14:48:54 test02 php: : Could not find IPv4 gateway for interface (wan). Aug 9 15:47:54 test02 dhclient[58767]: DHCPREQUEST on vr1 to 10.49.80.250 port 67 Aug 9 15:47:54 test02 dhclient[58767]: send_packet: No route to host Aug 9 15:47:54 test02 dhclient[58767]: send_packet: No route to host Aug 9 15:47:55 test02 dhclient[58767]: DHCPREQUEST on vr1 to 10.49.80.250 port 67 Aug 9 15:47:55 test02 dhclient[58767]: send_packet: No route to host Aug 9 15:47:55 test02 dhclient[58767]: send_packet: No route to host ...repeating about every minute
At 14:47 something happened!
Even if this is initiated by some transient issue on the switch connected to WAN, the software should be able to recover without user intervention. At the moment, the LAN side of the test system goes offline to the rest of the world. In a real remote access support situation that would be really annoying - no way to remotely get into the router to press release/renew. So it would be good to find the problem here, as it might save "random" problems in future for some production cases.
I can't see a dhclient log file. Is there some way to see more about what is happening to dhclient?
Is there other useful data I can dump from the system after this happens?
-
Has this issue fixed itself for you? I'm experiencing the same issue now that I moved to 2.1 dev. Going to update my snapshot as it's a week or so old.
-
I still get it on my test box every now and then (maybe about every 2 or 3 days). The WAN of the test box sits on my LAN and gets DHCP from the production pfSense that is talking to the real internet. All my production systems on the real internet have static IPs, so I can't say if there is any intermittent issue when getting DHCP from an ISP in some way.
I am in an area with mains power that goes on and off all the time (10 times a day), we have UPS with big battery banks, but I think that sometimes the transitions back and forth from mains <-> inverter cause glitches for some of our switches. So the test box WAN physical switch might "disappear" for a moment and come back. I'll try and induce it by power cycling its local switch.