dpinger stops (crashes?) after update to 2.6.0
-
You are probably hitting this: https://redmine.pfsense.org/issues/12827
Try the suggested temporary workaround there.Steve
-
I lose dpinger after suricata updates. I can even uninstall and install, or reinstall suricata and dpinger goes off. It seems to have something to do with suricata resetting the wan port. I am running suricata in legacy mode, but even with blocking turned off it happens. Every morning early I restart dpinger on 3 of my sites. One site has 4 heads. It seems to fail on only one of them.
The gateway logs are often not helpful. There are lots of these, but they happen during the day as well and I do not lose dpinger when they happen.
Feb 19 00:32:43 dpinger 89107 WAN_DHCP 192.168.0.1: sendto error: 65
The general logs show quite a lot of manipulating of the wan port. I am assuming that dpinger lose its target during these few minutes.
Feb 26 00:36:04 check_reload_status 2729 Reloading filter
Feb 26 00:35:38 check_reload_status 2729 updating dyndns wan
Feb 26 00:35:24 php-fpm 35378 /rc.newwanip: rc.newwanip: on (IP address: 10.0.0.1) (interface: LAN[lan]) (real interface: igb1).
Feb 26 00:35:24 php-fpm 35378 /rc.newwanip: rc.newwanip: Info: starting on igb1.
Feb 26 00:35:23 check_reload_status 2729 rc.newwanip starting igb1
Feb 26 00:35:23 php-fpm 35378 /rc.linkup: Hotplug event detected for LAN(lan) static IP (10.0.0.1 )
Feb 26 00:35:22 kernel igb1: link state changed to UP
Feb 26 00:35:22 check_reload_status 2729 Linkup starting igb1
Feb 26 00:35:19 check_reload_status 2729 Reloading filter
Feb 26 00:35:19 kernel igb1: promiscuous mode enabled
Feb 26 00:35:19 php-fpm 35378 /rc.linkup: Hotplug event detected for LAN(lan) static IP (10.0.0.1 )
Feb 26 00:35:18 kernel igb1: link state changed to DOWN
Feb 26 00:35:18 check_reload_status 2729 Linkup starting igb1
Feb 26 00:35:07 check_reload_status 2729 Reloading filter
Feb 26 00:35:07 php-fpm 35378 /rc.newwanip: rc.newwanip: on (IP address: 192.168.0.3) (interface: WAN[wan]) (real interface: igb0).
Feb 26 00:35:07 php-fpm 35378 /rc.newwanip: rc.newwanip: Info: starting on igb0.
Feb 26 00:35:06 check_reload_status 2729 Restarting IPsec tunnels
Feb 26 00:35:06 check_reload_status 2729 rc.newwanip starting igb0
Feb 26 00:35:05 check_reload_status 2729 Reloading filter
Feb 26 00:35:05 php-fpm 51175 /rc.linkup: HOTPLUG: Configuring interface wan
Feb 26 00:35:05 php-fpm 51175 /rc.linkup: DEVD Ethernet attached event for wan
Feb 26 00:35:04 php-fpm 86088 /rc.linkup: DEVD Ethernet detached event for wan
Feb 26 00:35:04 check_reload_status 2729 Reloading filter
Feb 26 00:34:34 check_reload_status 2729 updating dyndns wan
Feb 26 00:34:20 check_reload_status 2729 Reloading filter
Feb 26 00:34:20 php-fpm 20850 /rc.newwanip: rc.newwanip: on (IP address: 192.168.0.3) (interface: WAN[wan]) (real interface: igb0).
Feb 26 00:34:20 php-fpm 20850 /rc.newwanip: rc.newwanip: Info: starting on igb0.
Feb 26 00:34:19 check_reload_status 2729 Restarting IPsec tunnels
Feb 26 00:34:19 check_reload_status 2729 rc.newwanip starting igb0
Feb 26 00:34:18 kernel igb0: link state changed to UP
Feb 26 00:34:18 check_reload_status 2729 Linkup starting igb0
Feb 26 00:34:14 kernel igb0: link state changed to DOWN
Feb 26 00:34:14 check_reload_status 2729 Linkup starting igb0
Feb 26 00:34:14 php-fpm 43501 /rc.linkup: HOTPLUG: Configuring interface wan
Feb 26 00:34:14 php-fpm 43501 /rc.linkup: DEVD Ethernet attached event for wan
Feb 26 00:34:13 kernel igb0: link state changed to UP
Feb 26 00:34:13 check_reload_status 2729 Linkup starting igb0
Feb 26 00:34:12 check_reload_status 2729 Reloading filter
Feb 26 00:34:11 php-fpm 55570 /rc.linkup: DEVD Ethernet detached event for wan
Feb 26 00:34:10 kernel igb0: promiscuous mode enabled
Feb 26 00:34:10 check_reload_status 2729 Linkup starting igb0
Feb 26 00:34:10 kernel igb0: link state changed to DOWN
Feb 26 00:31:21 php 26894 [Suricata] The Rules update has finished.
Feb 26 00:31:21 php 26894 [Suricata] Suricata has restarted with your new set of rules for LAN...
Feb 26 00:31:21 php 26894 [Suricata] Suricata START for LAN(igb1)...
Feb 26 00:31:14 check_reload_status 2729 Reloading filter
Feb 26 00:31:14 php-fpm 35378 /rc.newwanip: rc.newwanip: on (IP address: 10.0.0.1) (interface: LAN[lan]) (real interface: igb1).
Feb 26 00:31:14 php-fpm 35378 /rc.newwanip: rc.newwanip: Info: starting on igb1.
Feb 26 00:31:13 check_reload_status 2729 Reloading filter
Feb 26 00:31:13 check_reload_status 2729 rc.newwanip starting igb1
Feb 26 00:31:13 php-fpm 35378 /rc.linkup: Hotplug event detected for LAN(lan) static IP (10.0.0.1 )
Feb 26 00:31:12 kernel igb1: link state changed to UP
Feb 26 00:31:12 check_reload_status 2729 Linkup starting igb1
Feb 26 00:31:10 check_reload_status 2729 Reloading filter
Feb 26 00:31:10 php-fpm 19761 /rc.linkup: Hotplug event detected for LAN(lan) static IP (10.0.0.1 )
Feb 26 00:31:09 kernel igb1: promiscuous mode disabled
Feb 26 00:31:09 kernel igb1: link state changed to DOWN
Feb 26 00:31:09 check_reload_status 2729 Linkup starting igb1
Feb 26 00:31:06 php 26894 [Suricata] Suricata STOP for LAN(igb1)...
Feb 26 00:31:04 php 26894 [Suricata] Building new sid-msg.map file for LAN...
Feb 26 00:31:04 php 26894 [Suricata] Enabling any flowbit-required rules for: LAN...
Feb 26 00:31:02 php 26894 [Suricata] Updating rules configuration for: LAN ...
Feb 26 00:31:02 php 26894 [Suricata] Suricata has restarted with your new set of rules for WAN...
Feb 26 00:31:02 php 26894 [Suricata] Suricata START for WAN(igb0)...
Feb 26 00:30:49 kernel igb0: promiscuous mode disabled
Feb 26 00:30:47 php 26894 [Suricata] Suricata STOP for WAN(igb0)...
Feb 26 00:30:45 php 26894 [Suricata] Building new sid-msg.map file for WAN...
Feb 26 00:30:45 php 26894 [Suricata] Enabling any flowbit-required rules for: WAN...
Feb 26 00:30:42 php 26894 [Suricata] Updating rules configuration for: WAN ...
Feb 26 00:30:40 php 26894 [Suricata] Snort GPLv2 Community Rules file update downloaded successfully.
Feb 26 00:30:39 php 26894 [Suricata] There is a new set of Snort GPLv2 Community Rules posted. Downloading community-rules.tar.gz...
Feb 26 00:30:38 php 26894 [Suricata] Emerging Threats Open rules file update downloaded successfully.
Feb 26 00:30:36 php 26894 [Suricata] There is a new set of Emerging Threats Open rules posted. Downloading emerging.rules.tar.gz...
Feb 26 00:24:00 sshguard 51492 Now monitoring attacks.
Feb 26 00:24:00 sshguard 46998 Exiting on signal. -
@reberhar said in dpinger stops (crashes?) after update to 2.6.0:
Feb 26 00:35:24 php-fpm 35378 /rc.newwanip: rc.newwanip: on (IP address: 10.0.0.1) (interface: LAN[lan]) (real interface: igb1).
Feb 26 00:35:24 php-fpm 35378 /rc.newwanip: rc.newwanip: Info: starting on igb1.
Feb 26 00:35:23 check_reload_status 2729 rc.newwanip starting igb1Your LAN is also losing link and it's triggering the newwanip script which should not happen unless it incorrectly has a gateway defined on it. Unless it's actually a second WAN.
Steve
-
@reberhar Yeah same here. My pfblocker and surricata updates at around 3AM and after that dpinger stops. That's the regular one I see daily. The other random ones were probably because of my WAN cable issue. I'll check again after fixing the cable. On my SG1100 that is not running surricata obviously I can see the same thing happen on pfblocker updates.
-
That was really quick. It is a stock install and I have not changed anything except for the upgrade to 2.6.0. However I will investigate that problem which is easy to do.
On the one site that is losing the pinging on one head we are using the lan for a gateway as well as a lan. There is only one wire available.
-
@stephenw10 No gateway defined
-
Is it DHCP then? Like running in AWS/Azure maybe?
-
@stephenw10 No not DHCP. It is Saturday and I have already been at this since before 6, but I will research it.
-
@reberhar said in dpinger stops (crashes?) after update to 2.6.0:
@stephenw10 No not DHCP. It is Saturday and I have already been at this since before 6, but I will research it.
I see you are running Suricata. From the log snippet you posted, I'm guessing Suricata is using Inline IPS Mode. If true, that mode uses the netmap kernel device. And each time Suricata stops and restarts, it closes and then reopens a netmap connection for the interface where Inline IPS Mode is used. When netmap closes and opens a connection, it will literally bounce the interface down and back up in FreeBSD the same as if you did the equivalent of an
ifupandifdownin Linux from the command line. Some daemons don't like the physical interface they are running on disappearing out from underneath them.If you suspect this might be your case, you can go to the GLOBAL SETTINGS tab in Suricata and enable the "Live Rule Swap on Update" option. That will tell Suricata to update its internal rules tables without restarting the deamon (and thus also netmap). The only downside of that option is a temporary increase in RAM usage during the rule swap process as two copies of the enabled rules are held in memory until the swap is complete. I probably should change the code to automatically enable the live swap option when Inline IPS is chosen for the blocking mode.
-
@reberhar said in dpinger stops (crashes?) after update to 2.6.0:
Feb 19 00:32:43 dpinger 89107 WAN_DHCP 192.168.0.1: sendto error: 65
Since I set this the "sento error 65" stops: kern.ipc.maxsockbuf Maximum socket buffer size 1000000
-
@bmeeks Hi bmeeks, Actually I saw the post on inline as opposed to legacy mode. I am using legacy mode. However I will try your suggestion. I am using a 2440 box at that location so memory is an issue. So I have adequate swap space however.
Roy
-
@nollipfsense Thanks for reminding me about the buffer change. I had forgotten that. I was over focused on the other problem. I have a 4 head box and had to do that with that install.
-
@reberhar I had the guy on site change the cable for the sendto error. First the simple stuff. I will be watching the site. One of the dpinger offlines stopped with a reinstall of Suricata. Now I am waiting to see if the Live Rule Swap on Update option helps on the other two.
-
@reberhar said in dpinger stops (crashes?) after update to 2.6.0:
@bmeeks Hi bmeeks, Actually I saw the post on inline as opposed to legacy mode. I am using legacy mode. However I will try your suggestion. I am using a 2440 box at that location so memory is an issue. So I have adequate swap space however.
Roy
I saw the physical interface "link state changed" messages, that's why I wondered about Suricata Inline IPS mode. Those messages occur when that mode is used. They should not happen in Legacy Mode (or at least they did not in previous FreeBSD versions).
-
@stephenw10 said in dpinger stops (crashes?) after update to 2.6.0:
Mmm, I would expect dpinger to stop if the WAN loses link and that's the only gateway. But it should start again when you reconnect it. Without needing the watchdog package.
Once successfully started, dpinger itself will not stop/exit for any reason other than a TERM signal. Send and recv errors are logged, but they do not cause the program to exit.
-
Hmm, I wonder what's killing it then...
-
@stephenw10 I tried the Live Reload on 2440 box and that worked even though I am using Legacy mode. I am going to try it on the 4 head system next.
-
@reberhar said in dpinger stops (crashes?) after update to 2.6.0:
@stephenw10 I tried the Live Reload on 2440 box and that worked even though I am using Legacy mode. I am going to try it on the 4 head system next.
That's interesting. The only thing Legacy Mode does with an interface is enable an instance of the PCAP library on it to capture traffic. Well that, and also enabling promiscuous mode. The Suricata binary does this using FreeBSD system calls. In the past, that never resulted in the physical interface bouncing.
-
@stephenw10 To help with this kind of thing in the future, I added logging of the signal number on exit to dpinger. It's pushed as release v3.2. I sent a note to Renato asking him to pull it in when he has time.
-
Thanks for that. Should be in soon.
