How to read Postgres EXPLAIN ANALYZE output: a practical field guide

Most of us run EXPLAIN ANALYZE when a query is slow, scroll until we see Seq Scan, add an index, and hope. Sometimes that works. Often the index is not used, or the query gets slower, because the real problem was a bad row estimate three levels down, or a nested loop that ran 40,000 times.

This guide is for application developers who can write SQL but have never been taught to read a plan. We will use one slow query from an invoicing app we maintain, read its plan from the inside out, and map each pattern to the fix it usually needs. Everything here applies to PostgreSQL 13 and later; the examples come from PostgreSQL 17.4.

Run the right command

Plain EXPLAIN shows the plan the optimizer picked and its estimates. It does not run the query. EXPLAIN ANALYZE runs it and adds what actually happened. Add BUFFERS to see how much data was touched, which is usually more telling than time:

EXPLAIN (ANALYZE, BUFFERS, SETTINGS)
SELECT c.name, sum(i.total_cents) AS open_cents
FROM invoices i
JOIN customers c ON c.id = i.customer_id
WHERE i.status = 'open'
  AND i.due_date < now() - interval '30 days'
  AND c.region = 'apac'
GROUP BY c.name
ORDER BY open_cents DESC
LIMIT 20;

Two warnings before you paste this into production:

• ANALYZE executes the statement. For UPDATE, DELETE or INSERT, wrap it in a transaction and roll back: BEGIN; EXPLAIN ANALYZE UPDATE ...; ROLLBACK;.
• SETTINGS lists any planner settings that differ from defaults, which saves a lot of confusion when someone has tuned random_page_cost or work_mem per role.

PostgreSQL 17 also added SERIALIZE (time spent converting rows for the client) and MEMORY (planner memory). Useful, but not needed for most investigations.

The shape of a plan

Here is the output, trimmed slightly:

Limit  (cost=48211.40..48211.45 rows=20 width=40) (actual time=1874.112..1874.118 rows=20 loops=1)
  Buffers: shared hit=12044 read=96512
  ->  Sort  (cost=48211.40..48213.90 rows=1000 width=40) (actual time=1874.110..1874.114 rows=20 loops=1)
        Sort Key: (sum(i.total_cents)) DESC
        Sort Method: top-N heapsort  Memory: 27kB
        ->  HashAggregate  (cost=48170.00..48180.00 rows=1000 width=40) (actual time=1873.502..1873.871 rows=842 loops=1)
              Group Key: c.name
              ->  Nested Loop  (cost=0.43..48160.12 rows=1976 width=20) (actual time=0.091..1861.330 rows=41388 loops=1)
                    ->  Seq Scan on invoices i  (cost=0.00..41230.00 rows=1976 width=16) (actual time=0.031..1702.554 rows=164020 loops=1)
                          Filter: ((status = 'open'::text) AND (due_date < (now() - '30 days'::interval)))
                          Rows Removed by Filter: 2835980
                          Buffers: shared hit=4012 read=96512
                    ->  Index Scan using customers_pkey on customers c  (cost=0.43..3.50 rows=1 width=20) (actual time=0.001..0.001 rows=0 loops=164020)
                          Index Cond: (id = i.customer_id)
                          Filter: (region = 'apac'::text)
                          Rows Removed by Filter: 1
                          Buffers: shared hit=8032
Planning Time: 0.412 ms
Execution Time: 1874.301 ms

A plan is a tree. Each -> is a node; children are indented under their parent. Rows flow upwards: leaves read tables or indexes, parents join, aggregate, sort and limit. Read it from the most indented line outwards, because that is where the work starts.

What each number means

Every node has two parenthesised groups.

The per-loop part trips everyone up. For the inner index scan above, actual time=0.001..0.001 looks free, but loops=164020 means it ran 164,020 times. Multiply time and rows by loops to get the real totals.

Buffers: shared hit=N read=M counts 8 kB pages. hit came from PostgreSQL's shared buffers, read came from the operating system (page cache or disk). A parent node's buffers include its children's. In our plan, 96,512 pages read is roughly 750 MB pulled in by the sequential scan, which explains most of the 1.7 seconds.

Rows Removed by Filter is the number of rows a node read and threw away. A large number next to a small output is the classic sign that an index, or a better one, would help.

Step 1: find where the time goes

Walk down the tree and look at each node's actual time end value times loops, minus its children. In our plan:

• The sequential scan on invoices ends at 1,702 ms.
• The nested loop ends at 1,861 ms, so the join itself plus 164,020 index lookups added about 160 ms.
• Aggregate, sort and limit add almost nothing.

So the scan is the hot spot. It reads 3 million invoices to keep 164,020 and discards 2.8 million.

Step 2: compare estimates with actuals

