Reload loop - pfsense unuseable

ggzengel · Feb 8, 2013, 3:06 PM

after update to
2.1-BETA1 (amd64)
built on Thu Feb 7 18:03:44 EST 2013

I get a reload loop.

15:05:12 php: : Removing static route for monitor 194.25.2.129 and adding a new route through 217.0.117.215
15:05:12 php: : rc.newwanip: on (IP address: 10.255.255.130) (interface: opt6) (real interface: ovpnc2).
15:05:12 php: : rc.newwanip: Informational is starting ovpnc2.
15:05:12 php: : Removing static route for monitor 194.25.2.129 and adding a new route through 217.0.117.215
15:05:12 php: : rc.newwanip: on (IP address: 10.255.255.2) (interface: opt7) (real interface: ovpnc1).
15:05:12 php: : rc.newwanip: Informational is starting ovpnc1.
15:05:10 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
15:05:10 php: : DynDns (): Current WAN IP: 217.91.144.12 Cached IP: 217.91.144.12
15:05:10 php: : DynDns debug information (): 217.91.144.12 extracted from local system.
15:05:10 php: : DynDns debug information (): 217.91.144.12 extracted from local system.
15:05:10 php: : DynDns: updatedns() starting
15:05:10 check_reload_status: rc.newwanip starting ovpnc2
15:05:10 kernel: ovpnc2: link state changed to UP
15:05:10 php: : The command '/sbin/route -q delete 10.255.255.130' returned exit code '1', the output was 'route: writing to routing socket: No such process'
15:05:10 kernel: ovpnc2: link state changed to DOWN
15:05:10 check_reload_status: rc.newwanip starting ovpnc1
15:05:10 kernel: ovpnc1: link state changed to UP
15:05:10 php: : The command '/sbin/route -q delete 10.255.255.2' returned exit code '1', the output was 'route: writing to routing socket: No such process'
15:05:09 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
15:05:09 php: : DynDns (): Current WAN IP: 78.42.74.173 Cached IP: 78.42.74.173
15:05:09 php: : DynDns debug information (): 78.42.74.173 extracted from local system.
15:05:09 php: : DynDNS (): running get_failover_interface for opt1. found em2
15:05:09 php: : DynDns debug information (): 78.42.74.173 extracted from local system.
15:05:09 php: : DynDns: updatedns() starting
15:05:09 kernel: ovpnc1: link state changed to DOWN
15:05:09 php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
15:05:07 check_reload_status: Reloading filter
15:05:07 check_reload_status: Restarting OpenVPN tunnels/interfaces
15:05:07 check_reload_status: Restarting ipsec tunnels
15:05:07 check_reload_status: Updating all dyndns
15:04:52 php: : Forcefully reloading IPsec racoon daemon
15:04:52 php: : Forcefully reloading IPsec racoon daemon
15:04:46 php: : Removing static route for monitor 194.25.2.129 and adding a new route through 217.0.117.215
15:04:46 php: : rc.newwanip: on (IP address: 10.255.255.130) (interface: opt6) (real interface: ovpnc2).
15:04:46 php: : rc.newwanip: Informational is starting ovpnc2.
15:04:46 php: : Removing static route for monitor 194.25.2.129 and adding a new route through 217.0.117.215
15:04:46 php: : rc.newwanip: on (IP address: 10.255.255.2) (interface: opt7) (real interface: ovpnc1).
15:04:46 php: : rc.newwanip: Informational is starting ovpnc1.
15:04:45 php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
15:04:45 php: : DynDns (): Current WAN IP: 217.91.144.12 Cached IP: 217.91.144.12
15:04:45 php: : DynDns debug information (): 217.91.144.12 extracted from local system.
15:04:45 php: : DynDns debug information (): 217.91.144.12 extracted from local system.
15:04:45 php: : DynDns: updatedns() starting
15:04:44 check_reload_status: rc.newwanip starting ovpnc2
15:04:44 kernel: ovpnc2: link state changed to UP
15:04:44 php: : The command '/sbin/route -q delete 10.255.255.130' returned exit code '1', the output was 'route: writing to routing socket: No such process'
15:04:44 kernel: ovpnc2: link state changed to DOWN
15:04:44 check_reload_status: rc.newwanip starting ovpnc1
15:04:44 kernel: ovpnc1: link state changed to UP
15:04:44 php: : The command '/sbin/route -q delete 10.255.255.2' returned exit code '1', the output was 'route: writing to routing socket: No such process'

