I'm looking for any help / advice against aggressive BotNet triggering sshd errors which fill auth.log rapidly.... What I am seeing could be a legitimate sshd bug -- or it could be a misconfiguration on my part that I've never encountered before...
I have a small linux host which is now and has been kept up to date, and has to the best of my ability been hardened for SSH and had fail2ban installed on it. Generally this host deals with the typical SSH Internet brute force attempts fine, and fail2ban bans recurring source IP attempts as planned.
This past week something "New and unexpected" happened... a botnet came after this host, and although I don't see any sign they ever successfully authenticated (which is also protected by google-authenticator-libpam), they nevertheless managed to do something that FILLed auth.log very rapidly, and effectively crashed the host until I realized it had a problem. None of what they were doing triggered jail from Fail2Ban which I get email notifications for...
The auth.log on this host (a sample is shown below) grew to 11GB rapidly and shows more than 250 source IPs from all around the world converging on this host with two or three at a time making attempts -- not just the typical script kiddie / dictionary attacks either - whoever this is intentionally never stayed on the same IPs long enough the get banned and the recycling of source IPs was carefully done...
In /var/log/auth.log I see this:
Please note the topmost line, and the lines at the bottom, that look like this:
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:1: type is not 2
There are millions of these lines with different integers, and an astonishing number of them were written quickly into auth.log, but none of this activity seemed to generate a ban out of fail2ban
Can someone more skilled than me - please eyeball this log snippet and tell me if I should bother anyone with a bug report, or if I am the one with the 'config' problem?
This host does not have any file system corruption and regenerating the primes doesn't seem to fix this issue, as this botnet can illicit the same effect over and over again... manually banning the offending source IPs just slows things down for a short while and they are right back at me from other IPs. Sadly - whoever has control of this botnet is not just running out of China, Russian, Iran, etc. they also have numerous source IPs in the USA -- New York, California, Washington State, etc. so blocking incoming connections outside of North America may not be a complete solution....
---------------------------------------------------
Sep 15 17:34:45 rp6 sshd[21258]: WARNING: no suitable primes in /etc/ssh/moduli
Sep 15 17:34:45 rp6 sshd[21258]: debug2: monitor_read: 0 used once, disabling now
Sep 15 17:34:45 rp6 sshd[21258]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent [preauth]
Sep 15 17:34:45 rp6 sshd[21258]: debug2: bits set: 1053/2048 [preauth]
Sep 15 17:34:45 rp6 sshd[21258]: debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT [preauth]
Sep 15 17:34:45 rp6 sshd[21258]: Connection closed by <REDACTED IP> port 58879 [preauth]
Sep 15 17:34:45 rp6 sshd[21258]: debug1: do_cleanup [preauth]
Sep 15 17:34:45 rp6 sshd[21258]: debug1: monitor_read_log: child log fd closed
Sep 15 17:34:45 rp6 sshd[21258]: debug1: do_cleanup
Sep 15 17:34:45 rp6 sshd[21258]: debug1: Killing privsep child 21259
Sep 15 17:34:45 rp6 sshd[21258]: debug1: audit_event: unhandled event 12
Sep 15 17:35:03 rp6 sshd[660]: debug1: Forked child 21262.
Sep 15 17:35:03 rp6 sshd[21262]: debug1: Set /proc/self/oom_score_adj to 0
Sep 15 17:35:03 rp6 sshd[21262]: debug1: rexec start in 7 out 7 newsock 7 pipe 9 sock 10
Sep 15 17:35:03 rp6 sshd[21262]: debug1: inetd sockets after dupping: 3, 3
Sep 15 17:35:03 rp6 sshd[21262]: Connection from <REDACTED IP> port 57168 on 192.168.86.25 port 22
Sep 15 17:35:03 rp6 sshd[21262]: debug1: Client protocol version 2.0; client software version libssh-0.6.3
Sep 15 17:35:03 rp6 sshd[21262]: debug1: no match: libssh-0.6.3
Sep 15 17:35:03 rp6 sshd[21262]: debug1: Local version string SSH-2.0-OpenSSH_7.9p1 Raspbian-10+deb10u2
Sep 15 17:35:03 rp6 sshd[21262]: debug2: fd 3 setting O_NONBLOCK
Sep 15 17:35:03 rp6 sshd[21262]: debug2: Network child is on pid 21263
Sep 15 17:35:03 rp6 sshd[21262]: debug1: permanently_set_uid: 107/65534 [preauth]
Sep 15 17:35:03 rp6 sshd[21262]: debug1: list_hostkey_types: ssh-ed25519,ssh-rsa [preauth]
Sep 15 17:35:03 rp6 sshd[21262]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Sep 15 17:35:03 rp6 sshd[21262]: Connection closed by 138.197.222.141 port 57168 [preauth]
Sep 15 17:35:03 rp6 sshd[21262]: debug1: do_cleanup [preauth]
Sep 15 17:35:03 rp6 sshd[21262]: debug1: monitor_read_log: child log fd closed
Sep 15 17:35:03 rp6 sshd[21262]: debug1: do_cleanup
Sep 15 17:35:03 rp6 sshd[21262]: debug1: Killing privsep child 21263
Sep 15 17:35:03 rp6 sshd[21262]: debug1: audit_event: unhandled event 12
Sep 15 17:35:25 rp6 sshd[660]: debug1: Forked child 21265.
Sep 15 17:35:25 rp6 sshd[21265]: debug1: Set /proc/self/oom_score_adj to 0
Sep 15 17:35:25 rp6 sshd[21265]: debug1: rexec start in 7 out 7 newsock 7 pipe 9 sock 10
Sep 15 17:35:25 rp6 sshd[21265]: debug1: inetd sockets after dupping: 3, 3
Sep 15 17:35:25 rp6 sshd[21265]: Connection from <REDACTED IP> port 58879 on 192.168.86.25 port 22
Sep 15 17:35:25 rp6 sshd[21265]: debug1: Client protocol version 2.0; client software version libssh2_1.8.0
Sep 15 17:35:25 rp6 sshd[21265]: debug1: no match: libssh2_1.8.0
Sep 15 17:35:25 rp6 sshd[21265]: debug1: Local version string SSH-2.0-OpenSSH_7.9p1 Raspbian-10+deb10u2
Sep 15 17:35:25 rp6 sshd[21265]: debug2: fd 3 setting O_NONBLOCK
Sep 15 17:35:25 rp6 sshd[21265]: debug2: Network child is on pid 21266
Sep 15 17:35:25 rp6 sshd[21265]: debug1: permanently_set_uid: 107/65534 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: list_hostkey_types: ssh-ed25519,ssh-rsa [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: SSH2_MSG_KEXINIT received [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: local server KEXINIT proposal [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: KEX algorithms:
curve255...@libssh.org,diffie-hellman-group-exchange-sha256 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: host key algorithms: ssh-ed25519,ssh-rsa [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: ciphers ctos:
chacha20...@openssh.com,
aes25...@openssh.com,
aes12...@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: ciphers stoc:
chacha20...@openssh.com,
aes25...@openssh.com,
aes12...@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: MACs ctos:
hmac-sha...@openssh.com,
hmac-sha...@openssh.com,
umac-1...@openssh.com,hmac-sha2-512,hmac-sha2-256 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: MACs stoc:
hmac-sha...@openssh.com,
hmac-sha...@openssh.com,
umac-1...@openssh.com,hmac-sha2-512,hmac-sha2-256 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: compression ctos: none,
zl...@openssh.com [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: compression stoc: none,
zl...@openssh.com [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: languages ctos: [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: languages stoc: [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: first_kex_follows 0 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: reserved 0 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: peer client KEXINIT proposal [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: KEX algorithms: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: host key algorithms: ssh-rsa,ssh-dss [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,
rijnda...@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,
rijnda...@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: MACs ctos: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,
hmac-ri...@openssh.com [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: MACs stoc: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,
hmac-ri...@openssh.com [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: compression ctos: none [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: compression stoc: none [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: languages ctos: [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: languages stoc: [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: first_kex_follows 0 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug2: reserved 0 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: kex: algorithm: diffie-hellman-group-exchange-sha256 [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: kex: host key algorithm: ssh-rsa [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
Sep 15 17:35:25 rp6 sshd[21265]: debug1: expecting SSH2_MSG_KEX_DH_GEX_REQUEST [preauth]
Sep 15 17:35:26 rp6 sshd[21265]: debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received [preauth]
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:1: type is not 2
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:2: type is not 2
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:3: type is not 2
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:4: type is not 2
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:5: type is not 2
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:6: type is not 2
Sep 15 17:35:26 rp6 sshd[21265]: error: moduli:7: type is not 2
(ad nauseum....)