A pod is healthy but slow

"A pod passes its health checks and its latency is terrible. Diagnose it, in order."

What the question is testing

Whether you have a method or a list of guesses. The failure mode is jumping to a favourite cause (it is always DNS, it is always GC) and confirming it. The strong answer orders the checks by cost to verify divided by prior probability, states that ordering out loud, and narrows systematically.

The framing to open with is USE and RED, said before any tool is named. USE (Utilisation, Saturation, Errors) applies to resources: for each resource, how busy is it, how much queued work is there, and is it throwing errors. RED (Rate, Errors, Duration) applies to services. Naming the method first is the difference between a debugging story and a debugging process.

The diagnostic ladder

The order below is not arbitrary. Each step is roughly one command, each rules out a large class of causes, and the early steps have both high prior probability and near-zero cost.

Step 0: establish the shape (30 seconds)

Before touching the pod, three questions, because they eliminate whole branches:

  • All replicas or one? One slow pod out of twelve is a node or a neighbour problem. All twelve is a code, dependency or config problem.
  • All requests or a subset? A slow p99 with a healthy p50 is queueing, GC or a tail dependency. Uniform slowness is a code path or a saturated resource.
  • Since when, and what changed? Deploy markers on the latency graph answer this instantly and correlate the majority of incidents. If there is no deploy marker on your dashboards, that is the cheapest observability fix in existence and you should add it after the incident.
# Per-pod latency: is it one pod or all of them?
histogram_quantile(0.99,
  sum by (pod, le)(rate(http_request_duration_seconds_bucket{app="search"}[5m])))

Step 1: CPU throttling (one query, catches a large fraction)

$ kubectl exec search-7d9f4 -- cat /sys/fs/cgroup/cpu.stat
nr_periods 180000
nr_throttled 21600        # 12% of periods throttled
throttled_usec 1490000000 # 1490 seconds frozen

Throttling is first because it is common, it is invisible on a CPU utilisation graph, and it is one command. A container using 35 percent of its limit can still be frozen for 90 ms at a time, because the quota is consumed in proportion to runnable threads within a 100 ms window. The full mechanism is in CPU limits and CFS throttling; here it is just the first thing to rule out.

rate(container_cpu_cfs_throttled_seconds_total{pod=~"search-.*"}[5m])
# Above ~0.02 is worth investigating; above 0.1 you have found your p99.

Step 2: memory pressure and garbage collection

Not the memory limit (that produces OOMKill, not slowness) but the pressure short of it.

$ kubectl exec search-7d9f4 -- cat /sys/fs/cgroup/memory.stat | grep -E 'pgmajfault|workingset'
pgmajfault 48211          # major faults = reading from disk. Should be ~0.
workingset_refault_anon 1204773   # pages evicted and immediately needed again

Major faults on a service that should be memory-resident mean the working set does not fit and the kernel is thrashing the page cache. That is a latency disaster with normal-looking memory utilisation, because the cgroup is at its limit and reclaiming constantly rather than being killed.

For the JVM:

$ kubectl exec search-7d9f4 -- jcmd 1 GC.heap_info
$ kubectl exec search-7d9f4 -- jstat -gcutil 1 1000 10
# Look at FGC (full GC count) and FGCT (time). Rising full-GC time with a
# heap that stays near-full after collection means a leak or an undersized heap.

The container-specific trap: -Xmx set to the container memory limit guarantees an eventual OOMKill, because the JVM's footprint is heap plus metaspace plus thread stacks plus code cache plus direct buffers. Use a percentage-of-RAM flag around 65 to 75 percent.

Step 3: is it us or downstream?

# Per-dependency latency. If a downstream moved, everything upstream of it moved.
histogram_quantile(0.99,
  sum by (upstream_service, le)(rate(client_request_duration_seconds_bucket[5m])))

If a dependency's p99 explains your p99, the investigation moves there and you stop looking at this pod. Two things to check before you do:

Connection pool wait time. The dependency may be fine while your pool is exhausted, which looks identical from the outside. Pool acquisition time is a separate metric from call duration and most clients expose it. Little's Law gives you the ceiling: a pool of N at latency L caps you at $N/L$ requests per second, and past that you are queueing for a connection rather than waiting on the dependency.

