Fail2Ban not blocking brute force attack on dovecot

dovecotfail2ban

I run a CentOS 5 server with fail2ban and I am currently getting hit with a bruteforce attack on my dovecot service.

I know fail2ban is working, because it is blocking attacks on my FTP server and Postfix. For some reason I am missing something with dovecot as the fail2ban log has nothing in it and the attack continues unabated.

My logs are as follows. Dovecot logs everything to – /var/log/dovecot-info.log

I see 2 types of logs. The first looks like this (Note: My server Ip is OK – I have blocked out the finer details with xxx.xxx.xxx):

Feb 22 21:48:21 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:48:23 auth: Info: passwd-file(felipe,177.19.151.139): unknown user
Feb 22 21:48:25 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felipe>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:48:29 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:48:31 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:48:40 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:48:42 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:48:50 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:48:52 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:49:00 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:49:02 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:49:11 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:49:13 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:49:21 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:49:23 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:49:32 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:49:34 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:49:42 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:49:44 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:49:52 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:49:54 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:50:03 auth: Info: passwd-file(felix,177.19.151.139): unknown user
Feb 22 21:50:05 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 21:50:13 auth: Info: passwd-file(felix,177.19.151.139): unknown user

The 2nd looks like this:

Feb 22 22:10:37 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<frankie>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:38 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<fox>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<frances>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<francis>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<forest>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<frank>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<forrest>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<frankie>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<fox>, method=PLAIN, rip=177.19.151.139, lip=173.xxx.xxx.xxx
Feb 22 22:10:51 auth: Info: passwd-file(francis,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(frances,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(forest,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(frank,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(forrest,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(frankie,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(fox,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(francis,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(frances,177.19.151.139): unknown user
Feb 22 22:10:51 auth: Info: passwd-file(forest,177.19.151.139): unknown user

jail.conf looks like this:

[dovecot-pop3imap]
enabled  = true
filter   = dovecot-pop3imap
action   = iptables-multiport[name=dovecot-pop3imap, port="pop3,pop3s,imap,imaps", protocol=tcp]
           sendmail-whois[name=dovecot-pop3imap, dest=me@me.com, sender=me@me.com]
logpath  = /var/log/dovecot-info.log
maxretry = 5
findtime = 1200
bantime  = 1200

filter.d/dovecot.conf looks like this:

failregex = ^%(__prefix_line)s(pam_unix(\(dovecot:auth\))?:)?\s+authentication failure; logname=\S* uid=\S* euid=\S* tty=dovecot ruser=\S* rhost=<HOST>(\s+user=\S*)?\s*$
            ^%(__prefix_line)s(pop3|imap)-login: (Info: )?(Aborted login|Disconnected)(: Inactivity)? \(((no auth attempts|auth failed, \d+ attempts)( in \d+ secs)?|tried to $
            ^%(__prefix_line)s(Info|dovecot: auth\(default\)): pam\(\S+,<HOST>\): pam_authenticate\(\) failed: (User not known to the underlying authentication module: \d+ Ti$

ignoreregex =

fail2ban.conf looks like this:

# Option:  loglevel
# Notes.:  Set the log level output.
#          1 = ERROR
#          2 = WARN
#          3 = INFO
#          4 = DEBUG
# Values:  NUM  Default:  3
#
loglevel = 3

# Option:  logtarget
# Notes.:  Set the log target. This could be a file, SYSLOG, STDERR or STDOUT.
#          Only one log target can be specified.
# Values:  STDOUT STDERR SYSLOG file  Default:  /var/log/fail2ban.log
#
#logtarget = SYSLOG
logtarget = /var/log/fail2ban.log

# Option: socket
# Notes.: Set the socket file. This is used to communicate with the daemon. Do
#         not remove this file when Fail2ban runs. It will not be possible to
#         communicate with the server afterwards.
# Values: FILE  Default:  /var/run/fail2ban/fail2ban.sock
#
socket = /var/run/fail2ban/fail2ban.sock

I am almost certain my regex is wrong somehow, but I am at a loss. Any help anyone can provide is most welcome at this point.

More Info – I have restarted the service after changes and it makes no difference and the date/time is accurate.

Best Answer

The official fail2ban wiki has some fine instructions on how to test your regular expressions.

More specifically, you should be running fail2ban-regex against (a sample of) your logs.

# fail2ban-regex /var/log/dovecot-info.log /etc/fail2ban/filter.d/dovecot.conf

Also, there seems to be an error in your configuration:

[dovecot-pop3imap]
  enabled  = true
  filter   = dovecot-pop3imap

as the name of the filter should match the name of the file in /etc/fai2ban/filters.d

I tested a sample of your logs, specifically:

Feb 22 21:48:21 pop3-login: Info: Aborted login (auth failed, 1 attempts): user=<felix>, method=PLAIN, rip=177.19.151.139, lip=173.111.111.111

and the first attempt failed with:

# fail2ban-regex sample.log /etc/fail2ban/filter.d/dovecot-pop3imap.conf

Running tests
=============

No section headers in /etc/fail2ban/filter.d/dovecot-pop3imap.conf

After adding a [Definition] tag to the regular expressions directives (you might as well have omitted it for brevity), the output is:

# fail2ban-regex sample.log /etc/fail2ban/filter.d/dovecot-pop3imap.conf --print-all-missed

Running tests
=============

Use   failregex file : /etc/fail2ban/filter.d/dovecot-pop3imap.conf
Use         log file : sample.log
Use         encoding : UTF-8


Results
=======

Failregex: 1 total
|-  #) [# of hits] regular expression
|   1) [1] ^\s*(<[^.]+\.[^.]+>)?\s*(?:\S+ )?(?:kernel: \[\d+\.\d+\] )?(?:@vserver_\S+ )?(?:(?:\[\d+\])?:\s+[\[\(]?\S*(?:\(\S+\))?[\]\)]?:?|[\[\(]?\S*(?:\(\S+\))?[\]\)]?:?(?:\[\d+\])?:?)?\s(?:\[ID \d+ \S+\])?\s*(pop3|imap)-login: (Info: )?(Aborted login|Disconnected)(: Inactivity)? \(((no auth attempts|auth failed, \d+ attempts)( in \d+ secs)?|tried to use disabled \S+ auth)\):( user=<\S*>,)?( method=\S+,)? rip=<HOST>, lip=(\d{1,3}\.){3}\d{1,3}(, session=<\w+>)?(, TLS( handshaking)?(: Disconnected)?)?\s*$
`-

Ignoreregex: 0 total

Date template hits:
|- [# of hits] date format
|  [1] MON Day 24hour:Minute:Second
`-

Lines: 1 lines, 0 ignored, 1 matched, 0 missed

Also note that your regex fails to compile (I have not tried debugging the reason). I have used the regex that comes packaged with fail2ban as of version:

# rpm -qi fail2ban
Name        : fail2ban
Version     : 0.9
Release     : 0.3.git1f1a561.fc20

which is slightly different:

failregex = ^%(__prefix_line)s(pam_unix(\(\S+\))?:)?\s+authentication failure; logname=\S* uid=\S* euid=\S* tty=dovecot ruser=\S* rhost=<HOST>(\s+user=\S*)?\s*$
            ^%(__prefix_line)s(pop3|imap)-login: (Info: )?(Aborted login|Disconnected)(: Inactivity)? \(((no auth attempts|auth failed, \d+ attempts)( in \d+ secs)?|tried to use disabled \S+ auth)\):( user=<\S*>,)?( method=\S+,)? rip=<HOST>, lip=(\d{1,3}\.){3}\d{1,3}(, session=<\w+>)?(, TLS( handshaking)?(: Disconnected)?)?\s*$
Related Topic