"tun_wg0: loop detected" following WireGuard gateway 100% loss and WAN interface rc.newwanip
-
@mixka said in "tun_wg0: loop detected" following WireGuard gateway 100% loss and WAN interface rc.newwanip:
Should I try dumb switch before WAN interface and what difference it might doing?
That's unlikely to help here because, AFAIK, you are not seeing igb0 actually lose link which is what that would prevent.
It would still hit whatever is causing it to see a new WAN IP triggering the reload of the interface and everything on it.Reviewing the thread though, this seems odd:
@mixka said in "tun_wg0: loop detected" following WireGuard gateway 100% loss and WAN interface rc.newwanip:I pin down problem that they all was behind same dummy switch. I restarted that switch and everything worked like 2 minutes and then goes down. I removed that switch and everything back to normal.
Could it be that switch has some loop detection and was shutting down one or more ports to prevent it?
If so that implies whatever is creating the loop ends up sending traffic to the LAN side incorrectly.Try checking the routing tables when it's working and compare that to the failed state.
Steve
-
This post is deleted! -
This post is deleted! -
This post is deleted! -
I have now connected one host directly to pfSense interface and deleted every VLAN and unnecessary interface. So every switch is out. Problem still exist.
How I can check routing tables when problem occur? It last under minute. Maybe I remove interface monitoring, so it won't recover from loop.
Also do you know if these settings are ok for eliminating buffer bloat? https://forum.netgate.com/topic/112527/playing-with-fq_codel-in-2-4/775
Aug 15 11:19:08 dhclient 20300 Creating resolv.conf Aug 15 11:19:08 dhclient 20119 Adding new routes to interface: igb0 Aug 15 11:19:08 dhclient 19776 New Routers (igb0): WAN_GW_IP Aug 15 11:19:08 dhclient 19433 New Broadcast Address (igb0): WAN_255_IP Aug 15 11:19:08 dhclient 19284 New Subnet Mask (igb0): 255.255.240.0 Aug 15 11:19:08 dhclient 19165 New IP Address (igb0): WAN_IP Aug 15 11:19:08 dhclient 18956 ifconfig igb0 inet WAN_IP netmask 255.255.240.0 broadcast WAN_255_IP Aug 15 11:19:08 dhclient 18914 Starting add_new_address() Aug 15 11:19:08 dhclient 18658 BOUND Aug 15 11:19:08 dhclient 18543 ARPCHECK Aug 15 11:19:05 dhclient 17989 ARPSEND Aug 15 11:19:05 dhclient 17554 PREINIT Aug 15 11:19:05 dhclient 16730 Deleting old routes Aug 15 11:19:05 dhclient 16311 EXPIRE Aug 15 11:19:09 check_reload_status 487 Reloading filter Aug 15 11:19:09 php-fpm 1307 /rc.newwanip: rc.newwanip: on (IP address: WAN_IP) (interface: WAN1[wan]) (real interface: igb0). Aug 15 11:19:09 php-fpm 1307 /rc.newwanip: rc.newwanip: Info: starting on igb0. Aug 15 11:19:08 check_reload_status 487 rc.newwanip starting igb0 Aug 15 11:19:08 kernel tun_wg1: loop detected Aug 15 11:19:07 kernel tun_wg1: loop detected Aug 15 11:19:07 kernel arpresolve: can't allocate llinfo for WAN_GW_IP on igb0 Aug 15 11:19:07 kernel tun_wg1: loop detected Aug 15 11:19:07 kernel tun_wg1: loop detected Aug 15 11:19:07 kernel arpresolve: can't allocate llinfo for WAN_GW_IP on igb0 Aug 15 11:19:06 kernel tun_wg1: loop detected Aug 15 11:19:06 kernel arpresolve: can't allocate llinfo for WAN_GW_IP on igb0 Aug 15 11:19:06 kernel tun_wg1: loop detected Aug 15 11:19:06 kernel arpresolve: can't allocate llinfo for WAN_GW_IP on igb0
-
Ah, I was just reviewing. Did something change?
-
I did not find anything change in behaviour, if that is what you mean.
Now I even tried with different connection. I have 5G router in bridged mode with external IP connected to WAN port. Still seeing loop messages in log:
Aug 15 21:16:59 php 5817 [pfBlockerNG] filterlog daemon started Aug 15 21:16:59 tail_pfb 5432 [pfBlockerNG] Firewall Filter Service started Aug 15 21:16:59 lighttpd_pfb 4636 [pfBlockerNG] DNSBL Webserver started Aug 15 21:16:59 php_pfb 1738 [pfBlockerNG] filterlog daemon stopped Aug 15 21:16:59 tail_pfb 1131 [pfBlockerNG] Firewall Filter Service stopped Aug 15 21:16:59 lighttpd_pfb 872 [pfBlockerNG] DNSBL Webserver stopped Aug 15 21:16:59 php-fpm 445 /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Applied package default settings as necessary. Aug 15 21:16:58 php-fpm 445 /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed Unbound ACL group (WireGuard). Aug 15 21:16:58 php-fpm 445 /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed Unbound ACL group (WireGuard). Aug 15 21:16:58 php-fpm 445 /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed interface group (WireGuard). Aug 15 21:16:58 php-fpm 445 /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed interface group (WireGuard). Aug 15 21:16:58 php-fpm 24315 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Aug 15 21:16:58 check_reload_status 484 Syncing firewall Aug 15 21:16:58 php-fpm 445 /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed earlyshellcmd(s). Aug 15 21:16:58 check_reload_status 484 Syncing firewall Aug 15 21:16:58 php-fpm 445 /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed earlyshellcmd(s). Aug 15 21:16:58 php 73522 haproxy: started new pid:76645 Aug 15 21:16:58 php 73522 haproxy: reload old pid:60858 Aug 15 21:16:58 php-fpm 445 /rc.start_packages: Restarting/Starting all packages. Aug 15 21:16:57 check_reload_status 484 Starting packages Aug 15 21:16:57 php-fpm 40603 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - OLD_WAN_GW_IP -> WAN_IP - Restarting packages. Aug 15 21:16:57 check_reload_status 484 Starting packages Aug 15 21:16:57 php-fpm 446 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - OLD_WAN_GW_IP -> WAN_IP - Restarting packages. Aug 15 21:16:55 php-fpm 40603 /rc.newwanip: Creating rrd update script Aug 15 21:16:55 php-fpm 40603 /rc.newwanip: Resyncing OpenVPN instances for interface WAN1. Aug 15 21:16:55 php-fpm 446 /rc.newwanip: Creating rrd update script Aug 15 21:16:55 php-fpm 446 /rc.newwanip: Resyncing OpenVPN instances for interface WAN1. Aug 15 21:16:54 php-fpm 40603 /rc.newwanip: phpDynDNS (pfsense.example.fi): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Aug 15 21:16:54 php-fpm 90936 /rc.dyndns.update: phpDynDNS (pfsense.example.fi): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Aug 15 21:16:54 php-fpm 446 /rc.newwanip: phpDynDNS (pfsense): (Success) pfsense updated to WAN_IP Aug 15 21:16:54 php-fpm 446 /rc.newwanip: phpDynDNS: updating cache file /conf/dyndns_wancloudflare'pfsense.example.fi'0.cache: WAN_IP Aug 15 21:16:46 php-fpm 40603 /rc.newwanip: IP Address has changed, killing states on former IP Address OLD_WAN_GW_IP. Aug 15 21:16:46 check_reload_status 484 Reloading filter Aug 15 21:16:46 check_reload_status 484 updating dyndns wan Aug 15 21:16:46 php-fpm 40603 /rc.newwanip: Removing static route for monitor 8.8.4.4 and adding a new route through WG_VPN_GW_IP Aug 15 21:16:46 php-fpm 40603 /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through WG_VPN_GW_IP Aug 15 21:16:46 php-fpm 40603 /rc.newwanip: Removing static route for monitor 1.1.1.1 and adding a new route through WAN_GW_IP Aug 15 21:16:45 php-fpm 79596 /rc.linkup: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1660587405] unbound[93610:0] error: bind: address already in use [1660587405] unbound[93610:0] fatal error: could not open ports' Aug 15 21:16:43 check_reload_status 484 Restarting IPsec tunnels Aug 15 21:16:43 check_reload_status 484 Restarting IPsec tunnels Aug 15 21:16:43 check_reload_status 484 updating dyndns GW_VPN3_gw Aug 15 21:16:43 check_reload_status 484 Restarting OpenVPN tunnels/interfaces Aug 15 21:16:43 check_reload_status 484 Restarting IPsec tunnels Aug 15 21:16:43 check_reload_status 484 updating dyndns GW_VPN2_gw Aug 15 21:16:43 rc.gateway_alarm 39811 >>> Gateway alarm: GW_VPN3_gw (Addr:8.8.8.8 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%) Aug 15 21:16:43 rc.gateway_alarm 41358 >>> Gateway alarm: GW_VPN2_gw (Addr:8.8.4.4 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%) Aug 15 21:16:43 kernel tun_wg0: loop detected Aug 15 21:16:43 kernel tun_wg0: loop detected Aug 15 21:16:42 kernel tun_wg0: loop detected Aug 15 21:16:42 kernel tun_wg0: loop detected Aug 15 21:16:42 kernel tun_wg0: loop detected Aug 15 21:16:42 php-fpm 40603 /rc.newwanip: rc.newwanip: on (IP address: WAN_IP) (interface: WAN1[wan]) (real interface: igb0). Aug 15 21:16:42 kernel tun_wg0: loop detected Aug 15 21:16:42 php-fpm 40603 /rc.newwanip: rc.newwanip: Info: starting on igb0. Aug 15 21:16:41 kernel tun_wg0: loop detected Aug 15 21:16:41 kernel tun_wg0: loop detected Aug 15 21:16:41 check_reload_status 484 rc.newwanip starting igb0 Aug 15 21:16:41 kernel tun_wg0: loop detected Aug 15 21:16:41 php-fpm 445 /rc.dyndns.update: Dynamic DNS (pfsense.example.fi) There was an error trying to determine the public IP for interface - wan (igb0 ). Aug 15 21:16:41 php-fpm 445 /rc.dyndns.update: Dynamic DNS cloudflare (pfsense.example.fi): IP address could not be extracted from Check IP Service Aug 15 21:16:41 kernel tun_wg0: loop detected Aug 15 21:16:41 php-fpm 79596 /rc.linkup: HOTPLUG: Configuring interface wan Aug 15 21:16:41 php-fpm 79596 /rc.linkup: DEVD Ethernet attached event for wan Aug 15 21:16:41 check_reload_status 484 Reloading filter Aug 15 21:16:41 kernel tun_wg0: loop detected Aug 15 21:16:41 php-fpm 445 /rc.dyndns.update: dpinger: No dpinger session running for gateway GW_VPN3_gw Aug 15 21:16:41 kernel tun_wg0: loop detected Aug 15 21:16:41 php-fpm 445 /rc.dyndns.update: dpinger: No dpinger session running for gateway GW_VPN2_gw Aug 15 21:16:41 php-fpm 90936 /rc.linkup: Removing static route for monitor 8.8.4.4 and adding a new route through WG_VPN_GW_IP Aug 15 21:16:41 php-fpm 90936 /rc.linkup: Removing static route for monitor 8.8.8.8 and adding a new route through WG_VPN_GW_IP Aug 15 21:16:40 php-fpm 446 /rc.newwanip: IP Address has changed, killing states on former IP Address OLD_WAN_GW_IP. Aug 15 21:16:40 check_reload_status 484 Restarting OpenVPN tunnels/interfaces Aug 15 21:16:40 check_reload_status 484 Restarting IPsec tunnels Aug 15 21:16:40 rc.gateway_alarm 28598 >>> Gateway alarm: GW_VPN3_gw (Addr:8.8.8.8 Alarm:1 RTT:1858.240ms RTTsd:0.000ms Loss:0%) Aug 15 21:16:40 php-fpm 90936 /rc.linkup: DEVD Ethernet detached event for wan Aug 15 21:16:40 check_reload_status 484 Reloading filter Aug 15 21:16:40 check_reload_status 484 updating dyndns wan Aug 15 21:16:38 php-fpm 446 /rc.newwanip: Removing static route for monitor 8.8.4.4 and adding a new route through WG_VPN_GW_IP Aug 15 21:16:38 php-fpm 446 /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through WG_VPN_GW_IP Aug 15 21:16:38 php-fpm 446 /rc.newwanip: Removing static route for monitor 1.1.1.1 and adding a new route through WAN_GW_IP Aug 15 21:16:37 check_reload_status 484 Reloading filter Aug 15 21:16:37 check_reload_status 484 Restarting OpenVPN tunnels/interfaces Aug 15 21:16:37 check_reload_status 484 Restarting IPsec tunnels Aug 15 21:16:37 check_reload_status 484 updating dyndns GW_VPN2_gw Aug 15 21:16:37 rc.gateway_alarm 80506 >>> Gateway alarm: GW_VPN2_gw (Addr:8.8.4.4 Alarm:1 RTT:14837.011ms RTTsd:12222.434ms Loss:58%) Aug 15 21:16:37 php-fpm 446 /rc.newwanip: rc.newwanip: on (IP address: WAN_IP) (interface: WAN1[wan]) (real interface: igb0). Aug 15 21:16:37 php-fpm 446 /rc.newwanip: rc.newwanip: Info: starting on igb0. Aug 15 21:16:36 check_reload_status 484 Restarting IPsec tunnels Aug 15 21:16:36 check_reload_status 484 rc.newwanip starting igb0 Aug 15 21:16:27 check_reload_status 484 Linkup starting igb0 Aug 15 21:16:27 kernel igb0: link state changed to UP Aug 15 21:16:23 check_reload_status 484 Linkup starting igb0 Aug 15 21:16:23 kernel igb0: link state changed to DOWN Aug 15 21:16:18 php-fpm 445 /rc.linkup: HOTPLUG: Configuring interface wan Aug 15 21:16:18 php-fpm 445 /rc.linkup: DEVD Ethernet attached event for wan Aug 15 21:16:17 kernel igb0: link state changed to UP Aug 15 21:16:17 check_reload_status 484 Linkup starting igb0
-
That log message is created by interface recursions such as a tunnel trying to open connections inside itself. The last time I saw this it was because of peer IPs that were defined as IPs inside the tunnel subnet:
https://forum.netgate.com/topic/168357/system-log-tun_wg0-loop-detectedHowever, since you're not seeing this continually it seems very likely that the default gateway setting being via the WG tunnel is causing problems when it fails or perhaps when it recovers.
If you don't configure the system default gateway to be the WG gateway and instead use policy based routing does it stop those logs?
Steve
-
I did lot of testing. Really pulled out my hairs out.
TL;DR: After I let my WAN interface DHCP lease to expire I changed interface MAC address to make sure that I got another IP. With new IP everything is working as should.
Really nice :)