Diagnosing a live system

Something is wrong in production. Latency is up, or errors are up, or a customer says checkout is broken. The difference between an engineer who fixes it in fifteen minutes and one who is still guessing after two hours is rarely knowledge of the system. It is method: an order of questions that narrows the problem instead of wandering around it.

This lesson is that method, and one worked example of it on a real JVM.

#First: how bad, and for whom

Before touching anything, answer three questions. They take a minute and decide everything that follows.

1. What are users experiencing? Errors, slowness, wrong data, nothing at all? Look at the symptom dashboards — request rate, error rate, latency percentiles — not at CPU.
2. How many, and which ones? All users, one region, one endpoint, one customer, one app version? The shape of "who" is the first clue to "where".
3. Since when, and what changed then? A deploy, a config change, a traffic spike, a dependency's incident, a scheduled job, the start of a business day.

The third question solves a large share of incidents on its own. When the graph bends at 14:02 and a deploy finished at 14:01, the most likely cause is not a mystery.

#Hypotheses, then evidence

With the symptom described, write down the plausible causes — actually write them, in the incident channel — and for each one, the evidence that would confirm or rule it out:

Then gather the cheapest evidence that separates them. The discipline is to look for evidence that could disprove your favourite theory, not more evidence that fits it; the first plausible story is the one people stop at.

#The resource checklist: USE

When the question is "is something on this machine exhausted?", Brendan Gregg's USE method gives a checklist that does not depend on intuition. For every resource — CPU, memory, disk, network, and in a Java service every pool — check:

• Utilisation: how busy is it?
• Saturation: is work queuing for it?
• Errors: is it failing?

For a Spring service, the resources worth listing explicitly are the CPU, the heap and GC, the Tomcat request threads, the database connection pool, any executor queues, and file descriptors. Saturation is the column people skip, and it is the one that explains latency: a connection pool at 100% with 40 threads waiting is the answer even when CPU is idle.

#Worked example: CPU at 100%

A service's CPU is pegged, latency is climbing, and nothing was deployed. Here is the path from "the process is hot" to "this line of code", on a running JVM.

Which thread? top can show threads instead of processes. On the Java process:

$ top -H -b -n 1 -p 1 | head -12
Threads:  23 total,   1 running,  22 sleeping,   0 stopped,   0 zombie
    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
     52 root      20   0 5222544  92772  21064 R  99.9   1.1   0:07.94 report-+
      1 root      20   0 5222544  92772  21064 S   0.0   1.1   0:00.01 java
     31 root      20   0 5222544  92772  21064 S   0.0   1.1   0:00.03 java
     32 root      20   0 5222544  92772  21064 S   0.0   1.1   0:00.00 GC Thre+

One thread, OS id 52, is using a whole core. Its name is truncated, but the id is all you need.

What is that thread doing? A thread dump lists every Java thread with its native id. The dump below is from a second run of the same program — thread ids are assigned per run, so this time the hot thread is 51, and top on that run agreed:

$ jcmd 1 Thread.print
"report-scheduler-1" #24 [51] prio=5 os_prio=0 cpu=7911.75ms elapsed=7.92s tid=0x0000ffff7c3d0840 nid=51 runnable  [0x0000ffff1b7c6000]
   java.lang.Thread.State: RUNNABLE
	at OrderService.buildDailyReport(OrderService.java:13)
	at OrderService$$Lambda/0x0000008801001800.run(Unknown Source)
	at java.lang.Thread.runWith(java.base@21.0.12/Thread.java:1596)

nid=51 matches top, cpu=7911.75ms in 7.92 seconds of life confirms it has been on a core the whole time, and the stack names the line:

static void buildDailyReport() {
    String status = "PENDING";
    long attempts = 0;
    while (!"READY".equals(checkReportStatus(status))) {
        attempts++;                                      // no sleep, no limit
    }
}

A retry loop with no delay and no limit, waiting for a status that never changes. From "CPU is high" to the line took two commands.

Take two or three dumps a few seconds apart. A thread in the same frame in every dump is stuck there; a thread in a different frame each time is merely busy. One dump cannot tell those apart.

If the hot threads are named GC Thread#… or G1 … instead, the CPU is being spent collecting garbage, and the memory lesson in this course is where to go next.

#One change at a time

When you move from evidence to fixes, change one thing, and watch the symptom before changing another. Two changes at once — a restart and a config tweak — leave you unable to say which one helped, or whether the restart merely cleared the symptom for an hour.

Restarting deserves a special mention. It is often the right mitigation, and it destroys evidence: the heap, the thread states, the connection pool's state. Take the dumps first; they take seconds.

#Communicating while you work

An incident has an audience — support, other teams, sometimes customers — and silence is interpreted as nobody working on it.

• Post regular updates on a schedule (every 30 minutes, say), even when the update is "still investigating; ruled out the database".
• Say what users see and what they should do, not which pod restarted.
• Keep a timeline as you go: the times, what was observed, what was changed. The root cause analysis lesson builds on it, and it cannot be reconstructed accurately from memory.

The on-call lesson's incident roles apply here: one person decides and communicates, others investigate, and every change to production is announced before it is made.