Score:2

fail2ban detects the attacker IP but doesn't ban it, and is slow reading logs

br flag

From a few days I'm receiving attacks from some IP addresses to my nginx. I have decided to use fail2ban to ban it automatically, but I have noticed that is not working very well. I can see in logs that is detecting the IP addressess, but is not banning as expected.

My jail file is:

[nginx-40x-req]
enabled  = true
bantime.rndtime = 2800
bantime.increment = true
port     = http,https
filter   = nginx-40x-req
logpath  = /var/log/nginx/access.log
maxretry = 5

and my filter looks like this:

[Definition]
failregex = ^{"status": (400|401|403), "request_time": [0-9\.]+,\s+"remote_addr": "<HOST>",

On my nginx I have added a map to detect its requests and returns 403 when detected. The the logs looks like this:

{"status": 403, "request_time": 0.000,  "remote_addr": "xx.xx.xx.xx", "@timestamp": "2021-09-03T18:32:34+02:00", "type": "nginx", "hostname": "vps-e642f340", "host": "d.itsyjd.com", "uri": "/v2/speed_test", "request": "GET https://d.itsyjd.com/v2/speed_test HTTP/1.1", "request_method": "GET", "request_proto": "http", "request_proto_proxy": "-", "request_uri": "/v2/speed_test", "request_args": "-", "server_proto": "HTTP/1.1", "body_bytes_sent": 552, "http_referer": "-", "http_user_agent": "Mozilla/5.0 (Linux; Android 8.0; MHA-AL00 Build/HUAWEIMHA-AL00; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/57.0.2987.132 MQQBrowser/6.2 TBS/044304 Mobile Safari/537.36 (compatible; Baiduspider/2.0;+http://www.baidu.com/search/spider.html)", "msec": 1630686754.923, "upstream_connect_time": -, "upstream_header_time": -, "upstream_response": -, "pipe": "p", "gzip_ratio": "-", "brotli_ratio": "-", "remote_user": "-", "bad_request": "1"}

On my fail2ban I can see a lot of messages saying that IP address was detected:

2021-09-03 18:34:31,494 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found xx.xx.xx.xx - 2021-09-03 18:29:33

But it still no banning those IP addresses.

One thing I have noticed is that fail2ban read speed is slower than log speed, so I have started to think that maybe that is the problem, because when those IP are banned and fail2ban reads at real time, then another IP addresses are banned without problem. Max_retry is 5 and all the IP addressess has been detected more than 5 times, so they must be banned.

Anyone knows what I can be doing wrong (because for sure is something that I am not seeing).

Best regards.

EDIT: After writting this message I have seen that is banning, but is working very slow. In about 15 minutes has banned about 4 IP addressess from about 11, when every second they are being detected a lot of times.

EDIT2: Clearing the log with a simple echo "" > <logfile> has triggered the bans.

My fail2ban version is 0.10.2

With the problematic attacker banned and receiving just a few requests, fail2ban is reading in real time and is banning:

2021-09-03 18:46:13,759 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:46:13
2021-09-03 18:46:13,909 fail2ban.actions        [32586]: NOTICE  [nginx-40x-req] Ban XX.XX.XX.XX
2021-09-03 18:46:18,855 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:46:18
2021-09-03 18:47:07,004 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:47:06
2021-09-03 18:48:34,390 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:48:34
2021-09-03 18:48:54,230 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:48:54
2021-09-03 18:48:54,231 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:48:54
2021-09-03 18:48:54,231 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:48:54
2021-09-03 18:48:54,335 fail2ban.actions        [32586]: NOTICE  [nginx-40x-req] Ban XX.XX.XX.XX
2021-09-03 18:50:08,488 fail2ban.filter         [32586]: INFO    [nginx-40x-req] Found XX.XX.XX.XX - 2021-09-03 18:50:08

So I still thinking that the problem maybe is the read speed.

EDIT3:

Finally I have upgraded the fail2ban version to 0.11.2, I have added a datepattern and I have changed the address detector. Now seems to read the nginx file a lot faster.

[Definition]
failregex = ^{"status": (400|401|403), "request_time": [0-9\.]+,\s+"remote_addr": "<ADDR>",
datepattern = "@timestamp": "%%Y-%%m-%%dT%%H:%%M:%%S%%z"
Michael Hampton avatar
cz flag
What version of fail2ban is this?
br flag
Hello Michael, the latest in Debian 10: 0.10.2. Now that the attacker is banned and the other attacker is doing just a few requests, seems to work. I still thinking about that the problem is the read speed.
Michael Hampton avatar
cz flag
Your log might have been too large. Are you rotating your nginx logs regularly?
br flag
The problem is that it becomes large when the attacker attacks and fail2ban is not able to read it fast enough. I have cleared the logfile several times during my tests because that is the first I have thought, so the logfile is almost empty.
br flag
One question: Fail2ban stores the detected ip addressess in memory, or it tries to read the "findtime" range in file?.
Score:2
il flag
  1. It is not advisable to monitor access-log, see fail2ban/wiki :: Best practice especially the part "Reduce parasitic log-traffic".
  2. Inappropriate regexs can also cause that fail2bans "read speed may be slower than log speed", just I don't see your RE is not good. But it can be made faster, just you'd need to change logging format for that. Also specifying of single and precise datepattern may help to speed up the processing.
  3. All in one it could create the known race condition, fail2ban was affected up to v.0.10.5, see https://github.com/fail2ban/fail2ban/issues/2660 for details (the fix was released within v.0.10.6 / v.0.11.2)

Also note the answers to similar issues, for instance https://github.com/fail2ban/fail2ban/issues/3021#issuecomment-834287295.

br flag
Thanks!, I was not able to find anything about it but the link is clear. I have updated to the latest version and I have done some changes in filter. Now seems to be faster, and also looks like the attacker has stopped.
mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.