Timing causing ban to fail? #2332
Comments
|
Neither mod_evasive tell me something, nor I understand what you trying to describe resp. what issue is exactly (e. g. which filter/jail is used and what exactly does not work). As for the subject "Timing causing ban to fail", you should read wiki :: How fail2ban works where it is pretty good described. Shortly, the combination Closed until more info provided. |
|
I completely understand what he's trying to report to you. I have experienced this issue dozens of times, but I do not know how to explain it properly. That is why I understand it: Fail2Ban is working. It is banning IPs. But sometimes, items are added to log files faster than Fail2Ban can process them. Usually fail2an takes action after 'maxretry' times, but sometimes the IP address is attacking you so often, Fail2Ban never gets time to actually take any action. It can happen with any jail and any filter. If I have maxretry=1 then I will expect my log to show something like: I do not know how Fail2Ban performs its magic. But I think probably something like this happens:
But sometimes something odd happens 🔽. I'm making up the times; they are there as an example. The key thing to understand is that the log entries are being added in real time - my system clock shows that it's 10:32:39. This is not a set of log entries that happened earlier. 2019-02-05 10:32:38,935 fail2ban.filter [4547]: INFO [crawlers] Found 34.73.237.101 - 2019-02-05 10:32:39 I think I know the reason for this. In the example above, the notifying system says "hey please look at crawlers.log" So, because this single IP address is generating a log item several times a second, Fail2Ban thinks it is still checking through the log file at the request of the original notifying task. At 10:32:39, the notifier said "crawlers.log has been modified - please check it" While Fail2Ban is noting down these changes, further entries are being added. Fail2Ban thinks these additions are from the original task that ran - the "crawlers.log has been modified" notifier. Fail2Ban continues to add these to the queue of actions to take. Even though maxretry=1 for this jail, the reason this IP address is not banned is because Fail2Ban isn't even reaching the "action" stage. It still keeps monitoring the log file because it thinks these are part of the initial task that ran at 10:32:39 The system is working exactly as it was designed to work. But sometimes there is this odd condition where a repeated attack doesn't lead to an immediate ban, because Fail2Ban never reaches the end of the "monitor the current changes" task. I've never reported this because - as I hope is clear now - it is hard to even explain the problem, let alone give you steps you can use to reproduce it. I don't think it's a bug - I think it's a design choice :-) I hope this makes sense. As soon as I read the email I know exactly what he was talking about. It's a real issue :-) In case you're wondering why have not attached any real logs of this issue, it's because I stopped looking for them because I don't know how to describe the issue :-) |
|
So your assumption is fail2ban filter finds failures "endless" and therefore never gets time to notify fail-manager (and hereafter ban-manager) about new tickets (and bans). If so, then it should be obsolete in my opinion (I made several preventive measures to avoid this). If exactly this situation is still occurred with 0.10 or 0.11, please provide which backend is used. BTW, I don't think @codeFarmerJ mean exactly this, because in the log excerpt some intervals between failures are second long... (with other words 5-6 failures per second is nothing for jails normally, at least for fail2ban >= v.0.10). Furthermore note that if you have some unsafe The solution here may be:
|
|
|
Thank you. I am away from home for a few days so I need some time to gather the information you've asked for when I get back. If I have misunderstood the original issue, do you want me to open a new issue once I am back home and have the information? |
|
Sure. |
|
I probably should not have said the ban fails. In a few cases the ban is so slow as to be ineffective. I have no evidence that fail2ban is not operating properly. 95% of the time it executes the ban in a timely manner. But there are now a few cases where a huge number of hits get through to my Apache server. I assume this blast must be doing something different, but what? Could it somehow be slowing my machine so that the log file cannot be read timely? This appears to me be a scripted attack which I began experiencing near the end of Oct 2018 (from looking at my log file history). I can provide a large number of log files, but doubt they will add clarity. I'm including my filter and jail which I've used for many years, so doubt that will explain this new challenge. I've noticed that many of these attacks begin with a valid request which returns 200: before the ensuing 100-400 invalid 404 requests. Is this a clue? Filter: [Definition]
failregex = ^<HOST> -.*GET.* 40[0-9] .
^<HOST> -.*POST.* 40[0-9] .
^<HOST> -.*HEAD.* 40[0-9] .
ignoreregex = ^.*favicon\.ico .Local Jail section: [apache-404-vhosts]
enabled = true
port = http,https
filter = apache-404
logpath = /var/log/apache2/other_vhosts_access.log
maxretry = 1 |
|
In the last week I have had 56 successful bans, and 1 that was not. |
I was assuming the attack was successful because it was so fast. In my attempt to slow it down I configured Apache mod-evasive, which introduces a pause from too many hits too quickly. I believe this is working correctly because I often experience it myself. However it has not stopped the attacks. |
|
Still again which fail2ban version it is?
So you has intentionally slowing down the logging of such requests too. What do you expect then? Now to your filter... As I wrote above some regex (developed by someone from the internet, but some of stock-fail2ban too) are worse and extremely vulnerable (at least as regards the performance). And it is definitely the case here too. failregex = ^<HOST>\s+\S+\s+\S+\s+(?:\[\])?\s*"(?:GET|POST|HEAD)\s\S+\s[A-Z]+/\d+.\d+" 40\d
# _ignore_uri = favicon\.ico|robot\.txt
_ignore_uri = favicon\.ico
ignoreregex = ^<HOST>\s+\S+\s+\S+\s+(?:\[\])?\s*"[A-Z]+\s\S*/(?:%(_ignore_url)s)\s[A-Z]+/\d+.\d+"Please note that fail2ban is as fast as your filter is, so each additional possibly not optimal regex (or ignore) will slow it down. Especially if you have large parasite log "traffic" that does not match (e. g. all 200 requests etc), because fail2ban tries each failregex for each line. Also note that fail2ban (alone) is not really a tool to protect you from DDOS-similar attacks (especially if it is wrong configured). You can use it in combination with other prevention tools, but sometimes also special measures are necessary (like special filter, shorting of log-messages/format with special logger, progressive rate limiting, etc). |
|
Sergey - First thank you for taking the time and effort for trying to understand and help me resolve this problem. I do appreciated it. Also I realize that I have used fail2ban for many years and not contributed. I have just now corrected that situation with a donation. I found that I had been using ver. 0.8.6. It had worked well for me for so long, I didn't realize how old it was. I have now updated to the stable ver. 0.9.4 Maybe this alone will fix my problem? My logic was that if the hits to my server were coming too fast, maybe fail2ban could not keep up with them. So, yes, my goal was to slow down the rapid fire hits so that fail2ban could have time to read the logs. Why is this poor reasoning? I will update my filter as you recommend. Can you help understand why your regex is superior? Mine is certainly easier to read . What would I use to "pre-filter" my log? I'm not sure I know how to do this. I don't think I have experienced a DDoS attack, but would guess that the request hits are all very similar, which is not my case. I think my logs show more of an attempt to probe my server for weakness. Again thank you for your time & help. |
Thank you! (it is not under my control, so I cannot see this), but it is really exemplary action.
I don't think so (this version is also too old). Fail2ban >= 0.10 would be your friend (or still better 0.11 with progressive ban time increment) in order to solve all the performance issues.
It is not at all. Just because I don't know how exactly it works, I can imagine many situations caused with delayed logging, for example: Click here for details
* no ban, because time between Found 1 and Found 5 exceeds As already said I don't know it, so... So I just intended recommend you to check this is really affected and to correct/change it in the configuration - for example if mod_evasive could write separate log-file which summarized all intruder attempts - this log (instead of the access-log) would be a right candidate for monitoring via fail2ban.
Firstly think about the log you observing is an access log, so it has many "parasite" log-messages in sense of fail2ban (all success entries with 20x-30x codes for example).
$ msg='IP - this is example string 1 with GET and 401 but somewhere at end it has still one 409 so it will be found';
$ python -c "import re; print(re.search('^\w+ -.*GET.* (40[0-9]) .', '$msg').groups())"
('409',)
All that glitters is not gold, at least not in case of regex. RE-engine is finite automaton and doing basically not "just take a look for some string" (also if it easy and you could read a "simple" RE this way).
- 103.100.60.15 - - [01/Jan/2019:05:01:58 -1000] "POST /m.php?pbid=open HTTP/1.1" 404 522 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.139 Safari/537.36" myserver.net:80
+ [01/Jan/2019:05:01:58 -1000] 103.100.60.15 404 "POST /m.php?pbid=open HTTP/1.1" 522
Anyway for multiple |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Rather than create a new thread, I thought to continue this one so the discussion is all in one place. I have been seeing exactly this problem for some time. The fail2ban version is 11.2, on a Centos 7 system. The block method is firewalld, which is working; I have verified that many times. fail2ban-0.11.2-3.el7.noarch As an example, yesterday there were a series of 17 accesses to varients of the following URL that took place over 17 seconds, all from the same ip, between 23:39:40 and 23:39:57. The variants were different paths between /path/.../wp-includes/. GET /path/wp-includes/wlwmanifest.xml The filter regex is this, to match the wp-includes component. failregex = (?i)^.(GET|POST|HEAD) [^"]?/wp-(config|content|includes|login) The fail2ban.log entries are below. According to the log the ip was immediately banned, but additional accesses continued over the next 17 seconds. The accesses were not all at once, so a delay due to server loading do not seem plausible. I see this delay quite often with accesses to similar URLs including wp-include, often trying to find wlwmanifest.xml. What could explain the delay in the ban actually activating? Thanks.... 2022-01-25 23:39:40,979 fail2ban.filter [8516]: INFO [bots] Found 13.234.110.168 - 2022-01-25 23:39:40 |
|
Already answered in #3209 (as already said it looks like not working action, so this has nothing to do with this issue). |
I've been successfully using fail2ban for years on my Debian 7 Apache server to screen out all 404's. Most commonly the block takes effect after the first 404 hit. Some are slower with multiple 404s in the first 4-6 seconds. But in the last few months, my log records 100 or more hits before the IP block takes effect. Or maybe it never takes effect? Is something holding my log file open so it can't be read? Or what is going on? TIA
I did add mod_evasive (which delays multiple hits from the same source) to my apache server and it seems to be working (except in this case). Most 404 are still being caught quickly, but a few are not and I can't figure out why.
334 lines with GET or POST - all returning 404
sample log:
The text was updated successfully, but these errors were encountered: