mitchellkrogza / Fail2Ban-Blacklist-JAIL-for-Repeat-Offenders-with-Perma-Extended-Banning

A customised jail with action and filter file for Fail2Ban. This jail is based on the recidive jail but makes use of a simple text file to enable extended and permanent bans.
150 stars 39 forks source link

banaction seems to be ignored #14

Closed bkis closed 5 years ago

bkis commented 5 years ago

I doubt it's a problem with your jail, so sorry I am spamming your issues with this. But maybe you could help me figuring this one out:
I set up everything exactly as instructed (apart from customized retry values). Unfortunately, the banaction doesn't seem to be executed. I got a message from fail2ban saying

The IP 223.197.XXX.XX has just been banned by Fail2Ban after 5 attempts against blacklist (X inserted by me)

So the jail seems to be reacting to the log entries, but the ip.blacklist isn't modified and sudo iptables -S doesn't show any related entries. BTW I didn't forget to chmod 755 the ip.blacklist. Do you have any idea what I could look at next to find the reason for this? Thanks for your help!

Edit: Also, the fail2ban.log says [blacklist] Found ... and [blacklist] Ban ..., but still no ban via blacklist jail and no modification of ip.blacklist.

bkis commented 5 years ago

Sorry to bother you again, but my problem persists. The log says the jail and filter work as expected, but the banaction is not executed:

fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 03:26:05
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 03:26:05
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 03:26:08
fail2ban.actions  NOTICE  [sshd] Ban 187.189.143.XX
fail2ban.filter   INFO    [blacklist] Found 187.189.143.XX - 2019-10-30 03:26:09
fail2ban.actions  NOTICE  [sshd] Unban 187.189.143.XX
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 04:51:13
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 04:51:13
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 04:51:15
fail2ban.actions  NOTICE  [sshd] Ban 187.189.143.XX
fail2ban.filter   INFO    [blacklist] Found 187.189.143.XX - 2019-10-30 04:51:16
fail2ban.actions  NOTICE  [sshd] Unban 187.189.143.XX
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 06:17:09
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 06:17:09
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 06:17:11
fail2ban.actions  NOTICE  [sshd] Ban 187.189.143.XX
fail2ban.filter   INFO    [blacklist] Found 187.189.143.XX - 2019-10-30 06:17:11
fail2ban.actions  NOTICE  [blacklist] Ban 187.189.143.XX
fail2ban.actions  NOTICE  [sshd] Unban 187.189.143.XX
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 07:43:05
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 07:43:05
fail2ban.filter   INFO    [sshd] Found 187.189.143.XX - 2019-10-30 07:43:07
fail2ban.actions  NOTICE  [sshd] Ban 187.189.143.XX
fail2ban.filter   INFO    [blacklist] Found 187.189.143.XX - 2019-10-30 07:43:08

(i removed some redundant data for readability)

ip.blacklist stays empty and sudo iptables -S | grep f2b says:

-N f2b-sshd
-A INPUT -p tcp -m multiport --dports 10022 -j f2b-sshd
-A f2b-sshd -s 187.189.143.XX/32 -j REJECT --reject-with icmp-port-unreachable
-A f2b-sshd -j RETURN

...so the sshd jail does it's job. Fine. It's just that there's no entry by the blacklist jail. Do you have any ideas?

mitchellkrogza commented 5 years ago

It's a permission issue somewhere, fail2ban cannot seem to add the filter to iptables, should look as follows.

-A f2b-blacklist -s x.x.x.x/32 -j DROP
-A f2b-blacklist -s x.x.x.x/32 -j DROP
-A f2b-blacklist -s x.x.x.x/32 -j DROP
-A f2b-blacklist -j RETURN
mitchellkrogza commented 5 years ago

@bkis please read this post of mine - https://ubuntu101.co.za/security/fail2ban/fail2ban-persistent-bans-ubuntu/

Particularly this section: 2019-10-30_09-26

Ubuntu 101
Fail2Ban SSH Nginx Persistent Bans Ubuntu 16.04
Fail2Ban SSH Nginx Persistent Bans Ubuntu 16.04 - how to properly configure fail2ban 0.91 with persistent recidive banning on ubuntu 16.04
bkis commented 5 years ago

Thank you for your reply! The problem seemed to be that I had a banaction

