Eric Wang
RSS

Writing

How to measure latency without fooling yourself

/12 min read/Reliability/#linux/#performance/#latency/#measurement/#benchmarking/#aws

The low-latency Linux tuning checklist starts with “measure first”. This post is about that step. Tuning is the easy part; knowing whether it worked is harder. Latency measurements are easy to get wrong in ways that look perfectly reasonable on a dashboard, and a wrong measurement is worse than none, because it gives you confidence. The low-latency Linux tuning checklist starts with “measure first”. This post is that step.

I run infrastructure for a trading firm on AWS, where the tail matters more than the average.

Tuning is the easy part. Knowing whether it worked is the hard part. Latency numbers go wrong in ways that look fine on a dashboard, and a wrong number is worse than no number, because you trust it.

1. Why averages lie

Latency isn’t a bell curve. You get a tight cluster of fast requests and a long tail of slow ones. The slow ones each have their own cause: a page fault, an interrupt, a GC pause, a retransmit.

The mean mashes all of that into one number that matches no real request. Say two systems both average 50 µs. One is steady. The other stalls for a few milliseconds once a second. Same mean, very different systems. And when the mean moves, you can’t tell if the common case got faster or the outliers got worse.

Standard deviation doesn’t save you. It assumes a shape your data doesn’t have.

It gets worse with fan-out. One operation often touches many hops, or a client sends many messages a second. If each hop has a 1% chance of hitting its p99, an operation touching 100 hops will hit at least one most of the time. The tail of each part becomes the normal case for the whole.

2. Percentiles and histograms

Report the distribution, not one number. My minimum set:

StatisticWhat it tells you
p50 (median)The typical case
p99What 1 in 100 operations sees
p99.9 / p99.99The rare stalls, which is usually what tuning is about
maxThe worst you saw. Always report it. Don’t trust a summary without it
countHow many samples. A p99.99 from 5,000 samples means nothing

Three rules:

  • Don’t average percentiles. The mean of ten per-second p99s is not the p99 of those ten seconds. Merge the histograms, then compute the percentile.
  • Sample count caps what you can claim. p99.9 needs many thousands of samples in the window. p99.99 needs more.
  • Look at the whole curve. Plot latency against percentile, with the percentile axis on a log scale. You’ll see where the curve bends. Two runs with the same p99 can look nothing alike.

HdrHistogram

HdrHistogram is what I’d reach for. It buckets values to a fixed number of significant digits over a wide range (say 1 ns to an hour, 3 digits), in fixed memory, with constant-time recording. Cheap enough for the hot path, precise enough for tails. Histograms from different threads, hosts or time windows add together exactly, which fixes the “averaging percentiles” problem.

How to use it:

  • Record into one histogram per interval (say per second) and log them. HdrHistogram has a compact log format for this.
  • Track max separately. It’s the single most useful outlier signal.
  • Plot the full percentile spectrum with the HdrHistogram plotter or similar, not three lines on a time series.

3. Coordinated omission

This is the most common way latency benchmarks lie. The name comes from Gil Tene’s talk “How NOT to Measure Latency”.

Most load generators do this: send a request, wait for the reply, record the time, send the next one.

Say it’s meant to send one request every millisecond, and the server stalls for 100 ms. The generator records one slow sample of 100 ms and carries on. In real life, with independent arrivals, about 100 requests would have shown up during that stall, each waiting 0 to 100 ms. The generator backed off exactly when the server was slow, and dropped the samples that would have shown it. That’s the “coordinated” part.

Your p99 can come out orders of magnitude better than reality.

What to do:

  • Measure from when the request was supposed to go out, not when it did. Scheduled at t=5 ms, actually sent at t=40 ms because the generator was blocked? Latency starts at 5 ms.
  • Use an open-loop generator at a fixed rate where you can (section 6).
  • Correct after the fact only as a fallback. HdrHistogram can back-fill missing samples given an expected interval (recordValueWithExpectedInterval in the Java version). It’s an approximation. Better than nothing, worse than generating load properly.
  • Check your tool. wrk2 exists specifically to fix this in wrk. Many tools don’t handle it.

This isn’t only a benchmark problem. Any monitoring that measures from “when we started processing” instead of “when the event arrived” has the same blind spot. Queueing before your timer starts is invisible.

4. Measuring at the right point

