[SSHGuard-users] Missed detections of ssh abuses

[Jonathan W. <jw...@at...>]

Hi all

I was wondering whether anyone could provide some insight into why a
particular host was not blocked by sshguard 1.6.4 on one of my servers. 
Sshguard is run using

  /usr/local/sbin/sshguard -w <internal-lan> -l /var/log/messages \
    -a 40 -p 420 -s 1800

The content of the messages file around the time of the missed detection was
as follows.

Oct 24 05:52:44 sshd[5253]: Did not receive identification string from 212.129.60.203 port 62662
Oct 24 05:52:47 sshd[5254]: Invalid user ubnt from 212.129.60.203 port 62676
Oct 24 05:52:47 sshd[5254]: input_userauth_request: invalid user ubnt [preauth]
Oct 24 05:52:48 sshd[5254]: Failed password for invalid user ubnt from 212.129.60.203 port 62676 ssh2
Oct 24 05:52:48 sshd[5254]: Disconnected from 212.129.60.203 port 62676 [preauth]
Oct 24 05:52:56 sshd[5275]: Invalid user admin from 212.129.60.203 port 64796
Oct 24 05:52:56 sshd[5275]: input_userauth_request: invalid user admin [preauth]
Oct 24 05:52:57 sshd[5275]: Failed password for invalid user admin from 212.129.60.203 port 64796 ssh2
Oct 24 05:52:57 sshd[5275]: Disconnected from 212.129.60.203 port 64796 [preauth]
Oct 24 05:53:02 sshd[5291]: User root from 212.129.60.203 not allowed because not listed in AllowUsers
Oct 24 05:53:02 sshd[5291]: input_userauth_request: invalid user root [preauth]
Oct 24 05:53:03 sshd[5291]: Failed password for invalid user root from 212.129.60.203 port 50666 ssh2
Oct 24 05:53:03 sshd[5291]: Disconnected from 212.129.60.203 port 50666 [preauth]
Oct 24 05:53:05 sshd[5295]: Received disconnect from 121.18.238.114 port 33649:11:  [preauth]
Oct 24 05:53:05 sshd[5295]: Disconnected from 121.18.238.114 port 33649 [preauth]
Oct 24 05:53:11 sshd[5323]: Invalid user guest from 212.129.60.203 port 52019
Oct 24 05:53:11 sshd[5323]: input_userauth_request: invalid user guest [preauth]
Oct 24 05:53:12 sshd[5323]: Failed password for invalid user guest from 212.129.60.203 port 52019 ssh2
Oct 24 05:53:14 sshd[5323]: Disconnected from 212.129.60.203 port 52019 [preauth]
Oct 24 05:53:18 sshd[5327]: Invalid user admin from 212.129.60.203 port 52079
Oct 24 05:53:18 sshd[5327]: input_userauth_request: invalid user admin [preauth]
Oct 24 05:53:19 sshd[5327]: Failed password for invalid user admin from 212.129.60.203 port 52079 ssh2
Oct 24 05:53:19 sshd[5327]: Disconnected from 212.129.60.203 port 52079 [preauth]
Oct 24 05:53:22 sshd[5348]: Invalid user support from 212.129.60.203 port 52131
Oct 24 05:53:22 sshd[5348]: input_userauth_request: invalid user support [preauth]
Oct 24 05:53:23 sshd[5348]: Failed password for invalid user support from 212.129.60.203 port 52131 ssh2
Oct 24 05:53:23 sshd[5348]: Disconnected from 212.129.60.203 port 52131 [preauth]
Oct 24 05:53:26 sshd[5359]: Invalid user test from 212.129.60.203 port 52177
Oct 24 05:53:26 sshd[5359]: input_userauth_request: invalid user test [preauth]
Oct 24 05:53:27 sshd[5359]: Failed password for invalid user test from 212.129.60.203 port 52177 ssh2
Oct 24 05:53:27 sshd[5359]: Disconnected from 212.129.60.203 port 52177 [preauth]
Oct 24 05:53:31 sshd[5361]: Invalid user user from 212.129.60.203 port 52222
Oct 24 05:53:31 sshd[5361]: input_userauth_request: invalid user user [preauth]
Oct 24 05:53:31 sshd[5361]: Failed password for invalid user user from 212.129.60.203 port 52222 ssh2
Oct 24 05:53:32 sshd[5361]: Disconnected from 212.129.60.203 port 52222 [preauth]
Oct 24 05:53:34 sshd[5377]: User operator from 212.129.60.203 not allowed because not listed in AllowUsers
Oct 24 05:53:34 sshd[5377]: input_userauth_request: invalid user operator [preauth]
Oct 24 05:53:35 sshd[5377]: Failed password for invalid user operator from 212.129.60.203 port 52247 ssh2
Oct 24 05:53:35 sshd[5377]: Disconnected from 212.129.60.203 port 52247 [preauth]

