Project

General

Profile

Actions

Bug #12747

open

System log is filled by sshguard

Added by Steve Wheeler over 2 years ago. Updated 2 months ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
Logging
Target version:
Start date:
Due date:
% Done:

0%

Estimated time:
Plus Target Version:
Plus-Next
Release Notes:
Default
Affected Version:
2.6.0
Affected Architecture:
All

Description

sshguard has to restart when he logs are rotated in 2.6 in order to monitor the current file. When it does so it logs the service restart.
In an even moderately busy firewall this can produce a lot of log entries to the point it starts to hide other more important logs.
It appears to restart whenever any log is rotated, is that actually required?

For example on a test system where an IPSec tunnel is configured but never connects the ipsec log rotates frequently resulting in a system log:

Jan 31 00:25:00     sshguard     29496     Exiting on signal.
Jan 31 00:25:00     sshguard     9940     Now monitoring attacks.
Jan 31 03:17:00     sshguard     9940     Exiting on signal.
Jan 31 03:17:00     sshguard     60321     Now monitoring attacks.
Jan 31 06:09:00     sshguard     60321     Exiting on signal.
Jan 31 06:09:00     sshguard     83661     Now monitoring attacks.
Jan 31 09:01:00     sshguard     83661     Exiting on signal.
Jan 31 09:01:00     sshguard     93166     Now monitoring attacks.
Jan 31 11:53:00     sshguard     93166     Exiting on signal.
Jan 31 11:53:00     sshguard     94019     Now monitoring attacks. 

It's possible to mitigate this to some extent by increasing the log file size reducing the rotation frequency.


Files

clipboard-202204221938-uajpw.png (9.84 KB) clipboard-202204221938-uajpw.png Marle Cua-chin, 04/22/2022 06:38 AM
clipboard-202206300621-7gjov.png (135 KB) clipboard-202206300621-7gjov.png Franck Ck, 06/30/2022 05:21 AM
clipboard-202309230719-waesz.png (85.5 KB) clipboard-202309230719-waesz.png Jonathan Stafford, 09/23/2023 11:19 AM
clipboard-202309230720-yhwfb.png (21.2 KB) clipboard-202309230720-yhwfb.png Jonathan Stafford, 09/23/2023 11:20 AM
Actions #1

Updated by Viktor Gurov over 2 years ago

it seems to be related to #12833

Actions #2

Updated by Todd Marimon over 2 years ago

I am seeing this as well. In my case it seems to be every 2 minutes-- quite a lot of log noise! On pfSense 2.6.0.

Feb 24 00:13:00    sshguard    62471    Now monitoring attacks.
Feb 24 00:13:00    sshguard    28882    Exiting on signal.
Feb 24 00:11:00    sshguard    28882    Now monitoring attacks.
Feb 24 00:11:00    sshguard    90479    Exiting on signal.
Feb 24 00:09:00    sshguard    90479    Now monitoring attacks.
Feb 24 00:09:00    sshguard    60259    Exiting on signal.
Feb 24 00:07:00    sshguard    60259    Now monitoring attacks.
Feb 24 00:07:00    sshguard    98243    Exiting on signal.
Feb 24 00:05:00    sshguard    98243    Now monitoring attacks.
Feb 24 00:05:00    sshguard    994    Exiting on signal.
Actions #3

Updated by Car F about 2 years ago

Having the same issue since 2.6.0.

Actions #4

Updated by Michael TRVL ALBT about 2 years ago

Having the same issue since 2.6.0 too.

Actions #5

Updated by Marle Cua-chin about 2 years ago

I'm also experiencing the same issue on 2.6.0

Actions #6

Updated by Antonio Pesce about 2 years ago

I'm having the same issue on 2.6.0 on 6 pfSense instance.

Actions #8

Updated by Geovane Gonçalves almost 2 years ago

I'm having the same issue on 2.6.0 at every 1 minute:

Jul 5 09:33:00 sshguard 77002 Exiting on signal.
Jul 5 09:33:00 sshguard 19637 Now monitoring attacks.
Jul 5 09:34:00 sshguard 19637 Exiting on signal.
Jul 5 09:34:00 sshguard 40779 Now monitoring attacks.
Jul 5 09:35:00 sshguard 40779 Exiting on signal.
Jul 5 09:35:00 sshguard 64718 Now monitoring attacks.
Jul 5 09:36:00 sshguard 64718 Exiting on signal.
Jul 5 09:36:00 sshguard 6061 Now monitoring attacks.
Jul 5 09:37:00 sshguard 6061 Exiting on signal.
Jul 5 09:37:00 sshguard 46190 Now monitoring attacks.

As a workaround I disabled the log packets matched from the default block rules in the ruleset to reduce the amount of system logs, but that didn't happen before the upgrade. The frequency has dropped and now I'm watching.

After a period of calm, he logged back in every minute. Maybe on restart of syslogd. I changed the file size from 500K to 1024 and I'm tracking again.

Doubling the size of the logs from 512K to 1024K didn't work either. After about a day the logs became polluted again. No solution.

Actions #9

Updated by Hayden Hill almost 2 years ago

I am having the same issue in 22.05.

Actions #10

Updated by van trung tran over 1 year ago

I am having the same issue in 22.05. Netgate XG1541

Actions #11

Updated by Michael Kellogg over 1 year ago

I am Still seeing this on 2.7 built on Fri Jan 20 03:01:02 UTC 2023

seems like every 5-10 minutes not a pattern i can figure out

Actions #12

Updated by Mitch Claborn about 1 year ago

Still an issue in 23.01. Suggestions:
1. Stop logging the stop and start. I can't see how this is useful.
2. Make sshguard smart enough to recognize a new log file without restarting. (e.g. send it a HUP to look for new log files)
3. Allow filtering on the log display to hide entries that we don't want to look at.

