pfSense WAN dhcp client exiting (error)
-
Suricata in in-line mode (as opposed to legacy mode) uses a netgraph interface to intercept the packets before it hits the interface. When that is created at start up the interface it moved from the NIC to the ng device and you can see a link state change. That might be what you're seeing. It shouldn't create a loop though.
-
Suricata in non blocking mode
Completely forgotten today is a holiday here, so the Log (Part1/2):
Mar 29 10:59:19 php-fpm[82809]: /interfaces.php: Configuration Change: admin@192.168.xxx.xxx (Local Database): Interfaces settings changed Mar 29 10:59:19 check_reload_status[433]: Syncing firewall Mar 29 10:59:21 check_reload_status[433]: Linkup starting em1 Mar 29 10:59:21 kernel: em1: link state changed to DOWN Mar 29 10:59:22 php-fpm[394]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp) Mar 29 10:59:22 php-fpm[394]: /rc.linkup: DEVD Ethernet detached event for wan Mar 29 10:59:22 rc.gateway_alarm[55196]: >>> Gateway alarm: WAN_DHCP (Addr: Alarm:down RTT:0ms RTTsd:0ms Loss:100%) Mar 29 10:59:22 check_reload_status[433]: updating dyndns WAN_DHCP Mar 29 10:59:22 check_reload_status[433]: Restarting IPsec tunnels Mar 29 10:59:22 check_reload_status[433]: Restarting OpenVPN tunnels/interfaces Mar 29 10:59:22 check_reload_status[433]: Reloading filter Mar 29 10:59:24 php-fpm[86993]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 10:59:24 check_reload_status[433]: Linkup starting em1 Mar 29 10:59:24 kernel: em1: link state changed to UP Mar 29 10:59:27 check_reload_status[433]: rc.newwanip starting em1 Mar 29 10:59:27 php-fpm[393]: /interfaces.php: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 10:59:27 check_reload_status[433]: Restarting IPsec tunnels Mar 29 10:59:28 php-fpm[97591]: /rc.newwanip: rc.newwanip: Info: starting on em1. Mar 29 10:59:28 php-fpm[97591]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.xxx.xxx) (interface: WAN[wan]) (real interface: em1). Mar 29 10:59:32 php-fpm[97591]: /rc.newwanip: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx Mar 29 10:59:34 check_reload_status[433]: Reloading filter Mar 29 10:59:34 php-fpm[86993]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp) Mar 29 10:59:34 php-fpm[86993]: /rc.linkup: DEVD Ethernet attached event for wan Mar 29 10:59:34 php-fpm[86993]: /rc.linkup: HOTPLUG: Configuring interface wan Mar 29 10:59:34 kernel: em1: link state changed to DOWN Mar 29 10:59:34 check_reload_status[433]: Linkup starting em1 Mar 29 10:59:35 php-fpm[97591]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:35 php-fpm[97591]: /rc.newwanip: Default gateway setting Interface WAN_DHCP Gateway as default. Mar 29 10:59:35 php-fpm[97591]: /rc.newwanip: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 10:59:35 php-fpm[97591]: /rc.newwanip: IP Address has changed, killing states on former IP Address 0.0.0.0. Mar 29 10:59:35 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:37 check_reload_status[433]: Linkup starting em1 Mar 29 10:59:37 kernel: em1: link state changed to UP Mar 29 10:59:37 php-fpm[36554]: /widgets/widgets/gateways.widget.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:38 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:39 php-fpm[394]: /rc.filter_configure_sync: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:40 check_reload_status[433]: rc.newwanip starting em1 Mar 29 10:59:41 php-fpm[82809]: /rc.newwanip: rc.newwanip: Info: starting on em1. Mar 29 10:59:41 php-fpm[82809]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.xxx.xxx) (interface: WAN[wan]) (real interface: em1). Mar 29 10:59:42 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:43 php-fpm[394]: /rc.filter_configure_sync: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:43 php-fpm[86993]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:43 php-fpm[86993]: /rc.linkup: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 10:59:43 check_reload_status[433]: Restarting IPsec tunnels Mar 29 10:59:46 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:49 php-fpm[393]: /interfaces.php: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711706389] unbound[68849:0] error: bind: address already in use [1711706389] unbound[68849:0] fatal error: could not open ports' Mar 29 10:59:50 check_reload_status[433]: updating dyndns wan Mar 29 10:59:54 php-fpm[82809]: /rc.newwanip: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx Mar 29 10:59:58 php-fpm[82809]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:58 php-fpm[82809]: /rc.newwanip: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 10:59:58 php-fpm[82809]: /rc.newwanip: IP Address has changed, killing states on former IP Address 0.0.0.0. Mar 29 10:59:59 php-fpm[86993]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:59 php-fpm[97591]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 10:59:59 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:00 php[69011]: [pfBlockerNG] Starting cron process. Mar 29 11:00:00 php-cgi[70512]: servicewatchdog_cron.php: Service Watchdog detected service unbound stopped. Restarting unbound (DNS Resolver) Mar 29 11:00:02 php-fpm[394]: /rc.dyndns.update: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:03 php-fpm[86993]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:03 php-fpm[97591]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:03 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:04 php[69011]: [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Mar 29 11:00:04 php-cgi[70840]: rc.filter_configure_sync: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:04 php-fpm[82809]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:05 php-fpm[63073]: /widgets/widgets/gateways.widget.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:06 php-fpm[86993]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:06 php-cgi[70512]: servicewatchdog_cron.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:06 php-fpm[97591]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:07 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:07 php-cgi[70840]: rc.filter_configure_sync: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:08 php-fpm[82809]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:10 php-fpm[86993]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:10 php-cgi[70512]: servicewatchdog_cron.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:10 php-fpm[97591]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:10 php-fpm[393]: /interfaces.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:11 php-fpm[82809]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:00:19 php-fpm[393]: /interfaces.php: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711706419] unbound[3007:0] error: bind: address already in use [1711706419] unbound[3007:0] fatal error: could not open ports' Mar 29 11:00:19 php-fpm[97591]: /rc.newwanip: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711706419] unbound[89726:0] error: bind: address already in use [1711706419] unbound[89726:0] fatal error: could not open ports' Mar 29 11:00:20 php-fpm[82809]: /rc.newwanip: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711706420] unbound[3633:0] error: bind: address already in use [1711706420] unbound[3633:0] fatal error: could not open ports' Mar 29 11:00:20 php-cgi[70512]: servicewatchdog_cron.php: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711706420] unbound[38652:0] error: bind: address already in use [1711706420] unbound[38652:0] fatal error: could not open ports' Mar 29 11:00:22 php-fpm[393]: /interfaces.php: Resyncing OpenVPN instances for interface WAN. Mar 29 11:00:22 php-fpm[393]: /interfaces.php: Removing static route for monitor xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx Mar 29 11:00:22 check_reload_status[433]: Reloading filter Mar 29 11:00:23 php-fpm[393]: /interfaces.php: Creating rrd update script Mar 29 11:00:23 check_reload_status[433]: Starting packages Mar 29 11:00:23 check_reload_status[433]: updating dyndns wan Mar 29 11:00:23 check_reload_status[433]: Reloading filter Mar 29 11:00:23 php-fpm[18930]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp) Mar 29 11:00:23 php-fpm[18930]: /rc.linkup: DEVD Ethernet detached event for wan Mar 29 11:00:24 php-fpm[63073]: /rc.start_packages: Restarting/Starting all packages. Mar 29 11:00:24 php-fpm[394]: /rc.filter_configure_sync: dpinger: status socket /var/run/dpinger_WAN_DHCP~192.168.xxx.xxx~xxx.xxx.xxx.xxx.sock not found Mar 29 11:00:24 php-fpm[86993]: /rc.dyndns.update: dpinger: status socket /var/run/dpinger_WAN_DHCP~192.168.xxx.xxx~xxx.xxx.xxx.xxx.sock not found Mar 29 11:00:24 php-fpm[393]: /widgets/widgets/gateways.widget.php: dpinger: status socket /var/run/dpinger_WAN_DHCP~192.168.xxx.xxx~xxx.xxx.xxx.xxx.sock not found Mar 29 11:00:24 rc.gateway_alarm[77855]: >>> Gateway alarm: WAN_DHCP (Addr:192.168.xxx.xxx Alarm:down RTT:0ms RTTsd:0ms Loss:100%) Mar 29 11:00:24 check_reload_status[433]: updating dyndns WAN_DHCP Mar 29 11:00:24 check_reload_status[433]: Restarting IPsec tunnels Mar 29 11:00:24 check_reload_status[433]: Restarting OpenVPN tunnels/interfaces Mar 29 11:00:24 check_reload_status[433]: Reloading filter Mar 29 11:00:26 php-cgi[70512]: servicewatchdog_cron.php: Service Watchdog detected service dpinger stopped. Restarting dpinger (Gateway Monitoring Daemon) Mar 29 11:00:28 php-fpm[393]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 11:00:37 php-cgi[70512]: servicewatchdog_cron.php: The command '/usr/local/bin/dpinger -S -r 0 -i WAN_DHCP -B 192.168.xxx.xxx -p /var/run/dpinger_WAN_DHCP~192.168.xxx.xxx~xxx.xxx.xxx.xxx.pid -u /var/run/dpinger_WAN_DHCP~192.168.xxx.xxx~xxx.xxx.xxx.xxx.sock -C "/etc/rc.gateway_alarm" -d 1 -s 15000 -l 2000 -t 60000 -A 30000 -D 500 -L 20 xxx.xxx.xxx.xxx >/dev/null' returned exit code '1', the output was '' Mar 29 11:00:37 php-cgi[70512]: servicewatchdog_cron.php: Error starting gateway monitor for WAN_DHCP Mar 29 11:00:41 bandwidthd[50037]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:00:41 bandwidthd[50037]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:00:41 bandwidthd[50037]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:00:41 bandwidthd[50197]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:00:41 bandwidthd[50197]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:00:41 bandwidthd[50197]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:00:41 bandwidthd[51006]: Recovering from log.1.2.cdf Mar 29 11:00:41 bandwidthd[51246]: Recovering from log.2.0.cdf Mar 29 11:00:41 bandwidthd[51345]: Recovering from log.3.0.cdf Mar 29 11:00:41 bandwidthd[51650]: Recovering from log.4.0.cdf Mar 29 11:00:41 bandwidthd[55014]: Recovering from log.2.0.cdf Mar 29 11:00:41 bandwidthd[51889]: Recovering from log.1.2.cdf Mar 29 11:00:41 bandwidthd[55271]: Recovering from log.3.0.cdf Mar 29 11:00:41 bandwidthd[55302]: Recovering from log.4.0.cdf Mar 29 11:00:41 bandwidthd[55302]: Finished recovering 5224 records Mar 29 11:00:41 bandwidthd[55302]: Opening re1 Mar 29 11:00:41 bandwidthd[55302]: Packet Encoding: Ethernet Mar 29 11:00:41 bandwidthd[55302]: Drawing initial graphs Mar 29 11:00:41 bandwidthd[51650]: Finished recovering 5224 records Mar 29 11:00:41 bandwidthd[51650]: Opening re1 Mar 29 11:00:41 bandwidthd[51650]: Packet Encoding: Ethernet Mar 29 11:00:41 bandwidthd[51650]: Drawing initial graphs Mar 29 11:00:41 bandwidthd[51006]: Finished recovering 16510 records Mar 29 11:00:41 bandwidthd[51889]: Finished recovering 16510 records Mar 29 11:00:41 bandwidthd[51006]: Recovering from log.1.1.cdf Mar 29 11:00:41 bandwidthd[51889]: Recovering from log.1.1.cdf Mar 29 11:00:41 bandwidthd[51889]: Finished recovering 15184 records Mar 29 11:00:41 bandwidthd[51889]: Recovering from log.1.0.cdf Mar 29 11:00:41 bandwidthd[51006]: Finished recovering 15184 records Mar 29 11:00:41 bandwidthd[51889]: Finished recovering 6624 records Mar 29 11:00:41 bandwidthd[51889]: Opening re1 Mar 29 11:00:41 bandwidthd[51006]: Recovering from log.1.0.cdf Mar 29 11:00:41 bandwidthd[51889]: Packet Encoding: Ethernet Mar 29 11:00:41 bandwidthd[51889]: Drawing initial graphs Mar 29 11:00:41 bandwidthd[51006]: Finished recovering 6624 records Mar 29 11:00:42 bandwidthd[51006]: Opening re1 Mar 29 11:00:42 bandwidthd[51006]: Packet Encoding: Ethernet Mar 29 11:00:42 bandwidthd[51006]: Drawing initial graphs Mar 29 11:00:42 bandwidthd[51345]: Finished recovering 119912 records Mar 29 11:00:42 bandwidthd[51345]: Opening re1 Mar 29 11:00:42 bandwidthd[51345]: Packet Encoding: Ethernet Mar 29 11:00:42 bandwidthd[51345]: Drawing initial graphs Mar 29 11:00:42 bandwidthd[51246]: Finished recovering 166949 records Mar 29 11:00:42 bandwidthd[51246]: Failed to parse part of log file. Giving up on the file Mar 29 11:00:42 bandwidthd[51246]: Opening re1 Mar 29 11:00:42 bandwidthd[51246]: Packet Encoding: Ethernet Mar 29 11:00:42 bandwidthd[51246]: Drawing initial graphs Mar 29 11:00:42 php-fpm[63073]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed earlyshellcmd(s). Mar 29 11:00:42 check_reload_status[433]: Syncing firewall Mar 29 11:00:42 php-fpm[63073]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed earlyshellcmd(s). Mar 29 11:00:42 bandwidthd[55271]: Finished recovering 119912 records Mar 29 11:00:42 bandwidthd[55271]: Opening re1 Mar 29 11:00:42 bandwidthd[55271]: Packet Encoding: Ethernet Mar 29 11:00:42 bandwidthd[55271]: Drawing initial graphs Mar 29 11:00:43 check_reload_status[433]: Syncing firewall Mar 29 11:00:43 bandwidthd[55014]: Finished recovering 166949 records Mar 29 11:00:43 bandwidthd[55014]: Failed to parse part of log file. Giving up on the file Mar 29 11:00:43 bandwidthd[55014]: Opening re1 Mar 29 11:00:43 bandwidthd[55014]: Packet Encoding: Ethernet Mar 29 11:00:43 bandwidthd[55014]: Drawing initial graphs Mar 29 11:00:43 php-fpm[63073]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed interface group (WireGuard). Mar 29 11:00:43 php-fpm[63073]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed interface group (WireGuard). Mar 29 11:00:43 php-fpm[63073]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed Unbound ACL group (WireGuard). Mar 29 11:00:43 php-fpm[63073]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed Unbound ACL group (WireGuard). Mar 29 11:00:43 php-fpm[63073]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Applied package default settings as necessary. Mar 29 11:00:43 kernel: em0: promiscuous mode disabled Mar 29 11:00:43 kernel: re0.10: promiscuous mode disabled Mar 29 11:00:43 kernel: re0: promiscuous mode disabled Mar 29 11:00:43 kernel: re0.20: promiscuous mode disabled Mar 29 11:00:43 kernel: re0: promiscuous mode enabled Mar 29 11:00:43 kernel: em0: promiscuous mode enabled Mar 29 11:00:43 kernel: re0.10: promiscuous mode enabled Mar 29 11:00:43 kernel: re0.20: promiscuous mode enabled Mar 29 11:00:43 vnstatd[96792]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting. Mar 29 11:00:44 arpwatch[82832]: listening on re1 Mar 29 11:00:44 arpwatch[83279]: listening on em0 Mar 29 11:00:44 arpwatch[83004]: listening on re0 Mar 29 11:00:44 arpwatch[83388]: listening on re0.10 Mar 29 11:00:44 arpwatch[83684]: listening on re0.20 Mar 29 11:00:44 php-fpm[97591]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN. Mar 29 11:00:44 php-fpm[97591]: /rc.newwanip: Creating rrd update script Mar 29 11:00:45 php-fpm[82809]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN. Mar 29 11:00:45 php-fpm[82809]: /rc.newwanip: Creating rrd update script Mar 29 11:00:46 php-fpm[97591]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.168.xxx.xxx - Restarting packages. Mar 29 11:00:46 check_reload_status[433]: Starting packages Mar 29 11:00:46 check_reload_status[433]: Reloading filter Mar 29 11:00:47 php-fpm[82809]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.168.xxx.xxx - Restarting packages. Mar 29 11:00:47 check_reload_status[433]: Starting packages Mar 29 11:00:47 check_reload_status[433]: Reloading filter Mar 29 11:00:47 php-fpm[36554]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp) Mar 29 11:00:47 php-fpm[36554]: /rc.linkup: DEVD Ethernet attached event for wan Mar 29 11:00:47 php-fpm[36554]: /rc.linkup: HOTPLUG: Configuring interface wan Mar 29 11:00:47 check_reload_status[433]: Linkup starting em1 Mar 29 11:00:47 kernel: em1: link state changed to DOWN Mar 29 11:00:48 php-fpm[86993]: /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Mar 29 11:00:48 php-fpm[82809]: /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Mar 29 11:00:50 check_reload_status[433]: Linkup starting em1 Mar 29 11:00:50 kernel: em1: link state changed to UP Mar 29 11:00:51 check_reload_status[433]: rc.newwanip starting em1 Mar 29 11:00:51 php-fpm[36554]: /rc.linkup: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 11:00:51 check_reload_status[433]: Restarting IPsec tunnels Mar 29 11:00:52 php-fpm[393]: /rc.newwanip: rc.newwanip: Info: starting on em1. Mar 29 11:00:52 php-fpm[393]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.xxx.xxx) (interface: WAN[wan]) (real interface: em1). Mar 29 11:00:54 vnstatd[1916]: SIGTERM received, exiting. Mar 29 11:00:54 tail_pfb[93517]: [pfBlockerNG] Firewall Filter Service stopped Mar 29 11:00:54 php_pfb[94573]: [pfBlockerNG] filterlog daemon stopped Mar 29 11:00:54 lighttpd_pfb[95065]: [pfBlockerNG] DNSBL Webserver stopped Mar 29 11:00:54 lighttpd_pfb[97076]: [pfBlockerNG] DNSBL Webserver started Mar 29 11:00:54 vnstatd[98295]: vnStat daemon 2.11 (pid:98295 uid:0 gid:0, SQLite 3.43.1) Mar 29 11:00:54 vnstatd[98295]: Data retention: 48 5MinuteHours, 4 HourlyDays, 62 DailyDays, 25 MonthlyMonths, -1 YearlyYears, 20 TopDayEntries Mar 29 11:00:54 vnstatd[98295]: Monitoring (9): re1 (1000 Mbit) re0.20 (1000 Mbit) re0.10 (1000 Mbit) re0 (1000 Mbit) pfsync0 (1000 Mbit) pflog0 (1000 Mbit) enc0 (1000 Mbit) em1 (1000 Mbit) em0 (100 Mbit) Mar 29 11:00:54 tail_pfb[7]: [pfBlockerNG] Firewall Filter Service started Mar 29 11:00:54 vnstatd[98922]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting. Mar 29 11:00:54 php_pfb[460]: [pfBlockerNG] filterlog daemon started Mar 29 11:00:54 php[97869]: [pfBlockerNG] DNSBL parser daemon started Mar 29 11:01:00 php-cgi[15978]: servicewatchdog_cron.php: Service Watchdog detected service dpinger stopped. Restarting dpinger (Gateway Monitoring Daemon) Mar 29 11:01:00 php-cgi[15978]: servicewatchdog_cron.php: Suppressing repeat e-mail notification message. Mar 29 11:01:09 php-fpm[393]: /rc.newwanip: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx Mar 29 11:01:11 php-cgi[15978]: servicewatchdog_cron.php: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx Mar 29 11:01:13 php-fpm[393]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:01:13 php-fpm[393]: /rc.newwanip: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 11:01:13 php-fpm[393]: /rc.newwanip: IP Address has changed, killing states on former IP Address 0.0.0.0. Mar 29 11:01:17 suricata[33077]: [1:2210054:1] SURICATA STREAM excessive retransmissions [Classification: Generic Protocol Command Decode] [Priority: 3] {TCP} 192.168.xxx.xxx:34238 -> 212.227.xxx.xxx:993 Mar 29 11:01:18 suricata[33077]: [1:2210054:1] SURICATA STREAM excessive retransmissions [Classification: Generic Protocol Command Decode] [Priority: 3] {TCP} 192.168.xxx.xxx:48823 -> 212.227.xxx.xxx:993 Mar 29 11:01:19 php-fpm[393]: /rc.newwanip: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711706479] unbound[99703:0] error: bind: address already in use [1711706479] unbound[99703:0] fatal error: could not open ports' Mar 29 11:01:26 check_reload_status[433]: updating dyndns wan Mar 29 11:01:26 check_reload_status[433]: Reloading filter Mar 29 11:01:26 php-fpm[394]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp) Mar 29 11:01:26 php-fpm[394]: /rc.linkup: DEVD Ethernet detached event for wan Mar 29 11:01:27 rc.gateway_alarm[7691]: >>> Gateway alarm: WAN_DHCP (Addr:192.168.xxx.xxx Alarm:down RTT:0ms RTTsd:0ms Loss:100%) Mar 29 11:01:27 check_reload_status[433]: updating dyndns WAN_DHCP Mar 29 11:01:27 check_reload_status[433]: Restarting IPsec tunnels Mar 29 11:01:27 check_reload_status[433]: Restarting OpenVPN tunnels/interfaces Mar 29 11:01:27 check_reload_status[433]: Reloading filter Mar 29 11:01:29 php-fpm[97591]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 11:01:42 check_reload_status[433]: Reloading filter Mar 29 11:01:42 php-fpm[18930]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp) Mar 29 11:01:42 php-fpm[18930]: /rc.linkup: DEVD Ethernet attached event for wan Mar 29 11:01:42 php-fpm[18930]: /rc.linkup: HOTPLUG: Configuring interface wan Mar 29 11:01:43 kernel: em1: link state changed to DOWN Mar 29 11:01:43 check_reload_status[433]: Linkup starting em1 Mar 29 11:01:45 check_reload_status[433]: Linkup starting em1 Mar 29 11:01:45 kernel: em1: link state changed to UP Mar 29 11:01:46 check_reload_status[433]: rc.newwanip starting em1 Mar 29 11:01:46 php-fpm[18930]: /rc.linkup: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 11:01:46 check_reload_status[433]: Restarting IPsec tunnels Mar 29 11:01:47 php-fpm[394]: /rc.newwanip: rc.newwanip: Info: starting on em1. Mar 29 11:01:47 php-fpm[394]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.xxx.xxx) (interface: WAN[wan]) (real interface: em1). Mar 29 11:01:58 php-fpm[393]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN. Mar 29 11:01:58 php-fpm[393]: /rc.newwanip: Creating rrd update script Mar 29 11:02:00 php-fpm[393]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.168.xxx.xxx - Restarting packages. Mar 29 11:02:00 check_reload_status[433]: Starting packages Mar 29 11:02:00 check_reload_status[433]: Reloading filter Mar 29 11:02:00 php-cgi[2020]: servicewatchdog_cron.php: Service Watchdog detected service unbound stopped. Restarting unbound (DNS Resolver) Mar 29 11:02:01 php-fpm[393]: /rc.start_packages: Restarting/Starting all packages. Mar 29 11:02:02 php-fpm[394]: /rc.newwanip: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx Mar 29 11:02:04 bandwidthd[35420]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[35420]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[35420]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[35420]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[35591]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[35591]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[35591]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[35591]: Monitoring subnet 192.168.xxx.xxx with netmask 255.255.255.0 Mar 29 11:02:04 bandwidthd[43111]: Recovering from log.1.2.cdf Mar 29 11:02:04 bandwidthd[43979]: Recovering from log.4.0.cdf Mar 29 11:02:04 bandwidthd[44701]: Recovering from log.1.2.cdf Mar 29 11:02:04 bandwidthd[43453]: Recovering from log.2.0.cdf Mar 29 11:02:04 bandwidthd[45276]: Recovering from log.2.0.cdf Mar 29 11:02:04 bandwidthd[45795]: Recovering from log.4.0.cdf Mar 29 11:02:04 bandwidthd[43745]: Recovering from log.3.0.cdf Mar 29 11:02:04 bandwidthd[43111]: Finished recovering 16510 records Mar 29 11:02:04 bandwidthd[45453]: Recovering from log.3.0.cdf Mar 29 11:02:04 bandwidthd[43111]: Recovering from log.1.1.cdf Mar 29 11:02:04 bandwidthd[44701]: Finished recovering 16510 records Mar 29 11:02:04 bandwidthd[44701]: Recovering from log.1.1.cdf Mar 29 11:02:04 bandwidthd[45795]: Finished recovering 5224 records Mar 29 11:02:04 bandwidthd[43979]: Finished recovering 5224 records Mar 29 11:02:04 bandwidthd[43979]: Opening re1 Mar 29 11:02:04 bandwidthd[45795]: Opening re1 Mar 29 11:02:04 bandwidthd[43979]: Packet Encoding: Ethernet Mar 29 11:02:04 bandwidthd[45795]: Packet Encoding: Ethernet Mar 29 11:02:04 bandwidthd[43979]: Drawing initial graphs Mar 29 11:02:04 bandwidthd[44701]: Finished recovering 15184 records Mar 29 11:02:04 bandwidthd[45795]: Drawing initial graphs Mar 29 11:02:04 bandwidthd[44701]: Recovering from log.1.0.cdf Mar 29 11:02:04 bandwidthd[43111]: Finished recovering 15184 records Mar 29 11:02:04 bandwidthd[43111]: Recovering from log.1.0.cdf Mar 29 11:02:05 bandwidthd[44701]: Finished recovering 6624 records Mar 29 11:02:05 bandwidthd[43111]: Finished recovering 6624 records Mar 29 11:02:05 bandwidthd[43111]: Opening re1 Mar 29 11:02:05 bandwidthd[43111]: Packet Encoding: Ethernet Mar 29 11:02:05 bandwidthd[43111]: Drawing initial graphs Mar 29 11:02:05 bandwidthd[44701]: Opening re1 Mar 29 11:02:05 bandwidthd[44701]: Packet Encoding: Ethernet Mar 29 11:02:05 bandwidthd[44701]: Drawing initial graphs Mar 29 11:02:05 bandwidthd[45276]: Finished recovering 166949 records Mar 29 11:02:05 bandwidthd[43453]: Finished recovering 166949 records Mar 29 11:02:05 bandwidthd[45453]: Finished recovering 119912 records Mar 29 11:02:05 bandwidthd[45276]: Failed to parse part of log file. Giving up on the file Mar 29 11:02:05 bandwidthd[45453]: Opening re1 Mar 29 11:02:05 bandwidthd[45276]: Opening re1 Mar 29 11:02:05 bandwidthd[45453]: Packet Encoding: Ethernet Mar 29 11:02:05 bandwidthd[45276]: Packet Encoding: Ethernet Mar 29 11:02:05 bandwidthd[45453]: Drawing initial graphs Mar 29 11:02:05 bandwidthd[45276]: Drawing initial graphs Mar 29 11:02:05 bandwidthd[43453]: Failed to parse part of log file. Giving up on the file Mar 29 11:02:05 bandwidthd[43453]: Opening re1 Mar 29 11:02:05 bandwidthd[43453]: Packet Encoding: Ethernet Mar 29 11:02:05 bandwidthd[43453]: Drawing initial graphs Mar 29 11:02:05 bandwidthd[43745]: Finished recovering 119912 records Mar 29 11:02:05 bandwidthd[43745]: Opening re1 Mar 29 11:02:05 bandwidthd[43745]: Packet Encoding: Ethernet Mar 29 11:02:05 bandwidthd[43745]: Drawing initial graphs Mar 29 11:02:06 php-fpm[394]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:02:06 php-fpm[394]: /rc.newwanip: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Mar 29 11:02:06 php-fpm[394]: /rc.newwanip: IP Address has changed, killing states on former IP Address 0.0.0.0. Mar 29 11:02:06 php-fpm[393]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed earlyshellcmd(s). Mar 29 11:02:06 check_reload_status[433]: Syncing firewall Mar 29 11:02:06 php-fpm[97591]: /rc.filter_configure_sync: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:02:06 php-fpm[393]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed earlyshellcmd(s). Mar 29 11:02:06 check_reload_status[433]: Syncing firewall Mar 29 11:02:06 php-fpm[393]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed interface group (WireGuard). Mar 29 11:02:06 php-fpm[18930]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:02:06 php-fpm[393]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed interface group (WireGuard). Mar 29 11:02:07 php-fpm[63073]: /rc.dyndns.update: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:02:07 arpwatch[36732]: listening on re1 Mar 29 11:02:07 arpwatch[37082]: listening on re0 Mar 29 11:02:07 arpwatch[37710]: listening on em0 Mar 29 11:02:07 arpwatch[38485]: listening on re0.10 Mar 29 11:02:07 arpwatch[39767]: listening on re0.20 Mar 29 11:02:07 php-fpm[393]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed Unbound ACL group (WireGuard). Mar 29 11:02:07 php-fpm[393]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed Unbound ACL group (WireGuard). Mar 29 11:02:07 check_reload_status[433]: Syncing firewall Mar 29 11:02:07 php-cgi[2020]: servicewatchdog_cron.php: dpinger: timeout while retrieving status for gateway WAN_DHCP Mar 29 11:02:08 php-fpm[393]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Applied package default settings as necessary. Mar 29 11:02:08 vnstatd[55280]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting. Mar 29 11:02:09 php-fpm[86993]: /widgets/widgets/gateways.widget.php: dpinger: timeout while retrieving status for gateway WAN_DHCP
-
Sorry, second Part was flagged as Spam ;-(
-
In the between I uninstalled Suricata, but I also did nothing.
-
is this what I think it is :
@Nosense-0 said in pfSense WAN dhcp client exiting (error):
servicewatchdog_cron
?
Probably not related, but if you're using "Service_Watchdog" : remove it.
This package is useful if you do debugging and other bleeding edge situations.
For the other 99,99999 % pfSense users, like you and me, it inflict stress, and incomprehension, and a bad connection.When I see a line like this
@Nosense-0 said in pfSense WAN dhcp client exiting (error):
Mar 29 11:02:07 php-cgi[2020]: servicewatchdog_cron.php: dpinger: timeout while retrieving status for gateway WAN_DHCP
and all the other lines, like :
Interfaces come up.
VLANs are created
WAN IP is set up.
Routes are applied.
Tests are executes to see if you have "IPV6".
DynDNS checks are executed,
Etc. All the usual stuff.
But also , you have some really heavy weights on your system :
pfBlockerNG DNSBL,
vnstat,
suriacata,
bandwith,
...What happens is : the system needs more time to "settle in".
But "servicewatchdog" said it "enough" : it detects that there is no WAN gateway, and it pulls the plug on the WAN, and the whole restart story is starts again ....My advise : lower the load on the system == the number of events that can happen when "WAN" is created.
Start with a clean and lean pfSense, ditch all the gadgets.
Now, you're fine.
Then add a 'thing', one by one.
As soon as the system shows issues, go one step back, and you'll be good. -
Since we have intermediary disorders from our ISP, we absolutely need the "Service_Watchdog", we cannot do without that.
The Pfense has been running so stable in this configuration for 4 years (with up to 8 family members) and we are enthusiastic about it!
So it is our first "problem" with the Pfense and therefore we won't change that (unless we have to), but I temporarily switch off the watchdog and look at what happens.
Thanks for the support!
-
What services do you have selected in the Watchdog?
What happens if you don't have it enabled? What fails to start?
With Suricata in non-blocking mode it's not using netgraph or reconnecting anything. That's not the issue.
The only thing logged that looks even vaguely like it might affect the link state is:
Mar 29 11:00:43 kernel: em0: promiscuous mode disabled Mar 29 11:00:43 kernel: re0.10: promiscuous mode disabled Mar 29 11:00:43 kernel: re0: promiscuous mode disabled Mar 29 11:00:43 kernel: re0.20: promiscuous mode disabled Mar 29 11:00:43 kernel: re0: promiscuous mode enabled Mar 29 11:00:43 kernel: em0: promiscuous mode enabled Mar 29 11:00:43 kernel: re0.10: promiscuous mode enabled Mar 29 11:00:43 kernel: re0.20: promiscuous mode enabled
Which is probably arpwatch starting. Can you test with arpwatch disabled?
-
-All services removed from the watchdog
-Suricata uninstalled
-Pfblockerng stopped
-Bandwidthd stoppedPfsense reboot
Switched to DHCP, error still exists, new log:Mar 29 16:16:29 php-fpm[394]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:16:27 vnstatd[97122]: Monitoring (9): re1 (1000 Mbit) re0.20 (1000 Mbit) re0.10 (1000 Mbit) re0 (1000 Mbit) pfsync0 (1000 Mbit) pflog0 (1000 Mbit) enc0 (1000 Mbit) em1 (1000 Mbit) em0 (100 Mbit)
Mar 29 16:16:27 vnstatd[99103]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Mar 29 16:16:27 vnstatd[97122]: Data retention: 48 5MinuteHours, 4 HourlyDays, 62 DailyDays, 25 MonthlyMonths, -1 YearlyYears, 20 TopDayEntries
Mar 29 16:16:27 vnstatd[97122]: vnStat daemon 2.11 (pid:97122 uid:0 gid:0, SQLite 3.43.1)
Mar 29 16:16:27 lighttpd_pfb[98864]: [pfBlockerNG] DNSBL Webserver started
Mar 29 16:16:27 lighttpd_pfb[97703]: [pfBlockerNG] DNSBL Webserver stopped
Mar 29 16:16:27 vnstatd[21916]: SIGTERM received, exiting.
Mar 29 16:16:26 php-fpm[18742]: /widgets/widgets/gateways.widget.php: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:16:25 php-fpm[394]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:16:25 php-fpm[7795]: /rc.newwanip: IP Address has changed, killing states on former IP Address 0.0.0.0.
Mar 29 16:16:25 php-fpm[7795]: /rc.newwanip: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:16:25 php-fpm[7795]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:16:21 php-fpm[7795]: /rc.newwanip: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx
Mar 29 16:16:21 php-fpm[7795]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.xxx.xxx) (interface: WAN[wan]) (real interface: em1).
Mar 29 16:16:21 php-fpm[7795]: /rc.newwanip: rc.newwanip: Info: starting on em1.
Mar 29 16:16:20 check_reload_status[433]: Restarting IPsec tunnels
Mar 29 16:16:20 php-fpm[394]: /rc.linkup: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:16:20 check_reload_status[433]: rc.newwanip starting em1
Mar 29 16:16:19 arpwatch[58965]: listening on re0.20
Mar 29 16:16:19 arpwatch[58879]: listening on re0.10
Mar 29 16:16:19 arpwatch[58468]: listening on em0
Mar 29 16:16:19 arpwatch[58215]: listening on re0
Mar 29 16:16:19 arpwatch[57777]: listening on re1
Mar 29 16:16:17 vnstatd[54280]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Mar 29 16:16:17 check_reload_status[433]: Linkup starting em1
Mar 29 16:16:17 kernel: em1: link state changed to UP
Mar 29 16:16:17 kernel: em1: promiscuous mode enabled
Mar 29 16:16:17 kernel: re0.20: promiscuous mode enabled
Mar 29 16:16:17 kernel: re0.10: promiscuous mode enabled
Mar 29 16:16:17 kernel: em0: promiscuous mode enabled
Mar 29 16:16:17 kernel: re0: promiscuous mode enabled
Mar 29 16:16:17 kernel: re1: promiscuous mode enabled
Mar 29 16:16:17 kernel: em1: promiscuous mode disabled
Mar 29 16:16:17 kernel: re0.20: promiscuous mode disabled
Mar 29 16:16:17 kernel: re0: promiscuous mode disabled
Mar 29 16:16:17 kernel: re0.10: promiscuous mode disabled
Mar 29 16:16:17 kernel: em0: promiscuous mode disabled
Mar 29 16:16:17 kernel: re1: promiscuous mode disabled
Mar 29 16:16:17 check_reload_status[433]: Syncing firewall
Mar 29 16:16:17 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Applied package default settings as necessary.
Mar 29 16:16:17 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed Unbound ACL group (WireGuard).
Mar 29 16:16:17 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed Unbound ACL group (WireGuard).
Mar 29 16:16:17 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed interface group (WireGuard).
Mar 29 16:16:16 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed interface group (WireGuard).
Mar 29 16:16:16 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed earlyshellcmd(s).
Mar 29 16:16:16 check_reload_status[433]: Syncing firewall
Mar 29 16:16:16 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed earlyshellcmd(s).
Mar 29 16:16:16 php-fpm[5949]: /rc.start_packages: The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
Mar 29 16:16:16 check_reload_status[433]: Reloading filter
Mar 29 16:16:16 check_reload_status[433]: Syncing firewall
Mar 29 16:16:16 php-fpm[5949]: /rc.start_packages: Configuration Change: (system): pfBlockerNG: saving DNSBL changes
Mar 29 16:16:15 php-fpm[5949]: /rc.start_packages: Restarting/Starting all packages.
Mar 29 16:16:14 kernel: em1: link state changed to DOWN
Mar 29 16:16:14 check_reload_status[433]: Linkup starting em1
Mar 29 16:16:14 check_reload_status[433]: Reloading filter
Mar 29 16:16:14 check_reload_status[433]: Starting packages
Mar 29 16:16:14 php-fpm[47031]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.168.xxx.xxx - Restarting packages.
Mar 29 16:16:14 php-fpm[394]: /rc.linkup: HOTPLUG: Configuring interface wan
Mar 29 16:16:14 php-fpm[394]: /rc.linkup: DEVD Ethernet attached event for wan
Mar 29 16:16:14 php-fpm[394]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp)
Mar 29 16:16:14 check_reload_status[433]: Reloading filter
Mar 29 16:16:12 php-fpm[47031]: /rc.newwanip: Creating rrd update script
Mar 29 16:16:12 php-fpm[47031]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Mar 29 16:16:11 php-fpm[393]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:16:10 php-fpm[68905]: /rc.filter_configure_sync: dpinger: No dpinger session running for gateway WAN_DHCP
Mar 29 16:16:10 check_reload_status[433]: Reloading filter
Mar 29 16:16:10 check_reload_status[433]: Restarting OpenVPN tunnels/interfaces
Mar 29 16:16:10 check_reload_status[433]: Restarting IPsec tunnels
Mar 29 16:16:10 check_reload_status[433]: updating dyndns WAN_DHCP
Mar 29 16:16:10 rc.gateway_alarm[84752]: >>> Gateway alarm: WAN_DHCP (Addr:192.168.xxx.xxx Alarm:down RTT:0ms RTTsd:0ms Loss:100%)
Mar 29 16:16:09 php-fpm[7795]: /rc.linkup: DEVD Ethernet detached event for wan
Mar 29 16:16:09 php-fpm[7795]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp)
Mar 29 16:16:09 check_reload_status[433]: Reloading filter
Mar 29 16:16:09 check_reload_status[433]: updating dyndns wan
Mar 29 16:16:08 php-fpm[47031]: /rc.newwanip: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711725368] unbound[57484:0] error: bind: address already in use [1711725368] unbound[57484:0] fatal error: could not open ports'
Mar 29 16:16:05 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:16:04 php-fpm[18742]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:16:02 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:16:01 php-fpm[18742]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:59 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:58 vnstatd[21916]: Monitoring (9): re1 (1000 Mbit) re0.20 (1000 Mbit) re0.10 (1000 Mbit) re0 (1000 Mbit) pfsync0 (1000 Mbit) pflog0 (1000 Mbit) enc0 (1000 Mbit) em1 (1000 Mbit) em0 (100 Mbit)
Mar 29 16:15:58 vnstatd[21916]: Data retention: 48 5MinuteHours, 4 HourlyDays, 62 DailyDays, 25 MonthlyMonths, -1 YearlyYears, 20 TopDayEntries
Mar 29 16:15:58 vnstatd[21916]: vnStat daemon 2.11 (pid:21916 uid:0 gid:0, SQLite 3.43.1)
Mar 29 16:15:58 vnstatd[29163]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Mar 29 16:15:58 php-fpm[18742]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:58 lighttpd_pfb[19472]: [pfBlockerNG] DNSBL Webserver started
Mar 29 16:15:58 lighttpd_pfb[17749]: [pfBlockerNG] DNSBL Webserver stopped
Mar 29 16:15:57 vnstatd[99232]: SIGTERM received, exiting.
Mar 29 16:15:55 php-fpm[393]: /widgets/widgets/gateways.widget.php: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:54 php-fpm[18742]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:54 php-fpm[47031]: /rc.newwanip: IP Address has changed, killing states on former IP Address 0.0.0.0.
Mar 29 16:15:54 php-fpm[47031]: /rc.newwanip: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:15:54 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:51 php-fpm[47031]: /rc.newwanip: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx
Mar 29 16:15:50 php-fpm[47031]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.xxx.xxx) (interface: WAN[wan]) (real interface: em1).
Mar 29 16:15:50 php-fpm[47031]: /rc.newwanip: rc.newwanip: Info: starting on em1.
Mar 29 16:15:50 arpwatch[71913]: listening on re0.20
Mar 29 16:15:50 arpwatch[71545]: listening on re0.10
Mar 29 16:15:49 arpwatch[71233]: listening on em0
Mar 29 16:15:49 arpwatch[71028]: listening on re0
Mar 29 16:15:49 arpwatch[69563]: listening on re1
Mar 29 16:15:49 check_reload_status[433]: Restarting IPsec tunnels
Mar 29 16:15:49 php-fpm[18742]: /rc.linkup: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:15:49 check_reload_status[433]: rc.newwanip starting em1
Mar 29 16:15:48 kernel: em1: link state changed to UP
Mar 29 16:15:48 check_reload_status[433]: Linkup starting em1
Mar 29 16:15:47 vnstatd[40633]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Mar 29 16:15:47 kernel: em1: promiscuous mode enabled
Mar 29 16:15:47 kernel: re0.20: promiscuous mode enabled
Mar 29 16:15:47 kernel: re0.10: promiscuous mode enabled
Mar 29 16:15:47 kernel: em0: promiscuous mode enabled
Mar 29 16:15:47 kernel: re0: promiscuous mode enabled
Mar 29 16:15:47 kernel: re1: promiscuous mode enabled
Mar 29 16:15:47 kernel: em1: promiscuous mode disabled
Mar 29 16:15:47 kernel: re0.20: promiscuous mode disabled
Mar 29 16:15:47 kernel: re0: promiscuous mode disabled
Mar 29 16:15:47 kernel: re0.10: promiscuous mode disabled
Mar 29 16:15:47 kernel: em0: promiscuous mode disabled
Mar 29 16:15:47 kernel: re1: promiscuous mode disabled
Mar 29 16:15:47 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Applied package default settings as necessary.
Mar 29 16:15:47 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed Unbound ACL group (WireGuard).
Mar 29 16:15:47 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed Unbound ACL group (WireGuard).
Mar 29 16:15:47 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed interface group (WireGuard).
Mar 29 16:15:47 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed interface group (WireGuard).
Mar 29 16:15:47 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed earlyshellcmd(s).
Mar 29 16:15:47 check_reload_status[433]: Syncing firewall
Mar 29 16:15:47 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed earlyshellcmd(s).
Mar 29 16:15:46 php-fpm[68905]: /rc.start_packages: The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
Mar 29 16:15:46 check_reload_status[433]: Reloading filter
Mar 29 16:15:46 check_reload_status[433]: Syncing firewall
Mar 29 16:15:46 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): pfBlockerNG: saving DNSBL changes
Mar 29 16:15:46 php-fpm[68905]: /rc.start_packages: Restarting/Starting all packages.
Mar 29 16:15:45 kernel: em1: link state changed to DOWN
Mar 29 16:15:45 check_reload_status[433]: Linkup starting em1
Mar 29 16:15:45 check_reload_status[433]: Reloading filter
Mar 29 16:15:45 check_reload_status[433]: Starting packages
Mar 29 16:15:45 php-fpm[47031]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.168.xxx.xxx - Restarting packages.
Mar 29 16:15:45 php-fpm[18742]: /rc.linkup: HOTPLUG: Configuring interface wan
Mar 29 16:15:45 php-fpm[18742]: /rc.linkup: DEVD Ethernet attached event for wan
Mar 29 16:15:45 php-fpm[18742]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp)
Mar 29 16:15:45 check_reload_status[433]: Reloading filter
Mar 29 16:15:43 php-fpm[47031]: /rc.newwanip: Creating rrd update script
Mar 29 16:15:43 php-fpm[47031]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Mar 29 16:15:42 php-fpm[68905]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:15:40 check_reload_status[433]: Reloading filter
Mar 29 16:15:40 check_reload_status[433]: Restarting OpenVPN tunnels/interfaces
Mar 29 16:15:40 check_reload_status[433]: Restarting IPsec tunnels
Mar 29 16:15:40 check_reload_status[433]: updating dyndns WAN_DHCP
Mar 29 16:15:40 rc.gateway_alarm[96758]: >>> Gateway alarm: WAN_DHCP (Addr:192.168.xxx.xxx Alarm:down RTT:0ms RTTsd:0ms Loss:100%)
Mar 29 16:15:39 php-fpm[5949]: /rc.linkup: DEVD Ethernet detached event for wan
Mar 29 16:15:39 php-fpm[5949]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp)
Mar 29 16:15:39 check_reload_status[433]: Reloading filter
Mar 29 16:15:39 check_reload_status[433]: updating dyndns wan
Mar 29 16:15:38 php-fpm[47031]: /rc.newwanip: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1711725338] unbound[61492:0] error: bind: address already in use [1711725338] unbound[61492:0] fatal error: could not open ports'
Mar 29 16:15:36 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:35 php-fpm[41925]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:32 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:32 php-fpm[41925]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:30 php-fpm[393]: /widgets/widgets/gateways.widget.php: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:29 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:28 php-fpm[41925]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:25 php-fpm[41925]: /rc.linkup: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:25 php-fpm[47031]: /rc.newwanip: IP Address has changed, killing states on former IP Address 0.0.0.0.
Mar 29 16:15:25 php-fpm[47031]: /rc.newwanip: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:15:25 php-fpm[47031]: /rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_DHCP
Mar 29 16:15:23 vnstatd[99232]: Monitoring (9): re1 (1000 Mbit) re0.20 (1000 Mbit) re0.10 (1000 Mbit) re0 (1000 Mbit) pfsync0 (1000 Mbit) pflog0 (1000 Mbit) enc0 (1000 Mbit) em1 (1000 Mbit) em0 (100 Mbit)
Mar 29 16:15:23 vnstatd[99232]: Data retention: 48 5MinuteHours, 4 HourlyDays, 62 DailyDays, 25 MonthlyMonths, -1 YearlyYears, 20 TopDayEntries
Mar 29 16:15:23 vnstatd[99232]: vnStat daemon 2.11 (pid:99232 uid:0 gid:0, SQLite 3.43.1)
Mar 29 16:15:23 vnstatd[99817]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Mar 29 16:15:23 lighttpd_pfb[99016]: [pfBlockerNG] DNSBL Webserver started
Mar 29 16:15:23 lighttpd_pfb[97011]: [pfBlockerNG] DNSBL Webserver stopped
Mar 29 16:15:23 vnstatd[49902]: SIGTERM received, exiting.
Mar 29 16:15:21 php-fpm[47031]: /rc.newwanip: Removing static route for monitor xxx.xxx.xxx.xxx and adding a new route through 192.168.xxx.xxx
Mar 29 16:15:21 php-fpm[47031]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.xxx.xxx) (interface: WAN[wan]) (real interface: em1).
Mar 29 16:15:21 php-fpm[47031]: /rc.newwanip: rc.newwanip: Info: starting on em1.
Mar 29 16:15:20 check_reload_status[433]: Restarting IPsec tunnels
Mar 29 16:15:20 php-fpm[41925]: /rc.linkup: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:15:20 check_reload_status[433]: rc.newwanip starting em1
Mar 29 16:15:16 kernel: em1: link state changed to UP
Mar 29 16:15:16 check_reload_status[433]: Linkup starting em1
Mar 29 16:15:15 arpwatch[69275]: listening on re0.20
Mar 29 16:15:15 arpwatch[68805]: listening on re0.10
Mar 29 16:15:15 arpwatch[68500]: listening on em0
Mar 29 16:15:15 arpwatch[68200]: listening on re0
Mar 29 16:15:15 arpwatch[68058]: listening on re1
Mar 29 16:15:13 kernel: em1: promiscuous mode enabled
Mar 29 16:15:13 vnstatd[50127]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Mar 29 16:15:13 kernel: re0.20: promiscuous mode enabled
Mar 29 16:15:13 kernel: re0.10: promiscuous mode enabled
Mar 29 16:15:13 kernel: em0: promiscuous mode enabled
Mar 29 16:15:13 kernel: re0: promiscuous mode enabled
Mar 29 16:15:13 kernel: re1: promiscuous mode enabled
Mar 29 16:15:13 kernel: em1: promiscuous mode disabled
Mar 29 16:15:13 kernel: re0.20: promiscuous mode disabled
Mar 29 16:15:13 kernel: re0: promiscuous mode disabled
Mar 29 16:15:13 kernel: re0.10: promiscuous mode disabled
Mar 29 16:15:13 kernel: em0: promiscuous mode disabled
Mar 29 16:15:13 kernel: re1: promiscuous mode disabled
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Applied package default settings as necessary.
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed Unbound ACL group (WireGuard).
Mar 29 16:15:12 kernel: em1: link state changed to DOWN
Mar 29 16:15:12 check_reload_status[433]: Linkup starting em1
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed Unbound ACL group (WireGuard).
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed interface group (WireGuard).
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed interface group (WireGuard).
Mar 29 16:15:12 php-fpm[41925]: /rc.linkup: HOTPLUG: Configuring interface wan
Mar 29 16:15:12 php-fpm[41925]: /rc.linkup: DEVD Ethernet attached event for wan
Mar 29 16:15:12 php-fpm[41925]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp)
Mar 29 16:15:12 check_reload_status[433]: Reloading filter
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed earlyshellcmd(s).
Mar 29 16:15:12 check_reload_status[433]: Syncing firewall
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed earlyshellcmd(s).
Mar 29 16:15:12 php-fpm[68905]: /rc.start_packages: The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
Mar 29 16:15:12 check_reload_status[433]: Reloading filter
Mar 29 16:15:11 check_reload_status[433]: Syncing firewall
Mar 29 16:15:11 php-fpm[68905]: /rc.start_packages: Configuration Change: (system): pfBlockerNG: saving DNSBL changes
Mar 29 16:15:11 php-fpm[68905]: /rc.start_packages: Restarting/Starting all packages.
Mar 29 16:15:10 check_reload_status[433]: Reloading filter
Mar 29 16:15:10 check_reload_status[433]: Starting packages
Mar 29 16:15:10 php-fpm[5949]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.168.xxx.xxx - Restarting packages.
Mar 29 16:15:09 php-fpm[47031]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Mar 29 16:15:08 check_reload_status[433]: Reloading filter
Mar 29 16:15:08 check_reload_status[433]: Restarting OpenVPN tunnels/interfaces
Mar 29 16:15:08 check_reload_status[433]: Restarting IPsec tunnels
Mar 29 16:15:08 check_reload_status[433]: updating dyndns WAN_DHCP
Mar 29 16:15:08 rc.gateway_alarm[24575]: >>> Gateway alarm: WAN_DHCP (Addr:192.168.xxx.xxx Alarm:down RTT:0ms RTTsd:0ms Loss:100%)
Mar 29 16:15:08 php-fpm[5949]: /rc.newwanip: Creating rrd update script
Mar 29 16:15:08 php-fpm[5949]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Mar 29 16:15:07 php-fpm[7795]: /rc.linkup: DEVD Ethernet detached event for wan
Mar 29 16:15:07 php-fpm[7795]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp)
Mar 29 16:15:07 check_reload_status[433]: Reloading filter
Mar 29 16:15:07 check_reload_status[433]: updating dyndns wan
Mar 29 16:15:06 check_reload_status[433]: Syncing firewall
Mar 29 16:15:06 php-fpm[393]: /pkg_edit.php: Configuration Change: admin@192.168.6.68 (Local Database): Removed cron job for /bin/pkill -HUP -F /var/run/bandwidthd.pid -
What exactly are you doing to trigger this? Reboot pfSense and the modem at the same time?
-
There are many opportunities:
Deactivate and activate the WAN interface on the Pfense
pull out the network plug
restart the modemEverything leads to a DHCP Loop, but in these cases the Pfense was not restarted.
Only when the Pfense itself is restarted does the error do not occur until there is a problem with the modem or ISP again.
-
Ok, interesting. This is not a DHCP issue though, that's just a symptom. The WAN interface is actually losing link and that triggers everything else to restart.
What is the WAN connected to? Can you set it to a fixed link speed? That could be a good test if it's a link negotiation issue. You would have to set it both ends though. Or putting a switch in between would prevent it.
Was this working in some earlier pfSense version?
-
@Nosense-0 said in pfSense WAN dhcp client exiting (error):
Since we have intermediary disorders from our ISP, we absolutely need the "Service_Watchdog", we cannot do without that.
I don't see the relation between the uplink connection and the usage of "Service_Watchdog".
This is what "Service_Watchdog" is doing :
It wakes up every minute.
Checks all the process that you've listed.
If it finds one that's not running, it starts it.Btw : "Service_Watchdog" is a Netgate pfSense open source tool. I use=d the code the describe what it does.
It isn't smart or something like that.It can not and will not help you in getting a better ISP connection.
I'm actually quiet convinced that it only worse your uplink connection quality and worse, the entire pfSense stability.
Processes like Suricata, unbound, etc etc don't just suddenly die. They do get restarted (example) when an interface event arrives : they are told to stopped, the orderly, controlled way - and when stopped, they get started.
At that moment : "Service_Watchdog" is also doing it's thing, and when it wakes up it does the same thing : example "Suricata" is just about to get restarted so "Service_Watchdog"found it stopped : it starts it. But is was already in the starting phase.
The scenario is set for a lot of hard to debug race conditions.And things are even better / worse (you pick) : you are using other heavy weight processes like bandwidth, vnstat, pfBlockerng, and you have two independent sources of process restarts.
Just think about the mess that this can ... no, will create.Of course, I hope to be wrong. As I said above, its easy to test.
-
I have now read extensively here in the forum and it is not an isolated case.
As with the others, all proposed solutions did not bring a solution.
It seems as if it were a problem in a script. Therefore, I will now stay with a fixed IP for the time being, since everything works as it used to be.
When I have time I'll take a look at the scripts.
Until then, thank you for the help.
-
It has to be a combination of things. The dhclient failing to pull a lease or just restarting cannot bounce the NIC link.
-
I have now installed a router for testing between the ISP modem and the Pfsense and the router confirms that the Pfsense has received the IP address via DHCP.
Therefore, I am quite sure that something has to go wrong in the script from the Pfense.
Just have to find out and need a little luck...
-
Yup since setting it fixed avoids the issue it must be dhclient triggering something. But dhclient alone cannot cause the link to flap so something else much be in play.
If you're able to I would test a default config and see if that still hit's it.
-
@stephenw10 said in pfSense WAN dhcp client exiting (error):
If you're able to I would test a default config and see if that still hit's it.
It would be roughly as if the hotline recommend to reinstall Windows, logically then the error will disappear.
With Linux, I may have a little chance to find the mistake, so a new installation would only be considered as the very last one for me.
Thanks anyway
-
Not really found, but error is gone.
Probable cause Keyword: GATEWAY
I had set up two additional gateways to monitor two of my websites BUT the "Disable Gateway Monitoring Action" was activated.
In the script "/etc/rc.linkup" there was the following line for dynamic IP:
else {
log_error("Hotplug event detected for {$friendly}({$iface}) dynamic IP address {$staticv4}, ({$addrs})");
switch ($action) {
case "stop":
log_error("DEVD Ethernet detached event for {$staticv4}, {$iface}");So there had to be an error in the Pfsense LOG and I kept having this entry.
A little further down in the script it says:
if (empty($gw4ip)) {
$gw4ip = get_interface_gateway_last($iface, 'inet');Why “_last”?
That seemed strange to me and so I deleted all gateway entries and a separate view under STATUS/MONITOR that used a gateway.Switched everything to DHCP again and the error was gone.
Strange thing with the "_last"...
-
By the way, of course, the default gateway was set fixed (no automatic) to DHCP Gateway.
-
Can you test that with DHCP WAN?
The purpose of testing with a default config (not reinstalled) is to determine if the issue is with the config or something with the local setup. That would have removed those additional gateways likely showing it is a config issue.
That is interesting though, I would not expect that to make any difference there. It tries to use the 'last gateway' value there for a dynamic gateway if a new one cannot be pulled.