Measuring SSH Login Delays Precisely | Generated by AI

Home 2026.03

Question: How can you measure SSH login latency — what command-line options or tools can you use to detect a delay like the 500ms anomaly Andres Freund noticed?


Answer:

Methods to Measure & Detect SSH Login Delay

There are several approaches, from the simplest one-liner to detailed diagnostic deep-dives.


Method 1 — time command (The Simplest Way)

This is most likely the method Andres Freund used first. Wrap your ssh command with time:

time ssh user@hostname hostname

Example normal output:

linux01.localdomain

real    0m0.120s     ← this is your total login round-trip time
user    0m0.021s
sys     0m0.008s

Anomalous output (XZ backdoor scenario):

real    0m0.620s     ← 500ms unexplained extra delay!

You can also run it multiple times for consistency:

for i in {1..5}; do time ssh user@host hostname; done

Method 2 — -v / -vv / -vvv Verbose Mode (Pinpoint Where the Delay Occurs)

Connect to your server using ssh -v user@server_ip. The verbose output provides detailed information about the connection process, including authentication steps, cipher negotiations, and potential timeouts, which can reveal specific points of delay. Using -vv or -vvv increases the verbosity further.

ssh -v user@hostname hostname       # basic verbose
ssh -vv user@hostname hostname      # more detail
ssh -vvv user@hostname hostname     # maximum detail

Using -vvv shows each handshake stage with timing, so you can identify exactly which phase — TCP connect, key exchange, authentication, or shell startup — is slow.

Sample output showing where time is spent:

debug1: Connecting to hostname [1.2.3.4] port 22.
debug1: Connection established.
debug1: identity file /home/user/.ssh/id_rsa
debug2: kex: server->client ...
debug3: Waited 520ms here   ← you'd see a gap in timestamps
debug1: Authentication succeeded (publickey).

Method 3 — ssh -E logfile + Timestamps (Log with timing)

Write verbose output to a file with timestamps for analysis:

ssh -vvv -E /tmp/ssh_debug.log user@hostname hostname
# Then inspect the log:
cat /tmp/ssh_debug.log

Or pipe through ts (timestamp tool from moreutils):

ssh -vvv user@hostname hostname 2>&1 | ts '%.s'

This prepends a Unix timestamp to each debug line, making it easy to spot where the 500ms was lost.


Method 4 — sshping Tool (Dedicated SSH Latency Benchmark)

sshping is an SSH-based ping utility that measures interactive character echo latency and file transfer throughput.

# Install
sudo apt-get install libssh-dev
# then build from https://github.com/spook/sshping

# Run
sshping -H user@hostname

It reports: ssh-Login-Time (time to establish TCP, authenticate, and form the SSH session), Minimum-Latency, Median-Latency, Average-Latency, Maximum-Latency, and transfer rates — all in human-readable format.

Example output:

ssh-Login-Time:   1.84 s
Minimum-Latency:  633 us
Median-Latency:   751 us
Average-Latency:  764 us
Maximum-Latency:  1.15 ms
Upload-Rate:      9.33 MB/s

Method 5 — strace on sshd (Server-Side, Deep Diagnosis)

You can run strace on the server-side sshd process to trace system calls and find exactly what the daemon is waiting on — file reads, network lookups, library calls, etc. It is not 100% safe for use on critical production processes, but is powerful for debugging.

# On the server, find the sshd child PID during a login attempt:
ps -ef | grep sshd

# Attach strace to trace system calls with timestamps:
strace -tt -p <PID>

This is essentially what Andres Freund did when he ran Valgrind — a similar deep introspection tool — against the process and noticed anomalous behavior from liblzma.


Method 6 — Valgrind (What Andres Actually Used)

Andres ran benchmarks using Valgrind for memory profiling:

valgrind --tool=callgrind ssh user@host hostname

The Valgrind errors pointed at liblzma, which pulled on the thread that unraveled the whole XZ backdoor.


Quick Reference Table

Method Command What it detects
Basic timing time ssh user@host hostname Total login roundtrip
Verbose ssh -vvv user@host hostname Which phase is slow
Timestamped log ssh -vvv ... 2>&1 \| ts '%.s' Millisecond-level phase gaps
sshping sshping -H user@host Structured latency report
strace (server) strace -tt -p <sshd_pid> System calls causing delay
Valgrind valgrind ssh user@host hostname Memory/library anomalies

Key Takeaway

For detecting the XZ-style anomaly specifically, the most practical everyday command is:

time ssh user@host hostname

If the real time is consistently 400–600ms higher than expected (and your network ping is normal), that’s your red flag — exactly what Andres noticed, which led him to investigate further with Valgrind and eventually uncover the backdoor.


References:


Back Donate