Bug 2138919

Summary: fail2ban suddently taking 100% CPU
Product: [Fedora] Fedora Reporter: dan
Component: fail2banAssignee: Richard Shaw <hobbes1069>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: 36CC: anon.amish, axel.thimm, hobbes1069, jvrodrigues, orion, vonsch
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
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:
Story Points: ---
Clone Of: Environment:
Last Closed: 2022-11-10 22:31:18 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

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.