Postgres EXPLAIN Plan Reader

Read a Postgres EXPLAIN plan and find where the time went. Node times are PER LOOP, so this multiplies them out, and then points at the bad estimates, the filters that should be indexes, and the sorts that spilled to disk.

Paste below, or drop a file anywhere on this panel

Or drop a file anywhere on this panel. Nothing is uploaded: the analysis runs in this tab.

The answer appears here

Paste on the left and press Read the plan. Nothing leaves this tab.

Wanted a different tool?

Examples

Real input you can load into the tool above. Each one shows a different thing going wrong, because that is what the tool is for.

The node that hid behind its loop count

The Index Scan shows 1.598 ms and ran 2,000 times, so it accounted for 3.2 seconds. The Seq Scan shows 45 ms and looks worse. Reading the printed numbers as totals sends you to the wrong node.

Nested Loop  (cost=0.42..8234.19 rows=1 width=64) (actual time=0.031..1612.443 rows=980 loops=1)
  ->  Seq Scan on orders  (cost=0.00..4521.00 rows=1000 width=32) (actual time=0.010..45.221 rows=980 loops=1)
        Filter: (status = 'open'::text)
        Rows Removed by Filter: 199020
  ->  Index Scan using idx_items_order on items  (cost=0.42..3.70 rows=1 width=32) (actual time=0.800..1.598 rows=1 loops=2000)
        Index Cond: (order_id = orders.id)
Planning Time: 0.180 ms
Execution Time: 1615.220 ms

A sort that went to disk

external merge means the sort did not fit in work_mem. That is usually an order of magnitude slower, and it also means the row estimate was low enough that the planner sized the sort wrongly.

Sort  (cost=10450.00..10700.00 rows=100000 width=64) (actual time=820.100..960.220 rows=980000 loops=1)
  Sort Key: created_at DESC
  Sort Method: external merge  Disk: 215360kB
  ->  Seq Scan on events  (cost=0.00..3200.00 rows=100000 width=64) (actual time=0.020..210.400 rows=980000 loops=1)
Planning Time: 0.140 ms
Execution Time: 1020.880 ms

EXPLAIN with no ANALYZE

Costs are arbitrary units and rows are guesses. A plan can look excellent and run badly, and this output cannot tell you which is happening.

Hash Join  (cost=1200.00..8400.00 rows=50000 width=96)
  Hash Cond: (o.customer_id = c.id)
  ->  Seq Scan on orders o  (cost=0.00..4521.00 rows=200000 width=64)
  ->  Hash  (cost=800.00..800.00 rows=32000 width=32)
        ->  Seq Scan on customers c  (cost=0.00..800.00 rows=32000 width=32)

Common mistakes

These are the ones that fail silently. The config is accepted, nothing raises an error, and the consequence arrives later.

  1. Reading a node's `actual time` as its total

    It is per loop. A node showing 0.8 ms at `loops=2000` accounted for 1.6 seconds, which is usually the answer, while the node showing 45 ms at `loops=1` accounted for 45.

    Instead:Multiply time by loops on every node before comparing them.

  2. Treating a bad row estimate as a cosmetic detail

    The planner chooses every join method and order from the estimate. When it expects one row and gets a thousand it picks the wrong shape for the whole query, so the slow node is a symptom rather than the cause.

    Instead:`ANALYZE` the table, raise the statistics target on the column, and use `CREATE STATISTICS` for correlated columns.

  3. Assuming a sequential scan is always the problem

    It is the right plan when it returns most of the table. What makes it wrong is the ratio: `Rows Removed by Filter` far exceeding rows returned means the whole table was read to discard nearly all of it.

    Instead:Compare rows returned against rows removed. Index the filtered column, or use a partial index on exactly that condition.

  4. Raising `work_mem` globally after seeing a spill to disk

    It is charged per sort node across every connection, so a global increase multiplies into the memory worst case for the whole server.

    Instead:`SET LOCAL work_mem` inside the transaction that needs it, and fix the low row estimate that made the planner size the sort wrongly.

  5. Reading `EXPLAIN` without `ANALYZE` and concluding anything about time

    The costs are arbitrary units and the rows are guesses. A plan can look excellent and run badly, and that output cannot tell you which.

    Instead:`EXPLAIN (ANALYZE, BUFFERS)`, inside a transaction you roll back if the statement writes.

The time on a node is per loop

An EXPLAIN plan is readable once you know which numbers are totals and which are not. One of them is not, and misreading it sends the investigation to the wrong node almost every time.

Multiply by loops before comparing anything

actual time and rows on a node are per execution of that node. A node showing 0.8 ms with loops=2000 accounted for 1.6 seconds, and a node showing 45 ms with loops=1 accounted for 45. Scanning the plan for the largest printed time finds the second one and misses the first, which is why a nested loop over a large outer side so often hides in plain sight.

->  Index Scan on items  (actual time=0.800..1.598 rows=1 loops=2000)
                                            ^^^^^^^^^^^^^^^^^^^^^^
    printed  1.598 ms
    real     1.598 x 2000 = 3,196 ms

An estimate out by an order of magnitude is the root cause

The planner picks every join method and order from its row estimates. When it expects one row and gets a thousand, it does not merely run one node slowly, it chooses the wrong shape for the whole query: a nested loop where a hash join belonged. Fixing the plan usually means fixing the estimate, with ANALYZE, a higher statistics target, or CREATE STATISTICS for columns that correlate.

Rows Removed by Filter is the missing index

A sequential scan that reads two hundred thousand rows to return nine hundred is doing the filtering after the reading. A sequential scan is the right plan when it returns most of the table and the wrong one when it discards nearly all of it, and the ratio between rows returned and rows removed is the clearest signal in the whole plan.

A spill to disk is a work_mem problem and an estimate problem

Sort Method: external merge, or Batches greater than one on a hash, means the operation did not fit in work_mem and went to temporary files, typically an order of magnitude slower. It also means the planner sized it from a row estimate that was too low, so there are usually two things to fix rather than one.

EXPLAIN without ANALYZE tells you nothing about time

The costs are arbitrary units and the row counts are guesses. A plan can look excellent and run badly and there is no way to tell which from that output. EXPLAIN (ANALYZE, BUFFERS) executes the query and gives real numbers, so run it inside a transaction you roll back for anything that writes.

What this cannot see

It reads the text output you paste and nothing else. It does not have your schema, your indexes, your statistics or your table sizes, so it can point at a node and say what the numbers mean, and it cannot tell you which index to create. It parses the TEXT format rather than JSON, because that is what people copy out of psql, and it reads the node lines and the detail lines beneath them; unusual node types and extension plans may parse as generic nodes. BUFFERS output is not interpreted, and buffer counts are often the fastest route to a cache problem this page will not mention.