ggzengel · Feb 8, 2013, 3:33 PM

After disabling gateway monitoring on openvpn interfaces the loop ended.
But I will get a lot of "501 - Not Implemented" on webconfigurator. I have to do a lot of resending the page in web browser to do some work.

eri-- · Feb 9, 2013, 8:38 AM

Not enough information here to tell what can be the cause.
Probably some routing issues or mismatches on subnet configuration?

ggzengel · Feb 10, 2013, 2:22 PM

I downgraded to
2.1-BETA1 (amd64)
built on Sat Feb 2 01:46:53 EST 2013

With this version I don't have this problem.
If have 2 gateway groups with 3 wans inside and 1 wan (tier1 and tier5 in the groups) which is down.

One group is used in openvpn.

cybercare · Feb 10, 2013, 2:26 PM

Try a newer snap?

Though I would wait for one not dated Saturday as it has GW route issues, though nothing too major :P

ggzengel · Feb 10, 2013, 2:55 PM

Meanwhile I updated to
2.1-BETA1 (amd64)
built on Sat Feb 9 23:46:16 EST 2013

Every 15 sec it reload the filters and ipsec tunnels stop forwarding for a few seconds.

It says:
php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing

But that's not true.

Feb 10 15:01:08 pfsense-hd php: : Forcefully reloading IPsec racoon daemon
Feb 10 15:01:08 pfsense-hd php: : Forcefully reloading IPsec racoon daemon
Feb 10 15:01:23 pfsense-hd check_reload_status: Updating all dyndns
Feb 10 15:01:23 pfsense-hd check_reload_status: Restarting ipsec tunnels
Feb 10 15:01:23 pfsense-hd check_reload_status: Restarting OpenVPN tunnels/interfaces
Feb 10 15:01:23 pfsense-hd check_reload_status: Reloading filter
Feb 10 15:01:25 pfsense-hd php: : DynDns: updatedns() starting
Feb 10 15:01:25 pfsense-hd php: : DynDns debug information (): 78.42.74.173 extracted from local system.
Feb 10 15:01:25 pfsense-hd php: : DynDNS (): running get_failover_interface for opt1\. found em2
Feb 10 15:01:25 pfsense-hd php: : DynDns debug information (): 78.42.74.173 extracted from local system.
Feb 10 15:01:25 pfsense-hd php: : DynDns (): Current WAN IP: 78.42.74.173 Cached IP: 78.42.74.173
Feb 10 15:01:25 pfsense-hd php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Feb 10 15:01:25 pfsense-hd kernel: ovpnc1: link state changed to DOWN
Feb 10 15:01:25 pfsense-hd php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Feb 10 15:01:25 pfsense-hd php: : The command '/sbin/route -q delete 10.255.255.2' returned exit code '1', the output was 'route: writing to routing socket: No such process'
Feb 10 15:01:25 pfsense-hd kernel: ovpnc1: link state changed to UP
Feb 10 15:01:25 pfsense-hd check_reload_status: rc.newwanip starting ovpnc1
Feb 10 15:01:25 pfsense-hd kernel: ovpnc2: link state changed to DOWN
Feb 10 15:01:25 pfsense-hd php: : The command '/sbin/route -q delete 10.255.255.130' returned exit code '1', the output was 'route: writing to routing socket: No such process'
Feb 10 15:01:25 pfsense-hd kernel: ovpnc2: link state changed to UP
Feb 10 15:01:25 pfsense-hd check_reload_status: rc.newwanip starting ovpnc2
Feb 10 15:01:26 pfsense-hd php: : DynDns: updatedns() starting
Feb 10 15:01:26 pfsense-hd php: : DynDns debug information (): 217.91.144.12 extracted from local system.
Feb 10 15:01:26 pfsense-hd php: : DynDNS (): running get_failover_interface for opt2\. found pppoe0
Feb 10 15:01:26 pfsense-hd php: : DynDns debug information (): 217.91.144.12 extracted from local system.
Feb 10 15:01:26 pfsense-hd php: : DynDns (): Current WAN IP: 217.91.144.12 Cached IP: 217.91.144.12
Feb 10 15:01:26 pfsense-hd php: : phpDynDNS: No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Feb 10 15:01:27 pfsense-hd php: : rc.newwanip: Informational is starting ovpnc1.
Feb 10 15:01:27 pfsense-hd php: : rc.newwanip: on (IP address: 10.255.255.2) (interface: opt7) (real interface: ovpnc1).
Feb 10 15:01:27 pfsense-hd php: : Removing static route for monitor 194.25.2.129 and adding a new route through 217.0.117.215
Feb 10 15:01:28 pfsense-hd php: : rc.newwanip: Informational is starting ovpnc2.
Feb 10 15:01:28 pfsense-hd php: : rc.newwanip: on (IP address: 10.255.255.130) (interface: opt6) (real interface: ovpnc2).
Feb 10 15:01:28 pfsense-hd php: : Removing static route for monitor 194.25.2.129 and adding a new route through 217.0.117.215
Feb 10 15:01:33 pfsense-hd php: : Forcefully reloading IPsec racoon daemon
Feb 10 15:01:34 pfsense-hd php: : Forcefully reloading IPsec racoon daemon

