Jail for MS SQL server work very slow #2592

jabacrack · 2020-01-10T15:27:28Z

We will be very grateful, if your problem was described as completely as possible,
enclosing excerpts from logs (if possible within DEBUG mode, if no errors evident
within INFO mode), and configuration in particular of effected relevant settings
(e.g., with fail2ban-client -d | grep 'affected-jail-name' for a particular
jail troubleshooting).
Thank you in advance for the details, because such issues like "It does not work"
alone could not help to resolve anything!
Thanks! (remove this paragraph and other comments upon reading)

Environment:

Fail2Ban version (including any possible distribution suffixes): 0.10.2
OS, including release name/version: Debian stretch
Fail2Ban installed via OS/distribution mechanisms
You have not applied any additional foreign patches to the codebase
Some customizations were done to the configuration (provide details below is so)

The issue:

I have MS SQL server running in docker and somebody attempt login to it several times to second.
Example of log:

{"log":"\r2020-01-10 16:18:06.75 Logon       Error: 18456, Severity: 14, State: 8.\r\n","stream":"stdout","time":"2020-01-10T15:18:06.756263235Z"}
{"log":"\r2020-01-10 16:18:06.75 Logon       Login failed for user 'sa'. Reason: Password did not match that for the login provided. [CLIENT: 154.66.156.58]\r\n","stream":"stdout","time":"2020-01-10T15:18:06.758660413Z"}
{"log":"\r2020-01-10 16:18:06.80 Logon       Error: 18456, Severity: 14, State: 8.\r\n","stream":"stdout","time":"2020-01-10T15:18:06.805356008Z"}
{"log":"\r2020-01-10 16:18:06.80 Logon       Login failed for user 'sa'. Reason: Password did not match that for the login provided. [CLIENT: 171.251.92.165]\r\n","stream":"stdout","time":"2020-01-10T15:18:06.808154181Z"}
{"log":"\r2020-01-10 16:18:06.99 Logon       Error: 18456, Severity: 14, State: 8.\r\n","stream":"stdout","time":"2020-01-10T15:18:06.999845981Z"}
{"log":"\r2020-01-10 16:18:06.99 Logon       Login failed for user 'sa'. Reason: Password did not match that for the login provided. [CLIENT: 106.201.3.197]\r\n","stream":"stdout","time":"2020-01-10T15:18:07.003073832Z"}
{"log":"\r2020-01-10 16:18:07.14 Logon       Error: 18456, Severity: 14, State: 8.\r\n","stream":"stdout","time":"2020-01-10T15:18:07.145766903Z"}
{"log":"\r2020-01-10 16:18:07.14 Logon       Login failed for user 'sa'. Reason: Password did not match that for the login provided. [CLIENT: 154.66.156.58]\r\n","stream":"stdout","time":"2020-01-10T15:18:07.14870471Z"}
{"log":"\r2020-01-10 16:18:07.18 Logon       Error: 18456, Severity: 14, State: 8.\r\n","stream":"stdout","time":"2020-01-10T15:18:07.18241051Z"}
{"log":"\r2020-01-10 16:18:07.18 Logon       Login failed for user 'sa'. Reason: Password did not match that for the login provided. [CLIENT: 175.112.113.182]\r\n","stream":"stdout","time":"2020-01-10T15:18:07.184938832Z"}

I write custom jail but it work very slow. For one day it detect ~ 200 failure logins, and do only 3 bans. But When I look at log I see 3 or more connect attempts from same ip in 1 minute.
This is problem in my poor regex or other settings?

My Jail