Between 05:52:44 and 05:53:35, there were plenty of matches with the
sshguard rule pattern "Failed XYZ for XYZ from 6.6.6.0 port 14423 ssh2":

  05:52:48 Failed password for invalid user ubnt from 212.129.60.203 port 62676 ssh2
  05:52:57 Failed password for invalid user admin from 212.129.60.203 port 64796 ssh2
  05:53:03 Failed password for invalid user root from 212.129.60.203 port 50666 ssh2
  05:53:12 Failed password for invalid user guest from 212.129.60.203 port 52019 ssh2
  05:53:19 Failed password for invalid user admin from 212.129.60.203 port 52079 ssh2
  05:53:23 Failed password for invalid user support from 212.129.60.203 port 52131 ssh2
  05:53:27 Failed password for invalid user test from 212.129.60.203 port 52177 ssh2
  05:53:31 Failed password for invalid user user from 212.129.60.203 port 52222 ssh2
  05:53:35 Failed password for invalid user operator from 212.129.60.203 port 52247 ssh2

While other ssh rules would have failed to match due to subtle differences
between the patterns and the message content[1], these "Failed password"
matches should have provided sufficient grounds to block 212.129.60.203, but
evidently this never happened.

About an hour later there was another attack with very similar log entries,
but this one was blocked:

Oct 24 01:04:19 sshd[21389]: Invalid user admin from 91.224.160.131 port 34317
Oct 24 01:04:19 sshd[21389]: input_userauth_request: invalid user admin [preauth]
Oct 24 01:04:19 sshd[21389]: Failed password for invalid user admin from 91.224.160.131 port 34317 ssh2
Oct 24 01:04:20 sshd[21389]: Connection closed by 91.224.160.131 port 34317 [preauth]
:
Oct 24 06:58:53 sshd[12038]: Invalid user admin from 91.224.160.131 port 42027
Oct 24 06:58:53 sshd[12038]: input_userauth_request: invalid user admin [preauth]
Oct 24 06:58:53 sshd[12038]: Failed password for invalid user admin from 91.224.160.131 port 42027 ssh2
Oct 24 06:58:54 last message repeated 4 times
Oct 24 06:58:57 sshd[12038]: Received disconnect from 91.224.160.131 port 42027:11:  [preauth]
Oct 24 06:58:57 sshd[12038]: Disconnected from 91.224.160.131 port 42027 [preauth]
Oct 24 06:59:01 sshd[12049]: Invalid user admin from 91.224.160.131 port 48773
Oct 24 06:59:01 sshd[12049]: input_userauth_request: invalid user admin [preauth]
Oct 24 06:59:01 sshd[12049]: Failed password for invalid user admin from 91.224.160.131 port 48773 ssh2
Oct 24 06:59:03 last message repeated 4 times
Oct 24 06:59:05 sshd[12049]: Received disconnect from 91.224.160.131 port 48773:11:  [preauth]
Oct 24 06:59:05 sshd[12049]: Disconnected from 91.224.160.131 port 48773 [preauth]
Oct 24 06:59:11 sshd[12062]: Invalid user admin from 91.224.160.131 port 33310
Oct 24 06:59:11 sshd[12062]: input_userauth_request: invalid user admin [preauth]
Oct 24 06:59:11 sshd[12062]: Failed password for invalid user admin from 91.224.160.131 port 33310 ssh2
Oct 24 06:59:12 last message repeated 4 times
Oct 24 06:59:15 sshd[12062]: Received disconnect from 91.224.160.131 port 33310:11:  [preauth]
Oct 24 06:59:15 sshd[12062]: Disconnected from 91.224.160.131 port 33310 [preauth]
Oct 24 06:59:20 sshd[12074]: Invalid user admin from 91.224.160.131 port 50973
Oct 24 06:59:20 sshd[12074]: input_userauth_request: invalid user admin [preauth]
Oct 24 06:59:20 sshd[12074]: Failed password for invalid user admin from 91.224.160.131 port 50973 ssh2
Oct 24 06:59:22 sshd[12074]: Received disconnect from 91.224.160.131 port 50973:11:  [preauth]
Oct 24 06:59:22 sshd[12074]: Disconnected from 91.224.160.131 port 50973 [preauth]
Oct 24 06:59:22 sshguard[532]: 91.224.160.131: blocking for 6720 secs (4 attacks in 25 secs, after 4 abuses over 199489 secs)

In this case, sshguard evidently blocked 91.224.160.131 after 4 of the
"Failed password" messages, as I would expect.  What I can't work out is why
91.224.160.131 was blocked while 212.129.60.203 was not, even though they
generated the same messages.  The only difference is that 91.224.160.131 had
the single failure around 6 hours before the main block, but this should not
make a difference.

As an aside, it would be good if sshguard could recognise the "last message
repeated N times" messages and count the proceeding message N times when it
matches an sshguard rule.  This would speed up attack detections on systems
which utilise these aggregation messages.

[1] For example, the "Invalid user inexu from 6.6.6.0" rule would not detect
the "Invalid user guest from 212.129.60.203 port 52019" entries because our
ssh logs the port number on the end of the rule.  This rule might require
"arbitrary text" to be added to the end to allow for this.

Regards
  jonathan