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

fail2ban not banning and just does nothing #1986

Closed
JamesJGoodwin opened this Issue Dec 4, 2017 · 28 comments

Comments

Projects
None yet
5 participants
@JamesJGoodwin

JamesJGoodwin commented Dec 4, 2017

Environment:

  • Fail2Ban version (including any possible distribution suffixes): v0.9.3
  • OS, including release name/version: Ubuntu 16.04.3 LTS
  • Fail2Ban installed via OS/distribution mechanisms
  • You have not applied any additional foreign patches to the codebase

The issue:

fail2ban just not banning. Does nothing.

My jail.local file:

[sshd]
enabled = true
filter = sshd
action = iptables[name=SSH, port=ssh, protocol=tcp]
logpath = /var/log/fail2ssh.log
findtime = 600
maxretry = 6
bantime = 86400

fail2ban-client status

Status
|- Number of jail:      1
`- Jail list:   sshd

Meanwhile in my auth.log:

Dec  4 21:01:59 vps447398 sshd[21628]: Failed password for root from 42.7.26.61 port 3080 ssh2
Dec  4 21:02:13 vps447398 sshd[21628]: message repeated 5 times: [ Failed password for root from 42.7.26.61 port 3080 ssh2]
@sebres

This comment has been minimized.

Member

sebres commented Dec 4, 2017

What do you see in fail2ban.log?
Do you see this IP there?
How many lines [sshd] Found <IP> for the same IP? Please note, that it will banned only after 6 (maxretry) attempt within 10 minutes (findtime) time window.

@sebres sebres added the moreinfo label Dec 4, 2017

@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 4, 2017

What do you see in fail2ban.log?

2017-12-04 21:28:14,814 fail2ban.database       [4031]: INFO    Connected to fail2ban persistent database '/var/lib/fail2ban/fail2ban.sqlite3'
2017-12-04 21:28:14,820 fail2ban.jail           [4031]: INFO    Creating new jail 'sshd'
2017-12-04 21:28:14,833 fail2ban.jail           [4031]: INFO    Jail 'sshd' uses pyinotify
2017-12-04 21:28:14,842 fail2ban.filter         [4031]: INFO    Set jail log file encoding to UTF-8
2017-12-04 21:28:14,845 fail2ban.jail           [4031]: INFO    Initiated 'pyinotify' backend
2017-12-04 21:28:14,850 fail2ban.filter         [4031]: INFO    Set maxRetry = 6
2017-12-04 21:28:14,851 fail2ban.filter         [4031]: INFO    Set findtime = 600
2017-12-04 21:28:14,852 fail2ban.filter         [4031]: INFO    Set jail log file encoding to UTF-8
2017-12-04 21:28:14,852 fail2ban.actions        [4031]: INFO    Set banTime = 86400
2017-12-04 21:28:14,856 fail2ban.filter         [4031]: INFO    Added logfile = /var/log/auth.log
2017-12-04 21:28:14,860 fail2ban.filter         [4031]: INFO    Set maxlines = 10
2017-12-04 21:28:14,906 fail2ban.server         [4031]: INFO    Jail sshd is not a JournalFilter instance
2017-12-04 21:28:14,911 fail2ban.jail           [4031]: INFO    Jail 'sshd' started

There's no any Found <IP> or Ban <IP> messages. Also, /var/log/fail2ssh.log is empty.

@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 4, 2017

May this issue been caused because of /etc/ssh(instead of /etc/sshd) on my machine?

@sebres

This comment has been minimized.

Member

sebres commented Dec 4, 2017

May this issue been caused because of /etc/ssh(instead of /etc/sshd) on my machine?

Nope.

What do you see if you execute this:

ln="Dec  4 21:01:59 vps447398 sshd[21628]: Failed password for root from 42.7.26.61 port 3080 ssh2"
fail2ban-regexp "$ln" /etc/fail2ban/filter.d/sshd.conf

Tested with current 0.9.x version:
Lines: 1 lines, 0 ignored, 1 matched, 0 missed.

And this:

?sudo? fail2ban-regex /var/log/auth.log /etc/fail2ban/filter.d/sshd.conf
@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 4, 2017

Lines: 1 lines, 0 ignored, 1 matched, 0 missed [processed in 0.00 sec]

And

Lines: 18312 lines, 0 ignored, 4938 matched, 13374 missed [processed in 12.70 sec]
@sebres

This comment has been minimized.

Member

sebres commented Dec 4, 2017

Hmm... Strange... No further ideas, except pyinotify backend does not work on your machine (tried "polling"?).
Can you puts fail2ban into DEBUG mode?

sudo fail2ban-client set loglevel DEBUG

Or if does not work, just start within DEBUG level (set it fail2ban.conf and restart).

And provide an excerpt of /var/log/fail2ban.log after some failure in auth.log...

Don't forget to switch back if you are ready...

sudo fail2ban-client set loglevel INFO
@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 4, 2017

Here's the logs of fail2ban.log after log level DEBUG was set:

2017-12-04 23:59:38,287 fail2ban.transmitter    [5325]: DEBUG   Command: ['stop']
2017-12-04 23:59:38,287 fail2ban.asyncserver    [5325]: DEBUG   Removed socket file /var/run/fail2ban/fail2ban.sock
2017-12-04 23:59:38,287 fail2ban.asyncserver    [5325]: DEBUG   Socket shutdown
2017-12-04 23:59:38,287 fail2ban.server         [5325]: INFO    Stopping all jails
2017-12-04 23:59:38,287 fail2ban.server         [5325]: DEBUG   Stopping jail sshd
2017-12-04 23:59:39,126 fail2ban.actions        [5325]: DEBUG   Flush ban list
2017-12-04 23:59:39,127 fail2ban.action         [5325]: DEBUG   iptables -w -D INPUT -p tcp --dport ssh -j f2b-SSH
iptables -w -F f2b-SSH
iptables -w -X f2b-SSH
2017-12-04 23:59:39,229 fail2ban.action         [5325]: DEBUG   iptables -w -D INPUT -p tcp --dport ssh -j f2b-SSH
iptables -w -F f2b-SSH
iptables -w -X f2b-SSH -- stdout: b''
2017-12-04 23:59:39,229 fail2ban.action         [5325]: DEBUG   iptables -w -D INPUT -p tcp --dport ssh -j f2b-SSH
iptables -w -F f2b-SSH
iptables -w -X f2b-SSH -- stderr: b''
2017-12-04 23:59:39,229 fail2ban.action         [5325]: DEBUG   iptables -w -D INPUT -p tcp --dport ssh -j f2b-SSH
iptables -w -F f2b-SSH
iptables -w -X f2b-SSH -- returned successfully
2017-12-04 23:59:39,230 fail2ban.actions        [5325]: DEBUG   sshd: action terminated
2017-12-04 23:59:39,230 fail2ban.jail           [5325]: INFO    Jail 'sshd' stopped
2017-12-04 23:59:39,239 fail2ban.server         [5325]: DEBUG   Remove PID file /var/run/fail2ban/fail2ban.pid
2017-12-04 23:59:39,239 fail2ban.server         [5325]: INFO    Exiting Fail2ban
2017-12-04 23:59:39,457 fail2ban.server         [24399]: INFO    Changed logging target to /var/log/fail2ban.log for Fail2ban v0.9.3
2017-12-04 23:59:39,457 fail2ban.database       [24399]: INFO    Connected to fail2ban persistent database '/var/lib/fail2ban/fail2ban.sqlite3'
2017-12-04 23:59:39,462 fail2ban.jail           [24399]: INFO    Creating new jail 'sshd'
2017-12-04 23:59:39,473 fail2ban.jail           [24399]: INFO    Jail 'sshd' uses pyinotify
2017-12-04 23:59:39,482 fail2ban.filter         [24399]: INFO    Set jail log file encoding to UTF-8
2017-12-04 23:59:39,484 fail2ban.jail           [24399]: INFO    Initiated 'pyinotify' backend
2017-12-04 23:59:39,489 fail2ban.filter         [24399]: INFO    Set jail log file encoding to UTF-8
2017-12-04 23:59:39,489 fail2ban.filter         [24399]: INFO    Set findtime = 600
2017-12-04 23:59:39,489 fail2ban.actions        [24399]: INFO    Set banTime = 86400
2017-12-04 23:59:39,490 fail2ban.filter         [24399]: INFO    Set maxRetry = 6
2017-12-04 23:59:39,494 fail2ban.filter         [24399]: INFO    Added logfile = /var/log/fail2ban.log
2017-12-04 23:59:39,497 fail2ban.filter         [24399]: INFO    Set maxlines = 10
2017-12-04 23:59:39,542 fail2ban.server         [24399]: INFO    Jail sshd is not a JournalFilter instance
2017-12-04 23:59:39,546 fail2ban.jail           [24399]: INFO    Jail 'sshd' started

Also, nothing was written to fail2ban.log since I set it's log level to DEBUG. And I'm still getting spammed with bruteforce:

Dec  5 00:05:19 vps447398 sshd[25196]: Failed password for root from 42.7.26.61 port 64360 ssh2
@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 5, 2017

Just tried to ban myself on my server previously connected to VPN and entering wrong password 6 times and here's what I've got in my auth.log:

Dec  5 01:08:13 vps447398 sshd[3236]: Failed password for root from 94.242.62.105 port 58699 ssh2
Dec  5 01:08:19 vps447398 sshd[3236]: Failed password for root from 94.242.62.105 port 58699 ssh2
Dec  5 01:08:24 vps447398 sshd[3236]: Failed password for root from 94.242.62.105 port 58699 ssh2
Dec  5 01:08:31 vps447398 sshd[3236]: Failed password for root from 94.242.62.105 port 58699 ssh2
Dec  5 01:08:37 vps447398 sshd[3236]: Failed password for root from 94.242.62.105 port 58699 ssh2
Dec  5 01:08:37 vps447398 sshd[3236]: error: maximum authentication attempts exceeded for root from 94.242.62.105 port 58699 ssh2 [preauth]
Dec  5 01:08:37 vps447398 sshd[3236]: Disconnecting: Too many authentication failures [preauth]
Dec  5 01:08:37 vps447398 sshd[3236]: PAM 5 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=94.242.62.105  user=root
Dec  5 01:08:37 vps447398 sshd[3236]: PAM service(sshd) ignoring max retries; 6 > 3

After entering wrong password 6 times in a row host dropped the connection, but then I reconnected and still was able to enter password. Hope there's some helpfull data that could help you to find out what's the issue.

@sebres

This comment has been minimized.

Member

sebres commented Dec 5, 2017

I'm staying with my guess - something wrong with pyinotify... Tried "polling"?
Otherwise try again with HEAVYDEBUG...
BTW your version is a bit obsolete... Can you try some newer version (>= 0.9.7, 0.10 or even 0.11)?

@scampuza

This comment has been minimized.

scampuza commented Dec 5, 2017

@JamesJGoodwin hi !

I have the very same issue, but in my case, I have a jail/rule watching an Apache HTTP Server access_log, trying to identify users hitting hard the web servers.

It stopped working suddenly, no errors, no traces in the logs. I even enabled the DEBUG mode but nothing appears.

@scampuza

This comment has been minimized.

scampuza commented Dec 5, 2017

I was about to open a new issue, but as this is similar to the one I'm having, I will follow up this...

@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 5, 2017

I've just installed v0.10.2 dev1 from fail2ban.org and seems like I did well and everything is working just fine, but there's no any bruteforce running currently on my server so I can't properly say if fail2ban working or not. I'll be in touch.

Tried "polling"

What is it? What am I supposed to do to enable it?

@scampuza hello! It seems like not fail2ban issue, but vendor's OS issue. Because earlier my server was hosted in Russia with OpenVZ virtualization and fail2ban worked just fine there, but then I moved to OVH server which has KVM virtualization and it's not working on this type of machine. Maybe there's just some kind of OS restrictions, idk.

@sebres

This comment has been minimized.

Member

sebres commented Dec 5, 2017

What is "polling"?

"polling" is another file-related backend fail2ban can use.

What am I supposed to do to enable it?

For example set it in jail.local:

[sshd]
backend = polling
@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 5, 2017

Just tried to ban myself by entering wrong password and still nothing happens.

Dec  5 16:21:12 vps447398 systemd-logind[1265]: New session 192 of user root.
Dec  5 16:22:12 vps447398 sshd[27225]: error: Could not load host key: /etc/ssh/ssh_host_ed25519_key
Dec  5 16:22:17 vps447398 sshd[27225]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=94.242.62.108  user=root
Dec  5 16:22:19 vps447398 sshd[27225]: Failed password for root from 94.242.62.108 port 58410 ssh2
Dec  5 16:23:00 vps447398 sshd[27225]: message repeated 5 times: [ Failed password for root from 94.242.62.108 port 58410 ssh2]
Dec  5 16:23:00 vps447398 sshd[27225]: error: maximum authentication attempts exceeded for root from 94.242.62.108 port 58410 ssh2 [preauth]
Dec  5 16:23:00 vps447398 sshd[27225]: Disconnecting: Too many authentication failures [preauth]
Dec  5 16:23:00 vps447398 sshd[27225]: PAM 5 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=94.242.62.108  user=root
Dec  5 16:23:00 vps447398 sshd[27225]: PAM service(sshd) ignoring max retries; 6 > 3

fail2ban.log also is empty. None Found or Ban. I think I should contact my hoster's support in this case.

@sebres

This comment has been minimized.

Member

sebres commented Dec 5, 2017

I think I should contact my hoster's support in this case.

Well, I don't think so. If fail2ban cannot ban (because of some reason like missing kernel features, etc.) you'll definitely get an error in fail2ban.log.
At least you'll see an [sshd] Ban <IP> before...

Your case - no failure will be recognized. This looks like the filter (backend):

  • either does not seen the log-file is actualized;
  • or just does not match (for some reasons, but you've tested it with fail2ban-regex).

Therefore I assumed that this is pyinotify-issue (possibly the modified-event just does not reach us).
So either try polling or use HEAVYDEBUG loglevel and see what fail2ban.log said if log-file get actualized.

@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 5, 2017

Well, enabling HEAVYDEBUG is caused very huge log file(now it's size is 332MB and it's still growing). Is it normal behavior?

@sebres

This comment has been minimized.

Member

sebres commented Dec 5, 2017

Yes.
But do you see there something like Working on line ... <IP>? resp. something else that signals pyinotify works...

@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 5, 2017

After a few minutes under HEAVYDEBUG log file became unreadable because of it's size(1,2GB). So I had to stop fail2ban, clear logs and then start it for a few seconds. Now what I've got:

Total lines: 62018
Working on line matched 2611 lines

Take a closer look on fail2ban.log

@sebres

This comment has been minimized.

Member

sebres commented Dec 5, 2017

Arghhh...
You path is wrong: you observes /var/log/fail2ban.log instead of /var/log/auth.log.

BTW. Therefore also a great "recursion" in heavydebug mode... :)

@JamesJGoodwin

This comment has been minimized.

JamesJGoodwin commented Dec 5, 2017

Damn, shame on me. I'm so sorry I took so much time from you. Now it's working, much thanks!

2017-12-05 17:41:41,606 fail2ban.filter         [5214]: INFO    [sshd] Found 94.242.62.108 - 2017-12-05 17:41:41
2017-12-05 17:41:43,610 fail2ban.filter         [5214]: INFO    [sshd] Found 94.242.62.108 - 2017-12-05 17:41:43
2017-12-05 17:42:39,688 fail2ban.filter         [5214]: INFO    [sshd] Found 94.242.62.108 - 2017-12-05 17:42:39
2017-12-05 17:42:39,689 fail2ban.filter         [5214]: INFO    [sshd] Found 94.242.62.108 - 2017-12-05 17:42:39
2017-12-05 17:42:39,736 fail2ban.actions        [5214]: NOTICE  [sshd] Ban 94.242.62.108
@sebres

This comment has been minimized.

Member

sebres commented Dec 5, 2017

Glad it works, thus I'm closing the issue.

@sebres sebres closed this Dec 5, 2017

@kirk86

This comment has been minimized.

kirk86 commented May 29, 2018

@sebres I'm having exactly the same issue as @JamesJGoodwin but with the difference that on Arch the file /var/log/auth.log doesn't exist everything is handled by systemd and journalctl shows efforts of brute force ssh attacks but fail2ban doesn't ban anything I"m trying to ban myself but nothing.

Issuing the following commands:

fail2ban-regex "$ln" /etc/fail2ban/filter.d/sshd.conf

Running tests
=============

Use   failregex filter file : sshd, basedir: /etc/fail2ban
Use         maxlines : 1
Use      datepattern : Default Detectors
Use      single line : May 28 21:39:04 ghost sshd[2824]: Failed password ...


Results
=======

Failregex: 1 total
|-  #) [# of hits] regular expression
|   4) [1] ^Failed \b(?!publickey)\S+ for (?P<cond_inv>invalid user )?<F-USER>(?P<cond_user>\S+)|(?(cond_inv)(?:(?! from ).)*?|[^:]+)</F-USER> from <HOST>(?: (?:port \d+|on \S+)){0,2}(?: ssh\d*)?(?(cond_user): |(?:(?:(?! from ).)*)$)
`-

