Module 2: EXPLAIN ANALYZE in Depth
Reading query plans: structure, order, and metrics
Capsule description
You already know how to capture a complete plan: EXPLAIN (ANALYZE, BUFFERS, VERBOSE) <query>. But capturing it isn't reading it. The first time you see a 30-line plan with weird indentation, nested joins, Bitmap Heap Scan and Hash Cond, it looks like hieroglyphics.
This capsule breaks down how to read any plan, whether it's 5 lines or 50:
- How it's structured (it's a tree, not a list).
- What order it runs in (bottom-up, not top-down like you read).
- What each number in each node means (cost, rows, width, actual time, loops).
- How to trace where the time goes and where the bottleneck is.
By the end, you'll be able to open any plan, identify the root node in 5 seconds, walk the tree bottom-up, and point your finger at where the problem is. That skill alone takes you from the 50% to the 90% of devs in any serious backend team.
Mental model: the plan is a tree that runs from the bottom up
The #1 mistake when reading plans is reading them top-down, like prose. A plan is an inverted tree, and the execution order is bottom-up: the leaves (the scans) run first, their results go up to the parent nodes (joins, sorts, aggregations), and so on until reaching the root node that returns the final result to the client.
┌─────────────┐
│ Client │
└──────┬──────┘
▲
│
┌────────────────┴────────────────┐
│ ROOT NODE │
│ (what the query returns) │
│ e.g.: Limit, Sort, Aggregate │
└────────┬────────────────┬───────┘
▲ ▲
│ │
┌────────────────┴───┐ ┌───────┴───────────┐
│ Intermediate node │ │ Intermediate node │
│ e.g.: Hash Join │ │ e.g.: Index Scan │
└────┬───────────┬───┘ └───────────────────┘
▲ ▲
│ │
┌────────┴───┐ ┌────┴────────┐
│ Leaf: Scan │ │ Leaf: Scan │
└────────────┘ └─────────────┘
(the leaves run FIRST)
Reading rule:
- Identify the root node (it's the first one in the output, with no indentation).
- Go down to the most nested node (the leaves — the
Scans). - Read bottom-up: each node receives rows from its children, processes them, passes them to the parent.
- The root node returns the final result to the client.
In the EXPLAIN output, this looks like indentation
PostgreSQL marks the hierarchy with indentation and the -> prefix. Each -> indicates a child node:
Hash Join (...) ← root node (no indentation)
-> Seq Scan on books (...) ← left child (1 level)
-> Hash (...) ← right child (1 level)
-> Seq Scan on authors (...) ← grandchild (2 levels)
Filter: ...
Mental reading:
"First I do a Seq Scan on
authorswith a filter. The result goes to theHash(which builds a hash table in memory). Separately, I do a Seq Scan onbooks. TheHash Jointakes the Seq Scan ofbooksand combines it with the Hash ofauthors. TheHash Joinis the root node, it returns the result to the client."
Practice reading it bottom-up a few times. After 10-15 plans, you do it automatically.
Anatomy of a node
Each line of a plan is a node. A node has this structure:
NodeType (cost=START..TOTAL rows=N width=W) (actual time=START..TOTAL rows=N loops=N)
Detail1: ...
Detail2: ...
Buffers: shared hit=H read=R
-> ChildNode (...)
Let's break down each part:
1. NodeType — what this node does
Common examples:
| Type | What it does | When it appears |
|---|---|---|
Seq Scan | Reads the whole table, row by row | Filter without an index, or the planner decided it's faster |
Index Scan | Reads rows through an index | Filter with a usable and selective index |
Index Only Scan | Reads only from the index (doesn't touch the table) | When the index contains all the requested columns (covering) |
Bitmap Heap Scan + Bitmap Index Scan | A combination of several indexes, or a low-selectivity index | Multiple filters, or an index that covers 5-30% of the table |
Hash Join | Joins two relations by building a hash in memory | Equi-joins (=) with no required order |
Nested Loop | For each row in A, looks for matches in B | Joins with one small side and the other indexed |
Merge Join | Joins two already-sorted relations | Joins where both sides come sorted (rare without GROUP BY/ORDER BY) |
Sort | Sorts rows | ORDER BY, or input for a Merge Join |
Aggregate / HashAggregate | Computes COUNT, SUM, MAX, etc. | Aggregations |
Limit | Applies LIMIT N | N rows remain, the rest are discarded |
Gather / Gather Merge | Collects results from parallel workers | When PostgreSQL parallelizes the query |
Materialize | Caches rows in memory for reuse | When the plan needs to iterate several times over the same thing |
(We go deeper into the scan types from the first half in capsule 05; the joins in this module we introduce but don't go deep on — advanced joins are out of scope.)
2. Cost: the planner's estimate
(cost=12.34..1850.20 rows=20 width=22)
cost=12.34..1850.20— two numbers:startup_cost..total_cost.startup_cost(12.34): how much cost is paid before returning the first row. For a Seq Scan, almost 0 (it returns the first row instantly). For a Sort, it's high (it has to read everything before returning the first).total_cost(1850.20): total cost when the node finishes.
rows=20— how many rows the planner estimates this node will emit.width=22— estimated average bytes per row.
Remember: cost ≠ time. It's an arbitrary planner unit for comparing plans. Capsule 04 goes deeper.
3. Actual: measured reality (only appears with ANALYZE)
(actual time=0.234..15.812 rows=22 loops=1)
actual time=0.234..15.812— two numbers:actual_startup_time..actual_total_timein milliseconds.0.234ms until returning the first row.15.812ms until finishing the node (includes the whole execution).
rows=22— real rows the node emitted.loops=1— how many times this node ran.
loops is critical: if a node runs inside a Nested Loop, it can run N times. The actual time and rows numbers are per-loop averages, not totals. So:
actual time=0.5..0.5 rows=1 loops=10000means: the node took 0.5ms each time, returned 1 row each time, and ran 10,000 times. Real total time: 0.5 × 10000 = 5,000ms. Not 0.5ms as you might think at a glance.- This is exactly how the N+1 problem manifests in plans (module 4).
4. Buffers (with BUFFERS)
Buffers: shared hit=812 read=24 dirtied=180
shared hit=812— buffers (8KB each) read from the shared buffer cache (PostgreSQL's RAM).shared read=24— buffers read from disk because they weren't in cache.dirtied=180— modified buffers (relevant on writes or if the query generates HOT-updated tuples).temp read/written— use of temporary files (large sorts that spill to disk, very large hash joins).
Capsule 06 goes deeper into buffers.
5. Node-specific details
Each type has its own details:
Seq Scan on books
Filter: (published_year < 1950)
Rows Removed by Filter: 60088
Filter:— the applied predicate. The rows that don't pass are discarded.Rows Removed by Filter— how many rows it read but discarded. If you read 100k to emit 100, that's a huge waste — a typical symptom of "you'd need an index".
Hash Join
Hash Cond: (b.author_id = a.id)
Hash Cond:— the join condition (the equi-join expression).
Index Scan using books_pkey on books
Index Cond: (id = 12345)
Index Cond:— the condition the index itself applies (efficient).- Distinguish it from the
Filter:— an Index Cond limits what the index reads; a Filter is applied after reading.
Complete reading of a plan: worked example
Let's read a plan from start to finish. Setup (the same as module 1, seeded by scripts):
-- The query we're going to analyze
EXPLAIN (ANALYZE, BUFFERS, VERBOSE)
SELECT b.id, b.title, b.author_id
FROM books b
JOIN authors a ON a.id = b.author_id
WHERE a.name = 'tolkien';
Output:
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------
Hash Join (cost=12.34..1850.20 rows=22 width=22) (actual time=0.245..1.823 rows=22 loops=1)
Output: b.id, b.title, b.author_id
Hash Cond: (b.author_id = a.id)
Buffers: shared hit=812
-> Seq Scan on public.books b (cost=0.00..1620.00 rows=100000 width=22) (actual time=0.013..1.245 rows=100000 loops=1)
Output: b.id, b.title, b.author_id, b.published_year
Buffers: shared hit=810
-> Hash (cost=12.32..12.32 rows=1 width=4) (actual time=0.142..0.142 rows=1 loops=1)
Output: a.id
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=2
-> Seq Scan on public.authors a (cost=0.00..12.32 rows=1 width=4) (actual time=0.118..0.140 rows=1 loops=1)
Output: a.id
Filter: (name = 'tolkien'::text)
Rows Removed by Filter: 4999
Buffers: shared hit=2
Planning Time: 0.412 ms
Execution Time: 1.901 ms
Step 1: identify the root node
Hash Join (cost=12.34..1850.20 rows=22 width=22) (actual time=0.245..1.823 rows=22 loops=1)
- Root node:
Hash Join. - Estimated total cost: 1850.20.
- Estimated rows: 22. Real rows: 22. ✅ The planner got it right.
- Time: 1.823ms to finish everything. It's the query's time (plus Planning Time = 1.901ms total).
Step 2: go down to the leaves (bottom-up)
There are two leaves (the two Seq Scans). Start with the most nested one — the Seq Scan on authors:
-> Seq Scan on public.authors a (cost=0.00..12.32 rows=1 width=4) (actual time=0.118..0.140 rows=1 loops=1)
Filter: (name = 'tolkien'::text)
Rows Removed by Filter: 4999
Buffers: shared hit=2
Reading:
- Type: Sequential Scan on
authors. - Filter:
name = 'tolkien'. PostgreSQL reads the whole table and discards what doesn't match. - Rows Removed: 4,999 — it read 5,000 rows in total, returned 1.
- Time: 0.140ms — very fast (small table, everything in cache:
shared hit=2, no disk read). - Tiny cost: 12.32.
Verdict for this node: it's fine. Small table (5,000 rows), a seq scan is reasonable. If the table grew a lot and name were filtered often, an index would be worth it. For now, OK.
Step 3: go up to the Hash node
-> Hash (cost=12.32..12.32 rows=1 width=4) (actual time=0.142..0.142 rows=1 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=2
Reading:
- Type: Hash. Builds a hash table in memory with the results of the
authorsSeq Scan. - 1 row to hash (the output of the filtered Seq Scan).
- 1 bucket (out of 1024 available). 1 batch (doesn't spill to disk). 9KB of memory. Trivial.
Verdict: OK.
Step 4: the Hash Join's other child — Seq Scan on books
-> Seq Scan on public.books b (cost=0.00..1620.00 rows=100000 width=22) (actual time=0.013..1.245 rows=100000 loops=1)
Output: b.id, b.title, b.author_id, b.published_year
Buffers: shared hit=810
Reading:
- Type: Sequential Scan on
books. - Reads 100,000 rows — the whole table. No filter.
- Time: 1.245ms (all in cache, 810 buffers shared hit).
- Cost: 1620.00.
Verdict: this is the theoretical bottleneck, even though it only lasts 1.2ms. If the filter were more selective (WHERE b.published_year = 1954), an index on published_year would avoid scanning the 100k. But here there's no filter on books — the filter is on authors.name, and you need that filter on one side and the data from books on the other for the join. The optimization question then becomes: "is there a way for PostgreSQL not to scan the 100k of books?". Answer: yes, with an index on books(author_id) to do an Index Scan after knowing which author_id comes from the filter. That's capsule 05 + module 3.
Step 5: read the full root node
Hash Join (cost=12.34..1850.20 rows=22 width=22) (actual time=0.245..1.823 rows=22 loops=1)
Hash Cond: (b.author_id = a.id)
Buffers: shared hit=812
Reading:
- Hash Join: combines
Seq Scan on books(probe side) with the hash table built fromauthors(build side). - Hash Cond: matches
b.author_idwitha.id. - Total buffers: 812 (the sum of the children: 810 + 2).
- Total time: 1.823ms.
Verdict for the whole plan:
- Fast query (1.9ms total).
- The planner estimates well (estimated vs real rows: 22 vs 22).
- Everything in cache.
- Bottleneck: the
booksSeq Scan reads the whole table. For this query with this small table it's not a problem; withbooksat 10M rows, it is.
Hypothetical next steps (that you wouldn't apply now):
- If the table grew a lot, an index
books(author_id)would change the plan: instead of Seq Scan + Hash Join, it could become an Index Scan or a Bitmap Index Scan + Bitmap Heap Scan. - If the query becomes frequent and
tolkienis highly selective, consider even a partial indexWHERE author_id = (SELECT id FROM authors WHERE name='tolkien').
But all of that is module 3. Here you only read the plan.
Metrics that matter for diagnosis
When you scan a plan, look at these five numbers before anything else:
1. Total Execution Time
Execution Time: 1.901 ms
It's the real time to run the query (without planning). The first thing you look at. If it's high vs what you expect, there's something to diagnose.
2. Divergence between estimated rows and actual rows (at each node)
If at some node you see:
(cost=... rows=10 ...) (actual time=... rows=10000 ...)
— that's a 1000x row mismatch. A typical symptom of:
- Outdated statistics (module 7)
- A non-uniform distribution the planner assumes is uniform
- A correlation between columns the planner doesn't see
- Filters with expressions the planner doesn't estimate well
The planner makes decisions based on estimates; if the estimates are wrong, the chosen plan can be disastrous.
3. loops=N on deep nodes
If you see loops=1000, that node ran 1000 times. Multiply actual time by loops for the total time. It's the typical sign of the N+1 problem in plans (module 4) and of large Nested Loops.
4. Rows Removed by Filter
If a Filter removes a huge proportion:
Seq Scan on books
Filter: (active = true)
Rows Removed by Filter: 999000
You read 1M rows to return 1k — 99.9% waste. Symptom: you're missing an index (probably a partial index if you only want active=true).
5. Buffers: shared hit=H read=R
If shared read is high, the query is loading data from disk. IO-bound. If shared read=0 and everything is hit, it's CPU-bound. Opposite diagnoses.
Plans with parallelism
PostgreSQL can parallelize queries (parallel query, since 9.6+). When it does, you see special nodes:
Gather (cost=1000.00..50000.00 rows=10000 width=8) (actual time=2.145..245.823 rows=12000 loops=1)
Workers Planned: 2
Workers Launched: 2
-> Parallel Seq Scan on big_table (cost=0.00..49000.00 rows=4000 width=8) (actual time=0.012..120.456 rows=4000 loops=3)
Filter: (active = true)
Reading:
Gather— the root node that coordinates the parallel workers.Workers Planned: 2— the planner planned 2 workers.Workers Launched: 2— the 2 workers actually started (sometimes it can't due tomax_worker_processeslimits).Parallel Seq Scan— the workers each scan part of the table.loops=3— read it like this: 1 leader worker + 2 parallel workers = 3 executions of the node. The rows (rows=4000) are per-worker averages, not totals. Real total: ~4000 × 3 = 12,000 (which matches the Gather'srows=12000).
For parallel queries, the parallel node's actual time is per worker (in parallel), not the sum. The Gather's actual time is the total time the client waits.
Why does this matter in real work?
1. Reading plans is the universal language of DBAs and SREs.
Any serious performance conversation involves showing and reading plans. Knowing how to read them lets you have that conversation without a dictionary at your side.
2. The plan reveals things the code doesn't.
Your ORM code says "bring books with their authors". The plan reveals that this is 2 queries (an efficient join) or 415 queries (a hidden N+1). The code looks the same in both cases; the plan doesn't.
3. Comparing two plans is the standard way to validate optimizations.
Before and after a change (a new index, a different WHERE, eager loading), you capture the plan of the same query. If the plan changed, you saw it; if it didn't change, you know the change didn't impact the execution (it may have impacted something else, but not this).
4. Big plans in chats / tickets / PRs.
In serious teams, PRs that change queries include the before/after plan in the description. If you don't know how to read them, you can't review PRs of that kind.
Traps and common mistakes
Mistake 1 (reading): reading top-down like prose
Symptom: "The plan says Hash Join, I don't understand what it does first."
Why it happens: you assume the plan runs in the order it's written. It doesn't. It runs bottom-up: the leaves (scans) first, their results go up.
How to fix it: get used to walking plans bottom-up. Start with the most nested leaf, go up. The root node is the last thing that runs.
Mistake 2 (interpretation): confusing cost with time
Symptom: "Cost=1850, that's 1.85 seconds."
Why it's wrong: we already said it in capsule 02. Cost is an arbitrary unit. Only actual time is real time. Capsule 04 goes deeper into cost.
How to fix it: every time you see cost, remind yourself "this is for comparing plans against each other". For time, you look at actual time or Execution Time.
Mistake 3 (interpretation): forgetting loops when multiplying time
Symptom: "The plan says actual time=0.5ms, it's super fast."
Why it's sometimes wrong: if the node is inside a Nested Loop with loops=10000, the total time is 0.5 × 10000 = 5 seconds. But the plan reports only the per-loop average.
How to fix it: always look at loops. If it's >1, multiply. Visual tools (capsule 07) do this calculation automatically.
Mistake 4 (reading): assuming actual rows are always the returned rows
Symptom: "The plan says rows=22, it returned 22."
Why it's sometimes wrong: the actual rows are the ones that node emitted to its parent, not necessarily the ones the client receives. If there's a Limit 10 above, the client receives 10 even if the node below emitted 22.
How to fix it: the client's rows are dictated by the root node. The intermediate nodes can emit more or fewer depending on what passes through filters, joins, aggregations.
Mistake 5 (interpretation): ignoring Rows Removed by Filter
Symptom: "I see an Index Scan, it's fine."
Why it's sometimes wrong: an Index Scan can bring back 100,000 candidates and then filter out most of them. If you see:
Index Scan using idx_active on users
Index Cond: (active = true)
Filter: (last_login > '2026-01-01')
Rows Removed by Filter: 95000
It brought back 100k active rows via the index, and discarded 95k due to the additional filter on last_login. That's inefficient — the index only partially covered the query. Solution: a composite index or a partial index.
How to fix it: always look at Rows Removed by Filter. If it's high, there's an opportunity for better indexing (module 3).
Mistake 6 (reading): not separating Index Cond from Filter
Symptom: "There's an Index Scan, that uses an index."
Why the subtlety matters: there's a difference between what the index itself evaluates (Index Cond) and what's filtered afterward (Filter):
Index Scan using idx_email on users
Index Cond: (email = 'foo@example.com') ← the index resolves this
Filter: (active = true) ← this is applied after reading the row
If the Filter removes a lot, the index was insufficient for the query — it doesn't cover all the columns the predicate needs.
How to fix it: Index Cond is what you leverage from the index; Filter is what the index didn't resolve. A good index minimizes the Filter.
Exercises
Exercise 1: identify the execution order
Given this plan, list the nodes in the order they run (from first to last):
Sort (cost=2150.00..2160.00 rows=4000 width=22)
Sort Key: b.published_year DESC
-> Hash Join (cost=12.34..1900.00 rows=4000 width=22)
Hash Cond: (b.author_id = a.id)
-> Seq Scan on books b (cost=0.00..1620.00 rows=100000 width=22)
-> Hash (cost=12.30..12.30 rows=4 width=4)
-> Seq Scan on authors a (cost=0.00..12.30 rows=4 width=4)
Filter: (name LIKE 'tol%')
See solution
Bottom-up walk:
Seq Scan on authorswith the filtername LIKE 'tol%'— scansauthors, returns 4 rows.Hash— builds a hash table in memory with those 4 rows.Seq Scan on books— scans the wholebookstable (100k rows).Hash Join— for each row ofbooks, looks for a match in theauthorshash table. Returns ~4000 rows that matched.Sort— takes those 4000 rows and sorts them bypublished_year DESC. It's the root node, it returns the result to the client.
Note: the Sort is at the top of the output but runs last. The leaves (scans) run first. The client receives the Sort's output.
Exercise 2: row mismatch — diagnosis
Look at this node:
Bitmap Index Scan on idx_status (cost=0.00..15.20 rows=100 width=0) (actual time=0.245..0.412 rows=85000 loops=1)
Index Cond: (status = 'active')
What does it tell you? What would you hypothesize?
See solution
Reading:
- Estimated: 100 rows with
status='active'. - Real: 85,000 rows.
- An 850x row mismatch.
Hypothesis:
- The table's statistics are outdated (
ANALYZEhasn't been run recently, or autovacuum didn't get to it). The planner thinksstatus='active'is very selective, but in reality it covers most of the table. - Non-uniform distribution: if the table has 1M rows and 85k are
active, the real selectivity is 8.5%. The planner estimated 0.01% (100/1M). - Consequence: the planner chose a Bitmap Index Scan because it thought "this brings back very little, the index is worth it". But in reality, reading 85k rows via bitmap can be more expensive than a Sequential Scan.
Next steps (that you don't apply yet):
- Run
ANALYZEon the table to refresh statistics. - If
statushas few values (active,inactive,pending), consider a higherdefault_statistics_targetorCREATE STATISTICS(module 7). - If
activealways covers most of the table, maybe the index shouldn't be used for that filter — a partial indexWHERE status != 'active'would be more useful.
For now, you note: "large row mismatch on status — investigate statistics (module 7)".
Exercise 3: loops and N+1
Look at this plan snippet:
Nested Loop (cost=0.00..15000.00 rows=10000 width=120) (actual time=0.045..820.234 rows=10000 loops=1)
-> Seq Scan on books b (cost=0.00..1620.00 rows=10000 width=22) (actual time=0.012..1.245 rows=10000 loops=1)
-> Index Scan using reviews_book_id_idx on reviews r (cost=0.42..1.34 rows=1 width=98) (actual time=0.075..0.080 rows=1 loops=10000)
Index Cond: (book_id = b.id)
What does the loops=10000 on the Index Scan tell you?
See solution
Reading:
- The Nested Loop iterates over each row of the
Seq Scan on books(10,000 rows) and, for each one, runs theIndex Scanonreviews. - The Index Scan says
actual time=0.075..0.080 rows=1 loops=10000. That means:- Each execution of the Index Scan takes ~0.08ms and returns 1 row.
- But it ran 10,000 times (one per book).
- Real total time of that node: 0.08ms × 10,000 = ~800ms.
- The Nested Loop's
actual time(820ms total) is dominated by those 10,000 lookups.
Diagnosis:
- You're seeing the symptom of a "one to many" join where for each book you bring its reviews — but instead of doing an efficient Hash Join, the planner chose a Nested Loop with index lookups.
- This can be optimal if the left side is small (say 50 books); with 10,000 books it's slow.
- Common causes:
- The planner underestimated how many books came from the left side.
- The index on
reviews(book_id)seems the obvious choice but at this scale, a Hash Join over the wholereviewstable would be faster.
Connection with the N+1 problem: this pattern in SQL looks almost identical to the N+1 problem in ORMs. The key difference is:
- Here PostgreSQL makes the decision and runs the 10,000 lookups in a single query.
- In SQLAlchemy's N+1, your app fires 10,000 separate queries.
Capsule 04 goes deeper into scan types; module 4 attacks N+1 from the app side.
Exercise 4: index cond vs filter
You have this query and this plan:
SELECT * FROM users WHERE active = true AND last_login > '2026-01-01';
Index Scan using idx_users_active on users (cost=0.42..3500.00 rows=1000 width=240) (actual time=0.045..82.234 rows=850 loops=1)
Index Cond: (active = true)
Filter: (last_login > '2026-01-01'::date)
Rows Removed by Filter: 49150
Buffers: shared hit=2200 read=180
Diagnose: is the index being used correctly? What improvement hypothesis would you propose?
See solution
Reading:
- Index Cond says
active = true— the index resolves that part. It reads all the rows withactive=true(they turned out to be 50,000: 49,150 removed by the filter + 850 that passed). - Filter says
last_login > '2026-01-01'— that's applied after reading each row from the index. - Rows Removed by Filter: 49,150 — it read 50,000 rows (all the active ones) and discarded 49,150. Only 850 passed the filter.
- Buffers: 2,200 hit + 180 read. Some IO.
Diagnosis:
- The
idx_users_activeindex is insufficient for this query. It only coversactive, but the query also filters bylast_login. PostgreSQL has to read 50,000 rows to discard 49,150. - That's 98.3% waste: only 1.7% of the read rows ended up in the result.
Improvement hypothesis (all would be applied in module 3):
-
Composite index
users(active, last_login)— the index would have both columns, the planner would do an Index Cond with both predicates, avoiding the Filter:CREATE INDEX idx_users_active_login ON users(active, last_login); -
Partial index if
active = trueis what gets filtered most of the time:CREATE INDEX idx_users_recent_login ON users(last_login) WHERE active = true;This would be even more efficient because the index is smaller (only active ones).
-
Composite index with the most selective column first — if
last_login > '2026-01-01'is more selective thanactive = true, the index should put it first:CREATE INDEX idx_users_login_active ON users(last_login, active);
Which of the three is optimal depends on the cardinality of each filter and on what other queries use the table. That's module 3. Here you only identify that the current index doesn't cover the query — the Rows Removed by Filter shouted it at you.
Exercise 5: capture and read a plan in your local DB
Connect to the module 1 DB (the pgbench_demo with seeded data or the simplified Bookstore API). Capture the complete plan of:
SELECT b.id, b.title, b.published_year
FROM books b
WHERE b.published_year BETWEEN 1980 AND 2000
ORDER BY b.published_year DESC
LIMIT 50;
Identify: root node, leaves, estimated vs real rows divergence (if any), and where the time goes.
See solution
EXPLAIN (ANALYZE, BUFFERS, VERBOSE)
SELECT b.id, b.title, b.published_year
FROM books b
WHERE b.published_year BETWEEN 1980 AND 2000
ORDER BY b.published_year DESC
LIMIT 50;
Typical output (without an index on published_year):
Limit (cost=2050.00..2050.13 rows=50 width=22) (actual time=12.412..12.420 rows=50 loops=1)
Output: id, title, published_year
Buffers: shared hit=810
-> Sort (cost=2050.00..2092.10 rows=16842 width=22) (actual time=12.410..12.414 rows=50 loops=1)
Output: id, title, published_year
Sort Key: published_year DESC
Sort Method: top-N heapsort Memory: 32kB
Buffers: shared hit=810
-> Seq Scan on public.books b (cost=0.00..1870.00 rows=16800 width=22) (actual time=0.012..7.812 rows=16842 loops=1)
Output: id, title, published_year
Filter: ((published_year >= 1980) AND (published_year <= 2000))
Rows Removed by Filter: 83158
Buffers: shared hit=810
Planning Time: 0.182 ms
Execution Time: 12.510 ms
Analysis:
- Root node:
Limit— returns 50 rows to the client. Takes 12.4ms (the whole plan). - Leaves:
Seq Scan on books— scans 100,000 rows, discards 83,158 (those not in 1980-2000), emits 16,842 to the Sort. - Sort: sorts the 16,842 rows by
published_year DESCand returns only the top 50 to the Limit. It usestop-N heapsort— efficient, doesn't spill to disk (32KB). - Estimated vs real rows:
- Seq Scan: estimated 16,800 / real 16,842. ✅ A good estimate.
- Sort: estimated 16,800 / real 50 (because the Limit above cuts it off). The planner doesn't pre-push the Limit into the Sort, but
top-N heapsortoptimizes that internally.
- Buffers: 810 hit, 0 read. Everything in cache. CPU-bound.
- Where does the time go? ~7.8ms in the Seq Scan, ~4.6ms in the Sort + Limit.
Diagnosis:
- The table has 100k rows and gets fully scanned to return 50 sorted ones. It's inefficient for the amount of data requested.
- If
published_yearhad an index, we could go straight to the rows in that range, sorted — without scanning the 100k:With that index, the plan would show anCREATE INDEX idx_books_year ON books(published_year DESC);Index Scan Backwardthat already returns rows in DESC order and theSortdisappears.
But — you only identify it. The CREATE INDEX is module 3.
Exercise 6: read a complex plan from your own app
If you have your own FastAPI app with SQLAlchemy and at least one non-trivial query: copy the real SQL query (the one SQLAlchemy emits, you can capture it with echo=True in the engine), run EXPLAIN (ANALYZE, BUFFERS, VERBOSE) on it, and write 3-5 lines of analysis identifying which nodes there are, where the time goes, and whether there are row mismatches.
See solution
There's no single solution — it depends on your app. But the structure of the analysis should be:
## Plan analysis: [query / endpoint name]
**Query:**
```sql
[the exact query]
Plan:
[complete EXPLAIN output]
Analysis:
- Root node: [type + time + rows]
- Leaves: [which scans on which tables]
- Where does the time go? [identify the node with the highest
actual time×loops] - Estimated vs real rows: [is there a significant divergence? where?]
- Buffers: [all cache hit, or are there disk reads?]
- Preliminary hypotheses: [which module would address each problem seen]
If your plan ends with an `Execution Time` above 100ms, there's material there for the following modules.
If you don't have your own app: replicate exercise 5 with another query of your interest against the test database. What matters is practicing the reading on something "yours", not copying the book's example.
</details>
---
## Summary and next step
In this capsule you learned:
- A plan is an **inverted tree**. It runs **bottom-up**: the leaves (scans) first, the results go up to the root node, which returns to the client.
- Each node has **cost (estimate), actual time/rows (measurement), buffers, and specific details** (Filter, Index Cond, Hash Cond, etc.).
- **`loops=N`** is critical: real total time = `actual time × loops`. If you ignore it, you misinterpret plans with nested joins or N+1.
- **Row mismatch** between estimated and actual is the most common symptom of bad statistics (module 7).
- **High `Rows Removed by Filter`** = an index insufficient for the query (an opportunity for module 3).
- **`Index Cond` vs `Filter`**: the first is resolved by the index; the second is applied after reading the row — a symptom that the index doesn't cover all the predicates.
Before moving on you should be able to:
- Walk a plan bottom-up and name the root node, the leaves, and the intermediate nodes
- Distinguish cost (arbitrary estimate) from actual time (real time)
- Identify `loops` and multiply for the total time
- Detect row mismatches and high `Rows Removed by Filter`
**Next capsule — Cost model and estimates.** You've read cost at each node, but you still don't know exactly what it is, how the planner computes it, and why it sometimes gets it so wrong. You'll learn the base costs (`seq_page_cost`, `random_page_cost`, `cpu_tuple_cost`), how the planner estimates rows using `pg_stats`, and why the cost of two alternative plans tells you which one it'll choose. It's the capsule that demystifies "the planner decided to use this plan instead of that one".
---
## Resources
1. [PostgreSQL Documentation — Using EXPLAIN](https://www.postgresql.org/docs/current/using-explain.html) — the official chapter. It has step-by-step examples of reading plans.
2. [Hubert "depesz" Lubaczewski — "Explaining the unexplainable, part 2: Sequential scan, function scan, values scan"](https://www.depesz.com/2013/04/27/explaining-the-unexplainable-part-2/) — the classic series, part 2 on scans.
3. [Hubert "depesz" Lubaczewski — "Explaining the unexplainable, part 3: Limit, Sort, joins"](https://www.depesz.com/2013/05/09/explaining-the-unexplainable-part-3/) — part 3 on joins and sorts.
4. [Markus Winand — "Use The Index, Luke!" — Execution Plans](https://use-the-index-luke.com/sql/explain-plan/postgresql/getting-started) — a visual explanation of plans in PostgreSQL specifically.
5. [Bruce Momjian — "Explaining the Postgres Query Optimizer" (slides)](https://momjian.us/main/presentations/optimizer.pdf) — from the core team, covers how the plan is built internally.
6. [PostgreSQL Documentation — Parallel Query](https://www.postgresql.org/docs/current/parallel-query.html) — to understand plans with `Gather` and parallel workers.
7. [pev — Postgres Explain Visualizer](https://explain.dalibo.com/) — a visual tool that renders complex plans as an interactive tree (capsule 07 goes deeper into it).
---
*Module 2 — Database Performance & Query Tuning Guide*