Debugging Linux Tail Latency from the Shell

Tutorial·9 min read·August 24, 2026

An average response time can look healthy while a small fraction of requests take seconds. Those slow requests are usually where queueing, lock contention, packet loss, storage stalls, or runtime pauses become visible.

This is a repeatable investigation for one Linux service. It starts outside the process, narrows the resource, and only then reaches for tracing. The goal is to replace “the server feels slow” with a timestamped observation and a mechanism.

Capture a baseline you can repeat

Keep the request constant: same URL, payload, headers, host, and network path. This small probe records the useful curl phases without adding another load-testing dependency:

url="http://127.0.0.1:8080/health/details"
for i in $(seq 1 200); do
  curl --silent --output /dev/null \
    --write-out '%{time_namelookup} %{time_connect} %{time_starttransfer} %{time_total}\n' \
    "$url"
done > timings.txt

sort -n -k4 timings.txt | awk '
  { total[NR] = $4 }
  END {
    printf "p50 %.3fs\n", total[int(NR * 0.50)]
    printf "p95 %.3fs\n", total[int(NR * 0.95)]
    printf "p99 %.3fs\n", total[int(NR * 0.99)]
  }'

This is sequential, so it does not model queueing under concurrency. That is useful at first: if the p99 is already bad with one request at a time, the problem is not load alone. Add a controlled concurrent probe later with wrk, oha, or the tool your service already uses.

Compare the columns. A slow time_connect points toward accept queues or networking. A normal connect followed by a slow time_starttransfer points inside the application or an upstream dependency.

Find the process and its limits

pid=$(systemctl show --property MainPID --value my-service)
printf 'pid=%s\n' "$pid"

cat "/proc/$pid/limits"
ls "/proc/$pid/fd" | wc -l
grep -E 'Threads|VmRSS|voluntary_ctxt_switches|nonvoluntary_ctxt_switches' \
  "/proc/$pid/status"

Look for a process close to its file-descriptor or process limit, an unexpected thread count, growing resident memory, or a sharp rise in involuntary context switches. None proves the cause, but each changes the next question.

Decide whether the host is saturated

vmstat 1
pidstat -p "$pid" -u -r -d -w 1
mpstat -P ALL 1
iostat -xz 1

Read these together:

Take at least thirty seconds of samples while the slow requests occur. A one-second snapshot taken after the event is usually noise.

Check sockets and queues

ss -ltnp
ss -tinp | head -80
ss -s
nstat -az | grep -E 'RetransSegs|ListenOverflows|ListenDrops'

For a listening socket, a receive queue near its configured backlog suggests the application is not accepting connections fast enough. Retransmissions and a rising TCP retransmit timer suggest loss or congestion. Many sockets in CLOSE-WAIT usually mean the application is not closing a peer-closed connection.

Do not immediately tune kernel limits. First establish whether the queue is full because the limit is too small or because the process behind it has stopped making progress.

Sample on-CPU work with perf

sudo perf record -F 99 -g -p "$pid" -- sleep 30
sudo perf report --stdio --no-children | head -80

perf samples stacks while the process is running. A wide stack near the top is consuming CPU. Repeated JSON parsing, regular-expression work, allocator pressure, compression, or TLS can be obvious here.

If symbols are missing, install debug symbols for native dependencies and make sure frame pointers are enabled where possible. For JIT runtimes, use their perf-map integration; otherwise the profile will contain unresolved addresses.

Measure blocked time

A service can have low CPU and still be slow because it is waiting. Use a short, filtered strace capture:

sudo timeout 15 strace -f -ttT -p "$pid" \
  -e trace=network,file,futex \
  -o /tmp/service.strace

sed -n 's/.*<\([0-9.]*\)>$/\1 &/p' /tmp/service.strace \
  | sort -nr | head -30

The duration in angle brackets is time spent in the syscall. Long futex waits suggest lock contention. Long connect, recvfrom, or poll calls point toward network or upstream waits. Long fsync or read calls point toward storage.

strace adds overhead, especially on syscall-heavy processes. Keep captures short and use them on a representative instance, not blindly across the fleet.

Correlate one slow request end to end

Host tools explain resource pressure, but they do not identify which request caused it. Add a request ID and log four timestamps:

request_id=8da1 route=/search queue_ms=184 app_ms=23 upstream_ms=411 total_ms=619

Queue time separates “waiting for a worker” from “running slowly.” Upstream time separates local compute from dependency latency. If the service has a connection pool, log pool wait time too. These small fields often answer more than a large tracing installation added after the incident.

Change one thing and rerun the same probe

A latency fix is a controlled experiment. Save the command, raw timings, host metrics, and configuration. Change one variable: worker count, pool size, query plan, lock scope, allocation pattern, or timeout. Then run the identical probe.

The useful result is not “CPU dropped.” It is “p99 fell from one measured value to another under the same request shape, while error rate and throughput stayed acceptable.” Keep the failed experiments too; they stop the next person from repeating them.

← All notesHome