How to buildOctober 11, 20269 min read
SQL and PostgreSQLStep 8 of 9

Query optimisation: EXPLAIN ANALYZE in practice

In short

First find the slow query, with pg_stat_statements or a log driven by log_min_duration_statement, then look at its plan with EXPLAIN (ANALYZE, BUFFERS). In the plan, look for the node that eats the most time and pages, and compare the estimated rows with the actual rows: an error of several times almost always explains a bad planner choice. The usual fixes are an index for the filter or join, rewriting a condition so no function wraps the column, NOT EXISTS instead of NOT IN, fresh statistics via ANALYZE, and extended statistics for dependent columns.

How-toLevel: AdvancedQuery OptimizationPractice: ~2–4 h

After this you will be able to

  • find slow and frequent queries with pg_stat_statements and log_min_duration_statement
  • read an EXPLAIN (ANALYZE, BUFFERS) plan: cost, actual time, loops, buffers, scan and join nodes
  • spot the gap between estimates and reality and fix it with ANALYZE or CREATE STATISTICS
  • apply typical fixes: an index on the foreign key, a condition without a function on the column, NOT EXISTS, removing N+1

Verified with

PostgreSQL 17 (17.11, postgres:17-alpine)pg_stat_statements 1.11

Checked against docs: October 11, 2026

Contents
  1. 01How to find slow queries
  2. 02How to read an EXPLAIN plan
  3. 03Queries 2 and 3: no function on the column, NOT EXISTS instead of NOT IN
  4. 04Estimates versus reality: statistics and ANALYZE
  5. 05N+1 from an ORM and pg_stat_statements
  6. 06Typical fixes and a workflow
  7. 07Exercises

How to find slow queries

Optimising blind is pointless: first you need a list of the queries that actually consume database time. PostgreSQL has two built-in tools for that, the pg_stat_statements extension and the server log.

pg_stat_statements

What it gives you
A summary of every query: calls, total and mean time, rows, buffers. Constants become $1, so identical queries with different values collapse into one row
How to enable it
shared_preload_libraries = 'pg_stat_statements', a server restart, then CREATE EXTENSION pg_stat_statements in the database

log_min_duration_statement

What it gives you
A log line for every statement slower than the threshold, with its text
How to enable it
For example 250ms; 0 logs everything, -1 (the default) turns it off

auto_explain

What it gives you
Plans of slow queries straight in the log
How to enable it
A standard contrib module, loaded via shared_preload_libraries or LOAD

The bench is a shop with 100,000 customers and a million orders on PostgreSQL 17. The container starts with pg_stat_statements loaded and a 200 ms log threshold.

bash
docker run -d --rm --name kb-pg-explain -e POSTGRES_PASSWORD=test postgres:17-alpine \
  -c shared_preload_libraries=pg_stat_statements -c log_min_duration_statement=200
docker exec -i kb-pg-explain psql -U postgres -f - < 01-seed.sql
The bench. The password test is for a throwaway local container only; the < redirect works in bash and Git Bash
01-seed.sql
-- A training shop database: 100,000 customers, 1,000,000 orders
DROP TABLE IF EXISTS orders, customers;

CREATE TABLE customers (
  id         bigint GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
  email      text NOT NULL UNIQUE,
  city       text NOT NULL,
  region     text NOT NULL,           -- fully determined by the city
  created_at timestamptz NOT NULL
);

CREATE TABLE orders (
  id          bigint GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
  customer_id bigint NOT NULL REFERENCES customers (id),  -- no index is created on the FK automatically
  status      text NOT NULL,
  total       numeric(10,2) NOT NULL,
  created_at  timestamptz NOT NULL
);
CREATE INDEX orders_created_at_idx ON orders (created_at);

SELECT setseed(0.17);

-- 50 cities in 10 regions: city n belongs to region n % 10
INSERT INTO customers (email, city, region, created_at)
SELECT 'user' || g || '@example.com',
       'city-' || c,
       'region-' || (c % 10),
       timestamptz '2024-01-01' + random() * interval '700 days'
FROM (SELECT g, floor(random() * 50)::int AS c FROM generate_series(1, 100000) AS g) AS s;

-- about 15% of customers have no orders
INSERT INTO orders (customer_id, status, total, created_at)
SELECT 1 + floor(random() * 85000)::int,
       (ARRAY['new', 'paid', 'shipped', 'done', 'done', 'done', 'cancelled'])[1 + floor(random() * 7)::int],
       round((500 + random() * 49500)::numeric, 2),
       timestamptz '2025-01-01' + random() * interval '365 days'
FROM generate_series(1, 1000000);

VACUUM ANALYZE customers, orders;

SELECT relname, n_live_tup, pg_size_pretty(pg_total_relation_size(relid)) AS total_size
FROM pg_stat_user_tables ORDER BY relname;
Customers, orders and a date index; setseed makes the data reproducible
terminal
$ docker logs kb-pg-explain 2>&1 | grep -E 'duration|ERROR'
LOG:  duration: 274.256 ms  statement: INSERT INTO customers (email, city, region, created_at)
LOG:  duration: 17797.375 ms  statement: INSERT INTO orders (customer_id, status, total, created_at)
LOG:  duration: 202.827 ms  statement: CREATE INDEX orders_customer_id_idx ON orders (customer_id);
ERROR:  canceling statement due to statement timeout
LOG:  duration: 1221.208 ms  statement: INSERT INTO orders (customer_id, status, total, created_at)
A log excerpt after all the examples: slow statements land there on their own (date and PID removed)

How to read an EXPLAIN plan

A plan is a tree of nodes. At the bottom are scan nodes that fetch rows from tables; above them are joins, sorts and aggregates. Read it from the inside out: the most deeply nested node runs first, and every node's cost and time include its children.

02-join-fk.sql
-- Query 1: a customer's orders by email
\echo '=== BEFORE: no index on orders.customer_id'
EXPLAIN (ANALYZE, BUFFERS)
SELECT o.id, o.status, o.total, o.created_at
FROM customers c
JOIN orders o ON o.customer_id = c.id
WHERE c.email = 'user4242@example.com';

CREATE INDEX orders_customer_id_idx ON orders (customer_id);

\echo '=== AFTER: an index on the foreign key'
EXPLAIN (ANALYZE, BUFFERS)
SELECT o.id, o.status, o.total, o.created_at
FROM customers c
JOIN orders o ON o.customer_id = c.id
WHERE c.email = 'user4242@example.com';
Query 1: a customer's orders by email, before and after an index on the foreign key
terminal
$ docker exec -i kb-pg-explain psql -U postgres -f - < 02-join-fk.sql
=== BEFORE: no index on orders.customer_id
 Gather  (cost=1008.45..14880.91 rows=10 width=30) (actual time=3.374..33.503 rows=8 loops=1)
   Workers Planned: 2
   Workers Launched: 2
   Buffers: shared hit=8720 read=3
   ->  Hash Join  (cost=8.45..13879.91 rows=4 width=30) (actual time=2.207..26.781 rows=3 loops=3)
         Hash Cond: (o.customer_id = c.id)
         Buffers: shared hit=8720 read=3
         ->  Parallel Seq Scan on orders o  (cost=0.00..12777.67 rows=416667 width=38) (actual time=0.007..12.652 rows=333333 loops=3)
               Buffers: shared hit=8611
         ->  Hash  (cost=8.44..8.44 rows=1 width=8) (actual time=0.025..0.026 rows=1 loops=3)
               Buckets: 1024  Batches: 1  Memory Usage: 9kB
               Buffers: shared hit=11 read=3
               ->  Index Scan using customers_email_key on customers c  (cost=0.42..8.44 rows=1 width=8) (actual time=0.021..0.022 rows=1 loops=3)
                     Index Cond: (email = 'user4242@example.com'::text)
                     Buffers: shared hit=11 read=3
 Planning:
   Buffers: shared hit=269 read=4
 Planning Time: 1.125 ms
 Execution Time: 33.633 ms
