Collections/sshd parser triple counts failures

I’ve just had a genuine user banned because they couldn’t remember their username twice, when I thought I had it configured to require more than 5 failures to trigger a ban.

I have the collections/sshd installed, but also have an extra scenario configured, simply so I can have it look for a capacity (still 5 before this) over a longer time period of 1 hour.

It appears that the way sshd-logs.yaml is set up it will count each of three separate lines for the same failure as separate events. Thus two failures equates to 6 events and goes over the capacity of 5.

Specifically that parser is matching on all of: SSHD_INVALID_USER, SSHD_PREAUTH_AUTHENTICATING_USER and … something else? I only have the one pam-related line for SSHD_AUTH_FAIL, and nothing seems to match on the Failed none for invalid user lines. But given my acquis.yaml is:

#Generated acquisition file - wizard.sh (service: sshd) / files : /var/log/auth.log
filenames:
  - /var/log/auth.log
labels:
  type: syslog
---
#Generated acquisition file - wizard.sh (service: mysql) / files : /var/log/mysql/error.log
filenames:
  - /var/log/mysql/error.log
labels:
  type: mysql
---
#Generated acquisition file - wizard.sh (service: linux) / files : /var/log/syslog /var/log/kern.log /var/log/messages
filenames:
  - /var/log/syslog
  - /var/log/kern.log
  - /var/log/messages
labels:
  type: syslog
---

And grep -F <ip> /var/log/auth.log /var/log/mysql/error.log /var/log/syslog /var/log/kern.log /var/log/messages | grep -Fc sshd says 7, there’s no double-counting of sshd lines otherwise.

Is this actually intended ? Does this mean the provided scenario’s capacity of 5 is intended to ban after only two invalid attempts ?

I can accept this is just a documentation issue, because Hub | doesn’t mention this at all, and there’s no comment in the ssh-bf.yaml scenario file to explain why it has ‘5’ in it.

For reference, the anonymised auth.log is the following. These are the only lines for that IP (log file started at 06:25:39):

Feb 19 09:33:37 river sshd[2198583]: Invalid user user1 from A.B.C.D port 52868
Feb 19 09:34:24 river sshd[2198583]: Failed none for invalid user user1 from A.B.C.D port 52868 ssh2
Feb 19 09:34:26 river sshd[2198583]: Connection closed by invalid user user1 A.B.C.D port 52868 [preauth]
Feb 19 09:34:37 river sshd[2199400]: Invalid user user2 from A.B.C.D port 52870
Feb 19 09:34:41 river sshd[2199400]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=A.B.C.D
Feb 19 09:34:43 river sshd[2199400]: Failed password for invalid user user2 from A.B.C.D port 52870 ssh2
Feb 19 09:35:18 river sshd[2199400]: Connection closed by invalid user user2 A.B.C.D port 52870 [preauth]

and the anonymised crowdsec.log lines are:

time="19-02-2023 09:35:18" level=info msg="Ip A.B.C.D performed 'fysh/ssh-bf' (6 events over 1m41.061656148s) at 2023-02-19 09:35:18.26682107 +0000 UTC"
time="19-02-2023 09:35:18" level=info msg="(<api credential>/crowdsec) fysh/ssh-bf by ip A.B.C.D (GB/5607) : 72h ban on Ip

The installed collection is:

crowdsecurity/sshd    ✔️ enabled   0.2       /etc/crowdsec/collections/sshd.yaml

And before I changed the capacity the custom scenario was:

# ssh bruteforce
type: leaky
name: fysh/ssh-bf
description: "Detect ssh bruteforce 5/1h"
filter: "evt.Meta.log_type == 'ssh_failed-auth'"
leakspeed: "1h"
references:
  - http://wikipedia.com/ssh-bf-is-bad
capacity: 5
groupby: evt.Meta.source_ip
blackhole: 1m
reprocess: true
labels:
 service: ssh
 type: bruteforce
 remediation: true
