mysql-auth doesn't ban to attacker

[jaimerletona]

Hello everyone.
I am using fail2ban 0.11.1-1 on ubuntu 20.04

I confured /etc/fail2ban/jail.local for ssh and other services like mysq-auth. ssh attacker have been blocked like expected. Mysql attackers are don't been banned although the log and fail2ban-regex matches exactly the attack log and type.

# systemctl status fail2ban.service
● fail2ban.service - Fail2Ban Service
Loaded: loaded (/lib/systemd/system/fail2ban.service; enabled; vendor preset: enabled)
Active: active (running) since Fri 2022-02-18 14:46:16 CST; 3s ago
Docs: man:fail2ban(1)
Process: 27402 ExecStartPre=/bin/mkdir -p /run/fail2ban (code=exited, status=0/SUCCESS)
Main PID: 27403 (f2b/server)
Tasks: 17 (limit: 4915)
Memory: 17.7M
CGroup: /system.slice/fail2ban.service
└─27403 /usr/bin/python3 /usr/bin/fail2ban-server -xf start

feb 18 14:46:16 DB_S systemd[1]: Starting Fail2Ban Service...
feb 18 14:46:16 DB_S systemd[1]: Started Fail2Ban Service.
feb 18 14:46:17 DB_S fail2ban-server[27403]: Server ready

/var/log/mysql/error.log
2022-02-18T19:15:17.102120Z 164639 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)
2022-02-18T19:40:27.174746Z 169562 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)
2022-02-18T19:44:25.781876Z 169955 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: NO)
2022-02-18T19:44:28.664117Z 169960 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)
2022-02-18T19:44:33.066639Z 169967 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)
2022-02-18T19:44:35.882599Z 169972 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)
2022-02-18T19:44:38.555488Z 169980 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)

(I was forced to configure mysql to log_error_verbosity = 3 to see the error log)

Extract of /etc/fail2ban/jail.local
[mysqld-auth]
enabled = true
port = 3306
#logpath = %(mysql_log)s
logpath = /var/log/mysql/error.log
backend = %(mysql_backend)s
maxretry = 3
findtime = 5d
bantime = 1d
filter = mysqld-auth

I did try test the regexp and matches, but not banned anything
Result of fail2banregex command

# fail2ban-regex --print-all-matches /var/log/mysql/error.log /etc/fail2ban/filter.d/mysqld-auth.conf
Usage: /usr/bin/fail2ban-regex [OPTIONS] [IGNOREREGEX]

fail2ban-regex: error: no such option: --print-all-matches
root@DB_S /etc/fail2ban# fail2ban-regex --print-all-matched /var/log/mysql/error.log /etc/fail2ban/filter.d/mysqld-auth.conf

Running tests

Use failregex filter file : mysqld-auth, basedir: /etc/fail2ban
Use datepattern : Default Detectors
Use log file : /var/log/mysql/error.log
Use encoding : UTF-8

Results

Failregex: 43 total
|- #) [# of hits] regular expression
| 1) [43] ^(?:[])?\s*(?:<[^.]+.[^.]+>\s+)?(?:\S+\s+)?(?:kernel:\s?[ \d+.\d+]:?\s+)?(?:@vserver_\S+\s+)?(?:(?:(?:[\d+])?:\s+[[(]?\S(?:(\S+))?[])]?:?|[[(]?\S*(?:(\S+))?[])]?:?(?:[\d+])?:?)\s+)?(?:[ID \d+ \S+]\s+)?(?:(?:\d{6}|\d{4}-\d{2}-\d{2})[ T]\s?\d{1,2}:\d{2}:\d{2} )?(?:\d+ )?[\w+] (?:[[^\]]+] )Access denied for user '[^']+'@'' (to database '[^']'|(using password: (YES|NO)))\s$
`-

Ignoreregex: 0 total

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

Lines: 52 lines, 0 ignored, 43 matched, 9 missed
[processed in 0.00 sec]

|- Matched line(s):
password: YES)
| 2022-02-18T19:44:57.789593Z 170012 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)
| 2022-02-18T19:45:01.150181Z 170015 [Note] [MY-010926] [Server] Access denied for user 'TTT'@'10.120.120.15' (using password: YES)
...
|- Missed line(s):
| 2022-02-18T18:39:46.015766Z 157239 [Warning] [MY-010055] [Server] IP address '10.120.120.15' could not be resolved: Name or service not known
| 2022-02-18T18:39:46.991594Z 157239 [Warning] [MY-013360] [Server] Plugin sha256_password reported: ''sha256_password' is deprecated and will be removed in a future release. Please use caching_sha2_password instead'
...

So, I see that everything is OK, but it doesn't work.
How can I trace or test if fail2ban is triggering the process when the log apply to the filter?
In advance, I'm thankful for any orientation.

[sebres]

What do you see in fail2ban.log for mysqld-auth?

backend = %(mysql_backend)s

this is set by your fail2ban distribution and could be wrong if it is set to systemd (since you need to monitor log-file and not a journal).
What shows fail2ban-client -d | grep "'add'.*mysqld-auth" for you?
If it is ['add', 'mysqld-auth', 'systemd'] then it is not correct.
Set backend = auto there (it would use file-related backends instead).

How can I trace or test if fail2ban is triggering the process when the log apply to the filter?

In fail2ban.log you'd see [mysqld-auth] Found 192.0.2.1 for every finding of IP 192.0.2.1 and [mysqld-auth] Ban 192.0.2.1 for a ban.
See https://github.com/fail2ban/fail2ban/wiki/How-fail2ban-works for details.

If you mean you may need more verbose logging you can try this:

# set runtime log-level to DEBUG or HEAVYDEBUG
?sudo? fail2ban-client set loglevel DEBUG
?sudo? fail2ban-client set loglevel HEAVYDEBUG

don't forget to restore log-level back to INFO hereafter:

?sudo? fail2ban-client set loglevel INFO

And last but not least - findtime = 5d is too heavy (do you really need to consider 3 attempts in 5 days?)
If you hope to find some old failures after restart, it would not work in fail2ban this way - it would ignore already processed entries (fail2ban stores last known position in log and seeks to it after restart) and it would ignore all entries older than 1 day (due to bantime = 1d, because the ban would be outdated).

[jaimerletona]

Thanks for your help, in fact I had configured wrong the backend = %(mysql_backend)s

Before:
fail2ban-client -d | grep "'add'.*mysqld-auth"
['add', 'mysqld-auth', 'systemd']

After:
fail2ban-client -d | grep "'add'.*mysqld-auth"
['add', 'mysqld-auth', 'auto']

I corrected that, and the findtime, and now works ok.
THANKS A LOT!!!