Tons sshguard log entries and its not enabled

bcruze · Feb 17, 2022, 7:11 PM

zero changes have been made to my firewall I have been at work since 5am
Feb 17 13:22:00 sshguard 77291 Now monitoring attacks.
Feb 17 13:22:00 sshguard 95660 Exiting on signal.
Feb 17 11:53:00 sshguard 95660 Now monitoring attacks.
Feb 17 11:53:00 sshguard 71573 Exiting on signal.
Feb 17 10:26:00 sshguard 71573 Now monitoring attacks.
Feb 17 10:26:00 sshguard 52424 Exiting on signal.
Feb 17 09:26:00 sshguard 52424 Now monitoring attacks.
Feb 17 09:26:00 sshguard 69608 Exiting on signal.
Feb 17 08:59:00 sshguard 69608 Now monitoring attacks.
Feb 17 08:59:00 sshguard 41750 Exiting on signal.
Feb 17 07:32:00 sshguard 41750 Now monitoring attacks.
Feb 17 07:32:00 sshguard 74171 Exiting on signal.
Feb 17 06:06:00 sshguard 74171 Now monitoring attacks.
Feb 17 06:06:00 sshguard 10870 Exiting on signal.
Feb 17 04:39:00 sshguard 10870 Now monitoring attacks.
Feb 17 04:39:00 sshguard 76561 Exiting on signal.
Feb 17 03:17:00 sshguard 76561 Now monitoring attacks.
Feb 17 03:17:00 sshguard 25392 Exiting on signal.
Feb 17 01:49:00 sshguard 25392 Now monitoring attacks.
Feb 17 01:49:00 sshguard 31908 Exiting on signal.
Feb 17 00:21:00 sshguard 31908 Now monitoring attacks.
Feb 17 00:21:00 sshguard 36299 Exiting on signal.

troysjanda · Feb 17, 2022, 7:17 PM

@johnpoz Yes I get these and these appear even if ssh is disabled. I mostly use the weg gui for administrating pfsense, and only use the ssh on occasion but never seen these in the logs before updating to 2.6, and then 22.01. to be honest I don't ever remember seeing a log entries for sshguard prior to 2.6/22.01 and have been using pfsense for years.

Feb 17 06:43:00 sshguard 4904 Now monitoring attacks.
Feb 17 06:43:00 sshguard 72981 Exiting on signal.
Feb 16 20:01:00 sshguard 72981 Now monitoring attacks.
Feb 16 20:01:00 sshguard 99149 Exiting on signal.

johnpoz · Feb 17, 2022, 7:29 PM

@troysjanda I do not recall seeing them before - for sure could be something new that now logged..

I think the sshguard is enabled by default, I don't see a way to turn it off specifically. I do have ssh enabled.

It seems to just be some log spam at the moment.. @stephenw10 is here - he is always helpful, but I am happy to help try and track it down as another install seeing them.. My logs are set to be pretty big, and don't have a lot of stuff in the logs overall... So will see if I can spot why its kicking off and stopping and starting..

I seem to be seeing them ever 2 hours

Feb 17 13:00:00 	sshguard 	39476 	Now monitoring attacks.
Feb 17 13:00:00 	sshguard 	61273 	Exiting on signal.
Feb 17 11:01:00 	sshguard 	61273 	Now monitoring attacks.
Feb 17 11:01:00 	sshguard 	70550 	Exiting on signal.
Feb 17 09:05:00 	sshguard 	70550 	Now monitoring attacks.
Feb 17 09:05:00 	sshguard 	51227 	Exiting on signal.

Well hmmm - this looks to be something for sure.. Look at the timestamps on the logs

-rw-------   1 root        wheel       148546 Feb 17 13:28 resolver.log
-rw-------   1 root        wheel       521113 Feb 17 13:00 resolver.log.0
-rw-------   1 root        wheel       513709 Feb 17 11:01 resolver.log.1
-rw-------   1 root        wheel       511581 Feb 17 09:05 resolver.log.2

stephenw10 · Feb 17, 2022, 7:31 PM

It's almost certainly one of the logs rotating. When I dug into it that was always the cause.
https://redmine.pfsense.org/issues/12747

sshguard doesn't only protect ssh, it monitors the logs for any login failures including the webgui.

You didn't see this in previous versions because the circular logs did not get rotated out. It didn't need to restart.

Steve

johnpoz · Feb 17, 2022, 7:35 PM

@stephenw10 yeah look at my edit the times of sshguard match up perfect with this log rotation.

edit: not sure what would be in the "resolver" log that sshguard would need to look at ;) but I get what your saying.. And make complete sense that if a new log is being used, prob need to cycle the process looking at the logs.

edit2: I just upped my log size from the 512000 size it was showing to 1024000 that for sure should reduce the amount of those entries in the log.

stephenw10 · Feb 17, 2022, 7:42 PM

Yeah, it's a bug. An unanticipated side affect of the logging change. Whilst it's just occasional log spam for most in some cases it actively fills the logs itself.