---
# ssh user-enum
type: leaky
name: fysh/ssh-bf_user-enum
description: "Detect ssh user enum bruteforce 5/1h"
filter: evt.Meta.log_type == 'ssh_failed-auth'
groupby: evt.Meta.source_ip
distinct: evt.Meta.target_user
leakspeed: "1h"
capacity: 5
blackhole: 1m
labels:
 service: ssh
 type: bruteforce
 remediation: true

So there was 6 events over 1m 41s, so it seems the sshd might be logging to multiple files so it will treat these events as unique. As you grepped the IP out of all the files you can see there was 7 events. So you either need to remove the duplicated log sources or double the capacity to account for the duplicated events.

If it wasn’t clear, the 7 events that grep count found are precisely those I cited a little further down. These precisely cover the cited 1m41s.

Feb 19 09:33:37 river sshd[2198583]: Invalid user user1 from A.B.C.D port 52868
Feb 19 09:34:24 river sshd[2198583]: Failed none for invalid user user1 from A.B.C.D port 52868 ssh2
Feb 19 09:34:26 river sshd[2198583]: Connection closed by invalid user user1 A.B.C.D port 52868 [preauth]
Feb 19 09:34:37 river sshd[2199400]: Invalid user user2 from A.B.C.D port 52870
Feb 19 09:34:41 river sshd[2199400]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=A.B.C.D
Feb 19 09:34:43 river sshd[2199400]: Failed password for invalid user user2 from A.B.C.D port 52870 ssh2
Feb 19 09:35:18 river sshd[2199400]: Connection closed by invalid user user2 A.B.C.D port 52870 [preauth]

Literally no other mentions of the IP in question in any of the acquis.yaml configured files.

In some of my own testing:

  1. Invalid user <ser> from <ip> port <port> is caused the moment the invalid user is offered. Keep in mind that this server has an AllowUsers directive in sshd_config, so it knows the user is invalid the moment it is offered before any check on the actual auth is performed.
  2. Failed password for invalid user <user> from <ip> port <port> is caused by attempts to provide a password for the same connection. This also causes the pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=<ip>.
  3. Connection closed by invalid user <user> <ip> port <port> [preauth] then occurs when the connection is closed.

And those match SSHD_INVALID_USER, SSHD_AUTH_FAIL (for the pam message), and SSHD_PREAUTH_AUTHENTICATING_USER.

I’m still confused as to why it gets to a count of 6 when there’s only 2x SSHD_INVALID_USER + 2x SSHD_INVALID_USER and one SSHD_INVALID_USER.

And to be sure, although I have /etc/crowdsec/acquis.d configured it doesn’t even exist, never mind have anything in it to pick up extra log files. There’s also no other mentions of /var/log anywhere under /etc/crowdsec.

What would be useful is if cscli explain ... gave information about which scenarios would be triggered (overflowed) by the supplied input. What it does show is:

line: Feb 19 09:33:39 river sshd[2199400]: Invalid user user2 from A.B.C.D port 52870
        ├ s00-raw
        |       ├ 🟢 crowdsecurity/non-syslog (first_parser)
        |       └ 🔴 crowdsecurity/syslog-logs
        ├ s01-parse
        |       ├ 🔴 crowdsecurity/mysql-logs
        |       └ 🟢 crowdsecurity/sshd-logs (+6 ~1)
        ├ s02-enrich
        |       ├ 🔴 crowdsecurity/dateparse-enrich
        |       ├ 🟢 crowdsecurity/geoip-enrich (+13)
        |       ├ 🟢 crowdsecurity/whitelists (unchanged)
        |       └ 🟢 fysh/whitelists (unchanged)
        ├-------- parser success 🟢
        ├ Scenarios
                ├ 🟢 crowdsecurity/ssh-bf
                ├ 🟢 crowdsecurity/ssh-bf_user-enum
                ├ 🟢 crowdsecurity/ssh-slow-bf
                ├ 🟢 crowdsecurity/ssh-slow-bf_user-enum
                ├ 🟢 fysh/ssh-bf
                └ 🟢 fysh/ssh-bf_user-enum

line: Feb 19 09:33:39 river sshd[2199400]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=A.B.C.D
        ├ s00-raw
        |       ├ 🟢 crowdsecurity/non-syslog (first_parser)
        |       └ 🔴 crowdsecurity/syslog-logs
        ├ s01-parse
        |       ├ 🔴 crowdsecurity/mysql-logs
        |       └ 🟢 crowdsecurity/sshd-logs (+8 ~1)
        ├ s02-enrich
        |       ├ 🔴 crowdsecurity/dateparse-enrich
        |       ├ 🟢 crowdsecurity/geoip-enrich (+13)
        |       ├ 🟢 crowdsecurity/whitelists (unchanged)
        |       └ 🟢 fysh/whitelists (unchanged)
        ├-------- parser success 🟢
        ├ Scenarios
                ├ 🟢 crowdsecurity/ssh-bf
                ├ 🟢 crowdsecurity/ssh-bf_user-enum
                ├ 🟢 crowdsecurity/ssh-slow-bf
                ├ 🟢 crowdsecurity/ssh-slow-bf_user-enum
                ├ 🟢 fysh/ssh-bf
                └ 🟢 fysh/ssh-bf_user-enum

line: Feb 19 09:33:39 river sshd[2199400]: Failed password for invalid user user2 from A.B.C.D port 52870 ssh2
        ├ s00-raw
        |       ├ 🟢 crowdsecurity/non-syslog (first_parser)
        |       └ 🔴 crowdsecurity/syslog-logs
        ├ s01-parse
        |       ├ 🔴 crowdsecurity/mysql-logs
        |       └ 🟢 crowdsecurity/sshd-logs (+8 ~1)
        ├ s02-enrich
        |       ├ 🔴 crowdsecurity/dateparse-enrich
        |       ├ 🟢 crowdsecurity/geoip-enrich (+13)
        |       ├ 🟢 crowdsecurity/whitelists (unchanged)
        |       └ 🟢 fysh/whitelists (unchanged)
        ├-------- parser success 🟢
        ├ Scenarios
                ├ 🟢 crowdsecurity/ssh-bf
                ├ 🟢 crowdsecurity/ssh-bf_user-enum
                ├ 🟢 crowdsecurity/ssh-slow-bf
                ├ 🟢 crowdsecurity/ssh-slow-bf_user-enum
                ├ 🟢 fysh/ssh-bf
                └ 🟢 fysh/ssh-bf_user-enum

line: Feb 19 09:33:39 river sshd[2199400]: Connection closed by invalid user user2 A.B.C.D port 52870 [preauth]
        ├ s00-raw
        |       ├ 🟢 crowdsecurity/non-syslog (first_parser)
        |       └ 🔴 crowdsecurity/syslog-logs
        ├ s01-parse
        |       ├ 🔴 crowdsecurity/mysql-logs
        |       └ 🟢 crowdsecurity/sshd-logs (+6 ~1)
        ├ s02-enrich
        |       ├ 🔴 crowdsecurity/dateparse-enrich
        |       ├ 🟢 crowdsecurity/geoip-enrich (+13)
        |       ├ 🟢 crowdsecurity/whitelists (unchanged)
        |       └ 🟢 fysh/whitelists (unchanged)
        ├-------- parser success 🟢
        ├ Scenarios
                ├ 🟢 crowdsecurity/ssh-bf
                ├ 🟢 crowdsecurity/ssh-bf_user-enum
                ├ 🟢 crowdsecurity/ssh-slow-bf
                ├ 🟢 crowdsecurity/ssh-slow-bf_user-enum
                ├ 🟢 fysh/ssh-bf
                └ 🟢 fysh/ssh-bf_user-enum

