Fail2Ban stops working when logs are rotated

M

Mayhem30

I'm using security/py-fail2ban to stop some attacks on my mail server. It's working great right up until my mail log is auto rotated.

Once that happens, the fail2ban.log file shows this :
Code: 
2016-11-27 00:00:00,060 fail2ban.filter         [53833]: INFO    Log rotation detected for /var/log/maillog
After that, no more fail2ban.log entries are recorded and Fail2Ban no longer does anything until I restart it.

Any suggestions on how to fix this issue?
 
Please check (part of) my /etc/newsyslog.conf:
Code: 
/var/log/fail2ban.log           640  3     100  *  J    /var/run/fail2ban/fail2ban.pid  30
Please note the last two field: path_to_pid_cmd_file and signal. Check newsyslog.conf() for details!

Edit: sorry, I misunderstood you. I think you can use similar with your maillog (with fail2ban-restart), I hope it helps you.
 
Code: 
/var/log/maillog ... /var/run/fail2ban/fail2ban.pid  30
I think in this case the fail2ban will restart when /var/log/maillog rotates.
 
No, that didn't work for me.

I must be doing something wrong ... as I just can't see why Fail2Ban stops working when any log file is rotated. Once that happens, Fail2Ban "stalls" and does absolutely nothing until it's restarted.

No one else is having this issue?
 
This is the debug file for when it stop working :
Code: 
2016-12-08 00:00:00,071 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event cookie=4334241 dir=False mask=0x80 maskname=IN_MOVED_TO name=maillog.3.bz2 path=/var/log pathname=/var/log/maillog.3.bz2 wd=13 >
2016-12-08 00:00:00,071 fail2ban.filterpyinotify[1586]: DEBUG   Ignoring creation of /var/log/maillog.3.bz2 we do not monitor
2016-12-08 00:00:00,071 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event cookie=4334127 dir=False mask=0x80 maskname=IN_MOVED_TO name=maillog.2.bz2 path=/var/log pathname=/var/log/maillog.2.bz2 wd=13 >
2016-12-08 00:00:00,071 fail2ban.filterpyinotify[1586]: DEBUG   Ignoring creation of /var/log/maillog.2.bz2 we do not monitor
2016-12-08 00:00:00,072 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event cookie=4333984 dir=False mask=0x80 maskname=IN_MOVED_TO name=maillog.1.bz2 path=/var/log pathname=/var/log/maillog.1.bz2 wd=13 >
2016-12-08 00:00:00,072 fail2ban.filterpyinotify[1586]: DEBUG   Ignoring creation of /var/log/maillog.1.bz2 we do not monitor
2016-12-08 00:00:00,072 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/maillog pathname=/var/log/maillog wd=14 >
2016-12-08 00:00:00,072 fail2ban.filter         [1586]: INFO    Log rotation detected for /var/log/maillog
2016-12-08 00:00:00,072 fail2ban.datedetector   [1586]: DEBUG   Matched time template (?:DAY )?MON Day 24hour:Minute:Second(?:\.Microseconds)?(?: Year)?
2016-12-08 00:00:00,072 fail2ban.datedetector   [1586]: DEBUG   Got time 1481184000.000000 for "u'Dec  8 00:00:00'" using template (?:DAY )?MON Day 24hour:Minute:Second(?:\.Microseconds)?(?: Year)?
2016-12-08 00:00:00,078 fail2ban.datedetector   [1586]: DEBUG   Sorting the template list
2016-12-08 00:00:00,078 fail2ban.datedetector   [1586]: DEBUG   Winning template: (?:DAY )?MON Day 24hour:Minute:Second(?:\.Microseconds)?(?: Year)? with 3010 hits
2016-12-08 00:00:00,078 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event dir=False mask=0x100 maskname=IN_CREATE name=maillog.0 path=/var/log pathname=/var/log/maillog.0 wd=13 >
2016-12-08 00:00:00,078 fail2ban.filterpyinotify[1586]: DEBUG   Ignoring creation of /var/log/maillog.0 we do not monitor
2016-12-08 00:00:00,078 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event dir=False mask=0x100 maskname=IN_CREATE name=maillog path=/var/log pathname=/var/log/maillog wd=13 >
2016-12-08 00:00:00,078 fail2ban.filterpyinotify[1586]: DEBUG   Removed file watcher for /var/log/maillog
2016-12-08 00:00:00,079 fail2ban.filterpyinotify[1586]: DEBUG   Added file watcher for /var/log/maillog
2016-12-08 00:00:00,080 fail2ban.datedetector   [1586]: DEBUG   Sorting the template list
2016-12-08 00:00:00,080 fail2ban.datedetector   [1586]: DEBUG   Winning template: (?:DAY )?MON Day 24hour:Minute:Second(?:\.Microseconds)?(?: Year)? with 3010 hits
2016-12-08 00:00:00,080 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event dir=False mask=0x8000 maskname=IN_IGNORED name='' path=/var/log/maillog pathname=/var/log/maillog wd=14 >
2016-12-08 00:00:00,082 fail2ban.datedetector   [1586]: DEBUG   Sorting the template list
2016-12-08 00:00:00,082 fail2ban.datedetector   [1586]: DEBUG   Winning template: (?:DAY )?MON Day 24hour:Minute:Second(?:\.Microseconds)?(?: Year)? with 3010 hits
2016-12-08 00:00:10,157 fail2ban.filterpyinotify[1586]: DEBUG   Default Callback for Event: <Event dir=False mask=0x100 maskname=IN_CREATE name=maillog.0.bz2 path=/var/log pathname=/var/log/maillog.0.bz2 wd=13 >
2016-12-08 00:00:10,158 fail2ban.filterpyinotify[1586]: DEBUG   Ignoring creation of /var/log/maillog.0.bz2 we do not monitor
Then it just stops working .. 7 minutes later I stopped / started Fail2Ban and it works again.
Code: 
2016-12-08 00:06:59,764 fail2ban.transmitter    [1586]: DEBUG   Command: ['stop']
2016-12-08 00:06:59,765 fail2ban.asyncserver    [1586]: DEBUG   Removed socket file /var/run/fail2ban/fail2ban.sock
2016-12-08 00:06:59,765 fail2ban.asyncserver    [1586]: DEBUG   Socket shutdown
2016-12-08 00:06:59,765 fail2ban.server         [1586]: INFO    Stopping all jails
2016-12-08 00:06:59,765 fail2ban.server         [1586]: DEBUG   Stopping jail postfix
2016-12-08 00:07:00,151 fail2ban.actions        [1586]: DEBUG   Flush ban list
In my newsyslog.conf file, I have it set to save up to 4 backups.
Code: 
/var/log/messages                       644  4     100  @0101T JC
Any ideas? Do you think the backups are messing things up?
 
