Delays between matching a filter and the block taking effect #3209
-
|
This is related to the closed discussion here: #2332 I have been seeing exactly this problem for some time. The fail2ban version is 11.2, installed from EPEL, fail2ban-0.11.2-3.el7.noarch, on a Centos 7 system. The block method is firewalld, which is working. The problem I am seeing in some cases is that an access is found by a filter and logs as immediately banned, but then successive accesses from the same ip are not blocked for a number of seconds. As an example, on the 25th there were 18 accesses to variants of this URL, “GET /path/wp-includes/wlwmanifest.xml”, that happened over about 18 seconds, all from the same ip, between 23:21:43 and 23:21:57. The variants were different paths between /path/.../wp-includes/. 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 18 seconds. I see this delay quite often with accesses to similar URLs that include 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 |
Beta Was this translation helpful? Give feedback.
Replies: 6 comments 1 reply
-
This doesn't look like a delayed ban. Moreover this is looking like a not working ban mechanism (for instance inappropriate or not working banaction). |
Beta Was this translation helpful? Give feedback.
-
|
Thanks for the response. I know it looks like the ban is not working, but it actually is. Looking at the fail2ban.log just now, the most recent three blocks for this jail were on ip 18.217.52.242, 103.217.111.144, and 3.238.185.226. All are listed in iptables; see below. Since the jail is working and blocking addresses, what additional information might be useful? The jail itself does not seem to be the problem. I will increase debug logging to see if more useful information is captured. I will try to gain more information about the accesses in which the actual block is delayed, as I originally posted. They usually come during the night, and trying to capture them at that moment is a matter of some luck. Again, thanks for your response. Did ban: 2022-01-27 12:50:39,856 fail2ban.filter [8516]: INFO [bots] Found 18.217.52.242 - 2022-01-27 12:50:39 2022-01-27 13:24:46,018 fail2ban.filter [8516]: INFO [bots] Found 103.217.111.144 - 2022-01-27 13:24:44 2022-01-27 13:47:50,586 fail2ban.filter [8516]: INFO [bots] Found 3.238.185.226 - 2022-01-27 13:47:50 2022-01-27 13:47:51,385 fail2ban.actions [8516]: NOTICE [gandy-bots] Ban 3.238.185.226 date iptables -L -n | grep 18.217.52.242 iptables -L -n | grep 103.217.111.144 date iptables -L -n | grep 3.238.185.226 The bots jails is below. [bots] |
Beta Was this translation helpful? Give feedback.
-
|
I'll try to explain why the ban doesn't work: As you can see the ban take place at 23:39:41, and first |
Beta Was this translation helpful? Give feedback.
-
|
Hello again, Thanks for the response. I am still working through your explanation of why the ban is not happening. I have noticed the delayed block even when manually testing a new regex. I access the test URL in a browser, and I immediately see the ban notice in the fail2ban log, but sometimes I can access the page again with forced refresh and access it once or twice before the block actually takes effect. I don’t know how firewalld works internally, but I have wondered if the delay is in firewalld, that there may be a delay between when a ban rule is added and when it actually takes effect. This seems more plausible than a delay in fail2ban actually issuing the ban rule. I found an instance a couple of days ago of a delayed block after numerous accesses. I saw it about 12–13 minutes aftr it happened, and iptables showed the ip as banned. I included the debug output for that ip in the log lines below, and I’ve grouped the log lines by time to make them easier to parse. The date and iptables output are given first to make them easier to see, although I ran them after finding the series of access from 68.183.226.92. date iptables -L -n | grep 68.183.226.92 2022-01-27 22:48:15,216 fail2ban.filter [8516]: DEBUG Processing line with time:1643345294 and ip:68.183.226.92 2022-01-27 22:48:16,067 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:15 2022-01-27 22:48:17,590 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:17 2022-01-27 22:48:18,448 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:17 2022-01-27 22:48:19,300 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:18 2022-01-27 22:48:20,186 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:19 2022-01-27 22:48:21,045 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:20 2022-01-27 22:48:21,918 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:21 2022-01-27 22:48:22,809 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:22 2022-01-27 22:48:23,667 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:23 2022-01-27 22:48:24,535 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:24 2022-01-27 22:48:25,403 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:24 2022-01-27 22:48:26,296 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:25 2022-01-27 22:48:27,161 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:26 2022-01-27 22:48:28,011 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:27 2022-01-27 22:48:28,940 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:28 2022-01-27 22:48:29,819 fail2ban.filter [8516]: INFO [bots] Found 68.183.226.92 - 2022-01-27 22:48:29 |
Beta Was this translation helpful? Give feedback.
-
|
Hello again, Looking into firewalld, I have a theory that might explain what I am seeing with the delay in the ban taking effect. If a bot sends multiple requests over a single connection, as long as the “--ctstate RELATED,ESTABLISHED,DNAT” rule takes precedence, adding a direct ban rule will have no effect on that established connection. This would explain why the ban does work, but sometimes I see multple successive accesses from the same ip over a 10–20 second span. iptables -L INPUT shows the 'ACCEPT ... ctstate RELATED,ESTABLISHED' rule as the first. The firewalld action ban rules are the standard ones in fail2ban. The point here is that it comes after the established connection pass. firewall-cmd --direct --add-rule <family> filter f2b-<name> 0 -s <ip> -j <blocktype> I have found some discussion of this that suggest different block rules. https://serverfault.com/questions/1054749/firewalld-insert-rule-before-established The second one recommends simple and complex options: firewall-cmd --zone=drop --remove-source=192.168.1.xx (I think it should be --add-source). firewall-cmd --direct --add-rule ipv4 mangle INPUT 0 -p tcp --dport 443 -s 192.168.1.xx -j DROP All of the systems I have using fail2ban are production systems, so I must be careful in changing the firewall rules. Do you have a recommendation which one to use, or perhaps another way of preceeding the ESTABLISHED rule? Thanks.... |
Beta Was this translation helpful? Give feedback.
-
|
Studying the firewalld options I think these could work as ban and unban commands to add the block prior to the ESTABLISHED input rule. Do you see any negative aspects to these commands? There may be other effects of these that I am missing. If these were adopted the start and stop actions would need to be altered to not create the various f2b-<name> chains, as they are no longer needed. This loses the granularity of having rules in different chains, but it places them prior to the ESTABLISHED rule that takes priority in the INPUT filter rules. I think that would block the repeated accesses I am seeing, due I think to them being issued over the same tcp connection. Because of the sed, I assume the ports are passed in either as a single number or a colon separated range, such as ‘80:443’. actionban = firewall-cmd --direct --add-rule ipv4 mangle INPUT 0 -p tcp --dport <port>' -s <ip> -j DROP actionunban = firewall-cmd --direct --remove-rule ipv4 mangle INPUT 0 -p tcp --dport <port>' -s <ip> -j DROP I ran these commands on a Rocky 8 system and they worked. # firewall-cmd --direct --add-rule ipv4 mangle INPUT 0 -p tcp --dport 80:443 -s 68.183.226.92 -j DROP # firewall-cmd --direct --get-rules ipv4 mangle INPUT # firewall-cmd --direct --remove-rule ipv4 mangle INPUT 0 -p tcp --dport 80:443 -s 68.183.226.92 -j DROP |
Beta Was this translation helpful? Give feedback.
-
|
Well, I have told you... :) I always wondering that people add some rules before the INPUT chain (directly or by usage of firewalld/uwf/whatever) allowing established connections and then surprised that blocking rules provided in INPUT chain don't work at all. Just to reference - #1609 (comment), #2503 (comment) |
Beta Was this translation helpful? Give feedback.
This doesn't look like a delayed ban. Moreover this is looking like a not working ban mechanism (for instance inappropriate or not working banaction).
For possible reasons see the second question [Q] Ban takes place but does not work, the intruder is still able to connect and continues an attack in the FAQ in our wiki.
In order to help you we may need more details like which action is used (or better output of
fail2ban-client -d | grep bots), listing of the net-filter (what is in the chains and tables, e. g.iptables -Lif it is iptables-action), etc.