line: Feb 19 09:33:37 river sshd[2198583]: Invalid user user1 from A.B.C.D port 52868
        ├ s00-raw
        |       ├ 🟢 crowdsecurity/non-syslog (first_parser)
        |       └ 🔴 crowdsecurity/syslog-logs
        ├ s01-parse
        |       ├ 🔴 crowdsecurity/mysql-logs
        |       └ 🟢 crowdsecurity/sshd-logs (+6 ~1)
        ├ s02-enrich
        |       ├ 🔴 crowdsecurity/dateparse-enrich
        |       ├ 🟢 crowdsecurity/geoip-enrich (+13)
        |       ├ 🟢 crowdsecurity/whitelists (unchanged)
        |       └ 🟢 fysh/whitelists (unchanged)
        ├-------- parser success 🟢
        ├ Scenarios
                ├ 🟢 crowdsecurity/ssh-bf
                ├ 🟢 crowdsecurity/ssh-bf_user-enum
                ├ 🟢 crowdsecurity/ssh-slow-bf
                ├ 🟢 crowdsecurity/ssh-slow-bf_user-enum
                ├ 🟢 fysh/ssh-bf
                └ 🟢 fysh/ssh-bf_user-enum

line: Feb 19 09:33:38 river sshd[2198583]: Failed none for invalid user user1 from A.B.C.D port 52868 ssh2
        ├ s00-raw
        |       ├ 🟢 crowdsecurity/non-syslog (first_parser)
        |       └ 🔴 crowdsecurity/syslog-logs
        ├ s01-parse
        |       ├ 🔴 crowdsecurity/mysql-logs
        |       └ 🔴 crowdsecurity/sshd-logs
        └-------- parser failure 🔴

line: Feb 19 09:33:38 river sshd[2198583]: Connection closed by invalid user user1 A.B.C.D port 52868 [preauth]
        ├ s00-raw
        |       ├ 🟢 crowdsecurity/non-syslog (first_parser)
        |       └ 🔴 crowdsecurity/syslog-logs
        ├ s01-parse
        |       ├ 🔴 crowdsecurity/mysql-logs
        |       └ 🟢 crowdsecurity/sshd-logs (+6 ~1)
        ├ s02-enrich
        |       ├ 🔴 crowdsecurity/dateparse-enrich
        |       ├ 🟢 crowdsecurity/geoip-enrich (+13)
        |       ├ 🟢 crowdsecurity/whitelists (unchanged)
        |       └ 🟢 fysh/whitelists (unchanged)
        ├-------- parser success 🟢
        ├ Scenarios
                ├ 🟢 crowdsecurity/ssh-bf
                ├ 🟢 crowdsecurity/ssh-bf_user-enum
                ├ 🟢 crowdsecurity/ssh-slow-bf
                ├ 🟢 crowdsecurity/ssh-slow-bf_user-enum
                ├ 🟢 fysh/ssh-bf
                └ 🟢 fysh/ssh-bf_user-enum

which indeed shows 6 of the lines passing through to scenarios, including fysh/ssh-bf.

The issue here does lie in part with how sshd logs this scenario. Whilst it’s true that if SSHD_INVALID_USER triggers then you already know the IP is bad and don’t care about any password attempts, or the closing of the connection, you do still need to trigger off at least one of those in the valid user case.

This scenario could fix it by splitting out parsing such that there’s only one set for invalid user, and another set for valid user but failed auth.

A reminder that in this case it was a genuine user forgetting their credentials, and from their point of view they only made two attempts with wrong usernames. Yet they got banned as if they had made 6 attempts.

Any ‘invalid user’ attempt should only increment the overflow by one.

If it’s a genuine user they need leeway to correct their typo/memory, and if it’s a bad actor then either they’ll go away after the one invalid user or likely try many more and trigger the scenario anyway.

I guess I might just drop this scenario in favour of writing a custom one that separates the parsing, rather than trying to merge it all into one with some unforseen consequences.

This thread can at least serve as a heads up for anyone else who encounters the same phenomena.

1 Like