Reading EXPLAIN ANALYZE: where the time actually went

EXPLAIN shows the plan the optimizer picked; EXPLAIN ANALYZE runs the query and shows what actually happened. The gap between those two is where slow queries live. Reading a plan is mostly knowing which four numbers to look at.

EXPLAIN (ANALYZE, BUFFERS)
SELECT c.name, o.total
FROM orders o JOIN customers c ON c.id = o.customer_id
WHERE o.status = 'pending';

Nested Loop  (cost=0.43..12.85 rows=5 width=88)
             (actual time=0.031..0.118 rows=42 loops=1)
  ->  Seq Scan on orders  (actual time=0.012..0.041 rows=42 loops=1)
        Filter: (status = 'pending')
        Rows Removed by Filter: 158
  ->  Index Scan using customers_pkey on customers
        (actual time=0.001..0.001 rows=1 loops=42)

The four numbers

actual time: two values, startup and total, in milliseconds, per loop. The node at the top includes everything below it, so find the child where most of the parent's time is spent, that's your hot node.
rows, estimated vs actual: the planner guessed 5, got 42. Small misses are fine; an order of magnitude or more (rows=100 estimated, rows=800000 actual) means the planner chose a strategy for a table that isn't the one you have. Stale statistics (ANALYZE the_table; fixes it) or correlated columns (extended statistics fix it) are the usual causes.
loops: the inner side of a nested loop runs once per outer row. actual time=0.001 rows=1 loops=42 means 42 executions; multiply the time by the loops to know the real cost. A cheap node with 100k loops is a expensive node in disguise.
Rows Removed by Filter: the scan read 200 rows to keep 42. When that ratio gets extreme (millions read, dozens kept), the filter wants an index.

The patterns worth recognizing

Seq Scan on a big table under a loop. A sequential scan is correct for small tables and for queries that read most rows. It's a problem when it sits on a large table inside a nested loop, or when its filter removes almost everything, that's the missing-index signature, and on join columns it's usually an unindexed foreign key.

Sort Method: external merge Disk. The sort didn't fit in work_mem and spilled to disk. Either raise work_mem (session-level for the one report that needs it, not globally times every connection), or get the rows pre-sorted from an index.

Hash join with a huge build side. Fine when the small table is the one being hashed; suspicious when the estimate miss put the big table there. This is where the estimated-vs-actual gap does its damage.

BUFFERS: shared hit vs read. hit is cache, read is disk. A query that's fast at 9am and slow at 3am with the same plan is usually the cache line moving, and BUFFERS is how you see it.

Getting a plan you can share

EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON) SELECT ...;

The JSON form is what visual tools consume. Two cautions: ANALYZE really executes the statement, so wrap data-modifying queries in a transaction you roll back (BEGIN; EXPLAIN ANALYZE UPDATE ...; ROLLBACK;), and the timing instrumentation itself has overhead on some systems, the shape of the plan is more trustworthy than microsecond differences.

Reading nested text gets old at about three levels deep. Schemint's plan visualizer renders the same output as an interactive tree, time per node, estimate misses highlighted, entirely in your browser: the plan never leaves the page.

Reading EXPLAIN ANALYZE: where the time actually went

The four numbers

The patterns worth recognizing

Getting a plan you can share

Related