banaction = blacklist

and an action

action = sendmail-whois[name=blacklist, dest=xxxxx@localhost, sender=fail2ban@domain.com]

Just to try it, I removed the action line and now it seems to try to execute the banaction, but the logs say that it fails because the iptables chain already exists (which I think is a little weird):

2019-10-30 10:08:32,149 fail2ban.jail           [2099]: INFO    Jail 'blacklist' started
2019-10-30 10:08:32,296 fail2ban.actions        [2099]: NOTICE  [blacklist] Restore Ban 141.98.255.xxx
2019-10-30 10:08:32,328 fail2ban.utils          [2099]: Level 39 7f552ba6a670 -- exec: iptables -N f2b-blacklist
iptables -A f2b-blacklist -j RETURN
iptables -I INPUT -p tcp -j f2b-blacklist
sort -u /etc/fail2ban/ip.blacklist -o /etc/fail2ban/ip.blacklist
cat /etc/fail2ban/ip.blacklist | while read IP; do iptables -I f2b-blacklist 1 -s $IP -j DROP; done
2019-10-30 10:08:32,329 fail2ban.utils          [2099]: ERROR   7f552ba6a670 -- stderr: 'iptables: Chain already exists.'
2019-10-30 10:08:32,329 fail2ban.utils          [2099]: ERROR   7f552ba6a670 -- stderr: "Bad argument `DROP'"
2019-10-30 10:08:32,329 fail2ban.utils          [2099]: ERROR   7f552ba6a670 -- stderr: "Try `iptables -h' or 'iptables --help' for more information."
2019-10-30 10:08:32,329 fail2ban.utils          [2099]: ERROR   7f552ba6a670 -- returned 2
2019-10-30 10:08:32,329 fail2ban.actions        [2099]: ERROR   Failed to execute ban jail 'blacklist' action 'blacklist' info 'ActionInfo({'ip': '141.98.255.xxx', 'family': 'inet4', 'ip-rev': '144.255.98.xxx.', 'ip-host': None, 'fid': '141.98.255.xxx', 'failures': 3, 'time': 1572426512.1489875, 'matches': '2019-10-20 15:30:13,550 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx\n2019-10-20 15:30:42,886 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx\n2019-10-20 15:31:25,628 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx', 'restored': 1, 'F-*': {'matches': [['', '2019-10-20 15:30:13,550', ' fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx'], '2019-10-20 15:30:42,886 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx', '2019-10-20 15:31:25,628 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx'], 'failures': 3, 'ip4': '141.98.255.xxx'}, 'ipmatches': 'Oct 20 15:30:07 hostname sshd[4369]: Failed password for user from 141.98.255.xxx port 50050 ssh2\nOct 20 15:30:12 hostname sshd[4369]: error: maximum authentication attempts exceeded for user from 141.98.255.xxx port 50050 ssh2 [preauth]\nOct 20 15:30:36 hostname sshd[4388]: Failed password for user from 141.98.255.xxx port 50053 ssh2\nOct 20 15:30:42 hostname sshd[4388]: error: maximum authentication attempts exceeded for user from 141.98.255.xxx port 50053 ssh2 [preauth]\nOct 20 15:31:19 hostname sshd[4404]: Failed password for user from 141.98.255.xxx port 50054 ssh2\nOct 20 15:31:24 hostname sshd[4404]: error: maximum authentication attempts exceeded for user from 141.98.255.xxx port 50054 ssh2 [preauth]\n2019-10-20 15:30:13,550 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx\n2019-10-20 15:30:42,886 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx\n2019-10-20 15:31:25,628 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx', 'ipjailmatches': '2019-10-20 15:30:13,550 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx\n2019-10-20 15:30:42,886 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx\n2019-10-20 15:31:25,628 fail2ban.actions        [4308]: NOTICE  [sshd] Ban 141.98.255.xxx', 'ipfailures': 12, 'ipjailfailures': 3})': Error starting action Jail('blacklist')/blacklist

And it says that for every IP it tries to restore the ban for. This is happening from reading the logs, i guess, because the ip.blacklist file is still empty.

The chain (taken from iptables -L) looks like this:

