# Collections/sshd parser triple counts failures

**URL:** <https://discourse.crowdsec.net/t/collections-sshd-parser-triple-counts-failures/1169>\
**Category:** Uncategorized\
**Created:** [February 19, 2023, 12:14pm UTC](https://discourse.crowdsec.net/t/collections-sshd-parser-triple-counts-failures/1169 "2023-02-19T12:14:23Z")\
**Posts on this page:** 4\
**Page:** 1

<div class="post-metadata">

**Author:** ![athan](https://avatars.discourse-cdn.com/v4/letter/a/f475e1/32.png) [@athan](https://discourse.crowdsec.net/u/athan)\
**Post date:** [February 19, 2023, 12:14pm UTC](https://discourse.crowdsec.net/t/collections-sshd-parser-triple-counts-failures/1169/1 "2023-02-19T12:14:23Z")

</div>

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:

```auto
#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 |](https://hub.crowdsec.net/author/crowdsecurity/collections/sshd) 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):

```auto
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:

```auto
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:

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

```

And before I changed the capacity the custom scenario was:

```auto
# 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

```

---

<div class="post-metadata">

**Author:** ![iiAmLoz](https://dub1.discourse-cdn.com/flex013/user_avatar/discourse.crowdsec.net/iiamloz/32/386_2.png) [@iiAmLoz](https://discourse.crowdsec.net/u/iiAmLoz)\
**Post date:** [February 20, 2023, 9:45am UTC](https://discourse.crowdsec.net/t/collections-sshd-parser-triple-counts-failures/1169/2 "2023-02-20T09:45:50Z")

</div>

> [@athan](#):
>
> `(6 events over 1m41.061656148s)`

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.

---

<div class="post-metadata">

**Author:** ![athan](https://avatars.discourse-cdn.com/v4/letter/a/f475e1/32.png) [@athan](https://discourse.crowdsec.net/u/athan)\
**Post date:** [February 20, 2023, 10:17am UTC](https://discourse.crowdsec.net/t/collections-sshd-parser-triple-counts-failures/1169/3 "2023-02-20T10:17:34Z")

</div>

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`.

```auto
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.

---

<div class="post-metadata">

**Author:** ![athan](https://avatars.discourse-cdn.com/v4/letter/a/f475e1/32.png) [@athan](https://discourse.crowdsec.net/u/athan)\
**Post date:** [February 20, 2023, 10:50am UTC](https://discourse.crowdsec.net/t/collections-sshd-parser-triple-counts-failures/1169/4 "2023-02-20T10:50:38Z")

</div>

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:

```auto
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.