Actions #13

Updated by Jim Pingle about 1 year ago

Unfortunately a lot of this is out of our control as we are at the mercy of what sshguard supports. Not saying we won't keep looking for a solution, but that our options here are limited.

The way it is currently used, sshguard will restart when syslogd restarts, which will happen any time a log is rotated. If your logs are rotating that fast, you should figure out what is causing such a high volume of logs and take some sort of corrective actions:

  • Reduce the logging of whatever is causing the high volume of logs
  • Increase the log rotation size of the affected log (or all logs)
  • Disable local logging and rely solely on remote logging

That high volume of logging would also be causing a high volume of disk writes on your device, which is likely undesirable as well.

Actions #14

Updated by Jonathan Stafford 8 months ago

I'm having this problem as well, with 23.05.1-RELEASE. For me, the issue seems to be that the filter logs are rolling every 45 minutes to an hour:

The vast majority of the logs are coming from what I assume are system rules, the 1000000??? entries. These don't match the tracking ids of any rules I have defined.

As far as I can tell these rules are matching:
  • 1000000003 - Mostly IPv6 mDNS on the LAN interface, although there is some DHCPv6 and ICMPv6.
  • 1000000103 - Most of the logs are IPv4 on the WAN interface addressed to my WAN IP. A few of the logs are on the LAN interface, to an assortment of IPs on 443.
  • 1000000004 - DHCPv6 from the WAN and ICMPv6 from the LAN

I do not have IPv6 enabled at System/Advanced/Networking/IPv6 Options->Allow IPv6. Additionally, it's a TP Link SG108E connected to the LAN port, which doesn't support IPv6 anyway ... so not really clear where this is even coming from. I don't know enough about the log format to swear this isn't 6in4. I have my own rules on the WAN and LAN to drop IPv6, but these never show any hits.

I have gotten an IPv6 address from my ISP in the past, but with no ability to use IPv6 on the network I turned that off.

I did just add some rules to drop 6in4 traffic in both directions and those haven't immediately shown any matches.

Looking through the various configuration pages, I don't see any way to enable/disable logging hits on system rules, but certainly could have missed it. Gonçalves, where did you see that? Ah it's at Status/System Logs/Settings/General Logging Options->Log firewall default blocks. At least now I don't know about this weird IPv6 traffic :)

Actions #15

Updated by Geovane Gonçalves 8 months ago

Jonathan Stafford wrote in #note-14:

I'm having this problem as well, with 23.05.1-RELEASE. For me, the issue seems to be that the filter logs are rolling every 45 minutes to an hour:

The vast majority of the logs are coming from what I assume are system rules, the 1000000??? entries. These don't match the tracking ids of any rules I have defined.

As far as I can tell these rules are matching:
  • 1000000003 - Mostly IPv6 mDNS on the LAN interface, although there is some DHCPv6 and ICMPv6.
  • 1000000103 - Most of the logs are IPv4 on the WAN interface addressed to my WAN IP. A few of the logs are on the LAN interface, to an assortment of IPs on 443.
  • 1000000004 - DHCPv6 from the WAN and ICMPv6 from the LAN

I do not have IPv6 enabled at System/Advanced/Networking/IPv6 Options->Allow IPv6. Additionally, it's a TP Link SG108E connected to the LAN port, which doesn't support IPv6 anyway ... so not really clear where this is even coming from. I don't know enough about the log format to swear this isn't 6in4. I have my own rules on the WAN and LAN to drop IPv6, but these never show any hits.

I have gotten an IPv6 address from my ISP in the past, but with no ability to use IPv6 on the network I turned that off.

I did just add some rules to drop 6in4 traffic in both directions and those haven't immediately shown any matches.

Looking through the various configuration pages, I don't see any way to enable/disable logging hits on system rules, but certainly could have missed it. Gonçalves, where did you see that? Ah it's at Status/System Logs/Settings/General Logging Options->Log firewall default blocks. At least now I don't know about this weird IPv6 traffic :)

Maybe it helps:

I believe that we have reached a suitable configuration for our case.

I'll report the actions in case anyone finds this useful in the future:

PfSense 2.6.0 - FW/GW/Proxy wifi network approx 1300 daily users.
Logs are sent remotely for auditing purposes. Lots of filter logs!

Our final configuration to avoid "sshguard" spam looked like this:

We increased log file size to 100MB;
To avoid excessive disk consumption, retention has been changed to only two files in "log settings";
rw------ 1 root wheel 97239550 Jul 14 11:35 filter.log
rw------ 1 root wheel 102682474 Jul 13 16:16 filter.log.0
rw------ 1 root wheel 102697059 Jul 13 11:31 filter.log.1

To avoid the risk of unnecessary CPU consumption, log compression was disabled (UFS);
We disabled the log packets matched from the default block rules in the ruleset to reduce the amount of system logs;
We reviewed the other firewall rules and kept the logs strictly necessary;
Also to avoid space consumption, squid log retention has been reduced from 30 to 3 files.
Thanks,

Geovane
original post:
https://forum.netgate.com/topic/169923/tons-sshguard-log-entries-and-its-not-enabled/63?lang=pt-BR

Actions #16

Updated by Daryl Morse 2 months ago

The original bug was reported against 2.6.0, but the problem has carried over to 2.7.x.

These messages are only one example of how the logs are being literally polluted by useless garbage messages. This is not cosmetic. Garbage messages cause important messages to be lost. The fix is not to reduce the size of the logs. The fix is to eliminate the garbage either by preventing them from being generated in the first place or if that isn't possible, by filtering them after they are created so there is room in the log for important messages.

Actions

Also available in: Atom PDF