Twelve thousand SSH attempts, counted properly

I sent 12,000 SSH connections as the user admin. sshd recorded that name as an invalid user, and every connection came from 10.0.2.2. The client got Permission denied 12,000 times and finished in 481.286 seconds. auth.log then held five lines per connection, 60,000 lines, and 12,000 of those say Failed password. The same window's Invalid user lines are another 12,000. Add the two greps and the number on the screen is 24,000. The journal matches the file on four of the five templates. On Connection closed the journal has 11,999. The child that handled source port 44148 wrote the close line to auth.log only.

Yogeshwar Tanwar tailed a fresh Hetzner box and wrote that the first hour had attempts from nine countries, and that by day three the count was "north of 12,000". Key auth, no root login, and fail2ban were already on. He then closed inbound SSH. Ashish Singh's headline says 50,000 attack attempts. The body is behind a member wall, so that figure stays his. The 12,000 here is the number of connections I generated, then counted back out of the logs.

The guest was Ubuntu 24.04.5 LTS, kernel 6.8.0-147-generic, qemu -m 1024 -smp 1. MemTotal was 984,552 kB. SwapTotal was 0. enp0s2 was 10.0.2.15/24. OpenSSH was the Ubuntu package openssh-server 1:9.6p1-3ubuntu13.20, and sshd -V printed OpenSSH_9.6p1 Ubuntu-3ubuntu13.20, OpenSSL 3.0.13. PAM was libpam-modules 1.5.3-5ubuntu5.7. ufw was 0.36.2-6. rsyslog was 8.2312.0-3ubuntu9.4, with $RepeatedMsgReduction on. From the host, the forward was 127.0.0.1:2299 to the guest's port 22. The daemon saw the client as 10.0.2.2, which is the user-mode network on the same machine.

How many log lines does one failed SSH password write?

The cloud image ships with /etc/ssh/sshd_config.d/60-cloudimg-settings.conf containing a single line, PasswordAuthentication no. A Failed password grep on that setting stays empty, which is its own measurement further down. For this window I wanted the line people actually grep, so password authentication had to be on.

A file named 99-lab.conf with PasswordAuthentication yes left sshd -T at passwordauthentication no. The manual uses the first value it obtains for a keyword, and 60-cloudimg-settings.conf is read before 99-. The same yes line in 00-lab.conf, followed by systemctl reload ssh, made sshd -T print passwordauthentication yes. I removed the 99- file. 00-lab.conf for the 12,000 also set MaxStartups 200:30:400. The stock value on this daemon is 10:30:100.

One of those connections, journal text with the timestamp stripped, is these five lines.

Invalid user admin from 10.0.2.2 port 45450
pam_unix(sshd:auth): check pass; user unknown
pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=10.0.2.2
Failed password for invalid user admin from 10.0.2.2 port 45450 ssh2
Connection closed by invalid user admin 10.0.2.2 port 45450 [preauth]

LogLevel was INFO. The client offered one password.

sshpass -p x ssh -p 2299 \
  -o PreferredAuthentications=password \
  -o PubkeyAuthentication=no \
  -o NumberOfPasswordPrompts=1 \
  -o GSSAPIAuthentication=no \
  [email protected] true

x was a wrong password. sshd logged admin as an invalid user. Port 2299 is the forward. The guest logged port 22.

Stock pam_unix.so held that client for 3.43 seconds. The authentication failure line and the Failed password line for that attempt were two seconds apart. Two hundred attempts, eight at a time, took 85.696 seconds, and all 200 came back Permission denied. I pointed /etc/pam.d/sshd at a copy of common-auth whose unix line is pam_unix.so nullok nodelay. Forty attempts, sixteen at a time, then took 1.499 seconds. The 12,000 used that stack, and the five lines kept the same shape. pam_unix is the module that inserts the delay.

What does a Failed password grep count on 12,000 connections?

I marked the journal, sent the 12,000, and counted only that window. The counter looked like this.

sudo journalctl -u ssh -o cat --no-pager | awk '
  /^Invalid user / {inv++}
  /^Failed password / {fail++}
  /authentication failure/ {pam++}
  /check pass;/ {check++}
  /^Connection closed / {closed++}
  END {
    print "invalid", inv+0
    print "failed", fail+0
    print "pam", pam+0
    print "check", check+0
    print "closed", closed+0
  }
'

On the window, both the journal and auth.log printed 12,000 for invalid, failed, pam, and check. auth.log printed 12,000 closes. The journal printed 11,999. The missing close belongs to sshd pid 14486, source port 44148, which did write Invalid user, check pass, authentication failure, and Failed password. The close line for that port is in auth.log.

$RepeatedMsgReduction was on for the whole run, and this window still wrote 12,000 of each of the five lines. Three of them carry the source port, so each connection is a different message, and the two PAM lines from neighboring children arrived between other lines. The host log below is where identical lines were folded.

The client saw one source address. The guest recorded 7,963 source ports, with ephemeral ports reused inside the 481.286 seconds. A count of the five templates in auth.log is 60,000. A count of Invalid user plus Failed password is 24,000. A count of source addresses is 1.

What is already in this host's auth log?

The machine under the guest is on a LAN. Its rotated auth.log files are the log a grep of this box actually returns.

There are 2,060 lines of the form error: connect_to 127.0.0.1 port N: failed. Another 134 lines say message repeated N times and hide 290 more of those events. Expanded, that is 2,350. Every one of them went to 127.0.0.1 (2,323) or localhost (27). High ephemeral ports, the same port often enough that rsyslog folded the duplicates. Those are local TCP forwards to a closed port.

The sshd lines in the same files come to Failed password 0, Failed publickey 0, Invalid user 4, Connection closed 9 (7 of them marked [preauth]), and Accepted publickey 173. A Failed password grep on this host is empty. A connect_to grep is a few thousand local failures. The 12,000 login attempts in this post were sent at the guest.