The plan before the fix. Timings are an example from our machine

cost=1008.45..14880.91

What it means
The estimated cost in arbitrary units: up to the first row and up to the last. Do not compare it with milliseconds

rows=10 width=30

What it means
How many rows the node is expected to return, and their average width in bytes

actual time=3.374..33.503

What it means
Real time in milliseconds: to the first row and to the last

rows=3 loops=3

What it means
Actual rows and how many times the node ran. Time and rows are per-execution averages, so multiply by loops

Buffers: shared hit=8720 read=3

What it means
8 kB pages: hit came from PostgreSQL's cache, read from disk or the OS cache

Rows Removed by Filter

What it means
How many rows the node read and threw away, a sign that the condition lacks an index

Planning Time / Execution Time

What it means
Time to build the plan and to run the query, excluding sending the result to the client

In the plan before the fix the whole query spends its time in Parallel Seq Scan on orders: three processes read 333,000 rows each so that Hash Join can find eight orders. A foreign key does not create an index automatically; the docs state plainly that you have to declare an index on the referencing columns yourself. After CREATE INDEX the plan becomes a Nested Loop: one customer row drives a single lookup in the orders index.

terminal
=== AFTER: an index on the foreign key
 Nested Loop  (cost=4.94..63.74 rows=10 width=30) (actual time=0.042..0.058 rows=8 loops=1)
   Buffers: shared hit=14 read=1
   ->  Index Scan using customers_email_key on customers c  (cost=0.42..8.44 rows=1 width=8) (actual time=0.015..0.015 rows=1 loops=1)
         Index Cond: (email = 'user4242@example.com'::text)
         Buffers: shared hit=4
   ->  Bitmap Heap Scan on orders o  (cost=4.53..55.17 rows=13 width=38) (actual time=0.025..0.040 rows=8 loops=1)
         Recheck Cond: (c.id = customer_id)
         Heap Blocks: exact=8
         Buffers: shared hit=10 read=1
         ->  Bitmap Index Scan on orders_customer_id_idx  (cost=0.00..4.52 rows=13 width=0) (actual time=0.015..0.015 rows=8 loops=1)
               Index Cond: (customer_id = c.id)
               Buffers: shared hit=2 read=1
 Planning:
   Buffers: shared hit=24 read=6
 Planning Time: 0.471 ms
 Execution Time: 0.094 ms
The plan after: 15 pages instead of 8,723

Seq Scan

When the planner picks it
A large share of the table is needed, there is no suitable index, or the table is small

Index Scan / Index Only Scan

When the planner picks it
Few rows, or the index order is needed; Only when every column is in the index

Bitmap Index Scan + Bitmap Heap Scan

When the planner picks it
A medium-sized result: row addresses go into a bitmap and are read in physical order

Nested Loop

When the planner picks it
The outer input is small and the inner one has an index on the join condition

Hash Join

When the planner picks it
Both inputs are large and the condition is equality; the smaller input becomes an in-memory hash table

Merge Join

When the planner picks it
Both inputs are already sorted on the join key, for example by indexes

Queries 2 and 3: no function on the column, NOT EXISTS instead of NOT IN

The second slow query computes revenue for a day and casts created_at to a date. The created_at index goes unused: it holds timestamps, not the result of created_at::date. The same day written as a range uses the index directly.

03-sargable.sql
-- Query 2: revenue for one day
\echo '=== BEFORE: a function on the column, the created_at index does not apply'
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*), sum(total)
FROM orders
WHERE created_at::date = '2025-06-01';

\echo '=== AFTER: the same day as a range'
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*), sum(total)
FROM orders
WHERE created_at >= '2025-06-01' AND created_at < '2025-06-02';

-- The result is unchanged (the session is in UTC, as are the range bounds)
SELECT (SELECT count(*) FROM orders WHERE created_at::date = '2025-06-01') AS by_cast,
       (SELECT count(*) FROM orders
        WHERE created_at >= '2025-06-01' AND created_at < '2025-06-02') AS by_range;
Query 2: a function on the column versus a range
terminal
$ docker exec -i kb-pg-explain psql -U postgres -f - < 03-sargable.sql
=== BEFORE: a function on the column, the created_at index does not apply
 Finalize Aggregate  (cost=15871.65..15871.66 rows=1 width=40) (actual time=25.066..27.945 rows=1 loops=1)
   Buffers: shared hit=8611
   ->  Gather  (cost=15871.42..15871.63 rows=2 width=40) (actual time=24.966..27.934 rows=3 loops=1)
         Buffers: shared hit=8611
         ->  Partial Aggregate  (cost=14871.42..14871.43 rows=1 width=40) (actual time=23.175..23.176 rows=1 loops=3)
               Buffers: shared hit=8611
               ->  Parallel Seq Scan on orders  (cost=0.00..14861.00 rows=2083 width=8) (actual time=0.018..23.057 rows=892 loops=3)
                     Filter: ((created_at)::date = '2025-06-01'::date)
                     Rows Removed by Filter: 332442
                     Buffers: shared hit=8611
 Planning Time: 0.515 ms
 Execution Time: 27.998 ms

=== AFTER: the same day as a range
 Aggregate  (cost=5940.96..5940.97 rows=1 width=40) (actual time=3.295..3.296 rows=1 loops=1)
   Buffers: shared hit=2301
   ->  Bitmap Heap Scan on orders  (cost=73.11..5926.96 rows=2799 width=8) (actual time=0.491..3.034 rows=2675 loops=1)
         Recheck Cond: ((created_at >= '2025-06-01 00:00:00+00'::timestamp with time zone) AND (created_at < '2025-06-02 00:00:00+00'::timestamp with time zone))
         Heap Blocks: exact=2288
         Buffers: shared hit=2301
         ->  Bitmap Index Scan on orders_created_at_idx  (cost=0.00..72.42 rows=2799 width=0) (actual time=0.310..0.311 rows=2675 loops=1)
               Index Cond: ((created_at >= '2025-06-01 00:00:00+00'::timestamp with time zone) AND (created_at < '2025-06-02 00:00:00+00'::timestamp with time zone))
               Buffers: shared hit=13
 Planning Time: 0.130 ms
 Execution Time: 3.335 ms

 by_cast | by_range
---------+----------
    2675 |     2675
(1 row)
Output trimmed: 8,611 pages versus about 2,300, and the same result

A cast to date depends on the session time zone, so the range bounds must use the same zone; the check at the end of the script confirms it. The alternative is an expression index, which only helps if the query spells the expression exactly the same way.

The third query finds customers with no orders using NOT IN (subquery). When the subquery result does not fit in work_mem for the hashed variant, PostgreSQL checks every customer row by brute force, and the cost estimate climbs into the hundreds of millions.

04-not-in.sql
-- Query 3: customers with no orders
\echo '=== BEFORE: NOT IN with a subquery, plan without ANALYZE'
EXPLAIN
SELECT count(*)
FROM customers c
WHERE c.id NOT IN (SELECT o.customer_id FROM orders o);

SET statement_timeout = '10s';
SELECT count(*)
FROM customers c
WHERE c.id NOT IN (SELECT o.customer_id FROM orders o);
RESET statement_timeout;

\echo '=== AFTER: NOT EXISTS'
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*)
FROM customers c
WHERE NOT EXISTS (SELECT 1 FROM orders o WHERE o.customer_id = c.id);
Query 3: NOT IN versus NOT EXISTS; statement_timeout guards against an endless wait
terminal
$ docker exec -i kb-pg-explain psql -U postgres -f - < 04-not-in.sql
=== BEFORE: NOT IN with a subquery, plan without ANALYZE
 Finalize Aggregate  (cost=625378177.42..625378177.43 rows=1 width=8)
   ->  Gather  (cost=625378177.21..625378177.42 rows=2 width=8)
         Workers Planned: 2
         ->  Partial Aggregate  (cost=625377177.21..625377177.22 rows=1 width=8)
               ->  Parallel Index Only Scan using customers_pkey on customers c  (cost=0.29..625377125.13 rows=20833 width=0)
                     Filter: (NOT (ANY (id = (SubPlan 1).col1)))
                     SubPlan 1
                       ->  Materialize  (cost=0.00..27518.00 rows=1000000 width=8)
                             ->  Seq Scan on orders o  (cost=0.00..18611.00 rows=1000000 width=8)
 JIT:
   Functions: 8
   Options: Inlining true, Optimization true, Expressions true, Deforming true

SET
psql:<stdin>:11: ERROR:  canceling statement due to statement timeout
RESET

=== AFTER: NOT EXISTS
 Finalize Aggregate  (cost=20908.03..20908.04 rows=1 width=8) (actual time=62.771..67.705 rows=1 loops=1)
   Buffers: shared hit=9808
   ->  Gather  (cost=20907.82..20908.03 rows=2 width=8) (actual time=60.106..67.697 rows=3 loops=1)
         Buffers: shared hit=9808
         ->  Partial Aggregate  (cost=19907.82..19907.83 rows=1 width=8) (actual time=52.182..52.184 rows=1 loops=3)
               Buffers: shared hit=9808
               ->  Parallel Hash Right Anti Join  (cost=2354.54..19885.90 rows=8768 width=0) (actual time=51.407..52.031 rows=5001 loops=3)
                     Hash Cond: (o.customer_id = c.id)
                     Buffers: shared hit=9808
                     ->  Parallel Seq Scan on orders o  (cost=0.00..12777.67 rows=416667 width=8) (actual time=0.007..13.566 rows=333333 loops=3)
                           Buffers: shared hit=8611
                     ->  Parallel Hash  (cost=1619.24..1619.24 rows=58824 width=8) (actual time=5.507..5.507 rows=33333 loops=3)
                           Buckets: 131072  Batches: 1  Memory Usage: 4992kB
                           Buffers: shared hit=1031
                           ->  Parallel Seq Scan on customers c  (cost=0.00..1619.24 rows=58824 width=8) (actual time=0.010..1.702 rows=33333 loops=3)
                                 Buffers: shared hit=1031
 Planning Time: 0.819 ms
 Execution Time: 67.825 ms
Output trimmed: NOT IN did not finish within 10 seconds, NOT EXISTS became a Hash Anti Join

Estimates versus reality: statistics and ANALYZE

The planner chooses a plan from row-count estimates, and the estimates come from statistics: reltuples and relpages in pg_class and value distributions in pg_statistic (easier to read through pg_stats). ANALYZE gathers the statistics, manually or via the background autovacuum. The docs name the main thing to check in EXPLAIN ANALYZE: how close the estimated row counts are to reality.

Experiment 1: after a bulk load of 60,000 orders with the refund status, the statistics do not know the new value yet. Autovacuum is disabled on the table only so that it cannot run ANALYZE on its own first.

05-stats.sql
-- Estimates vs reality 1: stale statistics after a bulk load
ALTER TABLE orders SET (autovacuum_enabled = off);   -- only to make the experiment reproducible
SELECT setseed(0.5);

INSERT INTO orders (customer_id, status, total, created_at)
SELECT 1 + floor(random() * 85000)::int, 'refund', 990.00,
       timestamptz '2025-12-01' + random() * interval '30 days'
FROM generate_series(1, 60000);

\echo '=== BEFORE ANALYZE: the planner does not know about the refund status yet'
EXPLAIN (ANALYZE, BUFFERS)
SELECT c.city, count(*)
FROM orders o
JOIN customers c ON c.id = o.customer_id
WHERE o.status = 'refund'
GROUP BY c.city;

ANALYZE orders;

\echo '=== AFTER ANALYZE'
EXPLAIN (ANALYZE, BUFFERS)
SELECT c.city, count(*)
FROM orders o
JOIN customers c ON c.id = o.customer_id
WHERE o.status = 'refund'
GROUP BY c.city;

