Fail2Ban does not return IP address for new filters

Participants:
Ubuntu 20.04.3 LTS
hestiacp 1.4.14 and earlier
fail2ban 0.11.1-1
nginx 1.21.3-1~focal

Problem:
Due to another than the default port for the Hestia panel (9090) in log /usr/local/hestia/log/nginx-error.log there appeared a lot of attacks on not existed API, example:

[error] 635016#0: *61 open() "/usr/local/hestia/web/api/v1/label/__name__/values" failed (2: No such file or directory), client: 167.94.138.116, server: _, request: "GET /api/v1/label/__name__/values HTTP/1.1"

I decided to activate this file to Fail2Ban rules in this way (file jail.local)

[nginx-scan]
enabled  = true
filter   = nginx-botsearch
action   = hestia[name=HESTIA]
logpath  = /usr/local/hestia/log/nginx-error.log
findtime = 2419200
maxretry = 3

in nginx-botsearch.conf filter I added a line:

failregex = ...no..change...
            ...no..change...
            ^ \[error\] \d+#\d+: \*\d+ open\(\) .* failed \(2\: No such file or directory\), client\: <HOST>\, server\: \S*\, request\: \"GET /api.*

after this change, I tested the filter:

fail2ban-regex /usr/local/hestia/log/nginx-error.log ./filter.d/nginx-botsearch.conf

Results
=======

