[BR]: Problem with multiple PAM-modules and sshd & pam-generic filters

[MatthiasKuehneEllerhold]

Environment:

• Fail2Ban version: 0.11.2-2
• OS, including release name/version: Debian 11
• Fail2Ban installed via OS/distribution mechanisms
• You have not applied any additional foreign patches to the codebase
• Some customizations were done to the configuration (provide details below is so)

The issue:

We have joined our machines to a Samba active directory controller and are using pam_winbind and pam_unix to authenticate users.

We've enabled the sshd and pam-generic filters. Both filters in conjunction with multiple pam_modules are leading to false positives - banning "good" people that successfully authenticated itself.

I think we've found 4 problems (or oddities if you want).

Steps to reproduce

• Install debian
• use multiple PAM modules for authentication (e. g. pam_unix and pam_winbind)
• enable "sshd" and "pam-generic" as fail2ban filters
• successfully connect to the server multiples times

Expected behavior

Not get banned.

Observed behavior

Got banned.

Any additional information

If a users connects successfully via SSH to a machine these log entries are generated:

3634 Jan 23 07:52:34 fileserver sshd[418563]: pam_krb5(sshd:auth): authentication failure; logname=AD\matthias.kuehne uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.1
3635 Jan 23 07:52:34 fileserver sshd[418563]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.1  user=AD\matthias.kuehne
3636 Jan 23 07:52:34 fileserver sshd[418563]: pam_winbind(sshd:auth): getting password (0x00000388)
3637 Jan 23 07:52:34 fileserver sshd[418563]: pam_winbind(sshd:auth): pam_get_item returned a password
3638 Jan 23 07:52:34 fileserver sshd[418563]: pam_winbind(sshd:auth): user 'AD\matthias.kuehne' granted access
3639 Jan 23 07:52:34 fileserver sshd[418563]: Accepted password for AD\\matthias.kuehne from 192.168.1.1 port 49603 ssh2
3640 Jan 23 07:52:34 fileserver sshd[418563]: pam_unix(sshd:session): session opened for user AD\matthias.kuehne(uid=10060) by (uid=0)
3641 Jan 23 07:52:34 fileserver systemd-logind[906]: New session 10905 of user AD\matthias.kuehne.
3642 Jan 23 07:52:34 fileserver systemd: pam_unix(systemd-user:session): session opened for user AD\matthias.kuehne(uid=10060) by (uid=0)

And the fail2ban.log shows:

2023-01-23 07:52:34,868 fail2ban.filter         [380247]: INFO    [sshd] Found 192.168.1.1 - 2023-01-23 07:52:34
2023-01-23 07:52:34,868 fail2ban.filter         [380247]: INFO    [pam-generic] Found 192.168.1.1 - 2023-01-23 07:52:34

After googling for a while we found that there is a "forget" feature in the sshd filter. A successfull connection clears the bad reputation of a user + ip combination. Sadly this is not reported in the fail2ban.log and the eventual ban is shown as in both filters ("sshd" and "pam-generic"). (IMHO Problem 1 & 2)

Disabled the pam-generic filter changes this behavior slightly: the "bad attempts" are still printed in the fail2ban.log but it seems like the forget features works correctly. I can connectly successfully 100 times without a ban.

Enabling it back again: ban galore! So this forgetting is filter-specific and not for all of fail2ban?
We tried to exclude the ssh daemon from the filter regex, but this only works in the filter.d/pam-generic.conf and not in the jail.local:

_ttys_re=(?!ssh)\S+

(Problem 3? idk)

Debugging this further we've discovered that pam-generic only reports pam_unix errors and ignores all the other pam-modules. (Problem 4) So we've created a common.local to override this:

__pam_auth = pam_\S+

The problem is: the pam-generic filter only sees auth failures, because there is no "pam auth succeeded" log entry. SSHd logs successfully entries - thats why the forget feature works great for this filter.

Configuration, dump and another helpful excerpts

