Fail2ban fails to ban

Hi,

Looking through the logs today revealed that my server has been hammered with requests throughout the night for many hours from the same ip-address. This was going on until I added this ip to the miab-postfix587 jail by hand using fail2ban-client.

However I am wondering why fail2ban did not do this automatically since the ip was opening connections every 3 seconds.

This is what mail.log shows:

......
Apr 13 10:21:29 box postfix/submission/smtpd[345606]: connect from unknown[189.190.226.55]
Apr 13 10:21:31 box postfix/submission/smtpd[345606]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:21:31 box postfix/submission/smtpd[345606]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:21:33 box postfix/submission/smtpd[346766]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:21:33 box postfix/submission/smtpd[346766]: connect from unknown[189.190.226.55]
Apr 13 10:21:34 box postfix/submission/smtpd[346766]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:21:34 box postfix/submission/smtpd[346766]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:21:35 box postfix/submission/smtpd[345606]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:21:35 box postfix/submission/smtpd[345606]: connect from unknown[189.190.226.55]
Apr 13 10:21:36 box postfix/submission/smtpd[345606]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:21:36 box postfix/submission/smtpd[345606]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:21:36 box postfix/submission/smtpd[346766]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:21:36 box postfix/submission/smtpd[346766]: connect from unknown[189.190.226.55]
Apr 13 10:21:37 box postfix/submission/smtpd[346766]: disconnect from unknown[189.190.226.55] quit=1 commands=1
Apr 13 10:21:38 box postfix/submission/smtpd[345606]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:21:38 box postfix/submission/smtpd[345606]: connect from unknown[189.190.226.55]
Apr 13 10:21:41 box postfix/submission/smtpd[345606]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:21:41 box postfix/submission/smtpd[345606]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:21:42 box postfix/submission/smtpd[346766]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:21:42 box postfix/submission/smtpd[346766]: connect from unknown[189.190.226.55]
Apr 13 10:22:01 box postfix/submission/smtpd[346766]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:22:01 box postfix/submission/smtpd[346766]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:22:02 box postfix/submission/smtpd[345606]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:22:02 box postfix/submission/smtpd[345606]: connect from unknown[189.190.226.55]
Apr 13 10:22:06 box postfix/submission/smtpd[346766]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:22:06 box postfix/submission/smtpd[346766]: connect from unknown[189.190.226.55]
Apr 13 10:22:07 box postfix/submission/smtpd[345606]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:22:07 box postfix/submission/smtpd[345606]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:22:08 box postfix/submission/smtpd[346766]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:22:08 box postfix/submission/smtpd[346766]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:22:09 box postfix/submission/smtpd[345606]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:22:09 box postfix/submission/smtpd[345606]: connect from unknown[189.190.226.55]
Apr 13 10:22:11 box postfix/submission/smtpd[345606]: lost connection after EHLO from unknown[189.190.226.55]
Apr 13 10:22:11 box postfix/submission/smtpd[345606]: disconnect from unknown[189.190.226.55] ehlo=1 mail=0/1 commands=1/2
Apr 13 10:22:12 box postfix/submission/smtpd[346766]: warning: hostname dsl-189-190-226-55-dyn.prod-infinitum.com.mx does not resolve to address 189.190.226.55: Name or service not known
Apr 13 10:22:12 box postfix/submission/smtpd[346766]: connect from unknown[189.190.226.55]

After I blocked the ip I got this in the logfile:

Apr 13 10:24:28 box postfix/anvil[330116]: statistics: max connection rate 24/60s for (submission:189.190.226.55) at Apr 13 10:15:29
Apr 13 10:24:28 box postfix/anvil[330116]: statistics: max connection count 3 for (submission:189.190.226.55) at Apr 13 10:20:41

Looking through the filter configuration for fail2ban I discovered this in /etc/fail2ban/filter.d/postfix.conf, which should have taken care of the situation.

mdpr-ddos = (?:lost connection after(?! DATA) [A-Z]+|disconnect(?= from \S+(?: \S+=\d+)* auth=0/(?:[1-9]|\d\d+)))
mdre-ddos = ^from [^[]*\[<HOST>\]%(_port)s:?

Further looking into /etc/fail2ban/filter.d/miab-postfix-submission.conf does not show this kind of filter-rule.
So, the question is, if the lines in postfix.conf are even considered or active? Or are those filters some sort of template that need to be referenced by miab-postfix-submission.conf to be actually enabled?

According to /etc/fail2ban/jail.d/mailinabox.conf the ‘maxretry’ value for miab-postfix587 is set to 20. Should this not have triggered the filter as stated in this line?

Apr 13 10:24:28 box postfix/anvil[330116]: statistics: max connection rate 24/60s for 

I am not sure I am even looking at the right places right now. Can somebody confirm my thinking or maybe set me on the right track?

Thanks

Lars

Best place to start is the /var/log/fail2ban.log file. There you can see what filters are actually triggered.
Note that there are several things that need to be in place for a working jail:

  • A jail must be configured and enabled. Jails are configured in /etc/fail2ban/jail.conf and the files in /etc/fail2ban/jail.d
  • The filters under /etc/fail2ban/filter.d are only used if used by an enabled jail

Specifically for some things you mention:

  • /etc/fail2ban/filter.d/postfix.conf is used by postfix jails. It might well be there are no jails enabled that use that filter. This is why fail2ban does not trigger on the mail.log entries you show.
  • The maxretry=20 entry means that fail2ban should detect the log entry at least 20 times in the last findtime amount of seconds. This is not connected to the max connection rate log entry you show.

Thank you very much for taking the time to answer @KiekerJan

the fail2ban logs did not indicate any jails being used. Also the fail2ban-client had no indication of any ip blocked in any of the jails. I went through all of them, even if they were not related to postfix. All was empty and nothing was blocked
I will try to understand why the postfix rules haven’t been used - need to investigate further.

In regards to maxretry - my mail.log log is full with the exact lines I have provided. There must be a couple thousand of those lines in there. I believe the amount of line items should have triggered the jail.

I have no way to access the box right now as I am on the road. Will check again next week and report my findings (if any)

Thanks

Lars

If there is no entry in the fail2ban.log the jail did not trigger. Example

2023-04-15 16:18:05,344 fail2ban.filter         [628]: INFO    [sshd] Found 159.203.85.196 - 2023-04-15 16:18:05
2023-04-15 16:18:05,539 fail2ban.actions        [628]: NOTICE  [sshd] Ban 159.203.85.196
2023-04-15 16:18:05,546 fail2ban.filter         [628]: INFO    [recidive] Found 159.203.85.196 - 2023-04-15 16:18:05
2

If a filter finds something, this is logged as e.g. [sshd] Found. This means filter configured in the jail sshd has one hit in the logfile it watches. If there are enough hits, the IP is banned (logged as [sshd] Ban) Enough hits is configured by the maxretry and findtime options.

If there are no Found lines in the fail2ban.log file, either the filter is not correctly written (see man fail2ban-regex to check that), the jail is not enabled or the specific filter is not used.
I suspect that in your case the postfix jail is not enabled or it does not use the postfix[ddos] filter. I think this is at least the case for the default Mail-in-a-Box installation.

The lines

Apr 13 10:24:28 box postfix/anvil[330116]: statistics: max connection rate 24/60s for (submission:189.190.226.55) at Apr 13 10:15:29
Apr 13 10:24:28 box postfix/anvil[330116]: statistics: max connection count 3 for (submission:189.190.226.55) at Apr 13 10:20:41

are not the result of fail2ban, but of the postfix built-in connection rate limiter.

This topic was automatically closed 40 days after the last reply. New replies are no longer allowed.