fail2ban not working in CentOS

[Cendent]

I've been trying to fix fail2ban for a while didn't want to bother anyone with the problem but haven't been able to figure whats wrong.
I'm using CentOS 5.5 distro, installed through RPM Fail2Ban v0.8.4

When I start the service I get an email saying The jail SSH has been started successfully.

It seems to be listening on the port correctly too: iptables -L -n -v|grep ":22"

52 6234 fail2ban-SSH tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:22
17 1108 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 state NEW tcp dpt:22


When I try to ssh in as root (not allowed on the server) I can enter the wrong password 5 times and then PAM seems to disconnect me. The fail2ban never sends an alert or blocks the ip.


Here is my config file with my email address, and fail2ban email address changed, cat /etc/fail2ban/jail.conf | grep -v '#':

[DEFAULT]

ignoreip =

bantime = 1200

findtime = 600

maxretry = 3

backend = auto



[ssh-iptables]

enabled = true
filter = sshd
action = iptables[name=SSH, port=22, protocol=tcp]
sendmail-whois[name=SSH, dest=myemail-address, sender=fail2ban-mail]
logpath = /var/log/sshd.log
maxretry = 3

[proftpd-iptables]

enabled = false
filter = proftpd
action = iptables[name=ProFTPD, port=ftp, protocol=tcp]
sendmail-whois[name=ProFTPD, dest=myemail-address]
logpath = /var/log/proftpd/proftpd.log
maxretry = 3


[sasl-iptables]

enabled = false
filter = sasl
backend = polling
action = iptables[name=sasl, port=smtp, protocol=tcp]
sendmail-whois[name=sasl, dest=myemail-address]
logpath = /var/log/mail.log


[ssh-tcpwrapper]

enabled = false
filter = sshd
action = hostsdeny
sendmail-whois[name=SSH, dest=myemail-address]
ignoreregex = for myuser from
logpath = /var/log/sshd.log


[apache-tcpwrapper]

enabled = false
filter = apache-auth
action = hostsdeny
logpath = /var/log/apache*/*error.log
/home/www/myhomepage/error.log
maxretry = 6


[postfix-tcpwrapper]

enabled = false
filter = postfix
action = hostsdeny[file=/not/a/standard/path/hosts.deny]
sendmail[name=Postfix, dest=myemail-address]
logpath = /var/log/postfix.log
bantime = 300


[vsftpd-notification]

enabled = false
filter = vsftpd
action = sendmail-whois[name=VSFTPD, dest=myemail-address]
logpath = /var/log/vsftpd.log
maxretry = 5
bantime = 1800


[vsftpd-iptables]

enabled = false
filter = vsftpd
action = iptables[name=VSFTPD, port=ftp, protocol=tcp]
sendmail-whois[name=VSFTPD, dest=myemail-address]
logpath = /var/log/vsftpd.log
maxretry = 5
bantime = 1800


[apache-badbots]

enabled = false
filter = apache-badbots
action = iptables-multiport[name=BadBots, port="http,https"]
sendmail-buffered[name=BadBots, lines=5, dest=myemail-address]
logpath = /var/www/*/logs/access_log
bantime = 172800
maxretry = 1


[apache-shorewall]

enabled = false
filter = apache-noscript
action = shorewall
sendmail[name=Postfix, dest=myemail-address]
logpath = /var/log/apache2/error_log


[php-url-fopen]