Ignoreregex: 0 total

Date template hits:
|- [# of hits] date format
|  [1] {^LN-BEG}(?:DAY )?MON Day %k:Minute:Second(?:\.Microseconds)?(?: ExYear)?
`-

Lines: 1 lines, 0 ignored, 1 matched, 0 missed
[processed in 0.00 sec]
sudo fail2ban-regex "$ln" /etc/fail2ban/filter.d/sshd.conf

Running tests
=============

Use   failregex filter file : sshd, basedir: /etc/fail2ban
Use         maxlines : 1
Use      datepattern : Default Detectors
Use      single line : May 28 21:39:04 ghost sshd[2824]: Failed password ...


Results
=======

Failregex: 1 total
|-  #) [# of hits] regular expression
|   4) [1] ^Failed \b(?!publickey)\S+ for (?P<cond_inv>invalid user )?<F-USER>(?P<cond_user>\S+)|(?(cond_inv)(?:(?! from ).)*?|[^:]+)</F-USER> from <HOST>(?: (?:port \d+|on \S+)){0,2}(?: ssh\d*)?(?(cond_user): |(?:(?:(?! from ).)*)$)
`-

Ignoreregex: 0 total

Date template hits:
|- [# of hits] date format
|  [1] {^LN-BEG}(?:DAY )?MON Day %k:Minute:Second(?:\.Microseconds)?(?: ExYear)?
`-

Lines: 1 lines, 0 ignored, 1 matched, 0 missed
[processed in 0.00 sec]

Any ideas on what changes should I make?

@distler

This comment has been minimized.

Contributor

distler commented May 31, 2018

I've seen the same issue on one of my machines.

Deleting the fail2ban.sqlite3 database and restarting fixed the problem.

@sebres

This comment has been minimized.

Member

sebres commented Jun 1, 2018

everything is handled by systemd and journalctl shows efforts of brute force ssh attacks but fail2ban doesn't ban anything

@kirk86 I may be just wrong config. You should set your backend for sshd jail to systemd. File-backends (like pyinotify, polling as well as auto) do montoring of the log-files only (not systemd-journals).

[sshd]
backend = systemd

And for check it via fail2ban-regex you can use:

# for >= 0.10:
fail2ban-regex systemd-journal sshd
# or for 0.9:
fail2ban-regex systemd-journal /etc/fail2ban/filter.d/sshd.conf
@kirk86

This comment has been minimized.

kirk86 commented Jun 1, 2018

@distler you're right deleting persistent database does help during debugging.
@sebres wrong config was also an issue as well.

I have a questions though, does fail2ban require iptables.service to be enabled and running in order to operate?

@sebres

This comment has been minimized.

Member

sebres commented Jun 1, 2018

does fail2ban require iptables.service to be enabled and running in order to operate?

This is platform- resp. distribution-depended, e. g. debian's don't have iptables.service (but however have iptables subsystem). Some distribution have different firewall systems, and we've different actions to operate with, e.g. firewalld, pf, iptables, nftables, etc. Which firewall you'll use is your choice.
And there is also the question what exactly is supported by your kernel...

@kirk86

This comment has been minimized.

kirk86 commented Jun 1, 2018

@sebres thanks for the answer.

there is also the question what exactly is supported by your kernel...

I presume that no matter what distro, the kernel support is pretty much the same across distros since the kernel is one thing that is ubiquitous?

@distler

This comment has been minimized.

Contributor

distler commented Jun 4, 2018

@distler you're right deleting persistent database does help during debugging.

I find that I have to delete it, periodically; otherwise fail2ban just stops banning (just as you describe). Haven't been able to pin down the source of the corruption, though.

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