Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failed to execute ban jail 'sshd' action 'firewallcmd-ipset' #2773

Closed
zoid009 opened this issue Jul 9, 2020 · 1 comment
Closed

Failed to execute ban jail 'sshd' action 'firewallcmd-ipset' #2773

zoid009 opened this issue Jul 9, 2020 · 1 comment

Comments

@zoid009
Copy link

zoid009 commented Jul 9, 2020

Hi!
I observe the following problem in sshd.
FirewallD is not running - but I don’t use it, I use iptables

2020-07-09 18:16:57,889 fail2ban.server [8958]: INFO --------------------------------------------------
2020-07-09 18:16:57,890 fail2ban.server [8958]: INFO Starting Fail2ban v0.10.5
2020-07-09 18:16:57,890 fail2ban.server [8958]: DEBUG Creating PID file /var/run/fail2ban/fail2ban.pid
2020-07-09 18:16:57,890 fail2ban.server [8958]: DEBUG Starting communication
2020-07-09 18:16:57,898 fail2ban.database [8958]: INFO Connected to fail2ban persistent database '/var/lib/fail2ban/fail2ban.sqlite3'
2020-07-09 18:16:57,899 fail2ban.jail [8958]: INFO Creating new jail 'sshd'
2020-07-09 18:16:57,924 fail2ban.jail [8958]: INFO Jail 'sshd' uses systemd {}
2020-07-09 18:16:57,924 fail2ban.filter [8958]: DEBUG Setting usedns = warn for FilterSystemd(Jail('sshd'))
2020-07-09 18:16:57,924 fail2ban.filter [8958]: DEBUG Created FilterSystemd(Jail('sshd'))
2020-07-09 18:16:57,925 fail2ban.filtersystemd [8958]: DEBUG Created FilterSystemd
2020-07-09 18:16:57,925 fail2ban.jail [8958]: INFO Initiated 'systemd' backend
2020-07-09 18:16:57,926 fail2ban.filter [8958]: DEBUG Setting usedns = warn for FilterSystemd(Jail('sshd'))
2020-07-09 18:16:57,926 fail2ban.server [8958]: DEBUG prefregex: '^\s*(?:\S+\s+)?(?:sshd(?:\[\d+\])?:?\s+)?(?:kernel:\s?\[ \d+\.\d+\]:?\s+)?(?:(?:error|fatal): (?:PAM: )?)?.+$'
2020-07-09 18:16:57,927 fail2ban.filter [8958]: INFO maxLines: 1
2020-07-09 18:16:57,927 fail2ban.server [8958]: DEBUG failregex: '^[aA]uthentication (?:failure|error|failed) for .
from ( via \S+)?(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,930 fail2ban.server [8958]: DEBUG failregex: '^User not known to the underlying authentication module for . from (?: (?:port \d+|on \S+|\[preauth\])){0,3}\s$'
2020-07-09 18:16:57,931 fail2ban.server [8958]: DEBUG failregex: '^Failed publickey for invalid user (?P<cond_user>\S+)|(?:(?! from ).)? from (?: (?:port \d+|on \S+)){0,2}(?: ssh\d)?(?(cond_user): |(?:(?:(?! from ).))$)'
2020-07-09 18:16:57,934 fail2ban.server [8958]: DEBUG failregex: '^Failed \b(?!publickey)\S+ for (?P<cond_inv>invalid user )?(?P<cond_user>\S+)|(?(cond_inv)(?:(?! from ).)
?|[^:]+) from (?: (?:port \d+|on \S+)){0,2}(?: ssh\d*)?(?(cond_user): |(?:(?:(?! from ).))$)'
2020-07-09 18:16:57,936 fail2ban.server [8958]: DEBUG failregex: '^ROOT LOGIN REFUSED FROM '
2020-07-09 18:16:57,937 fail2ban.server [8958]: DEBUG failregex: '^iI user .
? from (?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,939 fail2ban.server [8958]: DEBUG failregex: '^User .+ from not allowed because not listed in AllowUsers(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,941 fail2ban.server [8958]: DEBUG failregex: '^User .+ from not allowed because listed in DenyUsers(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,943 fail2ban.server [8958]: DEBUG failregex: '^User .+ from not allowed because not in any group(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,945 fail2ban.server [8958]: DEBUG failregex: '^refused connect from \S+ \(\)'
2020-07-09 18:16:57,946 fail2ban.server [8958]: DEBUG failregex: '^Received disconnect from (?: (?:port \d+|on \S+)){0,2}:\s3: .: Auth fail(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,948 fail2ban.server [8958]: DEBUG failregex: '^User .+ from not allowed because a group is listed in DenyGroups(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,950 fail2ban.server [8958]: DEBUG failregex: "^User .+ from not allowed because none of user's groups are listed in AllowGroups(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$"
2020-07-09 18:16:57,952 fail2ban.server [8958]: DEBUG failregex: '^pam_[a-z]+\(sshd:auth\):\s+authentication failure;(?:\s+(?:(?:logname|e?uid|tty)=\S*)){0,4}\s+ruser=<F-ALT_USER>\S*</F-ALT_USER>\s+rhost=(?:\s+user=\S*)?(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,955 fail2ban.server [8958]: DEBUG failregex: '^(error: )?maximum authentication attempts exceeded for . from (?: (?:port \d+|on \S+)){0,2}(?: ssh\d)?(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,957 fail2ban.server [8958]: DEBUG failregex: '^User .+ not allowed because account is locked(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*'
2020-07-09 18:16:57,958 fail2ban.server [8958]: DEBUG failregex: '^Disconnecting(?: from)?(?: (?:invalid|authenticating)) user \S+ (?: (?:port \d+|on \S+)){0,2}:\sChange of username or service not allowed:\s.\[preauth\]\s$'
2020-07-09 18:16:57,960 fail2ban.server [8958]: DEBUG failregex: '^Disconnecting: Too many authentication failures(?: for .+?)?(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s*$'
2020-07-09 18:16:57,961 fail2ban.server [8958]: DEBUG failregex: '^Received disconnect from (?: (?:port \d+|on \S+)){0,2}:\s11:'
2020-07-09 18:16:57,962 fail2ban.server [8958]: DEBUG failregex: '^(Connection closed|Disconnected) (?:by|from)(?: (?:invalid|authenticating) user \S+|.+?)? (?:(?: (?:port \d+|on \S+|\[preauth\])){0,3}\s
|\s*)$'
2020-07-09 18:16:57,965 fail2ban.server [8958]: DEBUG failregex: '^Accepted \w+ for \S+ from (?:\s|$)'
2020-07-09 18:16:57,967 fail2ban.server [8958]: DEBUG failregex: '^Connection from '
2020-07-09 18:16:57,973 fail2ban.filtersystemd [8958]: INFO [sshd] Added journal match for: '_SYSTEMD_UNIT=sshd.service + _COMM=sshd'
2020-07-09 18:16:57,973 fail2ban.filter [8958]: INFO maxRetry: 5
2020-07-09 18:16:57,973 fail2ban.filter [8958]: DEBUG Add '10.1.0.0/16' to ignore list ('10.1.0.0/16')
2020-07-09 18:16:57,973 fail2ban.filter [8958]: DEBUG Add '172.27.160.0/24' to ignore list ('172.27.160.0/24')
2020-07-09 18:16:57,973 fail2ban.filter [8958]: INFO encoding: UTF-8
2020-07-09 18:16:57,974 fail2ban.actions [8958]: INFO banTime: 3600
2020-07-09 18:16:57,974 fail2ban.filter [8958]: INFO findtime: 650
2020-07-09 18:16:57,974 fail2ban.CommandAction [8958]: DEBUG Created <class 'fail2ban.server.action.CommandAction'>
2020-07-09 18:16:57,974 fail2ban.CommandAction [8958]: DEBUG Set actionunban = ' -D f2b-sshd -s -j '
2020-07-09 18:16:57,974 fail2ban.CommandAction [8958]: DEBUG Set actionflush = ' -F f2b-sshd'
2020-07-09 18:16:57,974 fail2ban.CommandAction [8958]: DEBUG Set actionstop = ' -D INPUT -p tcp -m multiport --dports ssh -j f2b-sshd\n -F f2b-sshd\n -X f2b-sshd'
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set actionstart = ' -N f2b-sshd\n -A f2b-sshd -j RETURN\n -I INPUT -p tcp -m multiport --dports ssh -j f2b-sshd'
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set actionban = ' -I f2b-sshd 1 -s -j '
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set actioncheck = " -n -L INPUT | grep -q 'f2b-sshd[ \t]'"
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set protocol = 'tcp'
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set chain = '<known/chain>'
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set lockingopt = '-w'
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set blocktype = 'REJECT --reject-with icmp-port-unreachable'
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set blocktype?family=inet6 = 'REJECT --reject-with icmp6-port-unreachable'
2020-07-09 18:16:57,975 fail2ban.CommandAction [8958]: DEBUG Set port = 'ssh'
2020-07-09 18:16:57,976 fail2ban.CommandAction [8958]: DEBUG Set actname = 'iptables-multiport'
2020-07-09 18:16:57,976 fail2ban.CommandAction [8958]: DEBUG Set bantime = 3600
2020-07-09 18:16:57,976 fail2ban.CommandAction [8958]: DEBUG Set iptables = 'iptables '
2020-07-09 18:16:57,976 fail2ban.CommandAction [8958]: DEBUG Set returntype = 'RETURN'
2020-07-09 18:16:57,976 fail2ban.CommandAction [8958]: DEBUG Set iptables?family=inet6 = 'ip6tables '
2020-07-09 18:16:57,976 fail2ban.CommandAction [8958]: DEBUG Set name = 'sshd'
2020-07-09 18:16:57,976 fail2ban.jail [8958]: DEBUG Starting jail 'sshd'
2020-07-09 18:16:57,979 fail2ban.jail [8958]: INFO Jail 'sshd' started
2020-07-09 18:16:57,983 fail2ban.transmitter [8958]: DEBUG Status: ready
2020-07-09 18:17:23,000 fail2ban.filter [8958]: DEBUG Processing line with time:1594307843.0 and ip:10.0.0.4
2020-07-09 18:17:23,005 fail2ban.filter [8958]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:22
2020-07-09 18:17:23,005 fail2ban.failmanager [8958]: DEBUG Total # of detected failures: 1. Current failures from 1 IPs (IP:count): 10.0.0.4:1
2020-07-09 18:17:23,006 fail2ban.filter [412]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:22
2020-07-09 18:17:23,006 fail2ban.filter [10348]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:22
2020-07-09 18:17:26,728 fail2ban.filter [8958]: DEBUG Processing line with time:1594307846.73 and ip:10.0.0.4
2020-07-09 18:17:26,728 fail2ban.filter [412]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:26
2020-07-09 18:17:26,728 fail2ban.filter [10348]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:26
2020-07-09 18:17:26,729 fail2ban.filter [8958]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:26
2020-07-09 18:17:26,729 fail2ban.failmanager [8958]: DEBUG Total # of detected failures: 2. Current failures from 1 IPs (IP:count): 10.0.0.4:2
2020-07-09 18:17:30,190 fail2ban.filter [8958]: DEBUG Processing line with time:1594307850.19 and ip:10.0.0.4
2020-07-09 18:17:30,190 fail2ban.filter [412]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:30
2020-07-09 18:17:30,190 fail2ban.filter [10348]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:30
2020-07-09 18:17:30,190 fail2ban.filter [8958]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:30
2020-07-09 18:17:30,191 fail2ban.failmanager [8958]: DEBUG Total # of detected failures: 3. Current failures from 1 IPs (IP:count): 10.0.0.4:3
2020-07-09 18:17:34,834 fail2ban.filter [8958]: DEBUG Processing line with time:1594307854.82 and ip:10.0.0.4
2020-07-09 18:17:34,834 fail2ban.filter [412]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:34
2020-07-09 18:17:34,834 fail2ban.filter [10348]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:34
2020-07-09 18:17:34,834 fail2ban.filter [8958]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:34
2020-07-09 18:17:34,835 fail2ban.failmanager [8958]: DEBUG Total # of detected failures: 4. Current failures from 1 IPs (IP:count): 10.0.0.4:4
2020-07-09 18:17:40,126 fail2ban.filter [8958]: DEBUG Processing line with time:1594307860.12 and ip:10.0.0.4
2020-07-09 18:17:40,126 fail2ban.filter [412]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:40
2020-07-09 18:17:40,126 fail2ban.filter [10348]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:40
2020-07-09 18:17:40,127 fail2ban.filter [8958]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:40
2020-07-09 18:17:40,127 fail2ban.failmanager [8958]: DEBUG Total # of detected failures: 5. Current failures from 1 IPs (IP:count): 10.0.0.4:5
2020-07-09 18:17:40,238 fail2ban.actions [8958]: NOTICE [sshd] Ban 10.0.0.4
2020-07-09 18:17:40,239 fail2ban.action [8958]: DEBUG iptables -w -N f2b-sshd
iptables -w -A f2b-sshd -j RETURN
iptables -w -I INPUT -p tcp -m multiport --dports ssh -j f2b-sshd
2020-07-09 18:17:40,256 fail2ban.utils [8958]: DEBUG 7fe7480323f0 -- stderr: 'iptables: Chain already exists.'
2020-07-09 18:17:40,256 fail2ban.utils [8958]: DEBUG 7fe7480323f0 -- returned successfully 0
2020-07-09 18:17:40,257 fail2ban.action [8958]: DEBUG iptables -w -n -L INPUT | grep -q 'f2b-sshd[ \t]'
2020-07-09 18:17:40,265 fail2ban.utils [8958]: DEBUG 7fe741136138 -- returned successfully 0
2020-07-09 18:17:40,265 fail2ban.action [8958]: DEBUG iptables -w -I f2b-sshd 1 -s 10.0.0.4 -j REJECT --reject-with icmp-port-unreachable
2020-07-09 18:17:40,272 fail2ban.utils [8958]: DEBUG 7fe743927be8 -- returned successfully 0
2020-07-09 18:17:40,272 fail2ban.actions [8958]: DEBUG Banned 1 / 1, 1 ticket(s) in 'sshd'
2020-07-09 18:17:40,329 fail2ban.actions [10348]: WARNING [sshd] 10.0.0.4 already banned
2020-07-09 18:17:40,813 fail2ban.actions [412]: NOTICE [sshd] Ban 10.0.0.4
2020-07-09 18:17:41,149 fail2ban.utils [412]: ERROR 7fe9a89e3d30 -- exec: ipset create f2b-sshd hash:ip timeout 600
firewall-cmd --direct --add-rule ipv4 filter INPUT_direct 0 -p tcp -m multiport --dports ssh -m set --match-set f2b-sshd src -j REJECT --reject-with icmp-port-unreachable
2020-07-09 18:17:41,150 fail2ban.utils [412]: ERROR 7fe9a89e3d30 -- stderr: 'ipset v7.1: Set cannot be created: set with the same name already exists'
2020-07-09 18:17:41,150 fail2ban.utils [412]: ERROR 7fe9a89e3d30 -- stderr: 'FirewallD is not running'
2020-07-09 18:17:41,150 fail2ban.utils [412]: ERROR 7fe9a89e3d30 -- killed with signal 124 (return code: 252)
2020-07-09 18:17:41,150 fail2ban.actions [412]: ERROR Failed to execute ban jail 'sshd' action 'firewallcmd-ipset' info 'ActionInfo({'ip': '10.0.0.4', 'fid': <function at 0x7fe9a8998a28>, 'family': 'inet4', 'raw-ticket': <function at 0x7fe9a8998ed8>})': Error starting action Jail('sshd')/firewallcmd-ipset: 'Script error'

and next problem

fail2ban-server
2020-07-09 18:23:22,186 fail2ban [9698]: ERROR Server already running
2020-07-09 18:23:22,187 fail2ban [9698]: ERROR Async configuration of server failed

@sebres
Copy link
Contributor

sebres commented Jul 9, 2020

2020-07-09 18:17:23,005 fail2ban.filter [8958]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:22
2020-07-09 18:17:23,006 fail2ban.filter [412]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:22
2020-07-09 18:17:23,006 fail2ban.filter [10348]: INFO [sshd] Found 10.0.0.4 - 2020-07-09 18:17:22

As you can see for some reason there are three! instances of fail2ban, one 8958 was starting at 2020-07-09 18:16:57 (and indeed it doesn't use firewalld-actions), but there are still 2 instances - with pid 412 (and 10348), which trying to execute firewallcmd-ipset action.
You have to stop this instances (or kill them, but they can remain some rules in corresponding firewall sub-system) and clean up your configurations (seems to use multiple instances).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants