Reading query plans and fixing slow queries

40 minIntermediate

Reading query plans and fixing slow queries

When a screen is slow, guessing wastes days. Postgres will tell you exactly how it ran a query, step by step, with the time and pages each step cost. This lesson teaches you to read that report and turn it into a fix.

By the end you can

Run EXPLAIN (ANALYZE, BUFFERS) and read the plan tree from the bottom up
Name the common plan nodes and what each one costs
Spot a bad row estimate and fix it with ANALYZE
Find the queries that cost the most in total with pg_stat_statements
Recognise the N+1 problem in Prisma code and replace it with one batched query

The everyday picture

A food-delivery rider took 55 minutes for an order that should take 20. The customer only knows "it was slow". The rider's GPS trace tells the real story: 4 minutes to reach the restaurant, 25 minutes waiting for the food, 6 minutes stuck at one traffic signal, 20 minutes riding. Now you know the kitchen is the problem, not the rider or the road.

A query plan is that GPS trace. It lists every step Postgres took, which road it chose (an index or a full read of the table), how many rows it carried at each step, and how long each step took. You stop guessing and fix the step where the time went.

EXPLAIN shows the plan; ANALYZE runs it

EXPLAIN asks the planner for its plan without running the query. You see what Postgres intends to do and how many rows it expects. The numbers are estimates. This example uses the grn table (goods received notes, one row per delivery to a store) that the Build it section creates.

Output

EXPLAIN SELECT id, supplier_id, received_at FROM grn
WHERE site_id = 42 AND status = 'PENDING' ORDER BY received_at DESC LIMIT 20;

 Limit  (cost=44751.11..44753.45 rows=20 width=24)
   ->  Gather Merge  (cost=44751.11..44760.68 rows=82 width=24)
         Workers Planned: 2
         ->  Sort  (cost=43751.09..43751.19 rows=41 width=24)
               Sort Key: received_at DESC
               ->  Parallel Seq Scan on grn  (cost=0.00..43750.00 rows=41 width=24)
                     Filter: ((site_id = 42) AND (status = 'PENDING'::text))

Read each line as one step. cost=0.00..43750.00 is the planner's own unit of work, roughly "how many pages read in order". The first number is the cost before the first row comes out, the second is the cost for all rows. rows=41 is how many rows the planner expects that step to produce. width=24 is the average row size in bytes. Costs are only useful for comparing plans with each other; they are not milliseconds.

EXPLAIN (ANALYZE, BUFFERS) runs the query for real and adds what actually happened: actual time in milliseconds, actual rows, how many times the step ran (loops), and how many 8 KB pages it touched. shared hit pages were already in memory; read pages came from disk or the operating system cache.

Quick check

You run EXPLAIN ANALYZE DELETE FROM grn WHERE status = 'POSTED' outside a transaction. What happens to those rows?

Plain EXPLAIN only plans. With ANALYZE, Postgres executes the statement to measure it, and outside a transaction it commits. Wrap writes in BEGIN and ROLLBACK when you only want the plan.