enabled = false
port = http,https
filter = php-url-fopen
logpath = /var/www/*/logs/access_log
maxretry = 1


[lighttpd-fastcgi]

enabled = false
port = http,https
filter = lighttpd-fastcgi
logpath = /var/log/lighttpd/error.log
maxretry = 2


[ssh-ipfw]

enabled = false
filter = sshd
action = ipfw[localhost=192.168.0.1]
sendmail-whois[name="SSH,IPFW", dest=myemail-address]
logpath = /var/log/auth.log
ignoreip =


[named-refused-udp]

enabled = false
filter = named-refused
action = iptables-multiport[name=Named, port="domain,953", protocol=udp]
sendmail-whois[name=Named, dest=myemail-address]
logpath = /var/log/named/security.log
ignoreip =


[named-refused-tcp]

enabled = false
filter = named-refused
action = iptables-multiport[name=Named, port="domain,953", protocol=tcp]
sendmail-whois[name=Named, dest=myemail-address]
logpath = /var/log/named/security.log
ignoreip =



Let me know if you would like any information.

Thanks,
Josh

[unspawn]

What SSH logs to is configured in /etc/ssh/sshd_config. If it's syslog then the file syslog logs to is defined in /etc/.*syslog.*.conf. On Centos this defaults to syslog using /var/log/secure and not /var/log/sshd.log.

[Cendent]

Thanks, changed it to the correct log file. I'm still getting the same thing. Here is a sample of the log file:


Sep 26 17:56:21 cl-t222-480cl last message repeated 4 times
Sep 26 17:56:30 cl-t222-480cl sshd[2555]: Accepted password for sshadmin from 76.175.134.254 port 64075 ssh2
Sep 26 17:56:30 cl-t222-480cl sshd[2555]: pam_unix(sshd:session): session opened for user sshadmin by (uid=0)
Sep 26 17:56:47 cl-t222-480cl su: pam_unix(su-l:session): session opened for user root by sshadmin(uid=501)
Sep 26 18:02:28 cl-t222-480cl sshd[2647]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=76.175.134.254 user=sshadmin
Sep 26 18:02:30 cl-t222-480cl sshd[2647]: Failed password for sshadmin from 76.175.134.254 port 64085 ssh2


Might I need to have it actually write out the message each time instead of the log just updating the counter? Not sure how to make that happen or if thats even the problem.

Thanks

[unspawn]

Your log shows only *one* authentication failure for user=sshadmin and you have set maxretry=3. Can you confirm that failing to log in 4 times gets picked up by the fail2ban-SSH chain (packet counter) but doesn't trip blocking?

[Cendent]

Sorry should have posted the whole log:

Sep 26 17:55:58 cl-t222-480cl sshd[2555]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=sshadmin
Sep 26 17:56:00 cl-t222-480cl sshd[2555]: Failed password for sshadmin from 76.175.134.254 port 64075 ssh2
Sep 26 17:56:21 cl-t222-480cl last message repeated 4 times
Sep 26 17:56:30 cl-t222-480cl sshd[2555]: Accepted password for sshadmin from 76.175.134.254 port 64075 ssh2
Sep 26 17:56:30 cl-t222-480cl sshd[2555]: pam_unix(sshd:session): session opened for user sshadmin by (uid=0)
Sep 26 17:56:47 cl-t222-480cl su: pam_unix(su-l:session): session opened for user root by sshadmin(uid=501)
Sep 26 18:02:28 cl-t222-480cl sshd[2647]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=sshadmin
Sep 26 18:02:30 cl-t222-480cl sshd[2647]: Failed password for sshadmin from 76.175.134.254 port 64085 ssh2
Sep 26 18:02:40 cl-t222-480cl last message repeated 2 times
Sep 26 18:02:44 cl-t222-480cl sshd[2648]: Received disconnect from 76.175.134.254: 13: The user canceled authentication.
Sep 26 18:02:44 cl-t222-480cl sshd[2647]: PAM 2 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=sshadmin
Sep 26 21:23:09 cl-t222-480cl sshd[3704]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=root
Sep 26 21:23:11 cl-t222-480cl sshd[3704]: Failed password for root from 178.22.65.181 port 53047 ssh2
Sep 26 21:23:11 cl-t222-480cl sshd[3705]: Received disconnect from 178.22.65.181: 11: Bye Bye
Sep 26 21:23:12 cl-t222-480cl sshd[3706]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=178.22.65.181 user=root
Sep 26 21:23:14 cl-t222-480cl sshd[3706]: Failed password for root from 178.22.65.181 port 53430 ssh2
Sep 26 21:23:14 cl-t222-480cl sshd[3707]: Received disconnect from 178.22.65.181: 11: Bye Bye
Sep 26 21:23:15 cl-t222-480cl sshd[3708]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=178.22.65.181 user=root
Sep 26 21:23:16 cl-t222-480cl sshd[3708]: Failed password for root from 178.22.65.181 port 53777 ssh2
Sep 26 21:23:16 cl-t222-480cl sshd[3709]: Received disconnect from 178.22.65.181: 11: Bye Bye
Sep 26 21:23:17 cl-t222-480cl sshd[3710]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=178.22.65.181 user=root
Sep 26 21:23:19 cl-t222-480cl sshd[3710]: Failed password for root from 178.22.65.181 port 54079 ssh2
Sep 27 00:58:17 cl-t222-480cl sshd[4964]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=sshadmin
Sep 27 00:58:19 cl-t222-480cl sshd[4964]: Failed password for sshadmin from 76.175.134.254 port 53023 ssh2
Sep 27 00:58:35 cl-t222-480cl last message repeated 3 times
Sep 27 00:58:41 cl-t222-480cl sshd[4965]: Received disconnect from 76.175.134.254: 13: The user canceled authentication.
Sep 27 00:58:41 cl-t222-480cl sshd[4964]: PAM 3 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=sshadmin
Sep 27 00:58:41 cl-t222-480cl sshd[4964]: PAM service(sshd) ignoring max retries; 4 > 3
Sep 27 01:55:27 cl-t222-480cl sshd[18408]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=66.163.120.187 user=admin
Sep 27 01:55:29 cl-t222-480cl sshd[18408]: Failed password for admin from 66.163.120.187 port 9217 ssh2
Sep 27 01:55:29 cl-t222-480cl sshd[18409]: Received disconnect from 66.163.120.187: 11: Bye Bye
Sep 27 01:55:30 cl-t222-480cl sshd[18410]: Invalid user cindy from 66.163.120.187
Sep 27 01:55:30 cl-t222-480cl sshd[18411]: input_userauth_request: invalid user cindy
Sep 27 01:55:30 cl-t222-480cl sshd[18410]: pam_unix(sshd:auth): check pass; user unknown
Sep 27 01:55:30 cl-t222-480cl sshd[18410]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=66.163.120.187
Sep 27 01:55:30 cl-t222-480cl sshd[18410]: pam_succeed_if(sshd:auth): error retrieving information about user cindy
Sep 27 01:55:32 cl-t222-480cl sshd[18410]: Failed password for invalid user cindy from 66.163.120.187 port 9433 ssh2
Sep 27 01:55:32 cl-t222-480cl sshd[18411]: Received disconnect from 66.163.120.187: 11: Bye Bye
Sep 27 01:55:33 cl-t222-480cl sshd[18413]: Invalid user anna from 66.163.120.187
Sep 27 01:55:33 cl-t222-480cl sshd[18414]: input_userauth_request: invalid user anna
Sep 27 01:55:33 cl-t222-480cl sshd[18413]: pam_unix(sshd:auth): check pass; user unknown
Sep 27 01:55:33 cl-t222-480cl sshd[18413]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=66.163.120.187
Sep 27 01:55:33 cl-t222-480cl sshd[18413]: pam_succeed_if(sshd:auth): error retrieving information about user anna
Sep 27 01:55:35 cl-t222-480cl sshd[18413]: Failed password for invalid user anna from 66.163.120.187 port 9652 ssh2
Sep 27 02:33:51 cl-t222-480cl sshd[19010]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=66.163.120.187 user=admin
Sep 27 02:33:53 cl-t222-480cl sshd[19010]: Failed password for admin from 66.163.120.187 port 64597 ssh2
Sep 27 02:33:53 cl-t222-480cl sshd[19011]: Received disconnect from 66.163.120.187: 11: Bye Bye
Sep 27 02:33:54 cl-t222-480cl sshd[19012]: Invalid user cindy from 66.163.120.187
Sep 27 02:33:54 cl-t222-480cl sshd[19013]: input_userauth_request: invalid user cindy
Sep 27 02:33:54 cl-t222-480cl sshd[19012]: pam_unix(sshd:auth): check pass; user unknown
Sep 27 02:33:54 cl-t222-480cl sshd[19012]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=66.163.120.187
Sep 27 02:33:54 cl-t222-480cl sshd[19012]: pam_succeed_if(sshd:auth): error retrieving information about user cindy
Sep 27 02:33:55 cl-t222-480cl sshd[19012]: Failed password for invalid user cindy from 66.163.120.187 port 64736 ssh2
Sep 27 02:33:56 cl-t222-480cl sshd[19013]: Received disconnect from 66.163.120.187: 11: Bye Bye
Sep 27 02:33:56 cl-t222-480cl sshd[19014]: Invalid user anna from 66.163.120.187
Sep 27 02:33:56 cl-t222-480cl sshd[19015]: input_userauth_request: invalid user anna
Sep 27 02:33:56 cl-t222-480cl sshd[19014]: pam_unix(sshd:auth): check pass; user unknown
Sep 27 02:33:56 cl-t222-480cl sshd[19014]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=66.163.120.187
Sep 27 02:33:56 cl-t222-480cl sshd[19014]: pam_succeed_if(sshd:auth): error retrieving information about user anna
Sep 27 02:33:58 cl-t222-480cl sshd[19014]: Failed password for invalid user anna from 66.163.120.187 port 64905 ssh2








heres the fail2ban.log:

2010-09-26 17:53:30,857 fail2ban.server : INFO Changed logging target to /var/log/fail2ban.log for Fail2ban v0.8.4
2010-09-26 17:53:30,858 fail2ban.jail : INFO Creating new jail 'ssh-iptables'
2010-09-26 17:53:30,860 fail2ban.jail : INFO Jail 'ssh-iptables' uses Gamin
2010-09-26 17:53:30,885 fail2ban.filter : INFO Added logfile = /var/log/secure
2010-09-26 17:53:30,887 fail2ban.filter : INFO Set maxRetry = 3
2010-09-26 17:53:30,889 fail2ban.filter : INFO Set findtime = 600
2010-09-26 17:53:30,891 fail2ban.actions: INFO Set banTime = 600
2010-09-26 17:53:30,980 fail2ban.jail : INFO Jail 'ssh-iptables' started
2010-09-26 21:23:19,029 fail2ban.actions: WARNING [ssh-iptables] Ban 10178.22.65.181
2010-09-26 21:33:19,453 fail2ban.actions: WARNING [ssh-iptables] Unban 178.22.65.181
2010-09-27 01:55:35,068 fail2ban.actions: WARNING [ssh-iptables] Ban 66.163.120.187
2010-09-27 02:05:36,040 fail2ban.actions: WARNING [ssh-iptables] Unban 66.163.120.187
2010-09-27 02:33:57,916 fail2ban.actions: WARNING [ssh-iptables] Ban 66.163.120.187
2010-09-27 02:43:58,511 fail2ban.actions: WARNING [ssh-iptables] Unban 66.163.120.187
2010-09-27 02:51:25,498 fail2ban.actions: WARNING [ssh-iptables] Ban 66.163.120.187


Seems fail2ban worked for some. But didn't work for 99.99.99.99 (mine) when it had the the last message repeated 4 times.

[unspawn]

Your logins as sshadmin (please edit posts and blot out or obfuscate your own IP address) occur at Sep 26 17:5[5,6] but /var/log/fail2ban.log shows a gap between 17:53 and 21:23 so that ain't telling me anything.

As you have set no ignoreip = in /etc/fail2ban/jail.conf the only thing I can think of is a preceding rule in your firewall that could -j ACCEPT traffic before it hits the fail2ban-SSH chain. I'd run 'screen' on the server, split it, 'tail -f /var/log/secure /var/log/fail2ban.log' in one section and 'watch /sbin/iptables -t filter -nvxL INPUT' (or whatever chain is the parent of the fail2ban-SSH chain) in the other. When you hit the 3 bad logins mark the packet counter should show traffic actually goes through the fail2ban-SSH chain.

[Cendent]

Thanks for your help so far defiantly appreciated.

Heres the results from the tail:

==> /var/log/secure <==
Sep 27 16:08:51 cl-t222-480cl sshd[23751]: input_userauth_request: invalid user test
Sep 27 16:08:51 cl-t222-480cl sshd[23750]: pam_unix(sshd:auth): check pass; user unknown
Sep 27 16:08:51 cl-t222-480cl sshd[23750]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=143.225.223.159
Sep 27 16:08:51 cl-t222-480cl sshd[23750]: pam_succeed_if(sshd:auth): error retrieving information about user test
Sep 27 16:08:53 cl-t222-480cl sshd[23750]: Failed password for invalid user test from 143.225.223.159 port 42085 ssh2
Sep 27 21:36:28 cl-t222-480cl sshd[25241]: Accepted password for sshadmin from 76.175.134.254 port 56550 ssh2
Sep 27 21:36:28 cl-t222-480cl sshd[25241]: pam_unix(sshd:session): session opened for user sshadmin by (uid=0)
Sep 27 21:36:45 cl-t222-480cl sshd[25271]: Accepted password for sshadmin from 76.175.134.254 port 56551 ssh2
Sep 27 21:36:45 cl-t222-480cl sshd[25271]: pam_unix(sshd:session): session opened for user sshadmin by (uid=0)
Sep 27 21:36:58 cl-t222-480cl su: pam_unix(su-l:session): session opened for user root by sshadmin(uid=501)

==> /var/log/fail2ban.log <==
2010-09-27 03:26:10,582 fail2ban.actions: WARNING [ssh-iptables] Unban 66.163.120.187
2010-09-27 09:18:11,536 fail2ban.actions: WARNING [ssh-iptables] Ban 79.38.86.58
2010-09-27 09:18:14,101 fail2ban.actions: WARNING [ssh-iptables] 79.38.86.58 already banned
2010-09-27 09:28:12,049 fail2ban.actions: WARNING [ssh-iptables] Unban 79.38.86.58
2010-09-27 10:54:50,570 fail2ban.actions: WARNING [ssh-iptables] Ban 212.33.27.26
2010-09-27 11:04:50,951 fail2ban.actions: WARNING [ssh-iptables] Unban 212.33.27.26
2010-09-27 11:47:54,721 fail2ban.actions: WARNING [ssh-iptables] Ban 212.33.27.26
2010-09-27 11:57:55,018 fail2ban.actions: WARNING [ssh-iptables] Unban 212.33.27.26
2010-09-27 16:08:52,623 fail2ban.actions: WARNING [ssh-iptables] Ban 143.225.223.159
2010-09-27 16:18:52,957 fail2ban.actions: WARNING [ssh-iptables] Unban 143.225.223.159

==> /var/log/secure <==
Sep 27 21:37:17 cl-t222-480cl su: pam_unix(su-l:session): session opened for user root by sshadmin(uid=501)
Sep 27 21:38:45 cl-t222-480cl sshd[25376]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=sshadmin
Sep 27 21:38:46 cl-t222-480cl sshd[25376]: Failed password for sshadmin from 76.175.134.254 port 56553 ssh2
Sep 27 21:39:26 cl-t222-480cl last message repeated 4 times
Sep 27 21:39:52 cl-t222-480cl last message repeated 2 times
Sep 27 21:39:52 cl-t222-480cl sshd[25377]: Disconnecting: Too many authentication failures for sshadmin
Sep 27 21:39:52 cl-t222-480cl sshd[25376]: PAM 6 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=99.99.99.99 user=sshadmin
Sep 27 21:39:52 cl-t222-480cl sshd[25376]: PAM service(sshd) ignoring max retries; 7 > 3


On the watch I can see pkts and bytes increasing a small amount.

[unspawn]

Thanks for the logs. Unfortunately sorting your logs does not show *any* complete "session" per IP address leading up to a ban. One way to troubleshoot this further could be to use "-m state --state NEW -m tcp -p tcp --dport 22 -j LOG" target rules in both the chain leading up to the fail2ban chain and in that one itself, sort all related logs and then see if this correlates. (I'm pretty sure it's a configuration issue so if this step doesn't work out we could start from scratch by listing all complete configuration files but let's get to that when it's needed.)

[Cendent]

Hi thanks for all the help. Still new to linux so took me a bit to figure it out the "-m state --state NEW -m tcp -p tcp --dport 22 -j LOG" helped a lot.
It seems that the fail2ban is only increasing if a different port number is used, so I could login unlimited amount of times using the same port number and fail to ban would only reach the attempt as 1.

Its defiantly something in my config files. For now it is working fine with max_attempt set to 1.

Anything you could think of that would be causing this?

Thanks,
Josh

[unspawn]

It seems that the fail2ban is only increasing if a different port number is used, so I could login unlimited amount of times using the same port number and fail to ban would only reach the attempt as 1.

Authentication is handled by OpenSSH itself (using PAM or not) and its logging is configured in /etc/ssh/sshd_config which defaults to using Syslog as far as I know. Syslog by default logs SSH failures to /var/log/secure. Fail2ban parses /var/log/secure and responds to failures. So your statement does not seem right to me.

While you have posted back a lot of information (thanks) I'm still missing some information (or being posted in a factual way I can glean nfo from) which makes it difficult if not impossible to get a grip on this. Maybe you don't know how to provide the information or maybe you just read over it.

I'll make one final attempt but you need to post (or pastebin if you can't post that much here) the following information (obfuscate IP addresses and account names if necessary):
- the output from running 'rpm -Vv openssh-server pam setup fail2ban iptables syslog rsyslog syslog-ng 2>/dev/null| grep '^..5';' (should show just a few files),
- the contents of those files PLUS any /etc/*syslog*.conf, but only the 'grep -v ^# /path/to/file|grep .' output which you can do by running 'rpm -Vv openssh-server pam setup fail2ban iptables syslog rsyslog syslog-ng 2>/dev/null | grep '^..5' | egrep -v "limit|space|alia|cap|tty|te.d|it.d"|awk '{print "grep -v ^# "$NF"|grep ."}'|sh',
- the output of '/sbin/iptables-save' AFTER starting fail2ban.

I know this is overkill but I'm not able to ask for a more fine-grained response.