I also see no reason for it to be looking at, for example, the dns logs. There is room for improvement!

Steve

troysjanda · Feb 17, 2022, 8:26 PM

@stephenw10 I have this in the cron

*/1 * * * * root /usr/sbin/newsyslog is this a possible culprit checking every minute to see if logs need to re rotated. the resolver log seems to be my largest log I increased the log size again to 1024000 see how that goes.

this is just driving me crazy as I did not see this in the 2.6/22.01 versions. I don't use very elaborate pfsense box, no vpns, no vlans, only 1 lan rule for dns and 1 nat port forward rule for dns. everything else is default

stephenw10 · Feb 17, 2022, 11:12 PM

No that's an expected cron entry. It's not causing the log rotations.

johnpoz · Feb 18, 2022, 7:37 PM

@troysjanda btw - it occurred to me, why was my unbound logs rotating so often.. I had forgotten that I set log queries and replies in the options box troubleshooting something for someone, and never turned it back off ;)

In my custom options, I have turned these back off.. That should drastically reduce how often the resolver log rotates ;)

#log-queries: yes
#log-replies: yes

I would look in your /var/log folder and see which logs are doing the most rotating - maybe changes to whatever that is could reduce the number of rotations that happen, in turn lowering the number of times you see the sshguard log entry.

serbus · Feb 18, 2022, 8:51 PM

Hello!

Not exactly sure how sshguard is wired into the system, but it could be that every time newsyslog SIGHUPs syslogd on any log rotation (/var/etc/newsyslog.conf.d/pfSense.conf), sshguard gets restarted (piped from syslogd) and all of the bad actors tracked by sshguard are flushed (?). IOW, sshguard could have marginal value if it is getting restarted all the time, especially if there are bigger values set in System > Advanced > Admin Access > Login Protection. Maybe...

I guess if it is really bugging you and sshguard isnt delivering any value, you can just rename /usr/local/etc/sshguard.conf to something else and it wont run (?).

John

stephenw10 · Feb 18, 2022, 9:51 PM

Yeah after having dug into it further my understanding changed. Whilst sshguard can parse the logs to look for auth entries that isn't what it's doing here. Instead all auth logs are piped to it directly from syslogd. But that means it's restarted whenever syslogd is restarted which is when any of the logs is rotated.
Which means my first though if just excluding the irrelevant log files doesn't work. More thought required.

Steve

troysjanda · Feb 18, 2022, 10:22 PM

@stephenw10 thanks for digging and look forward to hear if another solution of fix comes from you looking into it further.

ebcdic · Feb 20, 2022, 9:50 PM

I noticed the same problem. The message occurs roughly every half hour and it's that frequent because of the firewall log file rotating - I turned off logging of the default deny rule and haven't had the message in the last 11 hours.

jeff3820 · Feb 20, 2022, 9:50 PM

@ebcdic Where can you turn off logging of the default deny rule??

stephenw10 · Feb 20, 2022, 9:58 PM

In Status > System Logs > Settings. Uncheck 'Log firewall default blocks'.

jeff3820 · Feb 20, 2022, 10:01 PM

@stephenw10 Thanks, got it. Yes, I am also seeing the MANY SSHGuard starting and stopping in the log. I'll try disabling the default deny rule logging...would be an easy fix.

johnpoz · Feb 20, 2022, 11:13 PM

@jeff3820 said in Tons sshguard log entries and its not enabled:

I'll try disabling the default deny rule logging...would be an easy fix.

That seems a bit over the top - because I get a log entry every time my log rotations - I just won't log anything hitting my firewall that is blocked..

A bit a drastic fix for what is some log spam... Like that damn fly - let me hit him with this 20 lb sledge hammer..

Wouldn't it be simpler to just up the log size so they don't rotate as often?

troysjanda · Feb 20, 2022, 11:17 PM

I reverted back to 2.6.0 and I am not seeing those entries as often, in the last 2 days I have only seen it 3 times.

I did a fresh install to move back to 2.6.0 using a 22.01 config.xml backup and switched to the ZFS file system using 2 disks in mirroring mode. It went without issue. i'd love to use the ZFS widget but for now i'm staying put on 2.6.0 until some sort of clarity is officially released concerning the EULA and home use.

Not hopping on the Reddit clusterfud but don't want updates to stop or usage of packages to stop at the end of a year or at some point like I have been hearing.

jeff3820 · Feb 20, 2022, 11:20 PM

@johnpoz What log size would you recommend? 1024000? 2048000?

johnpoz · Feb 20, 2022, 11:24 PM

@troysjanda after bumping my log to 1024K and turning off logging of all my dns queries and replies I saw 3 entries on the 19th..

Which I don't see how that could be even considered an issue.. 300 ok, bit of a log spam problem - 30 ok seems a bit excessive in a 24 hour period.. But 3.. Shoot HAproxy is way noisy that in its logs ;)

I had that at informational - just turned that down as well to error ;)