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.
After this you will be able to
- find slow and frequent queries with
pg_stat_statementsandlog_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
ANALYZEorCREATE STATISTICS - apply typical fixes: an index on the foreign key, a condition without a function on the column,
NOT EXISTS, removing N+1
Know beforehand
Verified with
PostgreSQL 17 (17.11, postgres:17-alpine)pg_stat_statements 1.11
Checked against docs: October 11, 2026
Contents
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, thenCREATE EXTENSION pg_stat_statementsin 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;0logs 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_librariesorLOAD
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.
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-- 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;$ 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)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.
-- 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';$ 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 mscost=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:
hitcame from PostgreSQL's cache,readfrom 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.
=== 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 msSeq 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.
-- 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;$ 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)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.
-- 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);$ 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 msEstimates 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.
-- 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);$ 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 msThe 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.
-- 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';$ 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- Estimates off by several times on the lower nodes: run
ANALYZEon 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 runANALYZEagain. - Correlated columns in one condition or
GROUP BY:CREATE STATISTICSwithdependenciesorndistinct. - After a bulk load, run
ANALYZEright 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.
-- 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;$ 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)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).
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;Typical fixes and a workflow
Find
The top of
pg_stat_statementsbytotal_exec_time, or thelog_min_duration_statementlog. Optimise what costs the most in total, not the single slowest query.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.
Read the plan
EXPLAIN (ANALYZE, BUFFERS): the most expensive node (time ×loops, buffers) and the gap betweenrowsandactual rows.Fix one cause
An index, a rewrite or statistics, one change at a time, so you can see the effect of each.
Verify
The plan again, and
pg_stat_statementsagain 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 INor a correlated subquery- Fix
NOT EXISTS, aJOIN
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-sessionwork_mem, measured
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.