Reading EXPLAIN and EXPLAIN ANALYZE

A first plan

With no index on customer_id, looking up one customer's orders in a 500,000-row table:

1EXPLAIN ANALYZE SELECT * FROM orders WHERE customer_id = 42;

1Gather  (cost=1000.00..7672.67 rows=25 width=34) (actual time=0.252..9.184 rows=25 loops=1)2  Workers Planned: 23  Workers Launched: 24  ->  Parallel Seq Scan on orders  (cost=0.00..6670.17 rows=10 width=34) (actual time=1.214..4.549 rows=8 loops=3)5        Filter: (customer_id = 42)6        Rows Removed by Filter: 1666587Planning Time: 0.007 ms8Execution Time: 9.189 ms

Read it from the innermost node outwards. Three processes (the leader and two workers, hence loops=3) each scan a share of the table, keep about 8 rows and throw away about 166,658. Gather collects their rows. cost=1000.00..7672.67 is the estimated cost to produce the first row and all rows, in planner units, not milliseconds. rows=25 was the estimate; the actual was also 25, so the statistics are good. The problem is simply that the only way to find 25 rows is to read all of them.

After CREATE INDEX orders_customer_idx ON orders (customer_id), the same query with EXPLAIN (ANALYZE, BUFFERS) (planning lines trimmed):

1Bitmap Heap Scan on orders  (cost=4.62..99.05 rows=25 width=34) (actual time=0.018..0.037 rows=25 loops=1)2  Recheck Cond: (customer_id = 42)3  Heap Blocks: exact=254  Buffers: shared hit=28 read=35  ->  Bitmap Index Scan on orders_customer_idx  (cost=0.00..4.61 rows=25 width=0) (actual time=0.015..0.015 rows=25 loops=1)6        Index Cond: (customer_id = 42)7Execution Time: 0.048 ms

The index finds the 25 row locations, sorts them by page, and the heap scan visits just those pages. From 9 ms to 0.05 ms.

What to look at

• Estimated against actual rows. A factor of 10 or more at a low node means the nodes above were planned for the wrong amount of data.
• loops. Actual rows and times are per loop. A cheap-looking inner node with loops=50000 is where the time goes.
• Rows Removed by Filter. Many rows read and thrown away suggests a missing or unusable index.
• Buffers. EXPLAIN (ANALYZE, BUFFERS) shows pages found in shared memory (hit) and read from the operating system (read). It is often a better measure of work than time, which depends on what happens to be cached.
• Sort Method. external merge Disk: ... means the sort did not fit in work_mem and spilled to disk.

Run it safely

ANALYZE really executes the statement. For writes:

1BEGIN;2EXPLAIN (ANALYZE, BUFFERS) UPDATE orders SET status = 'paid' WHERE id = 7;3ROLLBACK;

Timing every node also adds overhead, so the total can be a little higher than the query's real runtime. For queries that are slow only now and then, the auto_explain module can log the plans of statements that exceed a duration you choose.