← Back to the section

A query runs slowly, but it's not clear why. Add an index? Rewrite the JOIN? Increase memory? One command answers all these questions — EXPLAIN ANALYZE. It shows exactly what PostgreSQL did while running the query and how much time it spent on each step.

the result is on top, the leaves are at the bottom — and they run first bottom-up Hash Join actual time=12 400 ms Seq Scan on orders actual rows=850 000 Hash hash table in memory Seq Scan on customer actual rows=9 Seq Scan on customeractual rows=9 Hashhash table in memory Seq Scan on ordersactual rows=850 000 Hash Joinactual time=12 400 ms 1 2 3 4 rows=1 200 — the planner's guessactual rows=850 000 — 700 times morestale statistics: ANALYZE orders

A plan is a tree, and the numbers show the order it runs in: leaves first, root last. You read it the same way — bottom-up. On step three the rows= estimate is off from the fact by a factor of hundreds: everything above it picked a join strategy from wrong numbers, so the cause lives here, not in the Hash Join itself.

How to run it

The minimal option is to just add EXPLAIN ANALYZE before the query:

live example

EXPLAIN ANALYZE SELECT * FROM orders WHERE status = 'PAID';
Run

Running examples is part of paid access. There the same code runs inside the article: editor, run and check next to the paragraph. Three free days →

The best option is to add BUFFERS so you can see how much data came from cache and how much from disk:

-- the parenthesised form: output options go inside the brackets
EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM orders WHERE status = 'PAID';

An important point: EXPLAIN ANALYZE actually runs the query. This is needed for an accurate measurement. If you want to check the plan for an UPDATE or DELETE without applying the changes, wrap it in a transaction:

-- a plan for an UPDATE, leaving no trace in the data
BEGIN;
EXPLAIN ANALYZE UPDATE orders SET status = 'CANCELLED' WHERE id = 'ord-01';
ROLLBACK;

How to read the output

Here is a sample output:

Hash Join  (cost=12.34..567.89 rows=1000 width=64) (actual time=1.234..56.789 rows=987 loops=1)
  Hash Cond: (a.id = b.a_id)
  Buffers: shared hit=1234 read=56
  ->  Seq Scan on a
  ->  Hash
        ->  Seq Scan on b

What each part means:

  • cost=START..TOTAL — PostgreSQL's estimate in arbitrary units. These are not milliseconds.
  • rows=N — how many rows PostgreSQL expected to get.
  • actual time=START..TOTAL — the real time in milliseconds.
  • actual rows=N loops=M — how many rows the node actually returned and how many times it ran.
  • Buffers: shared hit=X read=Y — hit is pages found in PostgreSQL's own cache, read is pages that were not there. "Not in the database cache" does not mean "from disk": the page most likely came from the operating system cache, which is fast. The real disk read time is shown by a separate I/O Timings line, and it only appears when the track_io_timing parameter is on.

You need to read the plan bottom-up. The lower nodes are the inner operations that run first. The root is the final result.

The first thing to look at is the discrepancy between rows= (estimate) and actual rows= (fact). If the estimate is ten or more times smaller than the real number of rows, PostgreSQL is building the plan on wrong data. The ANALYZE command on the table helps — it updates the statistics.

The second important point is loops. If a node ran many times, the real time needs to be multiplied: loops=10000 × actual time=0.5..1.2 means 12 seconds inside a single Nested Loop.

Table scan nodes

PostgreSQL chooses how to read a table based on the size of the result set, the presence of indexes and the cost settings.

Seq Scan — a full pass

Seq Scan on orders
  Filter: (status = 'PAID')
  Rows Removed by Filter: 850000

PostgreSQL reads the whole table and discards the unneeded rows. This is fine for small tables and for queries that select most of the rows. It's bad when Rows Removed by Filter is millions of times larger than the result — that's a sign you need an index on the filter field.

Index Scan — a pass over the index

Index Scan using ix_orders_status on orders
  Index Cond: (status = 'PAID')

PostgreSQL walks the B-tree index, then reads the needed rows from the table. If a condition ended up in Filter: rather than Index Cond:, that means the index on this field is not being used as a search key — and the rows are still being scanned one by one.

Index Only Scan — index only, no table

Index Only Scan using ix_orders_status_created on orders
  Index Cond: (status = 'PAID')
  Heap Fetches: 12

If all the needed columns are in the index, PostgreSQL may not touch the table at all. This is the fastest option.

If Heap Fetches is greater than zero, PostgreSQL still goes to the table — the visibility map is stale and doesn't allow skipping the check. VACUUM on the table helps.

Bitmap Scan — a two-phase read

Bitmap Heap Scan on orders
  Recheck Cond: (status = 'PAID')
  ->  Bitmap Index Scan on ix_orders_status

A two-phase process: first a bitmap of the pages that contain the needed rows is built, then those pages are read in order. This is more efficient than random reads for a medium-sized result set. A Bitmap also lets you combine several indexes (BitmapAnd, BitmapOr).