What does MaxStartups drop before sshd logs a password?

The 12,000 window used MaxStartups 200:30:400, so those connections would clear the unauthenticated limit and become lines. The stock setting is 10:30:100. The manual describes that triple as a random early drop. Refusal starts when 10 connections are still unauthenticated, at 30 percent, and it reaches every new connection at 100.

I put 10:30:100 back, left password authentication on, and sent 200 connections, 48 at a time. The client finished in 3.187 seconds. 94 came back Permission denied. 106 came back Connection closed by 127.0.0.1 port 2299, which is the forward closing the TCP session before a password exchange. The journal has 94 of each of the five lines, and sshd's own summary:

error: beginning MaxStartups throttling
drop connection #11 from [10.0.2.2]:48340 on [10.0.2.15]:22 past MaxStartups
exited MaxStartups throttling after 00:00:09, 106 connections dropped

The drop count in that line matches the 106 closes the client saw. Failed password is 94. Someone counting the password line would report 94 attempts. Someone counting TCP sessions would report 200. sshd already printed the difference.

What does a key-only sshd log for the same attempt?

I took PasswordAuthentication yes back out of 00-lab.conf and reloaded. sshd -T printed passwordauthentication no, from the cloud-image file, with MaxStartups still at 200:30:400 so this hundred would clear the unauthenticated limit. One hundred connections, eight at a time, finished in 4.425 seconds, all Permission denied. The window held 100 Invalid user lines and 100 Connection closed lines. Failed password was 0. check pass was 0. authentication failure was 0.

On the image as it ships, those attempts show up as Invalid user and a close. The Failed password grep the other writeups are built on stays at 0.

What does ufw record when port 22 is dropped?

ufw was inactive at the start of this guest. I reset it, set the incoming policy to deny, left outgoing on allow, turned logging on (low), and enabled it. After the reset, port 22 was absent from the allow list. The session I already had stayed up, because ufw-before-input accepts ctstate RELATED,ESTABLISHED before the policy drop. I then sent 80 connections with a 3 second connect timeout, eight at a time.

All 80 timed out. The client took 31.159 seconds. journalctl -u ssh for that window printed 0 lines. The INPUT policy counter moved from 0 packets to 264 packets, 11,616 bytes. 11,616 divided by 264 is 44, which is the LEN=44 on the blocked SYNs, source 10.0.2.2, destination 10.0.2.15, DPT=22. ufw.log gained 12 lines. The logging rule that produced them is limit: avg 3/min burst 10 on ufw-after-logging-input, and that rule's counter was 12 packets, 528 bytes. The packet counter and the log line are different instruments. The log is rate limited. The policy counter is the one that moved with the SYNs, including the retransmits behind those 80 connection attempts.

sudo ufw --force reset
sudo ufw default deny incoming
sudo ufw default allow outgoing
sudo ufw logging on
sudo ufw --force enable
sudo iptables -L INPUT -v -n -x
sudo iptables -L ufw-after-logging-input -v -n -x

Docker Compose on a VPS measured a guest ufw deny that left nmap calling a published port open, because Docker's publish path hits DNAT before the INPUT chain ufw uses. Nothing on this guest was published that way. The policy drop is the packet sshd would have read, and sshd's line count for the window stayed at 0. The drop here was ufw on the guest. On a Proxmox VM from NodeRings, the ruleset in front of the guest is the firewall in the panel. WireGuard on a VPS, with a phone QR is a path that can already be up when you close 22. The path that survived here was the SSH session itself, matched as established, which is also how I turned ufw back off.

Does setting Port 2222 move Ubuntu's SSH socket?

ssh.socket is enabled and listening. The unit file has ListenStream=0.0.0.0:22 and ListenStream=[::]:22, with Accept=no, so systemd holds the socket and hands it to sshd. ssh.service is active because of that socket, and is-enabled on the service prints disabled.

I wrote Port 2222 into 00-lab.conf and reloaded. sshd -T printed port 2222. ss still showed only 0.0.0.0:22 and [::]:22, held by sshd and systemd. A connection from the guest to 127.0.0.1:2222 was refused. Twenty connections through the forward, which still lands on guest port 22, all got Permission denied, and the journal gained 20 Failed password lines. I took Port 2222 back out and reloaded. sshd -T printed port 22 again.

sudo sshd -T | awk '$1=="port"'
sudo ss -ltnp | awk '/:22|:2222/'

The keyword and the socket are two different settings. After the reload, the keyword said 2222 and the socket was still 22, and the 20 attempts were logged. The ufw policy drop is the change that took the sshd count to zero.

FAQ

How should I count failed SSH attempts?

Count the connections you can account for, then print the five templates separately. On this guest, 12,000 connections produced 12,000 Failed password lines and 60,000 lines if you add all five. Invalid user plus Failed password is 24,000. Unique source ports were 7,963. Unique source addresses were 1.

Why is Failed password zero when the attempts are real?

The cloud image has PasswordAuthentication no. One hundred password-only connections then wrote 100 Invalid user lines and 100 closes, and Failed password stayed at 0.

Why did ufw log 12 blocks for 80 connections?

Logging was on (low). The LOG rule is limited to an average of 3 a minute with a burst of 10, and its counter stopped at 12 packets. The INPUT policy counter recorded 264 dropped packets, 11,616 bytes, all of them 44-byte SYNs. sshd wrote nothing.

Will a different SSH port stop the log lines?

On this image, Port 2222 changed sshd -T and left ssh.socket on 22. The next 20 connections to that socket were logged as Failed password. The ufw incoming policy on deny, with port 22 left off the allow list, is what kept sshd at zero lines.