Fan-out arithmetic. If a request calls 20 shards and takes the slowest, your p99 is roughly the shards' p99.87, not their p99. A modest per-shard tail becomes your median. That is the tail-at-scale effect and it means "the dependency looks fine" can be true and irrelevant.

Step 4: DNS

$ kubectl exec search-7d9f4 -- cat /etc/resolv.conf
nameserver 10.96.0.10
search default.svc.cluster.local svc.cluster.local cluster.local
options ndots:5           # <- the classic

ndots:5 means any name with fewer than five dots is tried against each search domain first. So resolving api.stripe.com (two dots) issues queries for api.stripe.com.default.svc.cluster.local, .svc.cluster.local, .cluster.local, and only then the real name, and each miss is a round trip to CoreDNS, doubled if the client queries both A and AAAA. Five to ten DNS lookups per external call, on every call if nothing caches.

# Confirm it directly.
$ kubectl exec search-7d9f4 -- sh -c 'time nslookup api.stripe.com'
real 0m0.412s             # should be sub-millisecond from cache

# And check whether CoreDNS itself is the problem.
$ kubectl top pods -n kube-system | grep coredns

Fixes: a trailing dot on external hostnames to make them fully qualified (api.stripe.com.), dnsConfig with ndots: 2 on the pod, NodeLocal DNSCache, or in-process DNS caching in the client.

Step 5: the node, and the neighbours

$ kubectl describe node ip-10-0-3-44 | grep -A6 'Allocated resources'
$ kubectl exec search-7d9f4 -- vmstat 1 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 8  2      0 412332  88104 2841000    0    0   204    88 8412 21033 62 14  9  3 12

Two columns matter here. st (steal) at 12 percent means the hypervisor is giving your CPU to someone else, which on a shared instance type is a noisy neighbour and on a burstable instance means you have exhausted your CPU credits. r (run queue) of 8 against 4 allocated cores means processes are waiting for CPU regardless of what your cgroup accounting says.

Also check whether the node is overcommitted: if requests sum to more than the node's capacity, every pod on it is competing under contention even when none is individually over its limit.

Step 6: I/O and network

$ kubectl exec search-7d9f4 -- iostat -x 1 3
Device  r/s   w/s  rkB/s  wkB/s  r_await w_await  %util
nvme0n1 412  1840  8240  92000    0.42    18.3    98.2   # <- saturated

%util near 100 with a high w_await means the disk is the constraint. On cloud storage this usually means you have exhausted provisioned IOPS or burst credits, which is a quota problem rather than a hardware one.

$ kubectl exec search-7d9f4 -- ss -s
$ kubectl exec search-7d9f4 -- netstat -s | grep -iE 'retrans|overflow|pruned'
    1832 segments retransmitted        # packet loss on the path
    412 times the listen queue of a socket overflowed   # backlog too small

Listen-queue overflow is worth knowing: it means connections are being dropped at accept time, and clients see a connection timeout rather than a slow response. net.core.somaxconn and the application's own backlog parameter both apply, and the application's is usually the smaller one.

Step 7: probes and the application itself

An aggressive liveness probe on a briefly-slow container restarts it, which looks like a completely different problem: intermittent errors, cold caches, and connection churn. Check kubectl get pod -o jsonpath='{.status.containerStatuses[0].restartCount}' before believing any theory.

Then, and only then, profile:

# Go: 30-second CPU profile from a running pod.
$ kubectl port-forward search-7d9f4 6060:6060 &
$ go tool pprof -http=:8080 http://localhost:6060/debug/pprof/profile?seconds=30

# JVM: async-profiler avoids the safepoint bias that jstack-based tools have.
$ kubectl exec search-7d9f4 -- ./profiler.sh -d 30 -e cpu -f /tmp/flame.html 1

# Anything, from the node: sample the process and build a flame graph.
$ perf record -F 99 -p $(pgrep -f search) -g -- sleep 30
$ perf script | stackcollapse-perf.pl | flamegraph.pl > cpu.svg

Profiling is step seven rather than step one because it is the most expensive to set up and the most likely to send you down a rabbit hole. Profiling a service that is 90 ms slow because of CFS throttling shows you a perfectly normal profile.

A worked transcript

Symptom. Search API p99 goes from 85 ms to 640 ms at 09:15. p50 unchanged at 22 ms. No deploy. All 12 pods affected.

