fail2ban and sshd not working

Asked by Konrad Mauz on 2018-06-04

in the default installation the sshd jail does not work.

I raised the loglevel and added vsftpd jail in /etc/fail2ban/jail.d/defaults-debian.conf. Then I tried to login to the server with wrong credentials. Here is the (debug) log output:

018-06-04 12:47:25,241 fail2ban.jail [4091]: DEBUG Starting jail 'sshd'
2018-06-04 12:47:25,241 fail2ban.filterpyinotify[4091]: DEBUG [sshd] filter started (pyinotifier)
2018-06-04 12:47:25,242 fail2ban.jail [4091]: INFO Jail 'sshd' started
2018-06-04 12:47:25,243 fail2ban.jail [4091]: DEBUG Starting jail 'vsftpd'
2018-06-04 12:47:25,243 fail2ban.filterpyinotify[4091]: DEBUG [vsftpd] filter started (pyinotifier)
2018-06-04 12:47:25,244 fail2ban.jail [4091]: INFO Jail 'vsftpd' started
2018-06-04 12:47:49,728 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:47:49,728 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:47:51,335 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:47:51,335 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:47:54,039 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:47:54,040 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:00,138 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:00,139 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:01,171 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:01,172 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:02,775 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:02,775 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:04,561 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:04,561 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:11,962 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:11,962 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:13,100 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:13,100 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:14,703 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:14,704 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:16,525 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:16,526 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:24,088 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:24,089 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:25,264 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:25,264 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:26,867 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:26,867 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:28,633 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:28,634 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
2018-06-04 12:48:36,131 fail2ban.filterpyinotify[4091]: DEBUG Event queue size: 16
2018-06-04 12:48:36,131 fail2ban.filterpyinotify[4091]: DEBUG <_RawEvent cookie=0 mask=0x2 name='' wd=2 >
(END)

and here the /var/log/auth.log:

Jun 4 09:34:47 myhost1 sshd[2549]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:34:47 myhost1 sshd[2549]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:34:49 myhost1 sshd[2549]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:34:50 myhost1 sshd[2549]: Failed password for root from 192.168.178.111 port 60668 ssh2
Jun 4 09:34:59 myhost1 sshd[2549]: message repeated 2 times: [ Failed password for root from 192.168.178.111 port 60668 ssh2]
Jun 4 09:34:59 myhost1 sshd[2549]: error: maximum authentication attempts exceeded for root from 192.168.178.111 port 60668 ssh2 [preauth]
Jun 4 09:34:59 myhost1 sshd[2549]: Disconnecting authenticating user root 192.168.178.111 port 60668: Too many authentication failures [preauth]
Jun 4 09:34:59 myhost1 sshd[2549]: PAM 2 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:02 myhost1 sshd[2551]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:02 myhost1 sshd[2551]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:03 myhost1 sshd[2551]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:05 myhost1 sshd[2551]: Failed password for root from 192.168.178.111 port 60674 ssh2
Jun 4 09:35:11 myhost1 sshd[2551]: message repeated 2 times: [ Failed password for root from 192.168.178.111 port 60674 ssh2]
Jun 4 09:35:11 myhost1 sshd[2551]: error: maximum authentication attempts exceeded for root from 192.168.178.111 port 60674 ssh2 [preauth]
Jun 4 09:35:11 myhost1 sshd[2551]: Disconnecting authenticating user root 192.168.178.111 port 60674: Too many authentication failures [preauth]
Jun 4 09:35:11 myhost1 sshd[2551]: PAM 2 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:13 myhost1 sshd[2553]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:13 myhost1 sshd[2553]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:15 myhost1 sshd[2553]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:17 myhost1 sshd[2553]: Failed password for root from 192.168.178.111 port 60676 ssh2
Jun 4 09:35:22 myhost1 sshd[2553]: message repeated 2 times: [ Failed password for root from 192.168.178.111 port 60676 ssh2]
Jun 4 09:35:22 myhost1 sshd[2553]: error: maximum authentication attempts exceeded for root from 192.168.178.111 port 60676 ssh2 [preauth]
Jun 4 09:35:22 myhost1 sshd[2553]: Disconnecting authenticating user root 192.168.178.111 port 60676: Too many authentication failures [preauth]
Jun 4 09:35:22 myhost1 sshd[2553]: PAM 1 more authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:23 myhost1 sshd[2555]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:23 myhost1 sshd[2555]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:24 myhost1 sshd[2555]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:26 myhost1 sshd[2555]: Failed password for root from 192.168.178.111 port 60680 ssh2
Jun 4 09:35:33 myhost1 sshd[2555]: message repeated 2 times: [ Failed password for root from 192.168.178.111 port 60680 ssh2]