This is the most important habit. The scan estimated rows=1976 and produced rows=164020, an error of about 83 times. Because the planner believed only about 2,000 invoices would match, a nested loop with 2,000 index lookups looked cheap. With 164,020, a hash join on customers would have been far better.

When estimates are off by more than about 10x, fix the estimate before adding indexes. Common causes:

In our case, status = 'open' and due_date < now() - 30 days were strongly correlated: almost all old invoices are paid, but the ones that are still open are overdue. The planner multiplied the two selectivities and got a tiny number. We checked the last analyze time first:

SELECT relname, last_analyze, last_autoanalyze, n_mod_since_analyze
FROM pg_stat_user_tables
WHERE relname = 'invoices';

It was recent, so stale statistics were not the issue.

Step 3: read the node types

A sequential scan is not automatically bad. Reading 80 percent of a table sequentially is faster than an index. It is bad when the output is a small fraction of what was read.

Step 4: apply the fix and measure again

We gave the planner both a better estimate and a better access path. First, extended statistics on the correlated columns:

CREATE STATISTICS invoices_status_due (dependencies, mcv) ON status, due_date FROM invoices;
ANALYZE invoices;

Then a partial index that only contains open invoices, which are about 6 percent of the table:

CREATE INDEX CONCURRENTLY invoices_open_due_idx
  ON invoices (due_date, customer_id)
  INCLUDE (total_cents)
  WHERE status = 'open';

The new plan, trimmed:

Limit  (actual time=96.802..96.809 rows=20 loops=1)
  Buffers: shared hit=3121 read=402
  ->  Sort  (actual time=96.800..96.805 rows=20 loops=1)
        Sort Key: (sum(i.total_cents)) DESC
        Sort Method: top-N heapsort  Memory: 27kB
        ->  HashAggregate  (actual time=96.211..96.560 rows=842 loops=1)
              ->  Hash Join  (rows=40210) (actual time=4.950..88.410 rows=41388 loops=1)
                    Hash Cond: (i.customer_id = c.id)
                    ->  Index Only Scan using invoices_open_due_idx on invoices i  (rows=158400) (actual time=0.040..41.215 rows=164020 loops=1)
                          Index Cond: (due_date < (now() - '30 days'::interval))
                          Heap Fetches: 0
                    ->  Hash  (actual time=4.802..4.803 rows=11940 loops=1)
                          Buckets: 16384  Batches: 1  Memory Usage: 742kB
                          ->  Seq Scan on customers c  (actual time=0.012..3.410 rows=11940 loops=1)
                                Filter: (region = 'apac'::text)
Execution Time: 97.120 ms

The estimate is now within 4 percent, the planner switched to a hash join, the scan is index-only with zero heap fetches, and buffers dropped from about 108,000 pages to about 3,500. Execution went from 1,874 ms to 97 ms. The sequential scan on customers is fine: it is small and we need a fifth of it.

Habits that keep you out of trouble

• Run it twice. The first run warms the cache. Compare read counts between runs to see what is cold-cache cost and what is CPU.
• Use production-like data. Plans depend on statistics. A plan from a 1,000-row dev database says nothing about a 3-million-row table.
• Watch Planning Time. A few hundred milliseconds of planning points at too many partitions or a huge IN list, not at the executor.
• Look for spills. external merge Disk:, Batches: 8, or lossy blocks mean work_mem is too small for that node. Raise it per session or per role, not globally.
• Use auto_explain to log plans of slow queries in production, with auto_explain.log_min_duration and auto_explain.log_analyze set carefully, because analyze mode adds timing overhead to every logged statement.

Common mistakes

Key takeaways

• Read plans from the most indented node outwards, and multiply per-loop numbers by loops.
• The biggest gap between estimated and actual rows usually explains a bad join choice.
• BUFFERS shows the real cost of a query better than time on a warm cache.
• Large Rows Removed by Filter next to a small output is where an index, often a partial one, pays off.
• Correlated columns need CREATE STATISTICS; stale statistics need ANALYZE.
• Re-run the plan after every change and keep the before and after in the pull request.

References

• PostgreSQL documentation: Using EXPLAIN — https://www.postgresql.org/docs/current/using-explain.html
• PostgreSQL documentation: EXPLAIN command — https://www.postgresql.org/docs/current/sql-explain.html
• PostgreSQL documentation: Extended statistics (CREATE STATISTICS) — https://www.postgresql.org/docs/current/sql-createstatistics.html
• PostgreSQL documentation: Partial indexes — https://www.postgresql.org/docs/current/indexes-partial.html
• PostgreSQL documentation: auto_explain — https://www.postgresql.org/docs/current/auto-explain.html
• PostgreSQL 17 release notes — https://www.postgresql.org/docs/release/17.0/