Any customizations done to /etc/fail2ban/ configuration

Please see above.

Relevant parts of /var/log/fail2ban.log file:

Please see above.

Relevant lines from monitored log files:

Please see above.

[MatthiasKuehneEllerhold]

Little Update: the "forget" feature doesnt seem to work correctly too.
Weve tried with a manual script where I login every second 50 times - worked.
Our scp-script gets banned after 20 tries.

One connection in auth.log:

5928 Jan 23 13:45:03 fileserver CRON[2603804]: pam_unix(cron:session): session closed for user root
5929 Jan 23 13:45:09 fileserver sshd[2604259]: pam_krb5(sshd:auth): authentication failure; logname=AD\user1 uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.2
5930 Jan 23 13:45:09 fileserver sshd[2604259]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.2  user=AD\user1
5931 Jan 23 13:45:09 fileserver sshd[2604259]: pam_winbind(sshd:auth): getting password (0x00000388)
5932 Jan 23 13:45:09 fileserver sshd[2604259]: pam_winbind(sshd:auth): pam_get_item returned a password
5933 Jan 23 13:45:09 fileserver sshd[2604259]: pam_winbind(sshd:auth): user 'AD\user1' granted access
5934 Jan 23 13:45:10 fileserver sshd[2604259]: Accepted password for AD\\user1 from 192.168.1.2 port 59721 ssh2
5935 Jan 23 13:45:10 fileserver sshd[2604259]: pam_unix(sshd:session): session opened for user AD\user1(uid=10652) by (uid=0)
5936 Jan 23 13:45:10 fileserver systemd-logind[787]: New session 4844 of user AD\user1.
5937 Jan 23 13:45:10 fileserver systemd: pam_unix(systemd-user:session): session opened for user AD\user1(uid=10652) by (uid=0)
5938 Jan 23 13:45:11 fileserver sshd[2604336]: Received disconnect from 192.168.1.2 port 59721:11:
5939 Jan 23 13:45:11 fileserver sshd[2604336]: Disconnected from user AD\\user1 192.168.1.2 port 59721
5940 Jan 23 13:45:11 fileserver sshd[2604259]: pam_unix(sshd:session): session closed for user AD\user1
5941 Jan 23 13:45:11 fileserver sshd[2604259]: pam_winbind(sshd:setcred): user 'AD\user1' OK
5942 Jan 23 13:45:11 fileserver systemd-logind[787]: Session 4844 logged out. Waiting for processes to exit.
5943 Jan 23 13:45:11 fileserver systemd-logind[787]: Removed session 4844.

fail2ban.log:

113 2023-01-23 13:38:05,104 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:38:05
114 2023-01-23 13:45:10,076 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:10
115 2023-01-23 13:45:11,684 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:11
116 2023-01-23 13:45:13,180 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:13
117 2023-01-23 13:45:14,576 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:14
118 2023-01-23 13:45:15,982 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:15
119 2023-01-23 13:45:17,368 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:17
120 2023-01-23 13:45:18,838 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:18
121 2023-01-23 13:45:20,331 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:20
122 2023-01-23 13:45:21,717 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:21
123 2023-01-23 13:45:23,129 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:23
124 2023-01-23 13:45:24,384 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:24
125 2023-01-23 13:45:25,606 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:25
126 2023-01-23 13:45:26,878 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:26
127 2023-01-23 13:45:28,372 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:28
128 2023-01-23 13:45:29,772 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:29
129 2023-01-23 13:45:31,180 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:31
130 2023-01-23 13:45:32,549 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:32
131 2023-01-23 13:45:34,032 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:34
132 2023-01-23 13:45:35,529 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:35
133 2023-01-23 13:45:36,921 fail2ban.filter         [298414]: INFO    [sshd] Found 192.168.1.2 - 2023-01-23 13:45:36
134 2023-01-23 13:45:37,009 fail2ban.actions        [298414]: NOTICE  [sshd] Ban 192.168.1.2