If I try "fail2ban-regex /var/log/auth.log /etc/fail2ban/filter.d/sshd.conf" I got the right matches, but not in the fail2ban daemon.

With vsftpd everything works ok.

t1 sshd[2555]: error: maximum authentication attempts exceeded for root from 192.168.178.111 port 60680 ssh2 [preauth]
Jun 4 09:35:33 myhost1 sshd[2555]: Disconnecting authenticating user root 192.168.178.111 port 60680: Too many authentication failures [preauth]
Jun 4 09:35:33 myhost1 sshd[2555]: PAM 2 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:34 myhost1 sshd[2557]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:34 myhost1 sshd[2557]: userauth_pubkey: key type ssh-dss not in PubkeyAcceptedKeyTypes [preauth]
Jun 4 09:35:36 myhost1 sshd[2557]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root
Jun 4 09:35:38 myhost1 sshd[2557]: Failed password for root from 192.168.178.111 port 60682 ssh2
Jun 4 09:35:44 myhost1 sshd[2557]: message repeated 2 times: [ Failed password for root from 192.168.178.111 port 60682 ssh2]
Jun 4 09:35:44 myhost1 sshd[2557]: error: maximum authentication attempts exceeded for root from 192.168.178.111 port 60682 ssh2 [preauth]
Jun 4 09:35:44 myhost1 sshd[2557]: Disconnecting authenticating user root 192.168.178.111 port 60682: Too many authentication failures [preauth]
Jun 4 09:35:44 myhost1 sshd[2557]: PAM 2 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.178.111 user=root

If I try "fail2ban-regex /var/log/auth.log /etc/fail2ban/filter.d/sshd.conf" I got the right matches, but not in the fail2ban daemon.
Here a the partial output from fail2ban-regex:

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

Use failregex filter file : sshd, basedir: /etc/fail2ban
Use maxlines : 1
Use datepattern : Default Detectors
Use log file : /var/log/auth.log
Use encoding : UTF-8

Results
=======

Failregex: 65 total
|- #) [# of hits] regular expression
| 4) [21] ^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+(?: port \d+)?)?(?: ssh\d*)?(?(cond_user): |(?:(?:(?! from ).)*)$)
| 14) [26] ^pam_unix\(sshd:auth\):\s+authentication failure;\s*logname=\S*\s*uid=\d*\s*euid=\d*\s*tty=\S*\s*ruser=<F-USER>\S*</F-USER>\s*rhost=<HOST>\s.*(?: \[preauth\])?\s*$
| 15) [18] ^(error: )?maximum authentication attempts exceeded for <F-USER>.*</F-USER> from <HOST>(?: port \d+)?(?: on \S+(?: port \d+)?)?(?: ssh\d*)?(?: \[preauth\])?\s*$
`-

Ignoreregex: 0 total

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

Lines: 306 lines, 0 ignored, 65 matched, 241 missed
[processed in 0.07 sec]

Missed line(s): too many to print. Use --print-all-missed to print all 241 lines

With vsftpd everything works ok.

Here the content of /etc/fail2ban/jail.d/defaults-debian.conf:
[sshd]
enabled = true
maxretry = 3
action = ufw
[vsftpd]
enabled = true
maxretry = 3
action = ufw

Have I missed something?

Question information

Language:
English Edit question
Status:
Expired
For:
Ubuntu fail2ban Edit question
Assignee:
No assignee Edit question
Last query:
2018-06-20
Last reply:
2018-07-06
Launchpad Janitor (janitor) said : #1

This question was expired because it remained in the 'Open' state without activity for the last 15 days.

Konrad Mauz (kmauz) said : #2

Still doesn't work.

Launchpad Janitor (janitor) said : #3

This question was expired because it remained in the 'Open' state without activity for the last 15 days.