pfSense WAN dhcp client exiting (error)
-
I do agree about the race condition.
But i still think that the DHCP Client task should "loop" in trying to get an address. Even if the IF isn't up.
I'll probably change to a static ip, next time i'm there.
-
Hmm, looks similar to some issues that existed previously, like this: https://redmine.pfsense.org/issues/9484
Try changing the DHCP timeout option to something large enough to allow the modem to boot. Like 900 as suggested there.
Though I agree it should just continue to try. I'm pretty there was a bug for that....
Steve
-
Ah, yes, this: https://redmine.pfsense.org/issues/9267
Though that should be fixed. Check the dhcp logs for the client using the old lease incorrectly.
Steve
-
@stephenw10
I'll prob switch to fixed ip, as this is the summerhouse.
Any "timing issue" not caught, while there and testing. Will make my temperature monitoring unavailable. And during winter these measurements are essential , as we have "water in the pipes".Thanx anyway.
/Bingo
-
@bingo600 said in pfSense WAN dhcp client exiting (error):
But i still think that the DHCP Client task should "loop" in trying to get an address. Even if the IF isn't up.
Think again ;)
When a process is launched on a given interface, like dhclient, it needs that one (1) - WAN interface, unlike unbound or the nginx web service for the GUI, which are bound to all interfaces. If that interface disappears, because it goes down, because the upstream router/modem pull the connection down, it will get removed from the 'ifconfig' kernel interfaces list - it will not stay active or in a running state.
dhclient exits.I thought I found out why it is comes back - when an interface comes on line again :
The LINKUP event :
See /etc/rc.booutup : line 96-99 : and see devd.conf lines 56-60 :
I 'read' here :# # Try to start dhclient on Ethernet-like interfaces when the link comes # up. Only devices that are configured to support DHCP will actually # run it.for me : when an interface comes up- and it's an interface that should support dhclient, it is executed.
Note that the $subsystem variable isn't defined / used ?!?
So, is this used :notify 0 { match "system" "IFNET"; match "type" "LINK_UP"; media-type "ethernet"; action "service dhclient quietstart $subsystem"; };I really think that these tehse 6 lines should auto start the dhclient on that ($subsystem = set to what ? ) interface.
Real Plug and Play in action.Just my 2 cents btw.
Go for the static IP. That's proven technology.
-
@gertjan
I do agree that it's impossible (not feasible) to start a dhcpclient process on an IF that's down. But one could loop in a "sleep 5 min" retrying to see if the IF becomes available.Apparently something happens if/when my special condition is met.
That doesn't retrigger the dhcpclient startup , and leaves the now active wan IF , in a IP address limbo ....But as you mention , i'll switch to static/fixed ip next time i'm there.
/Bingo
-
Exactly the same problem.
Pfense Version 2.7.2 release (AMD64)
In the Log hot plug event Loop up to infinity.
WAN Interface loop up and down forever.
Everything changed, Cable, Nic etc.
The only solution to change, reboot of the Pfense or to fixed IP, which I have now done :-(
Incomprehensible...
-
A link change loop is not what the symptoms of this issue are.
What is causing it to lose link? What do your logs actually show?
Does this also happen after a power outage? So every device boots at the same time?
-
@stephenw10 said in pfSense WAN dhcp client exiting (error):
causing it to lose link
Very good question if I only knew that ...
-the connection to the ISP is interrupted
-definitv power outage
-the network cable is deducted
-?The logs show about the same as above
No, the devices all boot at different times.
Unfortunately, I don't know when it all started because the Pfense runs stable with me.
I can therefore only assume that it started with a modem exchange from the ISP a few months ago.
But there is a router between the ISP modem and the Pfense and does not cause any problems, it is for despair because I have unfortunately not found sufficient information in the logs.
Only the booting of the Pfense worked.
-
Do you have any example logs showing a couple of loops?
-
I'm sorry for the logs in the Pfense are only limited to 500 lines, this will not help you because it is a log from the router:
Mar/28/2024 02:03:28 interface,info ether2 Firewall link down
Mar/28/2024 02:03:30 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:05:27 interface,info ether2 Firewall link down
Mar/28/2024 02:05:29 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:07:10 interface,info ether2 Firewall link down
Mar/28/2024 02:07:11 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:09:00 interface,info ether2 Firewall link down
Mar/28/2024 02:09:02 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:10:58 interface,info ether2 Firewall link down
Mar/28/2024 02:11:02 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:12:48 interface,info ether2 Firewall link down
Mar/28/2024 02:12:52 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:14:48 interface,info ether2 Firewall link down
Mar/28/2024 02:14:49 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:16:47 interface,info ether2 Firewall link down
Mar/28/2024 02:16:49 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:18:45 interface,info ether2 Firewall link down
Mar/28/2024 02:18:48 interface,info ether2 Firewall link up (speed 1G, full duplex)
Mar/28/2024 02:20:35 interface,info ether2 Firewall link downOr where can you still see the log from the Pfsene?
-
Found on the hard drive
Mar 28 17:18:11 php-fpm[393]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Mar 28 17:18:11 php-fpm[393]: /rc.newwanip: Creating rrd update script
Mar 28 17:18:13 check_reload_status[433]: Reloading filter
Mar 28 17:18:13 php-fpm[394]: /rc.linkup: Hotplug event detected for WAN(wan) dynamic IP address (4: dhcp)
Mar 28 17:18:13 php-fpm[394]: /rc.linkup: DEVD Ethernet attached event for wan
Mar 28 17:18:13 php-fpm[394]: /rc.linkup: HOTPLUG: Configuring interface wan
Mar 28 17:18:13 check_reload_status[433]: Linkup starting em1
Mar 28 17:18:13 kernel: em1: link state changed to DOWN
Mar 28 17:18:13 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 28 17:18:13 check_reload_status[433]: Starting packages
Mar 28 17:18:13 check_reload_status[433]: Reloading filter
Mar 28 17:18:14 php-fpm[54515]: /rc.start_packages: Restarting/Starting all packages.
Mar 28 17:18:16 kernel: em1: link state changed to UP
Mar 28 17:18:16 check_reload_status[433]: Linkup starting em1
Mar 28 17:18:17 check_reload_status[433]: rc.newwanip starting em1 -
Hmm. Are you running Snort or Suricata in in-line mode? I'd expect to see some netgraph logs there but that's the only package I'm aware of that can affect the link state.
-
Snort -no
Suricata -yes
-
And specifically in in-line mode?
Do you have a more extensive log? Need to see at least two complete loop cycles to see whats happening there.
-
[101342 - Suricata-Main] 2024-03-28 17:47:05 Notice: suricata: This is Suricata version 7.0.4 RELEASE running in SYSTEM mode
Okay, I try to activate the DHCP client again at the weekend to get the desired protocol.
-
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.