Latency is the gap between two timestamps. Which two matters.

Wire vs application timestamps

  • Application timestamps are taken in your code when you read a message and write a reply. Cheap and easy. They leave out the kernel network stack, the NIC and socket buffer queueing, so they can look great while the host is slow.
  • Kernel/NIC timestamps via SO_TIMESTAMPING give you software or hardware receive and transmit times per packet. Hardware timestamps come from the NIC and cover everything on the host. Check support with ethtool -T <iface>.
  • Wire timestamps come from a network tap or a timestamping switch or capture card. They show what the outside world sees, independent of the host. Use them as the reference when you have them.

Record at more than one point and compare. If wire-to-wire got worse but app-to-app didn’t, the problem is in the stack or the NIC, not your code.

Clock sources and the TSC

Check what clock the kernel is using:

cat /sys/devices/system/clocksource/clocksource0/current_clocksource
cat /sys/devices/system/clocksource/clocksource0/available_clocksource
grep -o -w -E 'constant_tsc|nonstop_tsc' /proc/cpuinfo | sort -u

You want tsc. On x86 Linux, clock_gettime(CLOCK_MONOTONIC) then reads the TSC (the CPU’s cycle counter) through the vDSO, without entering the kernel, in tens of nanoseconds. If you see hpet or acpi_pm, every timestamp is a slow system call and your measuring is distorting the thing you measure. Check dmesg for the TSC being marked unstable. On EC2, newer instance types expose a usable TSC; some older Xen-based ones default to xen. Check, don’t assume.

Also:

  • Use CLOCK_MONOTONIC (or CLOCK_MONOTONIC_RAW) for durations. CLOCK_REALTIME jumps when NTP or PTP adjusts it.
  • Calling rdtsc directly is faster, but then calibration and CPU migration are your problem. Pin the thread if you do.
  • Measure your timer. Take two timestamps back to back, many times, and look at the distribution. That’s your floor.

Clock sync across hosts

One-way latency between two hosts only works if their clocks agree to well under what you’re measuring. NTP gets you roughly a millisecond over a WAN, better on a LAN. Not good enough for microseconds.

  • PTP (IEEE 1588) with hardware timestamping can get sub-microsecond on the right network. ptp4l syncs the NIC clock, phc2sys syncs the system clock to it.
  • On AWS, the Amazon Time Sync Service is on every instance, and AWS documents PTP hardware clock support on some instance types. Check the current docs for which types and Regions, and measure the offset yourself instead of trusting a headline figure.
  • Can’t trust the sync? Measure round trip. Timestamp send and receive on the same host. No sync needed.
  • Watch the offset during the run (chronyc tracking, or pmc/ptp4l logs). Say the offset is 20 µs: a one-way reading of 30 µs is then useless.

5. Warm-up and steady state

The first seconds or minutes of a run don’t count. Caches and TLBs are cold, pages fault in on first touch, the JIT hasn’t compiled hot paths, connection pools are filling, CPU frequency is ramping up.

  • Run a warm-up and throw it away. Don’t average it in. If you care about cold start, record it separately; it’s its own metric.
  • Decide up front what “steady” means. For example: per-interval p99 has stopped trending.
  • Run long enough to catch periodic stuff. Lots of stalls happen every few seconds or minutes: log rotation, metrics scrapes, cron, GC, timer-driven kernel work. A 30-second test can miss all of them.
  • Watch for the opposite problem too. Replaying the same small input over and over gives you a perfectly warm cache that production never has.

6. Load generators: open vs closed loop

  • Closed loop: a fixed number of clients, each waits for a reply before sending again. When the server slows down, so does the load, so you never push past what it can handle. Easy to write. Prone to coordinated omission.
  • Open loop: requests go out on a schedule (fixed rate or Poisson) no matter what comes back. If the server slows, queues build and latency climbs. That’s what real independent traffic does, like market data or user requests.

Pick the one that matches production. For event-driven systems that’s usually open loop. Then:

  • Sweep the rate. Latency at 10% load and at 80% load are different stories. Plot percentiles against offered load and find where the tail bends up. That knee is your real capacity.
  • Check the generator kept up. Compare the rate you got with the rate you asked for. A generator that quietly fell behind is running a closed-loop test.
  • Don’t run the generator on the host under test unless that’s how it runs in production. It fights for CPU, cache and interrupts.
  • Measure the generator’s own noise by pointing it at a trivial echo service.

