|
From: Jef P. <je...@ma...> - 2016-05-09 07:49:39
|
Hi. I ran across sshguard today and decided to give it a try.
I'm on FreeBSD 10.1R. I installed it from /usr/ports/security/sshguard
which gave me version 1.5 - no problems on the install. I enabled it
using syslogd and ipfw. I used the suggested syslog.conf line:
auth.info;authpriv.info |exec /usr/local/sbin/sshguard
And a slightly modified ipfw line:
ipfw add deny ip from 'table(22)' to me in via ${oif}
After restarting syslogd, I observed new log messages from
sshguard. Yay!
However, there was a minor problem: every hour it would exit and restart:
May 8 13:00:00 hydra sshguard[86471]: Got exit signal, flushing blocked addresses and exiting...
May 8 13:00:00 hydra sshguard[14184]: Started successfully [(a,p,s)=(40, 420, 1200)], now ready to scan.
May 8 14:00:00 hydra sshguard[14184]: Got exit signal, flushing blocked addresses and exiting...
May 8 14:00:00 hydra sshguard[85407]: Started successfully [(a,p,s)=(40, 420, 1200)], now ready to scan.
May 8 15:00:00 hydra sshguard[85407]: Got exit signal, flushing blocked addresses and exiting...
May 8 15:00:00 hydra sshguard[67455]: Started successfully [(a,p,s)=(40, 420, 1200)], now ready to scan.
I did a not-very-thorough search of the sshguard-users archives and
didn't see discussion of this. The reason for the looping is pretty
obvious: sshguard's exit message goes to auth.notice and therefore
gets sent to sshguard and starts it up again.
My first try at fixing this worked ok - I changed syslog.conf so it
doesn't send sshguard's own messages to itself:
!-sshguard
auth.info;authpriv.info |exec /usr/local/sbin/sshguard
However this makes the config file a little ugly since the sshguard
stuff now has to be in a separate paragraph.
Starting sshguard from an rc file instead of from syslog should also
fix the restart looping. I'll try that tomorrow.
A source-code fix would be to not log the exit message, or log it
at debug instead of notice. I haven't checked if something along these
lines has already been done in the development version - if so, hooray!
Anyway, thanks for the nice simple software.
---
Jef
Jef Poskanzer je...@ma... http://acme.com/jef/
|
|
From: Jef P. <je...@ma...> - 2016-05-09 19:19:19
|
I wrote:
>I'm on FreeBSD 10.1R. I installed it from /usr/ports/security/sshguard
>which gave me version 1.5 - no problems on the install.
After a reminder that portsnap exists, I updated everything and
tried again with sshguard 1.6.4. I undid my syslog config quick-fix
to test, and can confirm that the restart looping still happens
although with different log messages:
May 9 11:57:02 hydra sshguard[22878]: Monitoring attacks from stdin
May 9 12:00:00 hydra sshguard[22878]: Received EOF from stdin
May 9 12:00:00 hydra sshguard[22878]: Exiting on signal
May 9 12:00:00 hydra sshguard[28419]: Monitoring attacks from stdin
Looks like the exit message is now logged at level info instead
of notice, but that is still high enough to get caught by the
recommended syslog.conf line. And anyway the new 'Received EOF'
message is at level notice.
---
Jef
Jef Poskanzer je...@ma... http://acme.com/jef/
|
|
From: Kevin Z. <kev...@gm...> - 2016-05-09 20:25:53
|
Hi Jef, On 05/09/2016 12:19, Jef Poskanzer wrote: > After a reminder that portsnap exists, I updated everything and > tried again with sshguard 1.6.4. I undid my syslog config quick-fix > to test, and can confirm that the restart looping still happens > although with different log messages: > > May 9 11:57:02 hydra sshguard[22878]: Monitoring attacks from stdin > May 9 12:00:00 hydra sshguard[22878]: Received EOF from stdin > May 9 12:00:00 hydra sshguard[22878]: Exiting on signal > May 9 12:00:00 hydra sshguard[28419]: Monitoring attacks from stdin > > Looks like the exit message is now logged at level info instead > of notice, but that is still high enough to get caught by the > recommended syslog.conf line. And anyway the new 'Received EOF' > message is at level notice. Thanks for updating to 1.6.4. Could you try starting SSHGuard as a daemon using the rc.d script and see if the problem persists? Thanks, Kevin -- Kevin Zheng kev...@gm... | ke...@be... | PGP: 0xC22E1090 |
|
From: Jef P. <je...@ma...> - 2016-05-10 06:42:52
|
Kevin Zheng: >Thanks for updating to 1.6.4. Could you try starting SSHGuard as a >daemon using the rc.d script and see if the problem persists? I'm sure that would fix the restart looping, as I suggested in my initial message. At the moment I can't start using the rc.d script for other reasons, which actually could be considered a bug in sshguard. Ok, since you asked so nicely I'll explain. My auth.log doesn't get much traffic and hasn't been rotated in years. When sshguard starts up it reads the whole file, sees all of my own logins happening at the current instant, and marks me as an attacker. It may have something to do with syslog lines not including the year - maybe sshguard parses the yearless timestamps past today's date as being in the future? It just occured to me this this is *exactly* the plot line of tonight's Person of Interest episode! Anyway I have fixed my newsyslog.conf to rotate more often, but I don't want to manually rotate the files so I'm not going to start sshguard from rc.d until they rotate on their own. There's already a note in http://www.sshguard.net/docs/setup/ about syslogd terminating and restarting sshguard, although it's not completely accurate. If the devs don't want to lower the log level of the exiting messages to LOG_DEBUG to prevent the restarting, then perhaps just correct this note and add the "!-sshguard" tweak I worked out. A doc change is always easier than a code change right? --- Jef Jef Poskanzer je...@ma... http://acme.com/jef/ |
|
From: Peter B. <be...@an...> - 2016-05-10 14:20:50
|
Why not add your IP(s) to the whitelist? Did you fail to login successfully many times in the past few years? Why not rotate your auth.log? Why not run newsyslog manually once to rotate initially? To me this isn't a bug, more of a "it doesn't work the way I want" for some reasons that seem to be fairly easy to rememdy. Beckman On Mon, 9 May 2016, Jef Poskanzer wrote: > Kevin Zheng: >> Thanks for updating to 1.6.4. Could you try starting SSHGuard as a >> daemon using the rc.d script and see if the problem persists? > > I'm sure that would fix the restart looping, as I suggested in my > initial message. At the moment I can't start using the rc.d script > for other reasons, which actually could be considered a bug in > sshguard. Ok, since you asked so nicely I'll explain. My auth.log > doesn't get much traffic and hasn't been rotated in years. When > sshguard starts up it reads the whole file, sees all of my own > logins happening at the current instant, and marks me as an > attacker. It may have something to do with syslog lines not > including the year - maybe sshguard parses the yearless timestamps > past today's date as being in the future? > > It just occured to me this this is *exactly* the plot line of > tonight's Person of Interest episode! > > Anyway I have fixed my newsyslog.conf to rotate more often, but I > don't want to manually rotate the files so I'm not going to start > sshguard from rc.d until they rotate on their own. > > There's already a note in http://www.sshguard.net/docs/setup/ about > syslogd terminating and restarting sshguard, although it's not > completely accurate. If the devs don't want to lower the log level > of the exiting messages to LOG_DEBUG to prevent the restarting, > then perhaps just correct this note and add the "!-sshguard" > tweak I worked out. A doc change is always easier than a code > change right? --------------------------------------------------------------------------- Peter Beckman Internet Guy be...@an... http://www.angryox.com/ --------------------------------------------------------------------------- |
|
From: <li...@la...> - 2016-05-10 17:46:35
|
On Tue, 10 May 2016 10:04:57 -0400 Peter Beckman <be...@an...> wrote: > Why not add your IP(s) to the whitelist? Did you fail to login > successfully many times in the past few years? > > Why not rotate your auth.log? > > Why not run newsyslog manually once to rotate initially? > > To me this isn't a bug, more of a "it doesn't work the way I want" > for some reasons that seem to be fairly easy to rememdy. > > Beckman > > --------------------------------------------------------------------------- Checking my /var/log, it appears that once you put a file into newsyslog, it will chop it up into compressed files with one "operating" file at the appropriate rotation time. That is, my maillog, which I recently added to newsyslog, was chopped into 6 files when the rotation time came around. |
|
From: Peter B. <be...@an...> - 2016-05-10 19:08:05
|
Could you not adjust the size at which the log is rotated to avoid such
chopping?
Doing my own little test, this succeeded at rotating safely at 10 entries
per second being written:
cp auth.log auth.log.2 && cat /dev/null > auth.log
I had one process going writing a new entry to auth.log every 0.1 seconds
(10 per second), to ensure that I didn't lose any log entries during this
process.
What this does:
* copies all of the data from auth.log to auth.log.2, even while
auth.log is being written, the data is copied
* As soon as the copy completes, it truncates auth.log (unless the
copy fails, then it doesn't)
Now you (a) don't have to HUP any processes writing to auth.log, and (b)
don't lose any log entries due to timing issues.
Theoretically you could lose a few log lines depending on how loaded your
system is, but I lost ZERO log entries at 10 per second.
So again, I say, for the lot of you who are fussy about your log file sizes
for whatever reason, Why not rotate your logs?
Between newsyslog and writing your own if newsyslog doesn't have enough
knobs to meet your unique needs, I don't see how sshguard needs to be
rewritten to meet your needs.
Beckman
On Tue, 10 May 2016, li...@la... wrote:
> On Tue, 10 May 2016 10:04:57 -0400
> Peter Beckman <be...@an...> wrote:
>
>> Why not add your IP(s) to the whitelist? Did you fail to login
>> successfully many times in the past few years?
>>
>> Why not rotate your auth.log?
>>
>> Why not run newsyslog manually once to rotate initially?
>>
>> To me this isn't a bug, more of a "it doesn't work the way I want"
>> for some reasons that seem to be fairly easy to rememdy.
>>
>> Beckman
>>
>
>> ---------------------------------------------------------------------------
>
> Checking my /var/log, it appears that once you put a file into
> newsyslog, it will chop it up into compressed files with
> one "operating" file at the appropriate rotation time. That is, my
> maillog, which I recently added to newsyslog, was chopped into 6 files
> when the rotation time came around.
>
>
---------------------------------------------------------------------------
Peter Beckman Internet Guy
be...@an... http://www.angryox.com/
---------------------------------------------------------------------------
|
|
From: Kevin Z. <kev...@gm...> - 2016-05-11 18:42:02
|
On 05/09/2016 23:42, Jef Poskanzer wrote: > I'm sure that would fix the restart looping, as I suggested in my > initial message. At the moment I can't start using the rc.d script > for other reasons, which actually could be considered a bug in > sshguard. Ok, since you asked so nicely I'll explain. My auth.log > doesn't get much traffic and hasn't been rotated in years. When > sshguard starts up it reads the whole file, sees all of my own > logins happening at the current instant, and marks me as an > attacker. It may have something to do with syslog lines not > including the year - maybe sshguard parses the yearless timestamps > past today's date as being in the future? SSHGuard should certainly not be reading your entire auth.log at startup. What version of SSHGuard are you using? Are you just using the standard invocation from rc.d (no other options set)? > There's already a note in http://www.sshguard.net/docs/setup/ about > syslogd terminating and restarting sshguard, although it's not > completely accurate. If the devs don't want to lower the log level > of the exiting messages to LOG_DEBUG to prevent the restarting, > then perhaps just correct this note and add the "!-sshguard" > tweak I worked out. A doc change is always easier than a code > change right? Could you clarify which part is inaccurate? I'd like to fix it ASAP. Thanks, Kevin -- Kevin Zheng kev...@gm... | ke...@be... | PGP: 0xC22E1090 |
|
From: Jef P. <je...@ma...> - 2016-05-12 05:16:16
|
Kevin: >SSHGuard should certainly not be reading your entire auth.log at >startup. What version of SSHGuard are you using? Are you just using the >standard invocation from rc.d (no other options set)? Now that I've updated my FreeBSD ports tree I'm using sshguard 1.6.4. I started it via a plain old "service sshguard start", no added options, unmodified rc file. What keeps sshguard from reading the whole auth.log on startup? Is it the timestamps? If so then what about my speculation that the lack of a year on the timestamps is messing this up? I looked for the code that does this for a few minutes but didn't find it. This is a side issue since as soon as my logfiles rotate properly I'll try starting sshguard from rc again and expect it will work fine. Nevertheless it's interesting behavior and if it's easy to fix, why not. >> There's already a note in http://www.sshguard.net/docs/setup/ about >> syslogd terminating and restarting sshguard, although it's not >> completely accurate. > >Could you clarify which part is inaccurate? I'd like to fix it ASAP. - The big one is it says "several times a day". I was seeing exit & restart every hour, which is how often newsyslog runs on FreeBSD. 24 times a day is more than several. Maybe other systems run newsyslog less often? Or don't kill programs every time it runs? - It says "SIGHUP". sshguard 1.5 said "Got exit signal", 1.6.4 changed the wording to "Exiting on signal". If the code doesn't tell the user what signal then the note probably shouldn't either, to avoid confusion. - And, not an inaccuracy, but adding a mention of my "!-sshguard" config file tweak to prevent the immediate restarting would be nice. |
|
From: Kevin Z. <kev...@gm...> - 2016-05-12 06:06:20
|
On 05/11/2016 22:16, Jef Poskanzer wrote: > Now that I've updated my FreeBSD ports tree I'm using sshguard 1.6.4. > I started it via a plain old "service sshguard start", no added options, > unmodified rc file. > > What keeps sshguard from reading the whole auth.log on startup? > Is it the timestamps? If so then what about my speculation that > the lack of a year on the timestamps is messing this up? I looked > for the code that does this for a few minutes but didn't find it. In sshguard_logsuck.c, logsuck_add_logsource() does a lseek(cursource.current_descriptor, 0, SEEK_END) to the end of the file before polling for new entries. > This is a side issue since as soon as my logfiles rotate properly > I'll try starting sshguard from rc again and expect it will work > fine. Nevertheless it's interesting behavior and if it's easy to > fix, why not. The behavior you're observing is incorrect. I'm still trying to figure out why this is happening to you. What are the permissions on the log files? Are they hard links, FIFOs, or anything else weird? > - The big one is it says "several times a day". I was seeing > exit & restart every hour, which is how often newsyslog runs > on FreeBSD. 24 times a day is more than several. Maybe other > systems run newsyslog less often? Or don't kill programs every > time it runs? Check newsyslog.conf: /var/log/auth.log 600 7 100 @0101T JC The log is rotated when it's larger than 100 KB, or at a certain time? > - It says "SIGHUP". sshguard 1.5 said "Got exit signal", 1.6.4 > changed the wording to "Exiting on signal". If the code doesn't > tell the user what signal then the note probably shouldn't either, > to avoid confusion. I'll see if I can print out the signal received. > - And, not an inaccuracy, but adding a mention of my "!-sshguard" > config file tweak to prevent the immediate restarting would > be nice. Ahh, I see. SSHGuard's regex parser ignores lines beginning with sshguard, but that doesn't do anything if syslog starts it. Thanks, Kevin -- Kevin Zheng kev...@gm... | ke...@be... | PGP: 0xC22E1090 |
|
From: Jef P. <je...@ma...> - 2016-05-12 06:09:06
|
>Ahh, I see. SSHGuard's regex parser ignores lines beginning with >sshguard, but that doesn't do anything if syslog starts it. Yep. By the time sshguard gets the line, it has by definition already been restarted. :-) |
|
From: Jef P. <je...@ma...> - 2016-05-12 19:03:10
|
Kevin:
>In sshguard_logsuck.c, logsuck_add_logsource() does a
>lseek(cursource.current_descriptor, 0, SEEK_END) to the end of the file
>before polling for new entries.
Ok, good, thanks. I confirm the lseek is getting run on my log files.
>The behavior you're observing is incorrect. I'm still trying to figure
>out why this is happening to you. What are the permissions on the log
>files? Are they hard links, FIFOs, or anything else weird?
No, nothing weird.
-rw------- 1 root wheel 298394 May 12 11:42 /var/log/auth.log
-rw-r----- 1 root mail 1619946 May 12 11:43 /var/log/maillog
Re-running the test, I think these syslogs are a clue. I should have
sent them before!
May 12 11:42:02 hydra sshguard[58928]: Reloading rotated file /var/log/auth.log.
May 12 11:42:02 hydra sshguard[58928]: Reloading rotated file /var/log/maillog.
The code that does that is also in sshguard_logsuck.c, the comment says
it does this when "myentry->current_serial_number != fileinfo.st_ino".
A little debugging shows:
myentry->current_serial_number 0, fileinfo.st_ino 12
myentry->current_serial_number 0, fileinfo.st_ino 1532
Yes those are the correct inode numbers. So why is current_serial_number
zero...? Oh, I think I see the problem. sshguard_logsuck.c lines
116-117, activate_source() is getting called with an uninitialized
fileinfo. Got to add a stat() to fill it in.
So I guess this is happening to everyone but no one else noticed because
their log files get rotated on a sane schedule.
---
Jef
Jef Poskanzer je...@ma... http://acme.com/jef/
|