cybercare · Feb 10, 2013, 3:49 PM

hmm I don't see the VPN issue. I have a tunnel from an x86 box to an x64 box in a datacenter both now running the last Feb 09 build and the tunnel has been up since I updated which was a few hours ago.

You using IP or name to make the connection? If the name maybe something is happening when it tries to re-resolve it or something silly.

ggzengel · Feb 10, 2013, 4:04 PM

I think it's because one interface in the gateway group is down and the reload script is doing to much work.
The second problem could be the openvpn client which didn't come up completely.

I think if there are problems with some interfaces the router should work allways stable.

ggzengel · Feb 10, 2013, 4:11 PM

sometimes I see:
Feb 10 15:34:58 pfsense-hd php: : GATEWAYS: We did not find the first tier of the gateway group WAN! That's odd.
Feb 10 15:34:58 pfsense-hd php: : Gateways status could not be determined, considering all as up/active. (Group: Internet)
Feb 10 15:34:58 pfsense-hd php: : Gateways status could not be determined, considering all as up/active. (Group: WAN)

I already removed and added the (disabled) wan interface on the group. The script should see the interface and know that it's down.

eri-- · Feb 11, 2013, 9:45 AM

Can you share your configuration information.
Just the log does not tell anything about your architecture and guess work is hard for troubleshooting anything.

ggzengel · Feb 11, 2013, 5:05 PM

I will do this, but I need sometime for anonymization.
I wish there were an anonymization function at export.

ggzengel · Feb 11, 2013, 5:55 PM

@ermal: you got PM

ggzengel · Feb 17, 2013, 9:45 PM

I updated now my 4th pfsense from 1. Feb to 2.1-BETA1 (amd64) built on Fri Feb 15 04:33:17 EST 2013.
I have the same problem again.
If one interface unwired or for other reason down (gateway don't reply on ping) it reloads the config every 15 seconds.
Racoon is restarted cyclic and VPN is unuasable.