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.

Sign up for GitHub

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

Jump to bottom

fail2ban-client hangs if is called from action when service is stopping #7

Closed
selivan opened this issue Nov 20, 2011 · 8 comments
Closed

fail2ban-client hangs if is called from action when service is stopping #7

selivan opened this issue Nov 20, 2011 · 8 comments
Assignees
@yarikoptic

Comments

@selivan
Copy link

selivan commented Nov 20, 2011

I'm calling fail2ban-client from action to pass jail status to monitoring server(Zabbix). When I do '/etc/init.d/fail2ban stop' or 'fail2ban-client stop', it hangs forever: socket is still alive, but fail2ban server is not responding to fail2ban client, and so unban action is never completed. IMHO fail2ban-server should be able to answer the fail2ban-client during shutdown process, at least at ping request, and may be that requested jail does not exist anymore.
@yarikoptic
Copy link
Member

just to make it clearer (since I am a bit confused by dichotomy of summary/description)

  • what version of fail2ban?
  • you have an action file -- share it so this all could be reproduced (is it consistently reproducible? try on a different box)
  • those stop actions are not called within action file, right?
  • action file in questions just gets/sends the status and as soon as it is enabled, but regardless either it is "invoked" atm -- fail2ban-client stop fails if called outside
  • sample of fail2ban.log (at loglevel = 4, ie DEBUG)?

@selivan
Copy link
Author

selivan commented Nov 21, 2011

The bug occures only if there is at least one banned ip.

  • Fail2Ban v0.8.4-SVN
  • iptables-allports.local:
...
actionban = iptables -I fail2ban-<name> -s <ip> -j DROP
            /etc/zabbix/fail2ban_helper.sh <name>
actionunban = iptables -D fail2ban-<name> -s <ip> -j DROP
            /etc/zabbix/fail2ban_helper.sh <name>
...

/etc/zabbix/fail2ban_helper.sh:

#!/bin/bash
set -x