The Recheck Cond: line shows up on every Bitmap Heap Scan and by itself says nothing bad. Heap Blocks: ... lossy=N next to it does: there wasn't enough memory for the bitmap, so it remembered whole pages instead of rows, and the database now rechecks the condition on every row of those pages. Raising work_mem fixes it.

Joining tables

A second source in the query adds a join node to the tree — the one that decides how to glue two streams of rows:

live example

EXPLAIN ANALYZE
SELECT o.id, c.email, o.total_amount
FROM orders o
JOIN customer c ON c.id = o.customer_id
WHERE o.status = 'PAID'
ORDER BY o.created_at DESC;
Run

Running examples is part of paid access. There the same code runs inside the article: editor, run and check next to the paragraph. Three free days →

Three ways to glue them; the size of the inputs and the available indexes decide.

Nested Loop — a loop inside a loop

Nested Loop  (rows=100 loops=1)
  ->  Index Scan on a  (rows=100)
  ->  Index Scan on b  (rows=1 loops=100)
        Index Cond: (b.a_id = a.id)

For each row from the outer table, a match is looked up in the inner one. This works well when the outer result is small and the inner table has an index on the join key.

A common trap: loops=1000000 at actual time=0.5 — that's 500 seconds inside a single node. If the inner table is large and has no index, a Nested Loop degrades.

Hash Join — a hash table in memory

Hash Join
  Hash Cond: (a.id = b.a_id)
  ->  Seq Scan on a
  ->  Hash
        ->  Seq Scan on b

The smaller table is loaded into a hash table in memory, then for each row from the larger one a fast lookup is done. Good for joining two large tables without suitable indexes.

If the output shows Batches: 2 or more — the hash table didn't fit in memory and PostgreSQL wrote part of it to disk. Increasing work_mem for the session helps:

-- the memory is raised for the current database connection only
SET work_mem = '64MB';
EXPLAIN (ANALYZE, BUFFERS)
SELECT o.id, c.email FROM orders o JOIN customer c ON c.id = o.customer_id;

Merge Join — merging two sorted streams

Merge Join
  Merge Cond: (a.id = b.a_id)
  ->  Sort ...
  ->  Index Scan on ix_b_a_id

Both streams are sorted by the join key and merged like a zipper. Worth it on large volumes when the sorting comes for free — from a suitable index, for example.

Sorting and grouping

Sort — how to tell that data is going to disk

Sort
  Sort Key: created_at DESC
  Sort Method: external merge  Disk: 8192kB

external merge Disk: means the sort didn't fit in memory and went to disk. This is slow. There are two solutions: increase work_mem, or add an index with the needed sort order so the Sort node disappears from the plan.

If the sort is in memory, you'll see quicksort or top-N heapsort (for ORDER BY ... LIMIT N).

Grouping

  • Aggregate — simple aggregates: count(*), sum().
  • HashAggregate — GROUP BY via a hash table in memory. Fast, as long as the data fits.
  • GroupAggregate — GROUP BY after sorting. The planner picks it when rows already arrive sorted (from an index, say) or when its numbers say it's cheaper. The "hash doesn't fit in work_mem" case used to land here too, but since PostgreSQL 13 HashAggregate spills to disk — the plan shows a Disk Usage line.

Parallel plan

Gather
  Workers Planned: 2
  Workers Launched: 2
  ->  Parallel Seq Scan on orders

PostgreSQL can split the work across several parallel processes — the plan calls them Workers. The count is set by the max_parallel_workers_per_gather parameter (2 by default). Small tables are not parallelized — the threshold is controlled by min_parallel_table_scan_size (8 MB by default).

Tools for complex plans

When a plan has five or more levels, the text form stops being readable. Ready-made viewers help:

  • explain.depesz.com — color-highlights the nodes, shows the most expensive steps.
  • explain.dalibo.com (PEV2) — a graphical plan tree right in the browser.
  • pg_stat_statements — an extension that accumulates query statistics on a live database, without a manual EXPLAIN.

For PEV2 it's convenient to get the plan in JSON format:

-- the same plan, but machine-readable
EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON)
SELECT o.id, o.total_amount FROM orders o WHERE o.status = 'PAID';

In short

  • EXPLAIN (ANALYZE, BUFFERS) is the working option. The query really runs, so UPDATE and DELETE go inside BEGIN … ROLLBACK.
  • Read bottom-up, leaves first. A node's time is actual time × loops: that's how a Nested Loop with a million repeats turns into minutes.
  • rows= and actual rows= ten times apart or more — the planner worked from stale statistics, ANALYZE the table.
  • A condition in Filter: instead of Index Cond: — the index is not a search key. Heap Fetches > 0 on an Index Only Scan is cleared by VACUUM.
  • Short work_mem shows up as Batches > 1 in a Hash Join, external merge Disk: in a Sort, lossy=N in a Bitmap Heap Scan.
  • A large Buffers: read= — the pages weren't in the database cache, still not proof of disk: I/O Timings tells the disk time.