Failregex: 288 total
|-  #) [# of hits] regular expression
|   3) [288] ^ \[error\] \d+#\d+: \*\d+ open\(\) .* failed \(2\: No such file or directory\), client\: <HOST>\, server\: \S*\, request\: \"GET /api.*
`-

Ignoreregex: 0 total

Date template hits:
|- [# of hits] date format
|  [361] {^LN-BEG}ExYear(?P<_sep>[-/.])Month(?P=_sep)Day[T ]24hour:Minute:Second(?:[.,]Microseconds)?(?:\s*Zone offset)?

It seemed okay so I restarted Fail2Ban (service fail2ban restart)

Unfortunately, nothing happened, the fail2ban-Hestia chain remained empty, no IP address was blocked or even detected in Fail2Ban log
The log file has been correctly attached to Fail2Ban (/var/log/fail2ban.log):

fail2ban.filter [964622]: INFO Added logfile: '/usr/local/hestia/log/nginx-error.log' (pos = 109495, hash = 6fd02.....

I decided to test the action trigger and created action.d/test.conf

# Fail2Ban configuration file for test

[Definition]

actionstart = echo "start <name>" >> /etc/fail2ban/test
actionstop = echo "stop <name>" >> /etc/fail2ban/test
actioncheck = echo "check <name>" >> /etc/fail2ban/test
actionban = echo "add <name> <ip>" >> /etc/fail2ban/test
actionunban = echo "remove <name> <ip>" >> /etc/fail2ban/test

and in the file jail.local I changed the action to:

[nginx-scan]
enabled  = true
filter   = nginx-botsearch
action   = test[name=HESTIA]
logpath  = /usr/local/hestia/log/nginx-error.log
findtime = 2419200
maxretry = 3

after restart fail2ban in file /etc/fail2ban/test entries have appeared:

stop HESTIA
start HESTIA

and nothing else. I decided to check if it works at all and redirected mail filter to action test file

[exim-iptables]
enabled  = true
filter   = exim
action   = test[name=MAIL]
logpath  = /var/log/exim4/mainlog
findtime = 2419200
maxretry = 2

after reboot fail2ban contents of the /etc/fail2ban/test file looked as follows

stop HESTIA
start MAIL
start MAIL
check MAIL
add MAIL 5.188.206.203

so the exim filter returned the IP address correctly, while the nginx filter does not.

For example, I attach the NGINX filtering effect on the log file:

fail2ban-regex /usr/local/hestia/log/nginx-error.log ./filter.d/nginx-botsearch.conf --print-all-matched|awk '{print $17}'|tail -30

167.248.133.113,
167.248.133.113,
167.248.133.113,
167.248.133.113,
162.142.125.59,
162.142.125.59,
162.142.125.59,
162.142.125.59,
162.142.125.59,
162.142.125.59,
162.142.125.59,
162.142.125.59,
162.142.125.59,
162.142.125.59,
167.94.138.116,
167.94.138.116,
167.94.138.116,
167.94.138.116,
167.94.138.116,
167.94.138.116,
167.94.138.116,

As you can see, attacks from the same IP addresses appear many times and Fail2Ban is silent.
Where to look for a reason?
I took very similar activities by trying to turn on the proftpd filter - everything looked identically, the filter was working properly but Fail2Ban did not detect anything.

Maybe it is a silly question. Have you thoroughly tested the regex?

Hi. Thank you for your response, I don’t think there are silly questions here because I’ve spent a lot of time testing this problem and have no idea what else to do - every idea counts.
Do you have an idea what else could I check out of what I described above? Somewhere there is a catch - one rules correctly return the IP address and others do not return. For example - proftpd rules I did not modify in any way and so they do not work, although the filter test returns a large number of hits.

So, this is my full contents of nginx filter


# Fail2Ban filter to match web requests for selected URLs that don't exist
#

[INCLUDES]

# Load regexes for filtering
before = botsearch-common.conf

[Definition]

failregex = ^<HOST> \- \S+ \[\] \"(GET|POST|HEAD) \/<block> \S+\" 404 .+$
            ^ \[error\] \d+#\d+: \*\d+ (\S+ )?\"\S+\" (failed|is not found) \(2\: No such file or directory\), client\: <HOST>\, server\: \S*\, request: \"(GET|POST|HEAD) \/<block> \S+\"\, .*?$
# API atacks on 9090
            ^ \[error\] \d+#\d+: \*\d+ open\(\) .* failed \(2\: No such file or directory\), client\: <HOST>\, server\: \S*\, request\: \"GET /api.*

ignoreregex = 

datepattern = {^LN-BEG}%%ExY(?P<_sep>[-/.])%%m(?P=_sep)%%d[T ]%%H:%%M:%%S(?:[.,]%%f)?(?:\s*%%z)?
              ^[^\[]*\[({DATE})
              {^LN-BEG}

# DEV Notes:
# Based on apache-botsearch filter
# 
# Author: Frantisek Sumsal

As you can read above, testing this filter with fail2ban-regex returns a lot of hits.

I have read your posts very carefully and you have done it better than I would have.

It seems to be related to the filter as you explain above.

This is not a solution but maybe a debug help.

How about you create a new rule

[nginx-scan-9090]
enabled = true
filter = nginx-9090
action = hestia[name=HESTIA]
logpath = /usr/local/hestia/log/nginx-error.log
findtime = 2419200
maxretry = 3

nginx-9090.conf
failregex= ^ [error] \d+#\d+: *\d+ open() .* failed (2: No such file or directory), client: , server: \S*, request: "GET /api.*

I turned off all the other filters, leaving only the new one. However, the regex syntax seems to be incorrect, fail2ban has started but throws an error.

nginx-9090.conf:

[Definition]

failregex= ^ [error] \d+#\d+: *\d+ open() .* failed (2: No such file or directory), client: , server: \S*, request: "GET /api.*

/var/log/fail2ban.log:

fail2ban.filter         [1092922]: ERROR   No failure-id group in '^[error] \d+#\d+: *\d+ open() .* failed (2: No such file or directory), client: , server: \S*, request: "GET /api.*'

fail2ban                [1092922]: ERROR   NOK: ('No failure-id group in \'^[error] \\d+#\\d+: *\\d+ open() .* failed (2: No such file or directory), client: , server: \\S*, request: "GET /api.*\'',)

I’ll look here later because I was struck by a cold and I don’t have too clear thinking :slight_smile:
Thanx.

I thought that you were mixing results from different regexes here:

And therefore you were getting misleading results. But it is not the case…

Nevermind, you should definitely dig there.

After a longer time of observation, I can confirm that the collection of addresses works.
First of all, I changed a slight line in the filter configuration, but it was not the reason.

failregex = ^<HOST> \- \S+ \[\] \"(GET|POST|HEAD) \/<block> \S+\" 404 .+$
            ^ \[error\] \d+#\d+: \*\d+ (\S+ )?\"\S+\" (failed|is not found) \(2\: No such file or directory\), client\: <HOST>\, server\: \S*\, request: \"(GET|POST|HEAD) .*?$

The reason was the fact that fail2ban saves addresses to the SQL base:

/var/lib/fail2ban/fail2ban.sqlite3

And if some address is saved there, and the time of his ban has passed, nothing appears in the logs.
Only delete the file:

rm /var/lib/fail2ban/fail2ban.sqlite3

It showed in logs what’s really happening and then I saw a message about the duration of the ban time.

Therefore, after further testing after introducing changes, I restarted the entire ban system to read all logs again:

service fail2ban stop;rm /var/lib/fail2ban/fail2ban.sqlite3;echo -n > /var/log/fail2ban.log

By the way, I paste the command that shows in a simple way what they are in the database accumulated addresses and from which filters:

sqlite3 /var/lib/fail2ban/fail2ban.sqlite3 "select ip,jail from bips"

Another thing that should be solved is unlocking addresses by other filters added by the recidive filter.
Such a situation should not take place:

2021-09-24 03:51:10,343 fail2ban.filter         [1148615]: INFO    [recidive] Found 5.8.10.202
2021-09-24 04:21:08,649 fail2ban.actions        [1148615]: NOTICE  [ssh-iptables] Unban 5.8.10.202

considering the fact that there are the following times in the recidive filter:

[recidive]
enabled  = true 
filter   = recidive
action   = hestia[name=RECIDIVE]
logpath  = /var/log/fail2ban.log
maxretry = 3
findtime = 31622400
bantime  = 31622400

This results in the integer ineffectiveness of the recidive filter because other filters unlock IP if ban should end according to their calculations.

At the moment, I deal with this separating IP addresses to an additional file in Hestia configuration, change in the v-add-firewall-ban file

# Checking ip in banlist
conf="$HESTIA/data/firewall/banlist.conf"
perm="$HESTIA/data/firewall/banlist.perm"
for f in $conf $perm
do
check_ip=$(grep "IP='$ip' CHAIN='$chain'" $f 2>/dev/null)
if [ ! -z "$check_ip" ]; then
    exit
fi
done

# Adding ip to banlist
if [ $chain == "RECIDIVE" ];then
   echo "IP='$ip' CHAIN='$chain' TIME='$time' DATE='$date'" >> $perm
   $iptables -I fail2ban-$chain 1 -s $ip -j DROP 2>/dev/null
   else
   echo "IP='$ip' CHAIN='$chain' TIME='$time' DATE='$date'" >> $conf
   $iptables -I fail2ban-$chain 1 -s $ip -j REJECT --reject-with icmp-port-unreachable 2>/dev/null
fi

Thanks to this, an incremental permanent lock file is created:

/usr/local/hestia/data/firewall/
-rw-r--r-- 1 root root 3863 Sep 29 08:11 banlist.perm

In iptables, these addresses are added with DROP and they are not removed by other filters.
The entire file is restored when restarting services using the Command in v-add-firewall-chain

# Restoring recidive
perm="$HESTIA/data/firewall/banlist.perm"
[ -r "$perm" ] && [ $chain == RECIDIVE ] && grep RECIDIVE $perm|cut -d\' -f2|while read IPP;do $iptables -I fail2ban-$chain 1 -s $IPP -j DROP 2>/dev/null;done

Because before I figured that out I had run out of a lot of recidive addresses (they were blocked, unblocked, and so on over and over again), I wrote a short command to recreate all the addresses that managed to sneak through this way.

grep 'recidive] Unban' /var/log/fail2ban.log|while read "L";do DATE=$(echo "$L"|cut -d" " -f1);TIME=$(echo "$L"|cut -d" " -f2|cut -d, -f1);IP=$(echo "$L"|awk '{print $8}');grep -q $IP /usr/local/hestia/data/firewall/banlist.perm && continue;echo "IP='$IP' CHAIN='RECIDIVE' TIME='$TIME' DATE='$DATE'" >> /usr/local/hestia/data/firewall/banlist.perm;done

Not sure if this is related, but I had a different issue, and just got my server to start banning IP addresses by altering the parameter dbpurgeage in fail2ban.local. Its set to 1 day as default. I increased mine to 30d and started getting some matches. YMMV.