No dpinger session running for gateway - for no reason when switching WANs
-
I am on triple-WAN with fail over.
WAN-DHCP - cable modem - Tier 1 [let's call it WAN1]
WAN2_PPPOE - VDSL - Tier 2
WAN3CELL_DHCP - LTE modem in bridge mode - Tier 3I am on pfSense Plus 22.05, the latest.
Everything seemed to run fine until one day I decided to remove a dumb switch from between the cable modem (the WAN_DHCP) and pfSense. I unplugged Ethernet cables, removed the switch and plugged them back in less than a minute. I expected pfSense to fail over to WAN2_PPOE and it kind of did until I noticed that one of my 5 Dynamic DNS IPs was updated briefly to WAN3CELL_DHCP but then to WAN2_PPPOE. I noticed that only from Pushover messages that I get.
I had a look at the logs and saw pfSense failed over to WAN2, updated the first DynDSN, than showed message
/rc.dyndns.update: dpinger: No dpinger session running for gateway WAN2_PPPOE
for no reason. Switched to WAN3. Updated the second DynDNS. 3 second later switched to WAN2. Re-updated the second DynDNS to WAN2 IP and after that everything went as normal - updated the rest of DynDNS and failed back to WAN1 after I reconnected the cables.
Below is the full log around this unusual event. I think the developers should have a look as it seems there was some kind of a race condition that caused that "No dpinger session running for gateway".
Jul 30 13:53:56 php-fpm 48340 /rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_PreferWANcustom'*'1.cache: [WAN2-IP] Jul 30 13:53:55 php-fpm 454 /rc.dyndns.update: phpDynDNS (*): (Success) IP Address Updated Successfully! Jul 30 13:53:55 php-fpm 454 /rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_PreferWANcustom'*'1.cache: [WAN3-IP] Jul 30 13:53:55 php-fpm 202 /rc.filter_configure_sync: GW States: Gateway is down but its IP address cannot be located. Skipping state kill.: WAN_DHCP Jul 30 13:53:54 php-fpm 453 /rc.filter_configure_sync: GW States: Gateway is down but its IP address cannot be located. Skipping state kill.: WAN_DHCP Jul 30 13:53:53 php-fpm 48340 /rc.dyndns.update: phpDynDNS (*): No change in my IP address and/or 15 days has not passed. Not updating dynamic DNS entry. Jul 30 13:53:52 php-fpm 454 /rc.dyndns.update: Default gateway setting Interface WAN2_PPPOE Gateway as default. Jul 30 13:53:52 php-fpm 454 /rc.dyndns.update: Gateway, switch to: WAN2_PPPOE Jul 30 13:53:52 php-fpm 453 /rc.filter_configure_sync: Default gateway setting Interface WAN2_PPPOE Gateway as default. Jul 30 13:53:52 php-fpm 453 /rc.filter_configure_sync: Gateway, switch to: WAN2_PPPOE Jul 30 13:53:51 check_reload_status 483 Reloading filter Jul 30 13:53:51 check_reload_status 483 Restarting OpenVPN tunnels/interfaces Jul 30 13:53:51 check_reload_status 483 Restarting IPsec tunnels Jul 30 13:53:51 check_reload_status 483 updating dyndns WAN_DHCP Jul 30 13:53:51 rc.gateway_alarm 24258 >>> Gateway alarm: WAN_DHCP (Addr:x.x.x.x Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%) Jul 30 13:53:49 php-fpm 454 /rc.dyndns.update: Default gateway setting Interface WAN3CELL_DHCP Gateway as default. Jul 30 13:53:49 php-fpm 454 /rc.dyndns.update: Gateway, switch to: WAN3CELL_DHCP Jul 30 13:53:49 check_reload_status 483 Reloading filter Jul 30 13:53:49 php-fpm 454 /rc.dyndns.update: dpinger: No dpinger session running for gateway WAN2_PPPOE Jul 30 13:53:49 php-fpm 202 /rc.linkup: Removing static route for monitor q.q.q.q and adding a new route through [WAN3-IP] Jul 30 13:53:49 php-fpm 48340 /rc.filter_configure_sync: GW States: Killing states for down gateway: WAN_DHCP, [WAN1-IP] Jul 30 13:53:49 php 44710 notify_monitor.php: Message sent to xxx OK Jul 30 13:53:48 php-fpm 454 /rc.dyndns.update: phpDynDNS (*): (Success) IP Address Updated Successfully! Jul 30 13:53:48 php-fpm 454 /rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_PreferWANcustom'*'0.cache: [WAN2-IP] Jul 30 13:53:48 php-fpm 202 /rc.linkup: DEVD Ethernet detached event for wan Jul 30 13:53:47 php-fpm 48340 /rc.filter_configure_sync: Default gateway setting Interface WAN2_PPPOE Gateway as default. Jul 30 13:53:47 php-fpm 454 /rc.dyndns.update: Default gateway setting Interface WAN2_PPPOE Gateway as default. Jul 30 13:53:47 php-fpm 48340 /rc.filter_configure_sync: Gateway, switch to: WAN2_PPPOE Jul 30 13:53:47 php-fpm 454 /rc.dyndns.update: Gateway, switch to: WAN2_PPPOE Jul 30 13:53:47 php-fpm 453 x.x.x.x|y.y.y.y|WAN_DHCP|24.41ms|6.498ms|21%|down|highloss Jul 30 13:53:47 php-fpm 453 /rc.openvpn: MONITOR: WAN_DHCP has packet loss, omitting from routing group PreferWAN Jul 30 13:53:47 kernel igb0: link state changed to DOWN
-
I encountered another issue with dpinger. I changed one unimportant parameter in the WAN interface (CIDR length for the alias IPv4 address). Pressed save and apply and noticed that my IP switched over to the failover WAN2, then back to WAN1. I looked at the logs and found this:
php-fpm 89297 /interfaces.php: The command '/usr/local/bin/dpinger -S -r 0 -i WAN_DHCP -B x.x.x.x -p /var/run/dpinger_WAN_DHCP~x.x.x.x~y.y.y.y.pid -u /var/run/dpinger_WAN_DHCP~x.x.x.x~y.y.y.y.sock -C "/etc/rc.gateway_alarm" -d 1 -s 500 -l 2000 -t 30000 -A 1000 -D 500 -L 20 y.y.y.y.>/dev/null' returned exit code '1', the output was ''
It's weird that I saw changes for WAN3 that I haven't touched. I think the developers should have a look at the whole multi-WAN system. More logs:
Aug 4 19:02:27 php-fpm 73902 /rc.filter_configure_sync: Default gateway setting Interface WAN_DHCP Gateway as default. Aug 4 19:02:27 php-fpm 73902 /rc.filter_configure_sync: Gateway, switch to: WAN_DHCP Aug 4 19:02:25 upsmon 11497 Startup successful Aug 4 19:02:25 php-fpm 48340 /rc.start_packages: Starting service nut Aug 4 19:02:25 upsmon 85376 Signal 15: exiting Aug 4 19:02:25 php-fpm 48340 /rc.start_packages: Stopping service nut Aug 4 19:02:25 php-fpm 48340 /rc.start_packages: Restarting/Starting all packages. Aug 4 19:02:24 check_reload_status 483 Starting packages Aug 4 19:02:24 php-fpm 89297 /interfaces.php: Creating rrd update script Aug 4 19:02:24 check_reload_status 483 Reloading filter Aug 4 19:02:24 php-fpm 89297 /interfaces.php: Removing static route for monitor m.m.m.m and adding a new route through n.n.n.n [this is untouched WAN3] Aug 4 19:02:24 php-fpm 89297 /interfaces.php: Removing static route for monitor y.y.y.y and adding a new route through x1.x1.x1.x1 [this is WAN1] Aug 4 19:02:24 php-fpm 89297 /interfaces.php: Resyncing OpenVPN instances for interface WAN. Aug 4 19:02:23 php 77068 notify_monitor.php: Message sent to X OK Aug 4 19:02:22 php-fpm 202 /rc.dyndns.update: phpDynDNS (): (Success) IP Address Updated Successfully! Aug 4 19:02:22 php-fpm 202 /rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_PreferWANcustom''0.cache: k.k.k.k [this is WAN2 IP] Aug 4 19:02:21 check_reload_status 483 updating dyndns wan Aug 4 19:02:19 dhcpleases 50889 Could not deliver signal HUP to process 71960: No such process. Aug 4 19:02:18 check_reload_status 483 Restarting IPsec tunnels Aug 4 19:02:18 php-fpm 775 /rc.filter_configure_sync: Gateway, switch to: WAN2_PPPOE Aug 4 19:02:18 php-fpm 89297 /interfaces.php: Default gateway setting Interface WAN2_PPPOE Gateway as default. Aug 4 19:02:18 php-fpm 89297 /interfaces.php: Gateway, switch to: WAN2_PPPOE Aug 4 19:02:17 check_reload_status 483 Reloading filter Aug 4 19:02:17 php-fpm 98601 /rc.newwanip: rc.newwanip: on (IP address: x.x.x.x) (interface: WAN[wan]) (real interface: igb0). Aug 4 19:02:17 php-fpm 98601 /rc.newwanip: rc.newwanip: Info: starting on igb0. Aug 4 19:02:16 check_reload_status 483 rc.newwanip starting igb0 Aug 4 19:02:16 php-fpm 89297 /interfaces.php: Error starting gateway monitor for WAN_DHCP Aug 4 19:02:16 php-fpm 89297 /interfaces.php: The command '/usr/local/bin/dpinger -S -r 0 -i WAN_DHCP -B x.x.x.x -p /var/run/dpinger_WAN_DHCP~x.x.x.x~y.y.y.y.pid -u /var/run/dpinger_WAN_DHCP~x.x.x.x~y.y.y.y.sock -C "/etc/rc.gateway_alarm" -d 1 -s 500 -l 2000 -t 30000 -A 1000 -D 500 -L 20 y.y.y.y.>/dev/null' returned exit code '1', the output was '' Aug 4 19:02:16 php-fpm 89297 /interfaces.php: Removing static route for monitor m.m.m.m and adding a new route through n.n.n.n [this is really weird - this is untouched WAN3]
-
-