if [ $# -ne 1 ]; then
        echo "Usage: $0 <name>"
        exit 1
fi

zabbix_server=monitor
hostname=$(hostname)

# If script is called when fail2ban service is stopping
# Socket is alive, but fail2ban-server would not answer
# so fail2ban-client hangs. Here is DIRTY workaround:

#fail2ban-client ping &
#pid=$!
#sleep 1
#if [ ps -e | grep $pid ]; then
#       echo "Service is stopping, bans are removed"
#       zabbix_sender -z $zabbix_server -s $hostname -k ssh_num_banned_ips -o 0
#       zabbix_sender -z $zabbix_server -s $hostname -k ssh_list_of_banned_ips -o ""
#       exit 0
#fi

number_of_banned_ips=$(fail2ban-client status ssh | grep 'Currently banned' | cut -d':' -f 2 | tr -d '[:cntrl:]')
list_of_banned_ips=$(fail2ban-client status ssh | grep 'IP list' | cut -d':' -f 2 | tr -d '[:cntrl:]')

zabbix_sender -z $zabbix_server -s $hostname -k ssh_num_banned_ips -o $number_of_banned_ips
zabbix_sender -z $zabbix_server -s $hostname -k ssh_list_of_banned_ips -o "$list_of_banned_ips"
  • Yes, stop action is called outside
  • Here is part of process tree when fail2ban-client stop hangs:
- /usr/bin/python /usr/bin/fail2ban-server -b -s /var/run/fail2ban/fail2ban.sock
   - sh -c iptables -D fail2ban-ssh -s 10.0.0.9 -j DROP /etc/zabbix/fail2ban_helper.sh ssh
      - /bin/bash /etc/zabbix/fail2ban_helper.sh ssh
          - /bin/bash /etc/zabbix/fail2ban_helper.sh ssh
              - tr -d [:cntrl:]
              - cut -d: -f 2
              - grep Currently banned
              - /usr/bin/python /usr/bin/fail2ban-client status ssh

fail2ban.log, loglevel = 4:

2011-11-21 16:22:01,988 fail2ban.server : INFO   Changed logging target to /var/log/fail2ban.log for Fail2ban v0.8.4-SVN
2011-11-21 16:22:01,990 fail2ban.comm   : DEBUG  Command: ['add', 'ssh', 'polling']
2011-11-21 16:22:01,990 fail2ban.jail   : INFO   Creating new jail 'ssh'
2011-11-21 16:22:01,990 fail2ban.jail   : INFO   Jail 'ssh' uses poller
2011-11-21 16:22:02,097 fail2ban.filter : DEBUG  Created Filter
2011-11-21 16:22:02,097 fail2ban.filter : DEBUG  Created FilterPoll
2011-11-21 16:22:02,098 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addlogpath', '/var/log/auth.log']
2011-11-21 16:22:02,099 fail2ban.filter : INFO   Added logfile = /var/log/auth.log
2011-11-21 16:22:02,100 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'maxretry', '3']
2011-11-21 16:22:02,101 fail2ban.filter : INFO   Set maxRetry = 3
2011-11-21 16:22:02,102 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addignoreip', '127.0.0.1']
2011-11-21 16:22:02,102 fail2ban.filter : DEBUG  Add 127.0.0.1 to ignore list
2011-11-21 16:22:02,103 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'findtime', '600']
2011-11-21 16:22:02,104 fail2ban.filter : INFO   Set findtime = 600
2011-11-21 16:22:02,105 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'bantime', '600']
2011-11-21 16:22:02,106 fail2ban.actions: INFO   Set banTime = 600
2011-11-21 16:22:02,108 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*(?:error: PAM: )?Authentication failure for .* from \\s*$']
2011-11-21 16:22:02,114 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*(?:error: PAM: )?User not known to the underlying authentication module for .* from \\s*$']
2011-11-21 16:22:02,121 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*Failed (?:password|publickey) for .* from (?: port \\d*)?(?: ssh\\d*)?$']
2011-11-21 16:22:02,131 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*ROOT LOGIN REFUSED.* FROM \\s*$']
2011-11-21 16:22:02,139 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*[iI](?:llegal|nvalid) user .* from \\s*$']
2011-11-21 16:22:02,153 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*User .+ from  not allowed because not listed in AllowUsers$']
2011-11-21 16:22:02,168 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*authentication failure; logname=\\S* uid=\\S* euid=\\S* tty=\\S* ruser=\\S* rhost=(?:\\s+user=.*)?\\s*$']
2011-11-21 16:22:02,183 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*refused connect from \\S+ \\(\\)\\s*$']
2011-11-21 16:22:02,198 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', '^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*Address  .* POSSIBLE BREAK-IN ATTEMPT!*\\s*$']
2011-11-21 16:22:02,215 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addfailregex', "^\\s*(?:\\S+ )?(?:@vserver_\\S+ )?(?:(?:\\[\\d+\\])?:\\s+[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?|[\\[\\(]?sshd(?:\\(\\S+\\))?[\\]\\)]?:?(?:\\[\\d+\\])?:)?\\s*User .+ from  not allowed because none of user's groups are listed in AllowGroups\\s*$"]
2011-11-21 16:22:02,237 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'addaction', 'iptables-allports']
2011-11-21 16:22:02,237 fail2ban.actions.action: DEBUG  Created Action
2011-11-21 16:22:02,239 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'actionban', 'iptables-allports', 'iptables -I fail2ban- 1 -s  -j DROP\n/etc/zabbix/fail2ban_helper.sh ']
2011-11-21 16:22:02,239 fail2ban.actions.action: DEBUG  Set actionBan = iptables -I fail2ban- 1 -s  -j DROP
/etc/zabbix/fail2ban_helper.sh 
2011-11-21 16:22:02,240 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'actionstop', 'iptables-allports', 'iptables -D INPUT -p  -j fail2ban-\niptables -F fail2ban-\niptables -X fail2ban-']
2011-11-21 16:22:02,241 fail2ban.actions.action: DEBUG  Set actionStop = iptables -D INPUT -p  -j fail2ban-
iptables -F fail2ban-
iptables -X fail2ban-
2011-11-21 16:22:02,242 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'actionstart', 'iptables-allports', 'iptables -N fail2ban-\niptables -A fail2ban- -j RETURN\niptables -I INPUT -p  -j fail2ban-']
2011-11-21 16:22:02,242 fail2ban.actions.action: DEBUG  Set actionStart = iptables -N fail2ban-
iptables -A fail2ban- -j RETURN
iptables -I INPUT -p  -j fail2ban-
2011-11-21 16:22:02,244 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'actionunban', 'iptables-allports', 'iptables -D fail2ban- -s  -j DROP\n/etc/zabbix/fail2ban_helper.sh ']
2011-11-21 16:22:02,244 fail2ban.actions.action: DEBUG  Set actionUnban = iptables -D fail2ban- -s  -j DROP
/etc/zabbix/fail2ban_helper.sh 
2011-11-21 16:22:02,245 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'actioncheck', 'iptables-allports', 'iptables -n -L INPUT | grep -q fail2ban-']
2011-11-21 16:22:02,246 fail2ban.actions.action: DEBUG  Set actionCheck = iptables -n -L INPUT | grep -q fail2ban-
2011-11-21 16:22:02,247 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'setcinfo', 'iptables-allports', 'protocol', 'all']
2011-11-21 16:22:02,248 fail2ban.comm   : DEBUG  Command: ['set', 'ssh', 'setcinfo', 'iptables-allports', 'name', 'ssh']
2011-11-21 16:22:02,249 fail2ban.comm   : DEBUG  Command: ['start', 'ssh']
2011-11-21 16:22:02,250 fail2ban.filter : DEBUG  /var/log/auth.log has been modified
2011-11-21 16:22:02,251 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2011-11-21 16:22:02,251 fail2ban.jail   : INFO   Jail 'ssh' started
2011-11-21 16:22:02,257 fail2ban.actions.action: DEBUG  iptables -N fail2ban-ssh
iptables -A fail2ban-ssh -j RETURN
iptables -I INPUT -p all -j fail2ban-ssh
2011-11-21 16:22:02,298 fail2ban.actions.action: DEBUG  iptables -N fail2ban-ssh
iptables -A fail2ban-ssh -j RETURN
iptables -I INPUT -p all -j fail2ban-ssh returned successfully
2011-11-21 16:23:40,369 fail2ban.filter : DEBUG  /var/log/auth.log has been modified
2011-11-21 16:23:40,413 fail2ban.filter : DEBUG  Found 10.0.0.9
2011-11-21 16:23:40,414 fail2ban.filter : DEBUG  Found 10.0.0.9
2011-11-21 16:23:40,414 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2011-11-21 16:23:41,417 fail2ban.filter : DEBUG  /var/log/auth.log has been modified
2011-11-21 16:23:41,418 fail2ban.filter : DEBUG  Found 10.0.0.9
2011-11-21 16:23:41,418 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2011-11-21 16:23:42,412 fail2ban.actions: WARNING [ssh] Ban 10.0.0.9
2011-11-21 16:23:42,412 fail2ban.actions.action: DEBUG  iptables -n -L INPUT | grep -q fail2ban-ssh
2011-11-21 16:23:42,421 fail2ban.filter : DEBUG  /var/log/auth.log has been modified
2011-11-21 16:23:42,423 fail2ban.filter : DEBUG  Found 10.0.0.9
2011-11-21 16:23:42,423 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2011-11-21 16:23:42,448 fail2ban.actions.action: DEBUG  iptables -n -L INPUT | grep -q fail2ban-ssh returned successfully
2011-11-21 16:23:42,448 fail2ban.actions.action: DEBUG  iptables -I fail2ban-ssh 1 -s 10.0.0.9 -j DROP
/etc/zabbix/fail2ban_helper.sh ssh
2011-11-21 16:23:42,535 fail2ban.comm   : DEBUG  Command: ['status', 'ssh']
2011-11-21 16:23:42,626 fail2ban.comm   : DEBUG  Command: ['status', 'ssh']
2011-11-21 16:23:42,768 fail2ban.actions.action: DEBUG  iptables -I fail2ban-ssh 1 -s 10.0.0.9 -j DROP
/etc/zabbix/fail2ban_helper.sh ssh returned successfully
2011-11-21 16:24:42,950 fail2ban.comm   : DEBUG  Command: ['status']
2011-11-21 16:24:43,032 fail2ban.comm   : DEBUG  Command: ['stop']
2011-11-21 16:24:43,489 fail2ban.filter : DEBUG  ssh: filter terminated
2011-11-21 16:24:43,839 fail2ban.actions: DEBUG  Flush ban list
2011-11-21 16:24:43,839 fail2ban.actions: WARNING [ssh] Unban 10.0.0.9
2011-11-21 16:24:43,839 fail2ban.actions.action: DEBUG  iptables -n -L INPUT | grep -q fail2ban-ssh
2011-11-21 16:24:43,845 fail2ban.actions.action: DEBUG  iptables -n -L INPUT | grep -q fail2ban-ssh returned successfully
2011-11-21 16:24:43,846 fail2ban.actions.action: DEBUG  iptables -D fail2ban-ssh -s 10.0.0.9 -j DROP
/etc/zabbix/fail2ban_helper.sh ssh