ALTER TABLE orders RESET (autovacuum_enabled);
Stale statistics after a bulk load
terminal
$ docker exec -i kb-pg-explain psql -U postgres -f - < 05-stats.sql
=== BEFORE ANALYZE: the planner does not know about the refund status yet
 GroupAggregate  (cost=15630.18..15630.20 rows=1 width=15) (actual time=94.837..100.496 rows=50 loops=1)
   Group Key: c.city
   Buffers: shared hit=189114
   ->  Sort  (cost=15630.18..15630.18 rows=1 width=7) (actual time=94.666..96.747 rows=60000 loops=1)
         Sort Key: c.city
         Sort Method: quicksort  Memory: 1537kB
         Buffers: shared hit=189114
         ->  Nested Loop  (cost=1000.29..15630.17 rows=1 width=7) (actual time=12.979..79.094 rows=60000 loops=1)
               Buffers: shared hit=189111
               ->  Gather  (cost=1000.00..15621.86 rows=1 width=8) (actual time=12.946..17.080 rows=60000 loops=1)
                     Buffers: shared hit=9111
                     ->  Parallel Seq Scan on orders o  (cost=0.00..14621.76 rows=1 width=8) (actual time=11.187..16.144 rows=20000 loops=3)
                           Filter: (status = 'refund'::text)
                           Rows Removed by Filter: 333333
                           Buffers: shared hit=9111
               ->  Index Scan using customers_pkey on customers c  (cost=0.29..8.31 rows=1 width=15) (actual time=0.001..0.001 rows=1 loops=60000)
                     Index Cond: (id = o.customer_id)
                     Buffers: shared hit=180000
 Planning Time: 0.718 ms
 Execution Time: 100.866 ms

=== AFTER ANALYZE
 Finalize GroupAggregate  (cost=18176.45..18189.12 rows=50 width=15) (actual time=34.132..37.873 rows=50 loops=1)
   Group Key: c.city
   Buffers: shared hit=10188
   ->  Gather Merge  (cost=18176.45..18188.12 rows=100 width=15) (actual time=34.123..37.847 rows=150 loops=1)
         Buffers: shared hit=10188
         ->  Sort  (cost=17176.43..17176.55 rows=50 width=15) (actual time=30.251..30.256 rows=50 loops=3)
               Sort Key: c.city
               Sort Method: quicksort  Memory: 26kB
               Buffers: shared hit=10188
               ->  Partial HashAggregate  (cost=17174.52..17175.02 rows=50 width=15) (actual time=30.188..30.194 rows=50 loops=3)
                     Group Key: c.city
                     Buffers: shared hit=10172
                     ->  Parallel Hash Join  (cost=2354.54..17051.14 rows=24675 width=7) (actual time=21.687..27.951 rows=20000 loops=3)
                           Hash Cond: (o.customer_id = c.id)
                           Buffers: shared hit=10172
                           ->  Parallel Seq Scan on orders o  (cost=0.00..14631.83 rows=24675 width=8) (actual time=12.694..15.502 rows=20000 loops=3)
                                 Filter: (status = 'refund'::text)
                                 Rows Removed by Filter: 333333
                                 Buffers: shared hit=9111
                           ->  Parallel Hash  (cost=1619.24..1619.24 rows=58824 width=15) (actual time=8.626..8.626 rows=33333 loops=3)
                                 Buffers: shared hit=1031
                                 ->  Parallel Seq Scan on customers c  (cost=0.00..1619.24 rows=58824 width=15) (actual time=0.008..2.257 rows=33333 loops=3)
                                       Buffers: shared hit=1031
 Planning Time: 0.422 ms
 Execution Time: 37.957 ms
Output trimmed. Before ANALYZE: estimate rows=1, actual 60,000 rows and 60,000 Index Scan repetitions

