Reading EXPLAIN in PostgreSQL: ANALYZE, BUFFERS, Scan and Join Nodes, Statistics and pg_stat_statements
When you read a PostgreSQL plan, you first compare each node's estimated row count with the actual value from EXPLAIN ANALYZE; the planner's decisions rest on that estimate. Calculating cost by hand, BUFFERS on by default in 18, loops and fractional rows, nested loop, hash and merge joins, CREATE STATISTICS fixing an estimate off by 13 times, pg_stat_statements, GENERIC_PLAN and auto_explain catching an EF Core query's plan with its parameters.
Version note: The examples in this post were run with PostgreSQL 18.7 (the official postgres:18 Docker image), .NET 10, Npgsql 10.0.3 and Npgsql.EntityFrameworkCore.PostgreSQL 10.0.3, in the Bookstore lab we set up in post 02, right after reloading the schema.
Guess First
The product team of Bookstore, the online bookstore used as the shared example across this site's series, wants a "best sellers of the last 30 days" box on the category page. The query is simple: orders, order items and books are joined and cancelled orders are left out. As in post 06, we turned off parallel query in the session to keep the plans simple, and first ran only EXPLAIN:
SET max_parallel_workers_per_gather = 0;
EXPLAIN
SELECT b.book_id, b.title, sum(oi.quantity) AS sold
FROM orders o
JOIN order_items oi ON oi.order_id = o.order_id
JOIN books b ON b.book_id = oi.book_id
WHERE o.created_at >= timestamptz '2026-09-20' AND o.status <> 'Cancelled' AND b.category = 'Fantasy'
GROUP BY b.book_id, b.title
ORDER BY sold DESC
LIMIT 10;
Limit (cost=74686.63..74686.65 rows=10 width=30)
-> Sort (cost=74686.63..74696.59 rows=3983 width=30)
Sort Key: (sum(oi.quantity)) DESC
-> GroupAggregate (cost=74521.58..74600.56 rows=3983 width=30)
Group Key: b.book_id
-> Sort (cost=74521.58..74534.63 rows=5220 width=24)
Sort Key: b.book_id
-> Hash Join (cost=26565.84..74199.25 rows=5220 width=24)
Hash Cond: (oi.book_id = b.book_id)
-> Hash Join (cost=25572.05..73067.85 rows=52420 width=6)
Hash Cond: (oi.order_id = o.order_id)
-> Seq Scan on order_items oi (cost=0.00..40931.96 rows=2500496 width=10)
-> Hash (cost=25310.00..25310.00 rows=20964 width=4)
-> Seq Scan on orders o (cost=0.00..25310.00 rows=20964 width=4)
Filter: ((created_at >= '2026-09-20 00:00:00+00'::timestamp with time zone) AND (status <> 'Cancelled'::text))
-> Hash (cost=944.00..944.00 rows=3983 width=22)
-> Seq Scan on books b (cost=0.00..944.00 rows=3983 width=22)
Filter: (category = 'Fantasy'::text)
The schema has no index on orders.created_at; only 21 thousand of the one million orders are from the last 30 days. Two questions: where does this plan see most of its cost? If you add an index on orders (created_at), how much do the total cost and the number of pages read go down? We'll look at the answer after adding the index. First let's learn the language of the plan: cost, estimates versus actuals, scan and join nodes, statistics, and finding slow queries in production.
The Language of EXPLAIN: cost, rows, width
A plan is a tree. You start reading at the innermost node, the one indented furthest to the right; every node takes rows from the nodes below it, processes them and passes them up. It's the text form of the right-to-left flow you read in a graphical SQL Server plan. Every node carries three estimates: cost=startup..total, rows and width, the estimated bytes per row.
Cost is not a duration; it's the planner's own unit. It comes from settings and can be calculated by hand:
SELECT relpages, reltuples FROM pg_class WHERE relname = 'books';
SELECT name, setting FROM pg_settings
WHERE name IN ('seq_page_cost', 'random_page_cost', 'cpu_tuple_cost', 'cpu_operator_cost') ORDER BY 1;
EXPLAIN SELECT count(*) FROM books WHERE category = 'Fantasy';
relpages | reltuples
----------+-----------
444 | 40000
name | setting
-------------------+---------
cpu_operator_cost | 0.0025
cpu_tuple_cost | 0.01
random_page_cost | 4
seq_page_cost | 1
Aggregate (cost=953.96..953.97 rows=1 width=8)
-> Seq Scan on books (cost=0.00..944.00 rows=3983 width=0)
Filter: (category = 'Fantasy'::text)
444 pages × 1 (seq_page_cost) + 40,000 rows × 0.01 (cpu_tuple_cost) + 40,000 filter comparisons × 0.0025 (cpu_operator_cost) = 444 + 400 + 100 = 944. Every planner decision is a comparison of sums like this: a page read sequentially costs 1 unit, a page read randomly costs 4. The startup cost is the part spent before the first row can be returned. Nodes such as Sort and Hash can't return a single row before reading all of their input, so their startup and total costs are close. For queries with LIMIT, the planner likes plans with a low startup cost; we'll see that in the merge join example below.
The first half of the answer is already here: the plan's total cost is 74,686, of which 40,931 is the sequential scan of 2.5 million rows in order_items and 25,310 is the scan of orders.
EXPLAIN ANALYZE and BUFFERS: Reading Estimates Next to Reality
EXPLAIN doesn't run the query; it only shows the plan. The ANALYZE option really runs the query and adds the actual values to every node. Since PostgreSQL 18, BUFFERS is on by default together with ANALYZE. TIMING OFF turns off per-node timing; row and buffer counts stay, and the overhead of the measurement itself goes down.
EXPLAIN (ANALYZE, TIMING OFF)
SELECT b.book_id, b.title, sum(oi.quantity) AS sold
...;
Limit (cost=74686.63..74686.65 rows=10 width=30) (actual rows=10.00 loops=1)
Buffers: shared hit=13223 read=13464 written=97
...
-> Hash Join (cost=26565.84..74199.25 rows=5220 width=24) (actual rows=5376.00 loops=1)
Hash Cond: (oi.book_id = b.book_id)
-> Hash Join (cost=25572.05..73067.85 rows=52420 width=6) (actual rows=53224.00 loops=1)
Hash Cond: (oi.order_id = o.order_id)
-> Seq Scan on order_items oi (cost=0.00..40931.96 rows=2500496 width=10) (actual rows=2500496.00 loops=1)
Buffers: shared hit=6193 read=9734 written=91
-> Hash (cost=25310.00..25310.00 rows=20964 width=4) (actual rows=21351.00 loops=1)
Buckets: 32768 Batches: 1 Memory Usage: 1007kB
Buffers: shared hit=6580 read=3730 written=6
-> Seq Scan on orders o (cost=0.00..25310.00 rows=20964 width=4) (actual rows=21351.00 loops=1)
Filter: ((created_at >= '2026-09-20 00:00:00+00'::timestamp with time zone) AND (status <> 'Cancelled'::text))
Rows Removed by Filter: 978649
Buffers: shared hit=6580 read=3730 written=6
Planning:
Buffers: shared hit=30
Planning Time: 0.102 ms
Execution Time: 140.326 ms
Look at three things when you read it. First, the ratio of estimate to actual: 20,964 versus 21,351 for orders, 52,420 versus 53,224 for the join result. The estimates are within a few percent; the planner decided with correct information. Second, Rows Removed by Filter: a million rows were read for 21 thousand, which is where an index would help. Third, the buffers: hit is an 8 KB page found in shared buffers, read is one requested from the operating system (as we saw in post 01, it doesn't have to come from disk), and written is a dirty page this query had to write out to make room. The buffer counts of a node include those of the nodes below it; the 26,687 pages at the top are the whole query.
The .00 in the row counts is new in 18: PostgreSQL 18 shows actual rows with decimals. The reason is loops. When a node runs more than once, as the inner side of a nested loop or in parallel workers, rows is the average of one execution, and the total is rows × loops. In 17 and earlier this average was rounded to an integer, and an inner loop returning 0.4 rows showed up as 0.
Don't forget that ANALYZE really runs the statement. If you want the plan of a DELETE or UPDATE, do it inside a transaction and roll it back:
BEGIN;
EXPLAIN (ANALYZE, COSTS OFF, TIMING OFF, SUMMARY OFF)
DELETE FROM order_items WHERE order_id <= 1000;
ROLLBACK;
SELECT count(*) FROM order_items WHERE order_id <= 1000;
Delete on order_items (actual rows=0.00 loops=1)
Buffers: shared hit=2507 read=20 dirtied=16 written=17
-> Index Scan using ix_order_items_order_id on order_items (actual rows=2488.00 loops=1)
Index Cond: (order_id <= 1000)
count
-------
2488
2,488 rows were really deleted and came back with ROLLBACK. Even this needs care in production: the rows stay locked during the delete and triggers fire.
Scan Nodes
We saw the four basic ways to access a table in post 06; a reminder for reading plans:
| Node | What it does | Line to watch in the plan |
|---|---|---|
Seq Scan | Reads every page of the table in order | A large Rows Removed by Filter may mean a selective index is missing |
Index Scan | Finds rows in the index and visits the table for each one | Index Cond versus Filter: only Index Cond uses the index |
Index Only Scan | Answers from the index and visits the table only when the visibility map requires it | If Heap Fetches moves away from zero, the table isn't vacuumed enough |
Bitmap Heap Scan | Builds a list of pages from the index first, then reads the pages in physical order | Heap Blocks: lossy on a bitmap from a B-tree means the bitmap didn't fit in work_mem |
18 added an Index Searches line to index scans; it tells you how many times the index was descended. It was 6 for the skip scan in post 06, and we'll see 5,453 in the nested loop below.
Join Nodes: Nested Loop, Hash Join, Merge Join
PostgreSQL's three join algorithms follow the same ideas as SQL Server's. The selection logic from the first execution plan post of the SQL Server Derinlemesine series applies here too; what differs is how they look in the plan. First, the second half of the guess: we added the orders (created_at) index and ran the same query again.
CREATE INDEX ix_orders_created_at ON orders (created_at);
Limit (cost=50281.13..50281.16 rows=10 width=30) (actual rows=10.00 loops=1)
Buffers: shared hit=6977 read=9688
...
-> Hash Join (cost=1166.55..48662.35 rows=52420 width=6) (actual rows=53224.00 loops=1)
Hash Cond: (oi.order_id = o.order_id)
-> Seq Scan on order_items oi (cost=0.00..40931.96 rows=2500496 width=10) (actual rows=2500496.00 loops=1)
Buffers: shared hit=6303 read=9624
-> Hash (cost=904.50..904.50 rows=20964 width=4) (actual rows=21351.00 loops=1)
-> Index Scan using ix_orders_created_at on orders o (cost=0.42..904.50 rows=20964 width=4) (actual rows=21351.00 loops=1)
Index Cond: (created_at >= '2026-09-20 00:00:00+00'::timestamp with time zone)
Filter: (status <> 'Cancelled'::text)
Rows Removed by Filter: 889
Buffers: shared hit=230 read=64
The orders side went from 10,310 pages to 294, but the total only dropped from 26,687 to 16,665 and the cost from 74,686 to 50,281. order_items is still read from start to end. That's how a hash join works: it builds an in-memory hash table from the smaller input (21 thousand orders; the Hash node, where Batches: 1 means it fit), then scans the larger input once and looks up every row in the table. The alternative is to descend the order_items index once for each of the 21 thousand orders; the planner found that more expensive. Narrow the range to seven days and the decision changes:
Nested Loop (cost=0.85..33334.33 rows=12495 width=6) (actual rows=13697.00 loops=1)
Buffers: shared hit=21914 read=28
-> Index Scan using ix_orders_created_at on orders o (cost=0.42..221.37 rows=4997 width=4) (actual rows=5453.00 loops=1)
Index Cond: (created_at >= '2026-10-13 00:00:00+00'::timestamp with time zone)
-> Index Scan using ix_order_items_order_id on order_items oi (cost=0.43..6.60 rows=3 width=10) (actual rows=2.51 loops=5453)
Index Cond: (order_id = o.order_id)
Index Searches: 5453
A nested loop runs the inner side once for every row of the outer input: 5,453 orders, 5,453 index searches, 2.51 items per loop on average, 13,697 rows in total. Note the buffer count: 21,914 pages were "read", but they are mostly hits on the same index pages over and over. This cost grows linearly with the number of loops, so if the inner side has no index, or the outer side turns out far above its estimate, this becomes the most expensive plan. The threshold between 30 days and 7 days depends exactly on the planner's row estimate.
A merge join, on the other hand, walks both inputs together like a zipper when both are sorted on the join column. The order_id indexes of orders and payments provide sorted input:
EXPLAIN (ANALYZE, TIMING OFF, SUMMARY OFF)
SELECT count(*) FROM orders o JOIN payments p ON p.order_id = o.order_id WHERE o.order_id <= 300000;
Aggregate (cost=41515.24..41515.25 rows=1 width=8) (actual rows=1.00 loops=1)
-> Merge Join (cost=2.16..40765.77 rows=299786 width=0) (actual rows=300000.00 loops=1)
Merge Cond: (o.order_id = p.order_id)
-> Index Only Scan using orders_pkey on orders o (cost=0.42..8538.68 rows=299786 width=4) (actual rows=300000.00 loops=1)
Index Cond: (order_id <= 300000)
Heap Fetches: 0
-> Index Only Scan using ux_payments_order_id on payments p (cost=0.42..25980.42 rows=1000000 width=4) (actual rows=300000.00 loops=1)
Heap Fetches: 0
On the payments side the estimate is a million rows and the actual is 300 thousand: a merge join stops reading the right side once the left side is done. Its startup cost is also very low (2.16), because it finds the first match right away; that's why the planner often picks it for queries with LIMIT. The Memoize node you'll sometimes see on the inner side of a nested loop (14+) keeps the results of repeated lookups with the same key in memory.
Planner Statistics: pg_stats and CREATE STATISTICS
Row estimates come from the statistics that ANALYZE collects. Autovacuum does this on its own; running it by hand is the first thing to do after a bulk load. The pg_stats view shows what is known:
SELECT n_distinct, most_common_vals, most_common_freqs
FROM pg_stats WHERE tablename = 'orders' AND attname = 'status';
n_distinct | most_common_vals | most_common_freqs
------------+------------------------------------------------------+-----------------------------------------------------------------
5 | {Delivered,Cancelled,Shipped,Pending,PaymentPending} | {0.94226664,0.038533334,0.014233333,0.0045333332,0.00043333333}
In reality 940,502 orders are Delivered (94.05%), the statistics say 94.23%, because ANALYZE reads a sample, not the whole table. The sample size is proportional to default_statistics_target (default 100): the output of ANALYZE VERBOSE orders says "30000 rows in sample". Besides the most common values list and their frequencies, a histogram with 100 buckets is kept for sortable columns. If the estimates for a skewed column are off, you can raise that column's target with ALTER TABLE ... ALTER COLUMN ... SET STATISTICS 500.
Statistics are per column, and the planner assumes columns are independent. In Bookstore the city depends on the country: every customer in Lille is in France. The planner, however, multiplies the probabilities of "being in France" and "being in Lille":
EXPLAIN (ANALYZE, TIMING OFF, SUMMARY OFF)
SELECT o.currency, count(*), sum(o.total_amount)
FROM customers c JOIN orders o ON o.customer_id = c.customer_id
WHERE c.country = 'FR' AND c.city = 'Lille'
GROUP BY o.currency;
GroupAggregate (cost=9274.14..9279.46 rows=2 width=44) (actual rows=1.00 loops=1)
Buffers: shared hit=5142 read=3205 written=347
-> Sort (cost=9274.14..9275.46 rows=530 width=10) (actual rows=5096.00 loops=1)
-> Nested Loop (cost=4.61..9250.15 rows=530 width=10) (actual rows=5096.00 loops=1)
-> Seq Scan on customers c (cost=0.00..2665.00 rows=53 width=4) (actual rows=697.00 loops=1)
Filter: ((country = 'FR'::bpchar) AND (city = 'Lille'::text))
-> Bitmap Heap Scan on orders o (cost=4.61..123.92 rows=33 width=14) (actual rows=7.31 loops=697)
Recheck Cond: (c.customer_id = customer_id)
Estimated 53 customers, actual 697: off by a factor of 13. The planner chose a nested loop for 53 customers and the inner side ran 697 times. We teach the planner the relationship between the columns with extended statistics:
CREATE STATISTICS st_customers_country_city (dependencies) ON country, city FROM customers;
ANALYZE customers;
SELECT dependencies FROM pg_stats_ext WHERE statistics_name = 'st_customers_country_city';
HashAggregate (cost=25655.85..25655.87 rows=2 width=44) (actual rows=1.00 loops=1)
Buffers: shared hit=8228 read=3247
-> Hash Join (cost=2672.96..25608.07 rows=6370 width=10) (actual rows=5096.00 loops=1)
Hash Cond: (o.customer_id = c.customer_id)
-> Seq Scan on orders o (cost=0.00..20310.00 rows=1000000 width=14) (actual rows=1000000.00 loops=1)
-> Hash (cost=2665.00..2665.00 rows=637 width=4) (actual rows=697.00 loops=1)
-> Seq Scan on customers c (cost=0.00..2665.00 rows=637 width=4) (actual rows=697.00 loops=1)
dependencies
----------------------
{"6 => 5": 1.000000}
"6 => 5": 1.000000 says that column 6 (city) fully determines column 5 (country). The estimate went up to 637 and the planner switched to a hash join. In this small example the two plans are close, and the new one even reads a few more buffers; but an estimate off by 13 times is the most common cause of plans where a nested loop runs tens of thousands of times on large tables. Besides dependencies there are the ndistinct kind, for the number of distinct values of columns used together in GROUP BY estimates, and the mcv kind; the CREATE STATISTICS we used for an expression on a JSON column in post 05 was the same mechanism. pg_stats is the counterpart of the histogram and density from the statistics post of the SQL Server Derinlemesine series, and CREATE STATISTICS is the counterpart of a multi-column statistics object.
Finding Slow Queries: pg_stat_statements and auto_explain
To know which plan to look at, you first need to see where the load comes from. pg_stat_statements replaces constants with $1, $2, groups queries of the same shape, and accumulates the number of calls, total time, buffers read and more for each group. It's the counterpart of SQL Server's Query Store or sys.dm_exec_query_stats. It has to be loaded when the server starts, so it needs one restart:
docker exec -it bookstore-pg psql -U postgres -c "ALTER SYSTEM SET shared_preload_libraries = 'pg_stat_statements'"
docker restart bookstore-pg
docker exec -it bookstore-pg psql -U postgres -d bookstore -c "CREATE EXTENSION pg_stat_statements" -c "GRANT pg_read_all_stats TO bookstore_owner"
Without the pg_read_all_stats role the owner can't see the query text of other roles, such as the application role. The details of the extension mechanism are in post 13. After running the application for a while, the most expensive queries are:
SELECT calls, round(total_exec_time::numeric) AS total_ms, round(mean_exec_time::numeric, 1) AS mean_ms,
shared_blks_hit + shared_blks_read AS blocks, left(query, 40) AS query
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 3;
calls | total_ms | mean_ms | blocks | query
-------+----------+---------+--------+------------------------------------------
20 | 1054 | 52.7 | 551980 | SELECT o.book_id AS "BookId", b.title AS
Sort by total_exec_time: a 5 ms query that runs a thousand times a second puts more load on the server than a 10-second report that runs once a day. This query comes from EF Core; we'll come back to it below.
pg_stat_statements keeps the query text without parameter values. You can look at the plan of that text without supplying values using EXPLAIN (GENERIC_PLAN), available since PostgreSQL 16:
EXPLAIN (GENERIC_PLAN)
SELECT o.book_id, sum(o.quantity) FROM order_items AS o
JOIN orders AS o0 ON o.order_id = o0.order_id
WHERE o0.created_at >= $1
GROUP BY o.book_id;
HashAggregate (cost=95789.70..96100.98 rows=31128 width=12)
-> Hash Join (cost=18403.41..91622.21 rows=833498 width=6)
-> Seq Scan on order_items o (cost=0.00..40931.96 rows=2500496 width=10)
-> Hash (cost=12933.75..12933.75 rows=333333 width=4)
-> Index Scan using ix_orders_created_at on orders o0 (cost=0.42..12933.75 rows=333333 width=4)
Index Cond: (created_at >= $1)
Without a value the planner uses a fixed ratio for a range condition: a third of the table, 333,333 rows. A generic plan shows the structure, but its row estimates can be very different from the plan that runs with real values. To see the real plan you need the values, and auto_explain gives you those. The module writes the plan of every query that exceeds a given duration to the server log. A reload is enough:
ALTER SYSTEM SET session_preload_libraries = 'auto_explain';
ALTER SYSTEM SET auto_explain.log_min_duration = '40ms';
ALTER SYSTEM SET auto_explain.log_analyze = on;
ALTER SYSTEM SET auto_explain.log_buffers = on;
ALTER SYSTEM SET auto_explain.log_timing = off;
SELECT pg_reload_conf();
log_min_duration_statement, which we saw in post 02, writes only the text and duration of a slow query; auto_explain adds the actual plan at that moment. With log_analyze on, even queries that don't make it into the log pay for the measurement; log_timing = off turns off the most expensive part of that overhead, reading the clock for every node.
The Plan of the Query EF Core Generates
We wrote the same best sellers query with EF Core. Reporting.cs in the snapshot maps the three tables of the schema to simple entities; here a small loop provides the snake_case names, and in post 12 the EFCore.NamingConventions package will do that job:
var query = db.OrderItems
.TagWith("bestsellers-by-category")
.Where(i => i.Order.CreatedAt >= since && i.Order.Status != "Cancelled" && i.Book.Category == category)
.GroupBy(i => new { i.BookId, i.Book.Title })
.Select(g => new { g.Key.BookId, g.Key.Title, Sold = g.Sum(i => i.Quantity) })
.OrderByDescending(b => b.Sold)
.Take(10);
// print the generated SQL with its parameters
Console.WriteLine(query.ToQueryString());
$env:BOOKSTORE_PG = "Host=localhost;Port=5432;Database=bookstore;Username=bookstore_app;Password=<app-password>"
dotnet run --project src/Bookstore.PgLab -- bestsellers
-- @since='2026-09-20T00:00:00.0000000Z' (DbType = DateTime)
-- @category='Fantasy'
-- @p='10'
-- bestsellers-by-category
SELECT o.book_id AS "BookId", b.title AS "Title", COALESCE(sum(o.quantity::int), 0)::int AS "Sold"
FROM order_items AS o
INNER JOIN orders AS o0 ON o.order_id = o0.order_id
INNER JOIN books AS b ON o.book_id = b.book_id
WHERE o0.created_at >= @since AND o0.status <> 'Cancelled' AND b.category = @category
GROUP BY o.book_id, b.title
ORDER BY COALESCE(sum(o.quantity::int), 0)::int DESC
LIMIT @p
ToQueryString() is the quickest way during development; you can copy the SQL, put the value in place of @since and run it with EXPLAIN (ANALYZE) in psql. When the application ran it 20 times, auto_explain wrote this to the log:
LOG: duration: 50.786 ms plan:
Query Text: -- bestsellers-by-category
SELECT o.book_id AS "BookId", b.title AS "Title", COALESCE(sum(o.quantity::int), 0)::int AS "Sold"
...
Query Parameters: $1 = '2026-09-20 00:00:00+00', $2 = 'Fantasy', $3 = '10'
Limit (cost=48759.78..48759.81 rows=10 width=26) (actual rows=10.00 loops=1)
Buffers: shared hit=3983 read=23616 written=464
...
-> Gather Merge (cost=47921.58..48529.53 rows=5220 width=24) (actual rows=5376.00 loops=1)
Workers Planned: 2
Workers Launched: 2
...
-> Parallel Hash Join (cost=16669.19..45749.85 rows=21842 width=6) (actual rows=17741.33 loops=3)
-> Parallel Seq Scan on order_items o (cost=0.00..26345.73 rows=1041873 width=10) (actual rows=833498.67 loops=3)
Three things stand out. The TagWith comment is at the top of the query in the log, so it's easy to tell which C# query is slow. But it's missing from the text you saw in pg_stat_statements above; the extension takes the text of the statement itself, not the comment in front of it. Second, the parameter values: everything you need to reproduce the plan with values is here. Third, the plan is different because parallel query is on in the application's session: three processes ran, the leader plus two workers (loops=3), and rows=833498.67 is the average per process. Keep the session settings the same when you compare plans.
Production Notes
Turn on pg_stat_statements from day one; since it needs a restart, it's hard to turn on after a problem shows up. Reset the values now and then with pg_stat_statements_reset() and compare periods, or copy them into a table regularly. On managed services such as Azure Database for PostgreSQL and Amazon RDS the module usually comes preloaded and only needs CREATE EXTENSION.
Use auto_explain in production with a high threshold and log_timing = off; on very busy systems sample only part of the sessions with auto_explain.sample_rate. Watch the log volume too: every slow query means a plan of a few kilobytes.
In this post we compared buffer and row counts, not durations. Duration changes with the state of the cache even for the same query; when you measure the effect of a change, the number of pages read is more reliable.
Run ANALYZE after a bulk load or delete without waiting for autovacuum. Since 18, pg_upgrade keeps optimizer statistics but not extended statistics; you still need ANALYZE after an upgrade (post 14).
Common Pitfalls
Treating cost as milliseconds: cost is the planner's own unit and is only good for comparing alternative plans of the same query.
Not comparing estimates with actuals: the first place to look in a slow plan is the lowest node where the rows estimate is off from the actual by 10 times or more. Every decision above it rests on that wrong number.
Ignoring loops: actual rows=7.31 loops=697 means 5,096 rows, not seven. A node that looks small on the inner side of a nested loop can become the most expensive part of the query once multiplied by the number of loops.
Forcing a plan with settings like enable_seqscan = off: these settings exist for diagnosis. You can use them in a single session to answer "would the index be faster?", but the lasting fix is to correct the statistics, the index or the query. Core PostgreSQL has no query hints like SQL Server; third-party extensions such as pg_hint_plan exist.
A Small Experiment
★☆☆ Run EXPLAIN SELECT count(*) FROM customers WHERE country = 'TR', take relpages and reltuples from pg_class and calculate the Seq Scan cost by hand.
★★☆ In the best sellers query, shorten the date range from 30 days one day at a time and find the threshold where the plan switches from a hash join to a nested loop. Compare the buffer counts of the two plans at that threshold.
★★★ Create a statistics object of kind (ndistinct) on country and city of customers, and show how the estimated number of groups for SELECT country, city, count(*) FROM customers GROUP BY 1, 2 changes, before and after.
In the next post we look inside a topic that keeps appearing in plans: the dead tuples MVCC leaves behind, VACUUM and autovacuum, HOT updates, the visibility map and transaction ID wraparound.