Chain f2b-blacklist (8 references)
target     prot opt source               destination         
RETURN     all  --  anywhere             anywhere            
RETURN     all  --  anywhere             anywhere            
RETURN     all  --  anywhere             anywhere            
RETURN     all  --  anywhere             anywhere            
RETURN     all  --  anywhere             anywhere            
RETURN     all  --  anywhere             anywhere            
RETURN     all  --  anywhere             anywhere            
RETURN     all  --  anywhere             anywhere            
bkis commented 5 years ago

I removed all f2b-blacklist-related iptables rules, flushed and deleted the f2b-blacklist chain and removed the blacklist jail, rebooted. Result: Everything runs smoothly. Then I re-enabled the blacklist-jail and restarted fail2ban. Result: Same errors in logs as above :(

mitchellkrogza commented 5 years ago

Post your jail settings for [blacklist]

bkis commented 5 years ago

Thanks for your attention!
I only changed the log paths (to check 2 months) and the bantime/findtime, because the last thing I tried is to make sure it's not because of this (and no, it's not).

[DEFAULT]
port = 0:65535
filter = %(__name__)s

[blacklist]
enabled = true
logpath = /var/log/fail2ban.log
          /var/log/fail2ban.log.1
filter = blacklist
banaction = blacklist
bantime  = 4294967
findtime = 4294967
maxretry = 3

As I said, the filter works fine. Both blacklist.conf files (filter and action) are unchanged BTW. And again, thank you!

mitchellkrogza commented 5 years ago

Do you have other jails in your jail.local ???

Make sure this is not duplicated

[DEFAULT]
port = 0:65535
filter = %(__name__)s
bkis commented 5 years ago

It was, my bad. And I really hoped this is the reason for my problem, but it's not.
I cleared the iptable rules, reset the fail2ban DB and logs, corrected the jail.local, restarted fail2ban, let myself be banned by the server (using a VPN, of course), checking the fresh logs:

