Part 6 — Data at work › Chapter 42

Diagnosing a slow database in production

A method, not a guess: wait statistics, the top-ten list, blocking chains, and what to look at first.

From the advert

“Esperienza su ambienti di produzione” — this chapter is what “production experience” actually consists of: a method for the twenty minutes after somebody says “the system is slow”.

Ask three questions before touching anything

🧒 Simple

Somebody says “the car is making a noise”. Before you open the bonnet: is it always, or only when turning? Did it start today? Does it do it when the radio is off? Three questions, and you have halved the search.

🎓 The three questions
  1. Everything, or one thing? Everything slow points at a resource — CPU, memory, disk, network — or at blocking. One thing slow points at that query, its plan or its indexes.
  2. Since when, and what changed? A deploy, a data load, a growth threshold crossed, a statistics update, an index rebuild. Almost everything has a “since”.
  3. Slow, or waiting? A query burning CPU and a query blocked on a lock look identical from the application and have nothing in common. Wait statistics answer this in one query, and it is the highest-value question of the three.

Wait statistics: what is the server waiting for?

The first question in any triage: what is the server actually waiting for?
-- SQL Server: the top waits since the last restart or clear.
SELECT TOP 12 wait_type,                          -- what kind of wait…
       wait_time_ms / 1000 AS wait_s,             -- …how long in total, in seconds…
       signal_wait_time_ms / 1000 AS cpu_queue_s, -- …of which this much was waiting for CPU…
       waiting_tasks_count                        -- …across how many waits
FROM sys.dm_os_wait_stats                         -- cumulative since the last restart
WHERE wait_type NOT IN ('CLR_SEMAPHORE','SLEEP_TASK',   -- the idle-wait exclusion list…
                        'BROKER_TASK_STOP','XE_TIMER_EVENT',           -- …continues…
                        'LAZYWRITER_SLEEP','SQLTRACE_BUFFER_FLUSH',  -- …and continues…
                        'WAITFOR',                                     -- …to the end
                        'HADR_FILESTREAM_IOMGR_IOCOMPLETION')  -- idle waits: pure noise
ORDER BY wait_time_ms DESC;                       -- biggest total first

-- PostgreSQL: what is happening right NOW, rather than cumulatively.
SELECT wait_event_type, wait_event, state, count(*)   -- group the live sessions…
FROM pg_stat_activity WHERE state <> 'idle'           -- …ignoring idle connections…
GROUP BY 1,2,3 ORDER BY count DESC;                   -- …commonest wait first
Reading waits, in three sentences
  • A server is always waiting for something. The question is whether it is waiting for disk (PAGEIOLATCH), for locks (LCK_M_*), for CPU (a high signal wait), or for the network — and each answer sends you somewhere completely different.
  • The NOT IN list filters idle waits: background threads sleeping. Leave them in and they dominate the top twelve, which is why every version of this query on the internet carries a list like it.
  • signal_wait_time_ms is the part of the wait spent runnable but not running — a queue for CPU. A large fraction of it means the box is CPU-bound, whatever the wait type says.
  • SQL Server's view is cumulative since restart; PostgreSQL's is a live sample. Different questions: “what has this server been doing” versus “what is it doing right now”.
WaitMeansLook at
PAGEIOLATCH_* / DataFileReadWaiting for a data page from diskMissing index, too little memory, slow storage
LCK_M_* / LockBlocked by another sessionThe blocking chain. Chapter 23
CXPACKET / CXCONSUMERParallelism coordinationUsually a symptom of a big scan, not the cause
WRITELOG / WALWriteWaiting for the log to flushLog disk latency; too many tiny transactions
RESOURCE_SEMAPHOREWaiting for a memory grantBad estimates causing huge grants. Chapter 28
ASYNC_NETWORK_IOThe client is not reading fast enoughThe application, not the database
SOS_SCHEDULER_YIELDCPU pressureGenuinely expensive queries, or too few cores
✔ ASYNC_NETWORK_IO is the one worth memorising

It almost never means the network is slow. It means the database produced rows faster than the application consumed them — usually because the client is fetching a million rows and processing them one at a time in a loop, or paging through a grid it never finishes. The database is being blamed for the application's behaviour, and being able to demonstrate that calmly, with a number, is a genuinely valuable thing to be able to do.

The top-ten list

The top-ten list, sorted by total cost — never by average.
-- Sort by TOTAL, never by average. See chapter 28 for why.
-- PostgreSQL
SELECT calls,                                              -- how many times it ran
       round(total_exec_time::numeric)      AS total_ms,   -- ::numeric so round() can take 2 args
       round(mean_exec_time::numeric, 2)    AS mean_ms,    -- the mean, to two decimals
       rows,                                               -- rows returned in total
       left(query, 120) AS q                               -- the statement, truncated
FROM pg_stat_statements ORDER BY total_exec_time DESC LIMIT 10;   -- the ten biggest totals

-- SQL Server
SELECT TOP 10 qs.execution_count,                          -- the same five questions…
       qs.total_worker_time/1000  AS cpu_ms,               -- CPU, microseconds → ms
       qs.total_elapsed_time/1000 AS elapsed_ms,           -- wall clock: includes waiting
       qs.total_logical_reads,                             -- 8 KB pages touched
       SUBSTRING(t.text, 1, 120)  AS q                     -- the statement text
FROM sys.dm_exec_query_stats qs                            -- one row per cached plan
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) t          -- resolve the handle
ORDER BY qs.total_elapsed_time DESC;                       -- biggest total elapsed first

