Bug 2138919 - fail2ban suddently taking 100% CPU
Summary: fail2ban suddently taking 100% CPU
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: fail2ban
Version: 36
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Richard Shaw
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-10-31 17:01 UTC by dan
Modified: 2022-11-11 01:29 UTC (History)
6 users (show)

Fixed In Version: fail2ban-1.0.1-2.fc37 fail2ban-1.0.1-2.fc36 fail2ban-1.0.1-2.el9
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-11-10 22:31:18 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 2135621 0 unspecified CLOSED fail2ban processing dovecot error logs uses 100% of the CPU. 2022-11-11 01:29:04 UTC

Description dan 2022-10-31 17:01:39 UTC
Cause unknown.  Noticed after a recent dnf update.

A systemctl stop fail2ban hangs and does not gracefully stop the process.


● fail2ban.service - Fail2Ban Service
     Loaded: loaded (/usr/lib/systemd/system/fail2ban.service; enabled; vendor preset: disabled)
     Active: active (running) since Sat 2022-10-29 10:35:42 EDT; 2 days ago
       Docs: man:fail2ban(1)
    Process: 1049 ExecStartPre=/bin/mkdir -p /run/fail2ban (code=exited, status=0/SUCCESS)
   Main PID: 1065 (fail2ban-server)
      Tasks: 21 (limit: 4657)
     Memory: 16.7M
        CPU: 2d 3h 22min 23.192s
     CGroup: /system.slice/fail2ban.service
             └─ 1065 /usr/bin/python3 -s /usr/bin/fail2ban-server -xf start

Oct 29 10:35:41 lin1 systemd[1]: Starting fail2ban.service - Fail2Ban Service...
Oct 29 10:35:42 lin1 systemd[1]: Started fail2ban.service - Fail2Ban Service.
Oct 29 10:35:43 lin1 fail2ban-server[1065]: 2022-10-29 10:35:43,166 fail2ban.configreader   [1065]: WARNING 'allowipv6' not defined in 'Definition'. Using default one: 'auto'
Oct 29 10:35:43 lin1 fail2ban-server[1065]: Server ready

$ rpm -qa | grep fail2ban
fail2ban-selinux-1.0.1-1.fc36.noarch
fail2ban-server-1.0.1-1.fc36.noarch
fail2ban-firewalld-1.0.1-1.fc36.noarch
fail2ban-sendmail-1.0.1-1.fc36.noarch
fail2ban-1.0.1-1.fc36.noarch
fail2ban-systemd-1.0.1-1.fc36.noarch