['add', 'mssql-auth', 'auto']
['set', 'mssql-auth', 'prefregex', '^\\{"log":"\\\\r<F-CONTENT>.+</F-CONTENT>\\}$']
['set', 'mssql-auth', 'addfailregex', 'Login failed for user .* \\[CLIENT: <ADDR>\\]']
['set', 'mssql-auth', 'maxretry', 3]
['set', 'mssql-auth', 'findtime', '10m']
['set', 'mssql-auth', 'usedns', 'warn']
['set', 'mssql-auth', 'ignorecommand', '']
['set', 'mssql-auth', 'logencoding', 'auto']
['set', 'mssql-auth', 'bantime', '10m']
['set', 'mssql-auth', 'addlogpath', '/var/lib/docker/containers/ece2af73a3077746a97945224e33974e2783167747451aa3f6f985ed98bbe9f0/ece2af73a3077746a97945224e33974e2783167747451aa3f6f985ed98bbe9f0-json.log', 'head']
['set', 'mssql-auth', 'addaction', 'iptables-allports']
['multi-set', 'mssql-auth', 'action', 'iptables-allports', [['actionstop', '<iptables> -D INPUT -p tcp -j f2b-mssql-auth\n<iptables> -F f2b-mssql-auth\n<iptables> -X f2b-mssql-auth'], ['actioncheck', "<iptables> -n -L INPUT | grep -q 'f2b-mssql-auth[ \\t]'"], ['actionstart', '<iptables> -N f2b-mssql-auth\n<iptables> -A f2b-mssql-auth -j RETURN\n<iptables> -I INPUT -p tcp -j f2b-mssql-auth'], ['actionunban', '<iptables> -D f2b-mssql-auth -s <ip> -j <blocktype>'], ['actionban', '<iptables> -I f2b-mssql-auth 1 -s <ip> -j <blocktype>'], ['actionflush', '<iptables> -F f2b-mssql-auth'], ['iptables', 'iptables <lockingopt>'], ['blocktype?family=inet6', 'REJECT --reject-with icmp6-port-unreachable'], ['blocktype', 'REJECT --reject-with icmp-port-unreachable'], ['protocol', 'tcp'], ['chain', 'INPUT'], ['iptables?family=inet6', 'ip6tables <lockingopt>'], ['port', 'ssh'], ['lockingopt', '-w'], ['actname', 'iptables-allports'], ['name', 'mssql-auth'], ['returntype', 'RETURN']]]
['start', 'mssql-auth']

The text was updated successfully, but these errors were encountered:

sebres · 2020-01-10T17:03:38Z

For one day it detect ~ 200 failure logins, and do only 3 bans.
But When I look at log I see 3 or more connect attempts from same ip in 1 minute.

Either you have an issue with banning action - something (docker? or wrong config) prevents f2b (iptables) to ban it properly.
In this case you'll see a lot of [mssql-auth] 192.0.2.1 already banned in fail2ban.log, which are possible in normal case also (due to some latency between last recognized failure >= maxretry and real ban), but rather very rare and generally not later as pair seconds after first message [mssql-auth] Ban 192.0.2.1 for this IP.

See our wiki for more info.

This is problem in my poor regex...

Well it is indeed "not optimal" because isn't anchored (anchors of prefreex are valid only for itself, and don't affects on search of failregex match). Furthermore there is a catch-all in the middle.
Also note that prefregex makes sense only if you have more as one failregex with same/similar common prefix (or suffix) but for your case (exactly one regex) it is more disturbing either.
Also because the date is not at begin, a search for non-anchored datepattern would be used here, so it is advisable to provide your own (anchored) pattern.

Try something like this:

[Definition]
# matches and cuts out `{"log":"\r2020-01-10 16:18:06.75`:
datepattern = ^\{"log":"\\r%%Y-%%m-%%d %%H:%%M:%%S\.%%f+\s+
# matches `Logon  Login failed for user 'sa'. ... [CLIENT: 192.0.2.1] ...`:
failregex = ^Logon\s+Login failed for user '<F-USER>[^']*</F-USER>'. [^\[]+ \[CLIENT: <ADDR>\]

This filter is at least 10-20 times faster.

somebody attempt login to it several times to second