Mayhem30 said:
I'm using security/py-fail2ban to stop some attacks on my mail server. It's working great right up until my mail log is auto rotated.

Once that happens, the fail2ban.log file shows this :
Code: 
2016-11-27 00:00:00,060 fail2ban.filter         [53833]: INFO    Log rotation detected for /var/log/maillog
After that, no more fail2ban.log entries are recorded and Fail2Ban no longer does anything until I restart it.

Any suggestions on how to fix this issue?
Click to expand...
You must ensure that newsyslog executes a script during rotation.

For example, the newsyslog rotation log entry has the 'R' flag set, which, according to the man page, is doing this:
newsyslog.conf():
Code: 
if this flag is set the newsyslog(8) will run shell
command defined in path_to_pid_cmd_file after rotation
instead of trying to send signal to a process id stored
in the file.

At the time when newsyslog is invoked, a new file will be created (fail2ban.log), but the process will keep on using the file descriptor of the file which was rotated by newsyslog (usually fail2ban.log.0).
Your script must inform the actual fail2ban process where to send data after having the file renamed/rotated with the FD open.
The script below should do it:
Code: 
#!/bin/sh
/usr/local/bin/fail2ban-client set logtarget /var/log/fail2ban.log > /dev/null

and this logrotate.conf snippet (feel free to put this in /usr/local/etc/newsyslog.conf.d/fail2ban.conf)
Code: 
# logfilename          [owner:group]    mode count size   when  flags [/pid_file] [sig_num]
/var/log/fail2ban.log                   600  10    10000  *     JBCR  /usr/local/bin/fail2ban-logrotate.sh
 
You must log in or register to reply here.
Back
Top