$ sudo fail2ban-server -v
2022-10-31 13:00:47,537 fail2ban.configreader   [70936]: INFO    Loading configs for fail2ban under /etc/fail2ban 
2022-10-31 13:00:47,538 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/fail2ban.conf']
2022-10-31 13:00:47,539 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/fail2ban.conf']
2022-10-31 13:00:47,539 fail2ban                [70936]: INFO    Using socket file /var/run/fail2ban/fail2ban.sock
2022-10-31 13:00:47,539 fail2ban                [70936]: INFO    Using pid file /var/run/fail2ban/fail2ban.pid, [INFO] logging to /var/log/fail2ban.log
2022-10-31 13:00:47,546 fail2ban.configreader   [70936]: INFO    Loading configs for jail under /etc/fail2ban 
2022-10-31 13:00:47,547 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/jail.conf']
2022-10-31 13:00:47,557 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/paths-fedora.conf']
2022-10-31 13:00:47,559 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/paths-common.conf']
2022-10-31 13:00:47,560 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/paths-overrides.local']
2022-10-31 13:00:47,560 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/jail.d/00-firewalld.conf']
2022-10-31 13:00:47,561 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/jail.d/00-systemd.conf']
2022-10-31 13:00:47,561 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/jail.local']
2022-10-31 13:00:47,562 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/paths-common.conf', '/etc/fail2ban/paths-fedora.conf', '/etc/fail2ban/jail.conf', '/etc/fail2ban/jail.d/00-firewalld.conf', '/etc/fail2ban/jail.d/00-systemd.conf', '/etc/fail2ban/jail.local']
2022-10-31 13:00:47,563 fail2ban.configreader   [70936]: WARNING 'allowipv6' not defined in 'Definition'. Using default one: 'auto'
2022-10-31 13:00:47,564 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/sshd under /etc/fail2ban 
2022-10-31 13:00:47,564 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/sshd.conf']
2022-10-31 13:00:47,566 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf']
2022-10-31 13:00:47,567 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.local']
2022-10-31 13:00:47,567 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/sshd.conf']
2022-10-31 13:00:47,571 fail2ban.configreader   [70936]: INFO    Loading configs for action.d/firewallcmd-ipset under /etc/fail2ban 
2022-10-31 13:00:47,572 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/action.d/firewallcmd-ipset.conf']
2022-10-31 13:00:47,573 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/action.d/firewallcmd-common.conf']
2022-10-31 13:00:47,574 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/action.d/firewallcmd-common.conf', '/etc/fail2ban/action.d/firewallcmd-ipset.conf']
2022-10-31 13:00:47,576 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/apache-auth under /etc/fail2ban 
2022-10-31 13:00:47,576 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/apache-auth.conf']
2022-10-31 13:00:47,577 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/apache-common.conf']
2022-10-31 13:00:47,578 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/apache-common.local']
2022-10-31 13:00:47,578 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/apache-common.conf', '/etc/fail2ban/filter.d/apache-auth.conf']
2022-10-31 13:00:47,581 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/apache-badbots under /etc/fail2ban 
2022-10-31 13:00:47,582 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/apache-badbots.conf']
2022-10-31 13:00:47,582 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/apache-badbots.conf']
2022-10-31 13:00:47,584 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/apache-noscript under /etc/fail2ban 
2022-10-31 13:00:47,585 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/apache-noscript.conf']
2022-10-31 13:00:47,586 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/apache-common.conf', '/etc/fail2ban/filter.d/apache-noscript.conf']
2022-10-31 13:00:47,590 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/vsftpd under /etc/fail2ban 
2022-10-31 13:00:47,591 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/vsftpd.conf']
2022-10-31 13:00:47,592 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/vsftpd.conf']
2022-10-31 13:00:47,594 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/postfix under /etc/fail2ban 
2022-10-31 13:00:47,595 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/postfix.conf']
2022-10-31 13:00:47,596 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/postfix.conf']
2022-10-31 13:00:47,600 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/dovecot under /etc/fail2ban 
2022-10-31 13:00:47,601 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/dovecot.conf']
2022-10-31 13:00:47,601 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/dovecot.conf']
2022-10-31 13:00:47,608 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/sshd-local under /etc/fail2ban 
2022-10-31 13:00:47,608 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/sshd-local.conf']
2022-10-31 13:00:47,609 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/sshd-local.conf']
2022-10-31 13:00:47,611 fail2ban.configreader   [70936]: INFO    Loading configs for filter.d/wordpress-userenum under /etc/fail2ban 
2022-10-31 13:00:47,612 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/wordpress-userenum.conf']
2022-10-31 13:00:47,613 fail2ban.configparserinc[70936]: INFO      Loading files: ['/etc/fail2ban/filter.d/common.conf', '/etc/fail2ban/filter.d/wordpress-userenum.conf']
2022-10-31 13:00:47,627 fail2ban                [70936]: ERROR   Fail2ban seems to be in unexpected state (not running but the socket exists)
2022-10-31 13:00:47,638 fail2ban                [70936]: ERROR   Async configuration of server failed
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/fail2ban/client/fail2banserver.py", line 193, in start
    cli.configureServer(phase=phase)
  File "/usr/lib/python3.10/site-packages/fail2ban/client/fail2banclient.py", line 243, in configureServer
    raise ServerExecutionException('Async configuration of server failed')