Several? It looks like a DoS :) I'm kidding, but it looks approximately up to 20 times per second.
If your filter is not optimal, it can bother banning (due to GIL in python, it's not really multi-threaded).
Also note similar issue Problem with unban on high volume ban lists #2410, if I can imagine your jail could be affected by this race condition (just delaying ban phase). This was fixed in 809acb6 (and fresh released with 0.10.5).
You can try this version if 1. and 2. don't solve it for you.

Also it is interesting how the fail2ban.log does look, e. g. how messages [mssql-auth] Found 192.0.2.1 and [mssql-auth] Ban 192.0.2.1 are distributed via this log.
To analyse this, it would be really good, if you could provide a fail2ban.log excerpt containing 3 Found and 1 Ban, together with a log excerpt of sql-server containing the same time interval as excerpt above.

jabacrack · 2020-01-10T19:03:32Z

Thank you!
Problem was in regex, now it work faster. It was not obvious to me that datepattern can contain regex, not just a date format.
But there is different problem:
fail2ban log say:

2020-01-10 20:01:10,523 fail2ban.actions        [14336]: WARNING [mssql-auth] 189.203.187.219 already banned

in iptables there is rule:

-A f2b-mssql-auth -s 189.203.187.219/32 -j REJECT --reject-with icmp-port-unreachable

And in same time I see in ms sql log:

{"log":"\r2020-01-10 20:02:55.76 Logon       Login failed for user 'sa'. Reason: Password did not match that for the login provided. [CLIENT: 189.203.187.219]\r\n","stream":"stdout","time":"2020-01-10T19:02:55.771080179Z"}

sebres · 2020-01-10T20:30:41Z

OK, your banning action (iptables-allports) or even netfilter subsystem seems to be "broken" for some reason:

check a rule with -j f2b-mssql-auth belong to the INPUT chain and there are no some whitelisting rules before f2b-rules (see Fail2ban says already banned an ip but the ip can still visit webserver #2545 (comment) describing similar thing).
So check attentive the output of iptables -nL INPUT in order to find some allowing chain or rule.
For example if sql-server does not close a connection by auth-error, and your iptables have somewhere a rule allowing established connections or your docker is proxying it this way (I don't know, but..), then the intruder would try it again and again unless connection gets closed at some point (and fail2ban or even your iptables action would be unable to ban it).
check it is active at all in the kernel and it is your primary netfilter subsystem (e. g. not a nftables or some other).
anyway be sure your firewall (netfilter) basically work. fail2ban can do nothing if the kernel subsystem or module does not work at all.

jabacrack · 2020-01-10T21:37:20Z

Ok, I'm not familiar with iptables, but looks like there no any additional rules in input

Chain INPUT (policy ACCEPT 812 packets, 4375K bytes)
 pkts bytes target     prot opt in     out     source               destination
29200   59M f2b-mssql-auth  tcp  --  *      *       0.0.0.0/0            0.0.0.0/0
14065 1460K f2b-sshd   tcp  --  *      *       0.0.0.0/0            0.0.0.0/0            multiport dports 22

Chain FORWARD (policy DROP 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
4907K  386M DOCKER-USER  all  --  *      *       0.0.0.0/0            0.0.0.0/0
4907K  386M DOCKER-ISOLATION-STAGE-1  all  --  *      *       0.0.0.0/0            0.0.0.0/0
2067K  193M ACCEPT     all  --  *      docker0  0.0.0.0/0            0.0.0.0/0            ctstate RELATED,ESTABLISHED
 553K   28M DOCKER     all  --  *      docker0  0.0.0.0/0            0.0.0.0/0
2286K  164M ACCEPT     all  --  docker0 !docker0  0.0.0.0/0            0.0.0.0/0
    0     0 ACCEPT     all  --  docker0 docker0  0.0.0.0/0            0.0.0.0/0

Chain OUTPUT (policy ACCEPT 894 packets, 3245K bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain DOCKER (1 references)
 pkts bytes target     prot opt in     out     source               destination
 553K   28M ACCEPT     tcp  --  !docker0 docker0  0.0.0.0/0            172.17.0.2           tcp dpt:1433

Chain DOCKER-ISOLATION-STAGE-1 (1 references)
 pkts bytes target     prot opt in     out     source               destination
2286K  164M DOCKER-ISOLATION-STAGE-2  all  --  docker0 !docker0  0.0.0.0/0            0.0.0.0/0
4907K  386M RETURN     all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain DOCKER-ISOLATION-STAGE-2 (1 references)
 pkts bytes target     prot opt in     out     source               destination
    0     0 DROP       all  --  *      docker0  0.0.0.0/0            0.0.0.0/0
2286K  164M RETURN     all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain DOCKER-USER (1 references)
 pkts bytes target     prot opt in     out     source               destination
 323M   26G RETURN     all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain f2b-mssql-auth (1 references)
 pkts bytes target     prot opt in     out     source               destination
    0     0 REJECT     all  --  *      *       199.192.80.10        0.0.0.0/0            reject-with icmp-port-unreachable
29199   59M RETURN     all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain f2b-sshd (1 references)
 pkts bytes target     prot opt in     out     source               destination
   16  1280 REJECT     all  --  *      *       206.189.165.94       0.0.0.0/0            reject-with icmp-port-unreachable
   18  1448 REJECT     all  --  *      *       117.50.13.170        0.0.0.0/0            reject-with icmp-port-unreachable
    0     0 REJECT     all  --  *      *       151.80.42.234        0.0.0.0/0            reject-with icmp-port-unreachable
   21  1668 REJECT     all  --  *      *       51.75.37.173         0.0.0.0/0            reject-with icmp-port-unreachable
   21  1644 REJECT     all  --  *      *       213.5.229.21         0.0.0.0/0            reject-with icmp-port-unreachable
   19  1500 REJECT     all  --  *      *       179.185.104.250      0.0.0.0/0            reject-with icmp-port-unreachable
   22  1740 REJECT     all  --  *      *       195.154.134.155      0.0.0.0/0            reject-with icmp-port-unreachable
    9   468 REJECT     all  --  *      *       152.32.72.122        0.0.0.0/0            reject-with icmp-port-unreachable
   23  1756 REJECT     all  --  *      *       51.255.162.65        0.0.0.0/0            reject-with icmp-port-unreachable
    1    60 REJECT     all  --  *      *       41.223.142.211       0.0.0.0/0            reject-with icmp-port-unreachable
   22  1688 REJECT     all  --  *      *       60.250.149.19        0.0.0.0/0            reject-with icmp-port-unreachable
    1    60 REJECT     all  --  *      *       178.62.37.78         0.0.0.0/0            reject-with icmp-port-unreachable
   23  1832 REJECT     all  --  *      *       49.233.75.234        0.0.0.0/0            reject-with icmp-port-unreachable
   24  2136 REJECT     all  --  *      *       158.69.243.190       0.0.0.0/0            reject-with icmp-port-unreachable
   23  1788 REJECT     all  --  *      *       138.197.5.191        0.0.0.0/0            reject-with icmp-port-unreachable
   20  1512 REJECT     all  --  *      *       150.223.17.130       0.0.0.0/0            reject-with icmp-port-unreachable
   33  2392 REJECT     all  --  *      *       218.92.0.203         0.0.0.0/0            reject-with icmp-port-unreachable
   20  1516 REJECT     all  --  *      *       175.197.233.197      0.0.0.0/0            reject-with icmp-port-unreachable
    2   120 REJECT     all  --  *      *       24.185.97.170        0.0.0.0/0            reject-with icmp-port-unreachable
   22  1724 REJECT     all  --  *      *       36.41.174.139        0.0.0.0/0            reject-with icmp-port-unreachable
   23  1784 REJECT     all  --  *      *       94.191.28.110        0.0.0.0/0            reject-with icmp-port-unreachable
   20  1512 REJECT     all  --  *      *       118.24.200.40        0.0.0.0/0            reject-with icmp-port-unreachable
10138 1164K RETURN     all  --  *      *       0.0.0.0/0            0.0.0.0/0

Alive connection - possible situation, thank you for idea.

Again thank you for your help.

sebres · 2020-01-10T22:11:38Z

Hmm looks not bad, but I don't know how prerouting or else routing decision is organized on your system, so which precedence is used for the packets to sql-server:

INPUT chain (before FORWARD chain) - then it's correct;
FORWARD (sole or before INPUT chain) - then it's wrong: f2b-rules will be ignored and packets going directly to docker;

See https://stackoverflow.com/questions/12945233/iptables-forward-and-input for similar question.

jabacrack · 2020-01-11T12:14:51Z

There is what I have. If I right understand first go DOCKER chain, that allow connections to port 1433 (MS SQL) and this go before reject from fail2ban?

root@Debian-99-stretch-64-minimal:~# iptables -L -n -t nat
Chain PREROUTING (policy ACCEPT)
target     prot opt source               destination
DOCKER     all  --  0.0.0.0/0            0.0.0.0/0            ADDRTYPE match dst-type LOCAL

Chain INPUT (policy ACCEPT)
target     prot opt source               destination

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination
DOCKER     all  --  0.0.0.0/0           !127.0.0.0/8          ADDRTYPE match dst-type LOCAL

Chain POSTROUTING (policy ACCEPT)
target     prot opt source               destination
MASQUERADE  all  --  172.17.0.0/16        0.0.0.0/0
MASQUERADE  tcp  --  172.17.0.2           172.17.0.2           tcp dpt:1433

Chain DOCKER (2 references)
target     prot opt source               destination
RETURN     all  --  0.0.0.0/0            0.0.0.0/0
DNAT       tcp  --  0.0.0.0/0            0.0.0.0/0            tcp dpt:1433 to:172.17.0.2:1433

sebres · 2020-01-11T14:44:03Z

One doesn't see the interface (NIC) in the rules, but DOCKER looks a bit strange (if both rules affecting same device): RETURN will bypass second rule (DNAT) in this case.
But it looks like PREROUTING would jump to the DOCKER for local addresses only.

If we can be sure the jail monitoring only one instance of docker with sql-server (listener of sql-server is accessible in single docker only), I would try to use either DOCKER-USER or FORWARD chain instead of INPUT, :

[mssql-auth]
# banaction = %(known/banaction)s[chain='DOCKER-USER']
banaction = %(known/banaction_allports)s[chain='DOCKER-USER']

But it were better to "repair" the routing (or insert some special fail2ban chain affecting both interfaces at same time).
Although PREROUTING would be also a candidate for that, but it'd be too heavy in my opinion.

Also note #2511, which provide some piece of documentation.
(@cljk Did you not want to extend the wiki with some docker documentation, Marcel? ;)

I does not use docker on host directly connected to the internet (only outside of internet, behind the intranet), so I can marginally help you here.

Additionally.

read docker documentation - e. g. https://docs.docker.com/network/iptables/
try to seek for help by SF (serverfault) or google;
or try to TRACE it by yourself:

# replace ... with some additional parameters (like dport) to filter mssql packets only:
iptables -t raw -A PREROUTING ... -j TRACE

The TRACE target marks packets so that the kernel will log every rule which match the packets as those traverse the tables, chains, rules.
Use tail -f /var/log/kern.log | grep 'TRACE:' to see it in shell.
Don't forget to delete this rule hereafter!

or try some special docker configs (google again) or even https://github.com/crazy-max/docker-fail2ban

Anyway it looks like a 3rd party issue, thus closed.

sebres closed this as completed Jan 11, 2020

sebres added 3rd party issue how-to labels Jan 11, 2020

4Syno mentioned this issue Nov 24, 2020

Help needed with fail2ban-regex guacamole docker logs #2879

Closed

3 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Jail for MS SQL server work very slow #2592

Jail for MS SQL server work very slow #2592

jabacrack commented Jan 10, 2020 •

edited by sebres

sebres commented Jan 10, 2020 •

edited

jabacrack commented Jan 10, 2020 •

edited by sebres

sebres commented Jan 10, 2020

jabacrack commented Jan 10, 2020 •

edited

sebres commented Jan 10, 2020

jabacrack commented Jan 11, 2020

sebres commented Jan 11, 2020

Jail for MS SQL server work very slow #2592

Jail for MS SQL server work very slow #2592

Comments

jabacrack commented Jan 10, 2020 • edited by sebres

Environment:

The issue:

My Jail

sebres commented Jan 10, 2020 • edited

jabacrack commented Jan 10, 2020 • edited by sebres

sebres commented Jan 10, 2020

jabacrack commented Jan 10, 2020 • edited

sebres commented Jan 10, 2020

jabacrack commented Jan 11, 2020

sebres commented Jan 11, 2020

jabacrack commented Jan 10, 2020 •

edited by sebres

sebres commented Jan 10, 2020 •

edited

jabacrack commented Jan 10, 2020 •

edited by sebres

jabacrack commented Jan 10, 2020 •

edited