The planner expected one row and chose a Nested Loop: one customer lookup by index for every order row. In fact there were 60,000 rows, so the Index Scan node ran 60,000 times (loops=60000) and read 180,000 pages. After ANALYZE the estimate came close to reality and the plan switched to a Hash Join that reads the customers table once.

Experiment 2: by default the planner treats conditions as independent and multiplies their selectivities. When the city fully determines the region, the estimate comes out about 10 times too low. Extended statistics, CREATE STATISTICS … (dependencies), tell the planner about the dependency.

06-extended-stats.sql
-- Estimates vs reality 2: dependent columns (the city determines the region)
\echo '=== BEFORE: the planner treats the conditions as independent'
EXPLAIN (ANALYZE)
SELECT id FROM customers WHERE city = 'city-7' AND region = 'region-7';

CREATE STATISTICS customers_city_region (dependencies) ON city, region FROM customers;
ANALYZE customers;

\echo '=== AFTER: extended statistics on the dependency'
EXPLAIN (ANALYZE)
SELECT id FROM customers WHERE city = 'city-7' AND region = 'region-7';
Extended statistics for dependent columns
terminal
$ docker exec -i kb-pg-explain psql -U postgres -f - < 06-extended-stats.sql
=== BEFORE: the planner treats the conditions as independent
 Seq Scan on customers  (cost=0.00..2531.00 rows=206 width=8) (actual time=0.013..4.471 rows=1991 loops=1)
   Filter: ((city = 'city-7'::text) AND (region = 'region-7'::text))
   Rows Removed by Filter: 98009
 Planning Time: 0.395 ms
 Execution Time: 4.541 ms

=== AFTER: extended statistics on the dependency
 Seq Scan on customers  (cost=0.00..2531.00 rows=1893 width=8) (actual time=0.010..3.804 rows=1991 loops=1)
   Filter: ((city = 'city-7'::text) AND (region = 'region-7'::text))
   Rows Removed by Filter: 98009
 Planning Time: 0.170 ms
 Execution Time: 3.851 ms
The row estimate before and after CREATE STATISTICS, with the same actual count
  • Estimates off by several times on the lower nodes: run ANALYZE on the table first, then check autovacuum (pg_stat_user_tables.last_autoanalyze).
  • A skewed distribution: raise the column's statistics target with ALTER TABLE … ALTER COLUMN … SET STATISTICS 500 (the default is 100) and run ANALYZE again.
  • Correlated columns in one condition or GROUP BY: CREATE STATISTICS with dependencies or ndistinct.
  • After a bulk load, run ANALYZE right away instead of waiting for autovacuum; the docs recommend it in the section on populating a database.

N+1 from an ORM and pg_stat_statements

N+1 is when code first fetches a list (1 query) and then loads related data separately for every item (N queries). An ORM does this quietly with lazy-loaded relations. Each query is fast, so it never shows up in the slow-query log, but pg_stat_statements gives it away through the call count.

07-n-plus-one.sql
-- How an ORM produces N+1 and how it shows up in pg_stat_statements
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;
SELECT pg_stat_statements_reset() IS NOT NULL AS reset;

-- N+1: first the customer list, then one query per customer (100 queries)
\o /dev/null
SELECT format('SELECT id, total FROM orders WHERE customer_id = %s', id)
FROM customers ORDER BY id LIMIT 100 \gexec
\o

-- The same in one query
\o /dev/null
SELECT o.customer_id, o.id, o.total
FROM orders o
WHERE o.customer_id = ANY (ARRAY(SELECT id FROM customers ORDER BY id LIMIT 100));
\o

SELECT calls,
       round(total_exec_time::numeric, 2) AS total_ms,
       round(mean_exec_time::numeric, 3)  AS mean_ms,
       rows,
       regexp_replace(query, '\s+', ' ', 'g') AS query
FROM pg_stat_statements
WHERE query LIKE '%FROM orders%' AND query NOT LIKE '%pg_stat_statements%'
ORDER BY calls DESC;
Simulating N+1 with \gexec: psql runs every result row as a separate query
terminal
$ docker exec -i kb-pg-explain psql -U postgres -f - < 07-n-plus-one.sql
 calls | total_ms | mean_ms | rows |                                                               query