[sebres]

1. The "forget" feature (<F-MLFFORGET> ) doesn't help here at all, it servers completely different purposes - it is just for sanitizing goals (to clean a buffered information gathered for session, because it seems to be closed).
2. I'm also unsure the current "gained" feature <F-MLFGAINED> of multi-line parsing mode would help here against that too - unfortunately this can be considered rather as a part of Regex to reset counter for IP #1243 only (basically it only resets failures by multi-line parsing that are not yet supplied to the failmanager (pending unless connection closed). That expect that the filter becomes completely rewritten (besides other things). For example this has a pre-requirement that the user doesn't switch during all the attempt, otherwise we could get a problem with a bruteforce of one account from another legitimate account - e. g. validuser trying to brute root account and then "reset" all failure by success login as validuser (this is one of the main reasons why Regex to reset counter for IP #1243 is not integrated yet).
3. The abovementioned user-switch issue may be an issue here too (assuming Regex to reset counter for IP #1243 got integrated), because if I interpret the log-excerpt correctly, once (by failure) the user is logged as AD\user1, latter (by accepted) it is logged as AD\\user1 which are obviously different, so it'd additionally expect some post-processing normalizing user name (e. g. ignoring second backslash or domain prefix).
4. pam-generic filter is not a multi-line filter at the moment, thus neither <F-MLFGAINED> nor <F-MLFFORGET> would play any role there.

To cut a long story short, it is hardly possible now (unless #1243 gets fully implemented), no matter how you'd try to rewrite the filter. The only way I see at the moment would be to adjust findtime and maxretry, but I know it is rather a dirty workaround.

[MatthiasKuehneEllerhold]

AD\user1 and AD\\user1 is the same. Different subsystem seem to deal differently with the backslash between the domain name and the user name.

The user1 log is a single scp copy of a small file. Thats why its happening 20 times in 1 minute.

How about this not so dirty workaround (well still extremely dirty but slightly better):

[sshd]
ignoreregex = pam_.+\(sshd:auth\):\s+authentication failure;\s*logname=\S*\s*uid=\d*\s*euid=\d*\s*tty=\S*\s*ruser=\S*\s*rhost=<HOST>\s.*$

Adding this to the sshd filter will ignore ANY pam_* lines BUT STILL capture the "authentication failed" lines.
So in reality a user can try 3 different password (each time only pam will report failures which get ignored) and then sshd will report auth failed -> this gets captures by fail2ban.
So for 3 wrong passwords 1 fail will be captured instead of 4. Reduce the maxretry accordingly to be on the safe side. What do you think?

[sebres]

AD\user1 and AD\\user1 is the same

It is clear to me, just they are different strings (therefore I spoke about normalization above).

How about this not so dirty workaround

It can surely work, but instead you could also try to add it to the failregex as no-failure:

[sshd]
failregex = ^<F-NOFAIL>pam_\w+\(sshd:auth\)</F-NOFAIL>:\s+authentication failure;\s*logname=\S*\s*uid=\d*\s*euid=\d*\s*tty=\S*\s*ruser=\S*\s*rhost=<ADDR>\s
            %(known/failregex)s

(try to avoid catch-alls like .+ or .*).
Compared to ignoreregex solution it would be faster (causes only one match instead of two matches once on failregex hereafter on ignoreregex), but also being better in multi-line mode, because allows to announce (store) IP address for the session, to consider some later failures without an IP in message with the same session-ID.

Just in both cases it may be affected by the afore-mentioned issue with a bruteforce on foreign name (legitimate user trying to launch an attack against different login in-between). It is definitely depending on your logging, so one can't predict how fail2ban would process that after all, but I'd recommend to check how it'd look on some test attempt with interim user switch.

So for 3 wrong passwords 1 fail will be captured instead of 4.

Sure. Ideally a good filter must always find only 1 failure by 1 login attempt... just it is not always possible.