-- MySQL: the slow log with long_query_time = 0 for a sampling window, then
-- pt-query-digest to aggregate it.
Two columns worth comparing before you optimise anything
  • cpu_ms versus elapsed_ms: if elapsed is much larger, the query is waiting, and rewriting the SQL will not help. Go back to the wait statistics.
  • total_logical_reads is the most stable measure of “how much work is this query”. It does not move with cache warmth or with how busy the server was, so it is the right number to compare before and after a rewrite.
  • ::numeric is not decoration: PostgreSQL's round(x, 2) two-argument form exists only for numeric, not for double precision. Without the cast the query fails.
Run it twice, a few minutes apart

These counters are cumulative since the server started, so the top of the list may be a batch job that ran at 03:00 and is irrelevant now. Snapshot, wait five minutes, snapshot again and diff. What grew is what is happening now, and that is a different list.

The blocking chain

The blocking chain, and how to find its head.
-- SQL Server: who is blocked, and by whom
SELECT r.session_id,                              -- the waiting session
       r.blocking_session_id,                     -- the session it is waiting for
       r.wait_type, r.wait_time,                  -- what kind, and how long
       r.status,                                  -- running, suspended, runnable
       SUBSTRING(t.text, 1, 120) AS running       -- what it is trying to do
FROM sys.dm_exec_requests r                       -- live requests only
CROSS APPLY sys.dm_exec_sql_text(r.sql_handle) t  -- one call per row
WHERE r.blocking_session_id <> 0;                 -- 0 means "not blocked"

-- Then find the HEAD of the chain — the session blocking others and blocked by
-- nobody. That is the one to look at; everyone else is a queue behind it.

-- PostgreSQL
SELECT pid, state,                                -- the backend, and what it is doing
       now() - xact_start AS xact_age,            -- how long its TRANSACTION has been open
       pg_blocking_pids(pid) AS blocked_by,       -- an array of blocking pids
       left(query, 100)                           -- the statement, truncated
FROM pg_stat_activity                             -- one row per connection
WHERE state <> 'idle'                             -- skip connections doing nothing…
ORDER BY xact_age DESC NULLS LAST;                -- …oldest transaction first
What to look for, and the answer that is usually right
  • The head of the chain is very often idle in transaction: a session that ran one statement, holds its locks, and is waiting for an application that has gone away. That is why xact_age is in the PostgreSQL query — the oldest open transaction is nearly always the culprit.
  • NULLS LAST matters: sessions with no open transaction have a NULL age, and PostgreSQL sorts NULLs first descending by default, which would bury the row you want.
  • Long blocking is usually an application problem — a transaction spanning a user's thinking time or an HTTP call — rather than a slow query. Fixing the query does not fix that.
  • Killing the head clears the queue instantly. Do it knowing what it was doing, because whatever it was, it will roll back.
⚠ The head of the chain is often idle in transaction

A session that ran one UPDATE, never committed, and is now sitting idle — because the application opened a transaction, called an external service, and is waiting for a timeout. It is using no CPU and running no query, which is why it does not appear in any "expensive queries" list, and it is holding the lock everyone else is queued behind. Look for long-running transactions, not just long-running queries.

The twenty-minute checklist

✔ In this order
  1. Is it the database at all? Application logs, the network, the disk. Do not assume it is yours because somebody said "the database is slow".
  2. Blocking chain. One query, thirty seconds. Rules out or confirms the most common cause of a sudden total freeze.
  3. Wait statistics. Slow or waiting, and waiting for what.
  4. Top queries by total time, diffed over five minutes. What is actually running now.
  5. Server resources. CPU, memory, disk latency, and how much free space the log volume has.
  6. What changed. Deploys, loads, index or statistics jobs, data growth.
  7. Only now, look at an individual query's plan (chapter 27).

The thing to do before the incident

“Is 400 ms bad?” has no answer without a baseline. Record, weekly: the top ten queries by total duration, wait statistics, index usage, table sizes, and the slowest report's runtime. Ten minutes a week, and the day something goes wrong you are comparing against last Tuesday instead of guessing. Proposing this in an interview says you have been on the wrong side of not having it.

  1. Everything slow means a resource or blocking; one thing slow means that query.
  2. “Slow or waiting?” is the highest-value question, and wait statistics answer it in one query.
  3. ASYNC_NETWORK_IO means the client is not consuming rows fast enough — it is the application's problem.
  4. CXPACKET is usually the symptom of a big scan, not a cause to tune away.
  5. Sort the top-query list by total time and diff two snapshots. Cumulative counters describe the whole uptime.
  6. Find the head of the blocking chain: blocked by nobody, blocking everyone.
  7. The head is often idle-in-transaction, so it appears in no expensive-query list.
  8. Look at the individual plan last, not first.
  9. Without a baseline, every number is unfalsifiable. Record one weekly.

Interview questions this chapter answers

The application is slow. Walk me through what you do.

First establish whether it is everything or one thing, and what changed and when. Then a blocking-chain query, which takes thirty seconds and catches the most common cause of a sudden freeze. Then wait statistics to find out whether we are slow or waiting, and for what. Then the top queries by total duration, diffed over a few minutes so I see what is happening now. Server resources. And only then an individual execution plan.

What are wait statistics and why start there?

They record what the engine spent time waiting for, aggregated by cause. They separate "we are doing too much work" from "we are queued behind something" — which are indistinguishable from the application and have entirely different fixes. It is one query and it usually points straight at the category of problem.

Everything is blocked and the head of the chain is running nothing. What is going on?

A session that is idle inside an open transaction — it made a change, never committed, and is probably waiting on an external call or a user. It holds its locks and uses no resources, so it appears in no expensive-query list. I would look for the oldest open transaction, not the longest-running query, and then fix the application pattern that leaves one open.