-------+----------+---------+------+------------------------------------------------------------------------------------------------------------------------------------
   100 |     5.76 |   0.058 | 1254 | SELECT id, total FROM orders WHERE customer_id = $1
     1 |     1.61 |   1.606 | 1254 | SELECT o.customer_id, o.id, o.total FROM orders o WHERE o.customer_id = ANY (ARRAY(SELECT id FROM customers ORDER BY id LIMIT $1))
(2 rows)
Output trimmed: 100 calls of one template versus a single query returning the same rows

Inside the database a hundred short queries took a few milliseconds, which is misleading: pg_stat_statements does not count network latency, and each of the hundred queries is a separate round trip between the app and the database. The fix is to load relations up front: a JOIN, WHERE id = ANY($1), or your ORM's eager loading (for example include, select_related or JOIN FETCH, depending on the library).

SQL
SELECT calls,
       round(total_exec_time::numeric, 1) AS total_ms,
       round(mean_exec_time::numeric, 2)  AS mean_ms,
       rows,
       100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent,
       left(query, 80) AS query
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;
A daily query: the 10 statements with the highest total time (after the example in the documentation)

Typical fixes and a workflow

  1. Find

    The top of pg_stat_statements by total_exec_time, or the log_min_duration_statement log. Optimise what costs the most in total, not the single slowest query.

  2. Reproduce

    The same query with real parameters on data of a similar size: the docs warn that a plan on a toy table does not carry over to a large one.

  3. Read the plan

    EXPLAIN (ANALYZE, BUFFERS): the most expensive node (time × loops, buffers) and the gap between rows and actual rows.

  4. Fix one cause

    An index, a rewrite or statistics, one change at a time, so you can see the effect of each.

  5. Verify

    The plan again, and pg_stat_statements again after a while: mean time and buffers should drop without hurting writes.

Seq Scan with a large Rows Removed by Filter

Likely cause
No index for the condition
Fix
An index; see the indexes lesson

Hash Join with a Seq Scan of a big table for a handful of rows

Likely cause
No index on the join column (often an FK)
Fix
An index on the foreign key

The index exists but you see Filter: (func(col) = …)

Likely cause
A function or type cast on the column
Fix
A range without the function, or an expression index

rows=1 but thousands of actual rows; a Nested Loop with huge loops

Likely cause
Stale statistics
Fix
ANALYZE

An underestimate with several conditions on correlated columns

Likely cause
The independence assumption
Fix
CREATE STATISTICS

A SubPlan in the filter and a cost in the millions

Likely cause
NOT IN or a correlated subquery
Fix
NOT EXISTS, a JOIN

Sort Method: external merge Disk

Likely cause
The sort ran out of work_mem
Fix
An index for the ORDER BY, fewer rows, or a per-session work_mem, measured
pg_stat_statementsEXPLAIN (ANALYZE, BUFFERS)CauseOne fixMeasure
The optimisation loop

Exercises

Next on this topic: transactions and isolation. Slow queries stretch transactions, hold locks longer and raise the number of conflicts.

How this was verified4 · passedchecked 11 October 2026

“Run” means the code was executed in a scratch project or container and the output in the article comes from that run. “Partial” means it was checked against stubs instead of external services. “Not run” means it needs a device, an account or a key; the steps were checked against the official documentation. The verification project files and run logs are kept in the InterLAB archive.

Tell us about your task — we'll review your request and get back to you

Got a project?
We'll scope and estimate it — for free.

Tell us about the product or the problem. After reviewing the task we'll come back with an architecture, a timeline and a price for the first version.

  • Scope and risks estimated before we start
  • NDA — yours or ours
  • Work starts within a week

Please do not send passwords, access keys or source code through this form — we will agree a safe way to share access separately.

By clicking the button you agree to the processing of your personal data.