Tools: wrk2 (HTTP, constant rate, handles coordinated omission), sockperf (UDP/TCP latency and throughput), and netperf request/response tests. For anything domain-specific you’ll probably write your own. The rules above are the spec.

7. Environment noise: what the host adds

Before you blame the app, measure how noisy the box is with nothing interesting running. Same tools as the tuning checklist; here’s how to read them.

hwlat: latency the OS can’t see

hwlat spins with interrupts off and looks for gaps in time. Anything over the threshold came from below the kernel: SMIs (firmware interrupts), firmware, or the hypervisor.

cd /sys/kernel/tracing        # or /sys/kernel/debug/tracing on older systems
echo hwlat > current_tracer
echo 10 > tracing_thresh      # microseconds
sleep 300
cat trace
echo nop > current_tracer

Reading it: each line is a gap and how long it was. On bare metal, the odd entry usually points at BIOS or firmware settings. On a VM it may be the hypervisor. You can’t tune that away; you can only try another instance type (bare metal or dedicated) and measure again. What you want: nothing over threshold across a long window.

cyclictest: scheduling latency

cyclictest --mlockall --smp --priority=80 --interval=200 --distance=0 \
  --duration=10m --histogram=400 --quiet > cyclictest.hist

Reading it: you get min, avg and max wake-up latency per CPU, plus a histogram. Look at max and the histogram tail for the CPUs your app runs on. Run it with and without realistic background load. A host that’s clean when idle can still be noisy when the NIC is busy.

perf: who interrupted you

perf stat -e context-switches,cpu-migrations,page-faults -C 4 -- sleep 60
perf sched record -C 4 -- sleep 30 && perf sched latency
perf record -e irq:irq_handler_entry -C 4 -- sleep 30 && perf report

Reading it: on an isolated core with one pinned thread, context switches, migrations and IRQ entries should be close to zero. Anything else is a suspect for tail latency. perf report or perf script tells you who.

turbostat: frequency and C-states

turbostat --interval 5 --show Core,CPU,Avg_MHz,Busy%,Bzy_MHz,C1%,C6%,IRQ,SMI

Reading it: your latency-critical cores should hold a steady frequency and stay out of deep C-states (CPU sleep states). An SMI count that keeps climbing during the run is firmware stealing time: the same thing hwlat catches, from another angle. On many VMs turbostat can’t see these counters at all.

8. Comparing before and after fairly

Most bad tuning calls come from comparing two runs that differed in more ways than you meant.

  • Change one thing. Changed a kernel parameter and rebooted onto a new kernel? That’s two changes.
  • Same hardware, same placement. In the cloud, another instance of the same type can sit on different hardware next to different neighbours. Run A and B on the same instance if you can, and repeat across a few instances.
  • Same input, rate, duration and warm-up.
  • Repeat runs and look at the spread. Run-to-run noise is often bigger than the effect you’re chasing. If five runs of A overlap five runs of B, you haven’t shown a difference.
  • Interleave: A, B, A, B. Not all A then all B. Otherwise drift (heat, time of day, neighbour load) shows up as an “improvement”.
  • Compare whole distributions, not one percentile. Overlay the percentile plots. Say p50 drops but p99.9 goes up: for latency-sensitive work that’s usually a bad trade.
  • Record the environment with every result: kernel version and command line, instance type, BIOS or tuned profile, clocksource, tool versions, commit hash. If you can’t reproduce “before”, you can’t trust “after”.

Summary checklist

  • Report p50, p99, p99.9, max and sample count; never just the mean.
  • Record into histograms (HdrHistogram); aggregate histograms, never percentiles.
  • Measure from intended send time; know whether your tool suffers coordinated omission.
  • Know where your timestamps are taken: app, kernel/NIC, or wire.
  • Clocksource is tsc; durations use a monotonic clock; timer cost measured.
  • For one-way latency, clock offset monitored and well below the values measured.
  • Warm-up discarded; run long enough to catch periodic events.
  • Load model matches production (usually open loop); generator verified to keep up.
  • Platform noise measured with hwlat, cyclictest, perf and turbostat.
  • Before/after: one change, same environment, repeated and interleaved runs, whole distributions compared, environment recorded.

References