@yarikoptic
Copy link
Member

Thanks for all the glory details
FWIW: I see -- so indeed server fails to communicate while it is in the "shutting down" mode, and since it tries to talk to itself (via running unbanning command which invokes fail2ban-client call -- it gets stuck). The problem lies in the locking mechanism since when server performs banning action all threads gets locked ...

as a quick resolution -- pushing the fix which would stop communications first and then will stop the jails upon 'quit' method of the server

@ghost ghost assigned yarikoptic Nov 22, 2011
@yarikoptic
Copy link
Member

Ah apparently syntax for commit message keywords to close issues for github 2.0 has changed:
https://github.com/blog/831-issues-2-0-the-next-generation

So -- this issue was addressed in 1632244

@selivan
Copy link
Author

selivan commented Nov 22, 2011

I'm not a progrmmer and I'm not familiar with github... but as I see, db39c74 is adding support of syslog-ng time format, it does not fix this problem.

@yarikoptic
Copy link
Member

oops -- wrong cut and paste. See
1632244

BF: stop all communications before stopping the jails (Close gh-7)

It is necessary because otherwise if jails actions try to communicate
to the server we are getting a lockup since threads are locked

@selivan
Copy link
Author

selivan commented Nov 22, 2011

Thank you for quick fix and for making this great tool :)