09:18  All pods, not one. Rules out a single bad node or neighbour.
       p50 flat, p99 up 7.5x. That's a tail problem: queueing, GC, or a
       fan-out amplifying something small.

09:20  cpu.stat: nr_throttled 41/180000 periods. 0.02%. Not throttling.

09:21  jstat: FGC count unchanged, young-gen collections normal. Not GC.

09:23  Per-dependency p99: the ranking service moved from 18 ms to 31 ms
       at 09:14. Real, but 13 ms doesn't explain 555 ms.

09:26  Connection pool wait time on the ranking client: 0.4 ms -> 490 ms.
       There it is. The pool is exhausted, not the dependency.

       Little's Law: pool is 25, latency now 31 ms.
       Ceiling = 25 / 0.031 = 806 requests/sec.
       Current traffic to ranking: 1,150 requests/sec.
       We are 43% over the pool's capacity. Everything queues.

09:29  Why now? Ranking deployed at 09:12 with a model change. 18 -> 31 ms
       is a legitimate quality tradeoff on their side. Our pool was sized
       for 18 ms and nobody re-derived it.

09:31  Mitigate: raise the pool from 25 to 50. Ceiling becomes 1,612/sec,
       comfortably above 1,150. p99 back to 95 ms within two minutes.

09:40  Root cause is not "the pool was too small". It is that pool size was
       a constant nobody owned, derived from a latency that changed
       underneath it and never re-checked.

Follow-ups that came out of it, and these are what make the postmortem worth writing: an alert on pool utilisation above 70 percent, because the pool was the binding constraint and nothing watched it; a documented sizing formula (pool >= peak_rps x p99_latency x 1.5) next to the config so the next person knows where 50 came from; a timeout on the ranking call so an unbounded queue becomes a bounded degradation; and a cross-team note that changing a service's latency profile is a change to its consumers' capacity plan.

The general lesson to state: the dependency looked healthy and was the cause. A modest latency increase upstream crosses a pool's Little's Law ceiling downstream and produces a nonlinear failure, which is why per-dependency latency alone is not enough and you must instrument the queue in front of it.

Production evidence

Brendan Gregg's USE method is the standard checklist for resource-level analysis and the source of the "utilisation, saturation, errors, per resource" framing. Systems Performance (2nd edition) is the reference for the tooling used above, and his flame graph work is what made CPU profiling readable.

The RED method (Tom Wilkie, Weaveworks) is the service-level counterpart and is why Prometheus dashboards conventionally show rate, errors and duration.

The ndots:5 DNS issue is documented in Kubernetes' own DNS configuration guidance and has been written up repeatedly by operators; NodeLocal DNSCache exists in-tree specifically because DNS latency at scale is a recurring production problem.

Google's tail-at-scale work (Dean and Barroso, CACM 2013) explains why a service that fans out to many backends inherits a much worse tail than any individual backend's, which is the arithmetic behind step 3 and the reason "downstream looks fine" can be misleading.

Deploy markers on dashboards are the cheapest observability investment available and are standard in every mature setup, because the majority of incidents correlate with a change and the marker turns an hour of investigation into a glance.

The debate

The alternative to a diagnostic ladder is always profile first. It is defensible: a profile is ground truth about where time goes, and a ladder can walk you past the actual cause.

Its weaknesses in a container environment are real. A CPU profile of a throttled container looks normal, because the process is not running during the freeze and sampling captures nothing. A profile does not show queueing, pool waits, or DNS. And getting a profile from a production pod is often the most operationally expensive step, requiring a port-forward, a profiler binary, or a restart with different flags.

My position: use the ladder for the first five minutes because it is cheap and catches most of it, and reach for the profiler once you have eliminated the environmental causes. The ordering is by cost-to-verify over prior probability, which puts one-command checks with high base rates first. And instrument so the ladder is unnecessary next time: throttling, pool wait, GC pause and per-dependency latency should all be on a dashboard before the incident.

The ladder is the wrong approach when you already have a strong signal (a deploy marker at exactly the inflection point, an error message naming the subsystem). Follow the signal. It is also wrong when the problem is not slowness but correctness, which this ladder will not find at all.

Follow-up Q&A

