Reading EXPLAIN (ANALYZE, BUFFERS) without panicking
A plan is a tree of numbers that all look important. Most of them aren't. This is the order I read them in.
- Find the node where
rows=andactual rows=disagree by ten times or more. That's where the planner was wrong, and every node above it inherited the mistake. It's almost always a stale statistic, two correlated columns the planner thinks are independent (CREATE STATISTICSexists for this), or a function wrapped around a column. - Look at
loops=. The times and rows on a node are per loop.rows=1 loops=48213is 48,213 index lookups, and the 0.016 ms next to it needs multiplying before it means anything. - Look at
Rows Removed by Filter. A large number here means the index fetched the wrong rows and the filter threw them away. Usually the column order in a composite index, sometimes a missing index entirely. - Only now,
Buffers.shared readis what came from disk or the OS cache rather than shared buffers; a node with millions of reads is I/O-bound and no amount of CPU will help.temp read/writtenmeans a sort or hash spilled; that'swork_mem. - Last, the total time. It's the number everyone looks at first and it tells you the least, because you already knew the query was slow.
An example, trimmed:
Nested Loop (cost=0.86..5240.12 rows=12 width=64)
(actual time=0.091..812.330 rows=48213 loops=1)
-> Index Scan using orders_created_idx on orders o
(cost=0.43..184.20 rows=12 width=40)
(actual time=0.030..9.412 rows=48213 loops=1)
Index Cond: (created_at >= '2023-11-01')
Filter: (status = 'paid')
Rows Removed by Filter: 3120
-> Index Scan using customers_pkey on customers c
(cost=0.43..0.47 rows=1 width=24)
(actual time=0.015..0.016 rows=1 loops=48213)
Index Cond: (id = o.customer_id)
Buffers: shared hit=192851 read=1044
The whole story is rows=12 against rows=48213 on the first index scan. The planner expected twelve orders since the first of the month, chose a nested loop on that basis, and then did 48,213 primary-key lookups into customers. With a correct estimate it would have hashed customers once. ANALYZE orders fixed it; the statistics had gone stale after a bulk load the night before, and autovacuum hadn't caught up. Nothing about the query was wrong. Nothing about the indexes was wrong. Step one, every time.