@yarikoptic
Copy link
Member

You are welcome !
I guess that I could take the gratitude as the confirmation that it resolved the issue for you ;-)

yarikoptic added a commit to yarikoptic/fail2ban that referenced this issue Jul 20, 2012
@yarikoptic
BF: stop all communications before stopping the jails (Close fail2ban…
1632244 
…gh-7)

It is necessary because otherwise if jails actions try to communicate
to the server we are getting a lockup since threads are locked
yarikoptic added a commit to yarikoptic/fail2ban that referenced this issue Jul 20, 2012
@yarikoptic
Merge commit '0.8.6' into debian
2fd8be1 
* commit '0.8.6':
  Changelog and version changes for 0.8.6
  Revert "ENH: server.py -- addLogPath with tail=True"
  DOC: updated contact information to direct to github and mailing list
  ENH: added custom timeformat with '.' as separator. Close gh-1
  BF: stop all communications before stopping the jails (Close fail2bangh-7)
  ENH: added logging while stopping the jails
  Add Date: header for sendmail*.conf actions
  BF: gentoo-initd assure /var/run dir + remove stale sock file
  ENH: fix of syntax for compatibility with Python 2.4
  ENH: stay compatible with python < 2.5 (use md5 if hashlib is N/A)
  BF: use hashlib instead of deprecated md5
  ENH: Remove obsolete code from gentoo init script. Bug gentoo#367819.
@ptempier ptempier mentioned this issue Jan 5, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@yarikoptic yarikoptic

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@yarikoptic @selivan