"A pod is healthy but slow. Diagnose in order." Establish the shape first: all replicas or one, all requests or the tail, and what changed. Then CPU throttling, because it is one command and it does not appear on a CPU utilisation graph. Then GC and memory pressure, specifically major faults rather than the limit. Then per-dependency latency and connection pool wait time, since the dependency can be healthy while your pool is exhausted. Then DNS, checking ndots. Then the node: steal time, run queue, overcommit. Then disk and network saturation. Then probe configuration. Then profile.

"Why is throttling first when CPU utilisation looks fine?" Because utilisation is an average and throttling is about instantaneous parallelism against a 100 ms quota window. A container averaging 35 percent of its limit can consume the whole quota in the first 6 ms of a period with 16 runnable threads and then be frozen for 94 ms. That lands directly in p99 and is invisible on every graph except cpu.stat.

"p50 is fine and p99 is terrible. What does that narrow it to?" A tail cause rather than a uniform one. GC pauses, lock contention, queueing at a saturated resource, a slow dependency amplified by fan-out, a cold cache path, or a noisy neighbour. Uniform slowness would point at a code path or a saturated resource affecting every request. The p50/p99 split is the most informative single observation in the whole diagnosis, and it costs nothing.

"What is ndots:5 and why does it cause latency?" Kubernetes sets options ndots:5 in the pod's resolv.conf, so any hostname with fewer than five dots is tried against each search domain before being tried as-is. Resolving api.stripe.com therefore issues three or four failing queries first, doubled if the client asks for both A and AAAA records, and each is a round trip to CoreDNS. On a hot path with no client-side caching that is milliseconds of pure overhead per call. Fix with a trailing dot to fully qualify the name, a pod dnsConfig with a lower ndots, or NodeLocal DNSCache.

"You found the dependency got slower but only slightly. How can that cause a 7x latency increase?" Little's Law and a finite pool. A pool of 25 at 18 ms sustains about 1,390 requests per second; at 31 ms it sustains 806. If you are sending 1,150, you crossed the ceiling and every request now queues for a connection, so wait time is added on top of service time and the queue grows. The relationship between dependency latency and your latency is not linear near the pool's capacity, it is a cliff. That is why pool utilisation needs its own alert.

"Nothing on the ladder explains it. Now what?" Profile, with a flame graph over 30 seconds, and compare against a known-good baseline rather than reading it cold. If the profile is flat, the time is not being spent on CPU, so look at off-CPU analysis: bpftrace on scheduler and futex events, or a blocking profile in the runtime. And check the one thing the ladder does not cover: whether the work itself changed. A query returning 10,000 rows instead of 100 is slow for reasons no system metric will reveal.

Common misconceptions

The most common is that a passing health check means the container is healthy. A liveness probe usually checks that a port accepts a connection, which a fully throttled or GC-thrashing process still does.

The second is that CPU utilisation graphs show throttling. They show average utilisation, and throttling is a burst phenomenon within a 100 ms window, so a throttled container looks comfortably under its limit.

The third is that a healthy dependency exonerates it. Your connection pool sits between you and the dependency, and it saturates at a throughput determined by the dependency's latency, so a small latency increase there produces a nonlinear failure here.

Interview delivery note

State the method before any tool: "USE for resources, RED for services. I'd start by establishing the shape: all pods or one, all requests or the tail, and what changed, which deploy markers answer instantly."

Then the ladder, quickly, with the reasoning for the ordering: "Throttling first, because it's one command and it doesn't show on a CPU graph. Then GC and major faults. Then per-dependency latency and pool wait time, because the dependency can be healthy while my pool is exhausted. Then DNS and ndots. Then node steal time. Profiling last, because profiling a throttled container shows you a normal profile."

The depth signal is separating pool wait from dependency latency, and being able to do the Little's Law arithmetic that connects a small upstream change to a large downstream failure. That is the answer of someone who has debugged this rather than read about it.

Further reading

  • Brendan Gregg, Systems Performance (2nd ed.), for the USE method and the full tooling; and his flame graph material.
  • Tom Wilkie's RED method write-ups, for the service-level counterpart.
  • Kubernetes documentation on DNS for services and pods, dnsConfig, and NodeLocal DNSCache.
  • Dean and Barroso, "The Tail at Scale" (CACM 2013), for why fan-out amplifies a modest per-backend tail into your median.