fail2ban.client.fail2bancmdline.ServerExecutionException: Async configuration of server failed

Comment 1 dan 2022-10-31 19:33:59 UTC
The culprint is the dovecot filter.  I don't know why, I did not make any config changes.  If I disable the dovecot filter CPU returns to its usual minimal level.

Comment 2 Richard Shaw 2022-10-31 20:45:05 UTC
Yes, this is a known issue. Upstream is aware and has mentioned a new release to fix but it has not happened yet.

Technically a dupe of https://bugzilla.redhat.com/show_bug.cgi?id=2135621 but that is against EPEL so I'll just reference it here.

Comment 3 Fedora Update System 2022-11-02 22:47:23 UTC
FEDORA-2022-9a192ab246 has been submitted as an update to Fedora 36. https://bodhi.fedoraproject.org/updates/FEDORA-2022-9a192ab246

Comment 4 Fedora Update System 2022-11-02 22:47:26 UTC
FEDORA-EPEL-2022-3b4c776408 has been submitted as an update to Fedora EPEL 9. https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2022-3b4c776408

Comment 5 Fedora Update System 2022-11-02 22:47:29 UTC
FEDORA-2022-3f9a2795e7 has been submitted as an update to Fedora 37. https://bodhi.fedoraproject.org/updates/FEDORA-2022-3f9a2795e7

Comment 6 Fedora Update System 2022-11-03 08:47:08 UTC
FEDORA-2022-3f9a2795e7 has been pushed to the Fedora 37 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --refresh --advisory=FEDORA-2022-3f9a2795e7`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2022-3f9a2795e7

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 7 Fedora Update System 2022-11-03 16:03:45 UTC
FEDORA-2022-9a192ab246 has been pushed to the Fedora 36 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --refresh --advisory=FEDORA-2022-9a192ab246`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2022-9a192ab246

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 8 Fedora Update System 2022-11-03 16:50:43 UTC
FEDORA-EPEL-2022-3b4c776408 has been pushed to the Fedora EPEL 9 testing repository.

You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2022-3b4c776408

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 9 dan 2022-11-03 18:13:00 UTC
The update does not fix the problem on FC36.  I applied the update, enabled the dovecot jail, and restarted fail2ban.  CPU quick hit almost 100%.

Comment 10 Richard Shaw 2022-11-03 20:59:01 UTC
(In reply to dan from comment #9)
> The update does not fix the problem on FC36.  I applied the update, enabled
> the dovecot jail, and restarted fail2ban.  CPU quick hit almost 100%.

Can you check for a rpmnew file? All configuration files are marked not to be replaced as to not overwrite local modifications.

Comment 11 dan 2022-11-03 21:31:03 UTC
No rpmnew file in /etc/fail2ban.

Comment 12 Richard Shaw 2022-11-04 12:35:03 UTC
The patch was definitely applied during the build...

What does your filter directory look like?

$ ll /etc/fail2ban/filter.d/ | grep dovecot
-rw-r--r--. 1 root root 2586 Oct  3 07:01 dovecot.conf

Also some context if it's helpful. Here's the upstream issue:

https://github.com/fail2ban/fail2ban/issues/3370

And the commit that was supposed to fix it:

https://github.com/fail2ban/fail2ban/commit/ca2b94c5229bd474f612b57b67d796252a4aab7a

Comment 13 Fedora Update System 2022-11-10 22:31:18 UTC
FEDORA-2022-3f9a2795e7 has been pushed to the Fedora 37 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 14 Fedora Update System 2022-11-11 01:15:40 UTC
FEDORA-2022-9a192ab246 has been pushed to the Fedora 36 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 15 Fedora Update System 2022-11-11 01:29:07 UTC
FEDORA-EPEL-2022-3b4c776408 has been pushed to the Fedora EPEL 9 stable repository.
If problem still persists, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.