2019-10-30 14:09:55,919 fail2ban.filter         [4674]: INFO    [sshd] Found 187.189xxx.xxx - 2019-10-30 14:04:25
2019-10-30 14:09:55,921 fail2ban.filter         [4674]: INFO    [sshd] Found 187.189xxx.xxx - 2019-10-30 14:04:25
2019-10-30 14:09:55,923 fail2ban.filter         [4674]: INFO    [sshd] Found 187.189xxx.xxx - 2019-10-30 14:04:27
2019-10-30 14:09:56,600 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 187.189xxx.xxx
2019-10-30 14:09:56,644 fail2ban.filter         [4674]: INFO    [blacklist] Found 187.189xxx.xxx - 2019-10-30 14:09:56
2019-10-30 14:09:58,659 fail2ban.actions        [4674]: NOTICE  [sshd] Unban 187.189xxx.xxx
2019-10-30 14:11:15,642 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:11:15
2019-10-30 14:11:18,351 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:11:17
2019-10-30 14:11:24,263 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:11:23
2019-10-30 14:11:24,850 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx
2019-10-30 14:11:24,969 fail2ban.filter         [4674]: INFO    [blacklist] Found 141.98.xxx.xxx - 2019-10-30 14:11:24
2019-10-30 14:11:34,899 fail2ban.actions        [4674]: NOTICE  [sshd] Unban 141.98.xxx.xxx
2019-10-30 14:11:40,696 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:11:40
2019-10-30 14:11:42,701 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:11:42
2019-10-30 14:11:47,961 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:11:47
2019-10-30 14:11:48,145 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx
2019-10-30 14:11:48,152 fail2ban.filter         [4674]: INFO    [blacklist] Found 141.98.xxx.xxx - 2019-10-30 14:11:48
2019-10-30 14:11:58,184 fail2ban.actions        [4674]: NOTICE  [sshd] Unban 141.98.xxx.xxx
2019-10-30 14:12:02,881 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:12:02
2019-10-30 14:12:04,907 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:12:04
2019-10-30 14:12:10,818 fail2ban.filter         [4674]: INFO    [sshd] Found 141.98.xxx.xxx - 2019-10-30 14:12:10
2019-10-30 14:12:10,847 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx
2019-10-30 14:12:10,849 fail2ban.filter         [4674]: INFO    [blacklist] Found 141.98.xxx.xxx - 2019-10-30 14:12:10
2019-10-30 14:12:11,022 fail2ban.actions        [4674]: NOTICE  [blacklist] Ban 141.98.xxx.xxx
2019-10-30 14:12:11,047 fail2ban.utils          [4674]: Level 39 7fd543f83670 -- exec: iptables -N f2b-blacklist
iptables -A f2b-blacklist -j RETURN
iptables -I INPUT -p tcp -j f2b-blacklist
sort -u /etc/fail2ban/ip.blacklist -o /etc/fail2ban/ip.blacklist
cat /etc/fail2ban/ip.blacklist | while read IP; do iptables -I f2b-blacklist 1 -s $IP -j DROP; done
2019-10-30 14:12:11,049 fail2ban.utils          [4674]: ERROR   7fd543f83670 -- stderr: "Bad argument `DROP'"
2019-10-30 14:12:11,049 fail2ban.utils          [4674]: ERROR   7fd543f83670 -- stderr: "Try `iptables -h' or 'iptables --help' for more information."
2019-10-30 14:12:11,054 fail2ban.utils          [4674]: ERROR   7fd543f83670 -- returned 2
2019-10-30 14:12:11,060 fail2ban.actions        [4674]: ERROR   Failed to execute ban jail 'blacklist' action 'blacklist' info 'ActionInfo({'ip': '141.98.xxx.xxx', 'family': 'inet4', 'ip-rev': '145.255xxx.xxx.', 'ip-host': None, 'fid': '141.98.xxx.xxx', 'failures': 3, 'time': 1572441130.0, 'matches': '2019-10-30 14:11:24,850 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx\n2019-10-30 14:11:48,145 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx\n2019-10-30 14:12:10,847 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx', 'restored': 0, 'F-*': {'matches': [('', '2019-10-30 14:11:24,850', ' fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx'), '2019-10-30 14:11:48,145 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx', '2019-10-30 14:12:10,847 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx'], 'failures': 3, 'ip4': '141.98.xxx.xxx'}, 'ipmatches': 'Oct 30 14:11:17 hostname sshd[4750]: Failed password for user from 141.98.xxx.xxx port 48144 ssh2\nOct 30 14:11:23 hostname sshd[4750]: error: maximum authentication attempts exceeded for user from 141.98.xxx.xxx port 48144 ssh2 [preauth]\nOct 30 14:11:42 hostname sshd[4762]: Failed password for user from 141.98.xxx.xxx port 48152 ssh2\nOct 30 14:11:47 hostname sshd[4762]: error: maximum authentication attempts exceeded for user from 141.98.xxx.xxx port 48152 ssh2 [preauth]\n2019-10-30 14:11:24,850 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx\n2019-10-30 14:11:48,145 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx\n2019-10-30 14:12:10,847 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx\nOct 30 14:12:04 hostname sshd[4774]: Failed password for user from 141.98.xxx.xxx port 48156 ssh2\nOct 30 14:12:10 hostname sshd[4774]: error: maximum authentication attempts exceeded for user from 141.98.xxx.xxx port 48156 ssh2 [preauth]', 'ipjailmatches': '2019-10-30 14:11:24,850 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx\n2019-10-30 14:11:48,145 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx\n2019-10-30 14:12:10,847 fail2ban.actions        [4674]: NOTICE  [sshd] Ban 141.98.xxx.xxx', 'ipfailures': 12, 'ipjailfailures': 3})': Error starting action Jail('blacklist')/blacklist

This iptables error doesn't make sense to me.
Thank you for your help!

bkis commented 5 years ago

BTW adding the iptables rule manually (iptables -I f2b-blacklist 1 -s 123.123.123.123 -j DROP) works fine. It seems like $IP is not getting expanded in iptables -I f2b-blacklist 1 -s $IP -j DROP for some reason. Am I right? Oh my... wait a second! There's a whitespace char in my ip.blacklist! This is why $IP is expanded to a whitespace and it causes an error in the iptables command syntax. Let me check whether the banaction writes it there or if this is my fault...

bkis commented 5 years ago

I wish it wasn't true, but it was really just an empty line in the ip.blacklist. The script processed the line, $IP was expanded to when re-banning the blacklisted IPs at starting fail2ban, that's it.
I'm sorry I took your time for such a marginal problem. Thank you for your help, anyway!

mitchellkrogza commented 5 years ago

No worries, I've lost entire days looking for an error due to something a simple as a space. Glad its working now, enjoy.