Module 5: Query Profiling in Production
Reading `pg_stat_statements`: top queries
Capsule overview
In capsule 02 you installed pg_stat_statements and understood that the extension normalizes queries and accumulates counters per shape. That's half the work. The other half is knowing what question to ask that view, because the answer changes radically depending on the column you order by.
If you only order by total_exec_time, you miss queries that are individually very slow but run rarely. If you only look at mean_exec_time, the heavy queries almost nobody uses drown you. If you never look at calls, you don't detect hidden N+1s. If you ignore shared_blks_read, you don't see cache problems the planner can't solve.
This capsule teaches you the four canonical queries that any serious backend keeps as snippets for the rest of their career. Each one answers a different question:
- Which queries consume the most aggregate time? → order by
total_exec_time. - Which queries are individually slow? → order by
mean_exec_time. - Which queries are called too much? → order by
calls. - Which queries hit disk? → order by
shared_blks_read.
By the end, you'll be able to read the pg_stat_statements output, identify what kind of problem each top query suggests and, above all, decide which one to attack first using an impact formula = potential_improvement × frequency.
Mental model: four lenses on the same dataset
Imagine you have a physical store and want to optimize your sales. You can look at your transaction base from four angles:
- By total accumulated revenue: which product generated the most money in total? (aggregate impact)
- By average ticket: which product sells at the highest price per unit? (unit margin)
- By number of transactions: which product sells the most times? (volume)
- By cost of inventory moved: which product forced you to move the most stock from the warehouse? (logistics cost)
The same dataset, four lenses, four different kinds of decision. If you only look at one, you make bad decisions: optimizing the product with the highest average ticket may be irrelevant if it only sold 3 times; the highest-volume one may have such a low margin that it's not worth it.
pg_stat_statements is exactly the same applied to queries:
| Lens | Column | Question it answers | Kind of problem it detects |
|---|---|---|---|
| Aggregate impact | total_exec_time | Which query consumes the most DB CPU seconds in total? | Queries with the highest optimization ROI |
| Unit slowness | mean_exec_time | Which query is slow every time it runs? | Missing index, bad plan, badly written query |
| Volume | calls | Which query runs the most times? | N+1, missing cache, uncontrolled app loops |
| I/O cost | shared_blks_read | Which query hits disk the most? | Working set doesn't fit in memory |
All four are useful. What matters is knowing which one you care about depending on the problem you want to solve.
The four canonical queries
Before each query, it's convenient to have this common filter that excludes noise (queries from pg_stat_statements itself, from the catalog, and from your current session):
-- Reusable filter: excludes typical noise
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND query NOT LIKE 'BEGIN%'
AND query NOT LIKE 'COMMIT%'
AND query NOT LIKE 'ROLLBACK%'
You'll see it repeated in the four queries. Copy it to a snippet in your editor.
Query 1: top by total_exec_time (aggregate impact)
Question: which query consumes the most DB CPU seconds in total?
SELECT
calls,
round(total_exec_time::numeric, 2) AS total_ms,
round(mean_exec_time::numeric, 2) AS mean_ms,
round((100.0 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 2) AS pct_total,
rows,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND query NOT LIKE 'BEGIN%'
AND query NOT LIKE 'COMMIT%'
AND query NOT LIKE 'ROLLBACK%'
ORDER BY total_exec_time DESC
LIMIT 10;
The computed column pct_total (percentage of aggregate time) is the metric that defines priority. A query that represents 40% of the system's total_exec_time is where your biggest improvement lever is.
Example output (bookstore after 5 minutes of load):
calls | total_ms | mean_ms | pct_total | rows | query
-------+-----------+---------+-----------+-------+--------------------------------------------------
4250 | 38500.20 | 9.06 | 42.30 | 21250 | SELECT b.id, b.title, b.author_id FROM books b WHERE b.author_id = $1
180 | 24300.50 | 135.00 | 26.70 | 3600 | SELECT b.*, count(r.id) FROM books b LEFT JOIN reviews r ON r.book_id = b.id GROUP BY b.id ORDER BY count(r.id) DESC LIMIT $1
8500 | 9100.30 | 1.07 | 10.00 | 17000 | SELECT a.name FROM authors a WHERE a.id = $1
50 | 6800.10 | 136.00 | 7.47 | 500 | SELECT count(*) FROM orders WHERE created_at > $1
...
How to read it:
Query #1 (SELECT books WHERE author_id = $1) represents 42% of the DB's total time. Even though each execution only takes 9ms, it's called 4,250 times. If you leave it at 1ms (with a better index), you recover 17 accumulated seconds — more than any optimization to individually slower queries.
Query #2 takes 135ms per execution (worst unit case), but only runs 180 times. Recovering even 50% (from 135ms to 67ms) is 12 accumulated seconds — half the impact of optimizing #1, with probably more effort.
Decision by aggregate impact: attack #1 first, then #2.
Query 2: top by mean_exec_time (unit slowness)
Question: which query is individually slowest every time it runs?
SELECT
calls,
round(mean_exec_time::numeric, 2) AS mean_ms,
round(max_exec_time::numeric, 2) AS max_ms,
round(stddev_exec_time::numeric, 2) AS stddev_ms,
round(total_exec_time::numeric, 2) AS total_ms,
rows,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND query NOT LIKE 'BEGIN%'
AND query NOT LIKE 'COMMIT%'
AND query NOT LIKE 'ROLLBACK%'
AND calls > 5 -- ignore queries almost never run
ORDER BY mean_exec_time DESC
LIMIT 10;
The calls > 5 filter is important: without it, any query run only once (a manual ANALYZE, a migration) shows up at the top with a huge mean and will never repeat. Your interest is queries that run regularly and are slow every time.
Example output:
calls | mean_ms | max_ms | stddev_ms | total_ms | query
-------+----------+----------+-----------+-----------+--------------------------------------
180 | 135.00 | 890.50 | 78.20 | 24300.50 | SELECT b.*, count(r.id) ... ORDER BY count(r.id) DESC LIMIT $1
50 | 136.00 | 410.30 | 45.60 | 6800.10 | SELECT count(*) FROM orders WHERE created_at > $1
25 | 85.40 | 120.10 | 12.50 | 2135.00 | SELECT * FROM books WHERE title ILIKE $1
...
How to read it:
The first two queries are at 135ms average. Both are candidates for a deep EXPLAIN (capsule 04). But pay attention to stddev_ms: query #1 has stddev = 78ms, almost as large as the mean. That indicates the query is sometimes very fast and sometimes takes 890ms (max_exec_time). Behind that there's usually plan flapping (the planner changes strategy depending on the data), skewed data (some LIMITs hit enormous groups), or hot vs cold cache.
Query #2 has stddev = 45ms with max = 410ms. More stable, but the worst case is still 3x the average. Also worth investigating.
Decision by unit slowness: the queries that appear here are natural candidates for EXPLAIN ANALYZE (module 2) and index improvement (module 3).
Query 3: top by calls (volume)
Question: which query runs too much?
SELECT
calls,
round(mean_exec_time::numeric, 2) AS mean_ms,
round(total_exec_time::numeric, 2) AS total_ms,
round((calls / extract(epoch FROM (now() - stats_reset)))::numeric, 2) AS calls_per_sec,
rows,
query
FROM pg_stat_statements,
pg_stat_statements_info -- contains stats_reset (PG 14+)
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND query NOT LIKE 'BEGIN%'
AND query NOT LIKE 'COMMIT%'
AND query NOT LIKE 'ROLLBACK%'
ORDER BY calls DESC
LIMIT 10;
The computed column calls_per_sec gives you the approximate execution rate. If a simple query has a sustained 200 calls/sec, that already tells you something in the app is firing it in a loop.
Example output:
calls | mean_ms | total_ms | calls_per_sec | rows | query
-------+---------+-----------+---------------+-------+----------------------------------
8500 | 1.07 | 9100.30 | 28.30 | 17000 | SELECT a.name FROM authors a WHERE a.id = $1
4250 | 9.06 | 38500.20 | 14.16 | 21250 | SELECT b.id, b.title, b.author_id FROM books b WHERE b.author_id = $1
2100 | 0.45 | 945.00 | 7.00 | 2100 | SELECT * FROM users WHERE id = $1
...
How to read it:
Query #1 (SELECT name FROM authors WHERE id = $1) has mean = 1ms and calls = 8,500. Individually it's trivial. But a sustained 28 calls/sec on authors almost always indicates an N+1: you're iterating over something (probably books) and for each one you query the author by id instead of doing a single JOIN or an IN with eager loading.
If you check query #2 (SELECT books WHERE author_id = $1), it also has a suspicious pattern: 4,250 calls when you should probably be making 50 requests to /books with a single JOIN. Another clue of the same kind of N+1.
Decision by volume: queries that appear here with a very low mean_exec_time and a very high calls are classic signatures of a hidden N+1. The action is not to optimize the query (it's already fast) but to find the endpoint that fires it so many times and apply joinedload or selectinload (module 4).
Query 4: top by shared_blks_read (I/O cost)
Question: which query hits disk the most because its data doesn't fit in cache?
SELECT
calls,
shared_blks_hit,
shared_blks_read,
round((100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0))::numeric, 2) AS hit_pct,
round(mean_exec_time::numeric, 2) AS mean_ms,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND query NOT LIKE 'BEGIN%'
AND query NOT LIKE 'COMMIT%'
AND query NOT LIKE 'ROLLBACK%'
AND shared_blks_read > 0 -- queries that touched disk at least once
ORDER BY shared_blks_read DESC
LIMIT 10;
shared_blks_hit counts blocks served from PostgreSQL's buffer cache (memory). shared_blks_read counts blocks that had to be read from disk (slow). The hit_pct is the key metric: a healthy app should have hit_pct > 99% for almost every query. If you see queries with hit_pct < 90%, their working set doesn't fit in shared_buffers.
Example output:
calls | shared_blks_hit | shared_blks_read | hit_pct | mean_ms | query
-------+-----------------+------------------+---------+---------+--------------------------------
180 | 2400000 | 85000 | 96.58 | 135.00 | SELECT b.*, count(r.id) ... LIMIT $1
25 | 180000 | 22000 | 89.10 | 85.40 | SELECT * FROM books WHERE title ILIKE $1
50 | 950000 | 15000 | 98.45 | 136.00 | SELECT count(*) FROM orders WHERE created_at > $1
...
How to read it:
Query #1 read 85,000 blocks from disk. Assuming 8KB blocks, that's ~660MB of accumulated I/O just from this query. If your shared_buffers is 128MB (a conservative default), it will never be enough for this query. Possible solutions:
- Raise
shared_buffersto 25% of available RAM (general PostgreSQL recommendation). - Add a covering index that avoids reading the table.
- Rewrite the query to scan less data (more selective filters before the JOIN).
Query #2 (ILIKE) has hit_pct = 89%, the lowest of the top. That normally indicates a sequential scan over books that doesn't fit in cache. The typical solution is a GIN index for text search (module 3).
Decision by I/O: queries here are candidates for reviewing global shared_buffers, indexes that reduce data read, or rewriting to reduce scan size.
Comparing the four tops
The same queries can appear in several tops or in just one. That's information:
| Appears in | Meaning | Typical action |
|---|---|---|
total_exec_time only | Frequent and reasonably efficient query individually | Hard to optimize; maybe already fine |
mean_exec_time only | Slow query but used rarely | Optimize if the worst case matters |
calls only | Trivial query but run in a loop | Look for N+1 in the app |
shared_blks_read only | Query with a working set out of cache | Review shared_buffers, covering indexes |
total_exec_time + calls | Hidden N+1 with aggregate cost | Eager loading + endpoint review |
total_exec_time + mean_exec_time | Slow and frequent query | The #1 optimization target; highest ROI |
mean_exec_time + shared_blks_read | Query slow due to I/O, not CPU | Reduce data read: index or rewrite |
The query with the highest ROI almost always appears in total_exec_time + mean_exec_time. The one that needs an app refactor appears in total_exec_time + calls.
The impact formula
When you have to decide what to optimize first among several queries, use this mental formula:
estimated_impact = potential_improvement × frequency
= (current_mean - estimated_mean_post_fix) × calls
Concrete example:
- Query A:
mean = 200ms,calls = 50. You estimate that with an index it drops to 20ms.- Impact: (200 - 20) × 50 = 9,000ms = 9s recovered
- Query B:
mean = 5ms,calls = 4,000. You estimate that with eager loading the calls drop to 50.- Impact: (5 - 5) × (4,000 - 50) executions × 5ms = 19,750ms = 19.7s recovered
Query B has greater impact even though it's individually faster, because the problem is the volume, not the slowness.
This is the logic you should internalize: total_exec_time is the best direct proxy of impact, but thinking about it in terms of "what would happen if I fix it" is what gives you the real priority.
Why this matters in real work
1. In senior technical interviews, "how do you identify the most expensive query in your system?" is a standard question. The correct answer is not "I look at Datadog", but "I query pg_stat_statements ordered by total_exec_time and review the top 10 with the percentage over the total". Interviewers who know the topic expect exactly this level of answer.
2. In planning meetings with your PM or tech lead, being able to say "this query represents 40% of the DB's total time, it's where optimizing has the most impact" is the difference between them approving your tuning task or postponing it. Concrete data, not intuition.
3. In incident diagnosis, the four queries are your first line of exploration. Before looking at app logs, running EXPLAIN, or talking to the DBA, the pg_stat_statements tops tell you where to look.
4. It's portable to any profiling tool. pganalyze, Datadog DBM, AWS Performance Insights, Azure Query Performance Insight — they're all built on top of pg_stat_statements. The skill you learn here doesn't expire when you change company or cloud.
Traps and common mistakes
Mistake 1 (conceptual): treating the four tops as redundant
Symptom: "I already looked by total_exec_time, I don't need to look at the others."
Why it confuses: they look the same (always a top 10 of queries) but answer different questions. A query with high total_exec_time may have enormous calls (app problem) or enormous mean (query problem). One with low total_exec_time but very high calls may be the N+1 breaking another endpoint.
How to distinguish: the four queries in the same profiling run. Compare which queries appear in one and not the other. That difference is information.
How to fix it: the discipline of running the four whenever you open a profiling session. It takes 2 minutes. The information you get is worth 10 hours of guessing.
Mistake 2 (interpretation): optimizing query #1 without looking at calls
Symptom: "Query #1 by total_exec_time is slow. I'll add an index."
Why it happens: you assume high total_exec_time is always solved with an index. But if the query is trivial (mean = 1ms) and calls is enormous, the index doesn't help — the query is already using the best plan. The problem is the endpoint that fires it so much.
How to distinguish: divide total_exec_time / calls. If the result is < 5ms, it's not a query problem — it's a problem of who calls it. Look for N+1 in the app.
How to fix it: follow the flow: total_exec_time gives you priority, but mean_exec_time and calls tell you where the problem is (in the query or in the app).
Mistake 3 (operational): ignoring stddev_exec_time
Symptom: "The average is 50ms, it's fine." Meanwhile, there are 2-second executions in production that your p99 sees and your users suffer.
Why it happens: the average hides the long tail. If your query runs 1,000 times at 30ms and 1 time at 2,000ms, the average gives you 32ms and the worst case is 2s. The user who falls into that 2s doesn't care about the average.
How to distinguish: look at stddev_exec_time and max_exec_time always. If stddev > mean, there's high variability. If max_exec_time is 10x the mean, there are outliers.
How to fix it: for queries with high variability, capture the plan in the worst case (capsule 04 with auto_explain). The outlier almost always comes from plan flapping or skewed data.
Mistake 4 (filter selection): not excluding catalog and pg_stat_statements queries
Symptom: "The top is full of pg_catalog.pg_class queries and queries from pg_stat_statements itself. Is that fine?"
Why it happens: the query to pg_stat_statements itself is recorded in pg_stat_statements. If your monitoring client (psql, pgAdmin, Grafana) opens a connection per minute, you'll see that catalog query showing up at the top.
How to distinguish: if the top queries aren't from your app, you're missing a filter.
How to fix it: use the common filter we showed above (WHERE query NOT LIKE '%pg_stat_statements%' and others). In production, also filter by user or database if your app has its own user:
WHERE userid = (SELECT oid FROM pg_roles WHERE rolname = 'bookstore_app')
Mistake 5 (prioritization): attacking the slowest individual query without thinking about frequency
Symptom: "This query takes 3 seconds. I'll optimize it first."
Why it happens: "big first" bias. A 3-second query is visually alarming. But if it runs once per hour, optimizing it to 100ms recovers 2.9s/hour. A 50ms query run 10,000 times per hour recovers 50ms × 10,000 = 500s/hour if you bring it to 0ms — and if you bring it to 25ms (half), you still recover 250s/hour. Much more impact.
How to distinguish: always think in potential_improvement × frequency, not in potential_improvement alone.
How to fix it: order your list of fixes by total_exec_time (which is already a direct proxy of frequency × unit time), not by mean_exec_time.
Exercises
Exercise 1: run the four canonical queries on the bookstore
Bring up the bookstore with pg_stat_statements (capsule 02), generate load with wrk or curl for 2 minutes over the /books-with-author?author_name=tolkien, /books?page=10, and /orders?user_id=5 endpoints. Then, run the four canonical queries and save the output to a top-queries.txt file.
See solution
1. Previous reset:
docker exec -it bookstore-pg psql -U bookstore -d bookstore -c \
"SELECT pg_stat_statements_reset();"
2. Generate load (2 minutes, 5 requests/sec mixed):
for i in {1..600}; do
curl -s "http://localhost:8000/books-with-author?author_name=tolkien" > /dev/null &
curl -s "http://localhost:8000/books?page=10" > /dev/null &
curl -s "http://localhost:8000/orders?user_id=5" > /dev/null &
sleep 0.6
done
wait
3. Run the four queries and save them:
docker exec -it bookstore-pg psql -U bookstore -d bookstore <<'SQL' > top-queries.txt
\echo '=== TOP by total_exec_time ==='
SELECT calls, round(total_exec_time::numeric, 2) AS total_ms,
round(mean_exec_time::numeric, 2) AS mean_ms,
round((100.0 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 2) AS pct_total,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
ORDER BY total_exec_time DESC LIMIT 10;
\echo '=== TOP by mean_exec_time ==='
SELECT calls, round(mean_exec_time::numeric, 2) AS mean_ms,
round(max_exec_time::numeric, 2) AS max_ms,
round(stddev_exec_time::numeric, 2) AS stddev_ms,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND calls > 5
ORDER BY mean_exec_time DESC LIMIT 10;
\echo '=== TOP by calls ==='
SELECT calls, round(mean_exec_time::numeric, 2) AS mean_ms,
round(total_exec_time::numeric, 2) AS total_ms,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
ORDER BY calls DESC LIMIT 10;
\echo '=== TOP by shared_blks_read ==='
SELECT calls, shared_blks_hit, shared_blks_read,
round((100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0))::numeric, 2) AS hit_pct,
round(mean_exec_time::numeric, 2) AS mean_ms,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND shared_blks_read > 0
ORDER BY shared_blks_read DESC LIMIT 10;
SQL
4. Inspect top-queries.txt.
The bookstore has known N+1s in /books-with-author (which you probably fixed in module 4) and heavy queries in /orders. You should see:
- In
total_exec_time: the mainbooksorordersquery at the top. - In
mean_exec_time: probably an aggregation with a JOIN orcount(*)over orders. - In
calls: if the N+1 persists, a query toauthors WHERE id = $1with very high calls. - In
shared_blks_read: queries that touch large tables without a covering index.
Exercise 2: identify an N+1 from pg_stat_statements without seeing the code
You're given this output (simplified output, assume it came from 5 minutes of profiling):
calls | mean_ms | total_ms | query
--------+---------+----------+-------------------------------------------
12500 | 0.85 | 10625.00 | SELECT * FROM authors WHERE id = $1
250 | 10.20 | 2550.00 | SELECT * FROM books WHERE category = $1
180 | 35.40 | 6372.00 | SELECT * FROM books JOIN authors ON ... WHERE category = $1
Identify:
- What's the N+1 signature in this output?
- Which endpoint (of those implicit in these queries) is firing the N+1?
- What solution do you propose and which module is it from?
See solution
1. N+1 signature:
The first query (SELECT * FROM authors WHERE id = $1) has mean_ms = 0.85 (trivial) but calls = 12,500. That's 50x the number of calls of the other top queries. The classic N+1 signature is exactly that: a very frequent query, individually fast, hitting a referenced table.
2. Endpoint:
Queries 2 and 3 both filter WHERE category = $1, suggesting an endpoint like /books-by-category?category=X is active. Query 2 (SELECT * FROM books WHERE category = $1) has 250 calls. Query 3 (SELECT * FROM books JOIN authors ...) has 180 calls. The two together sum to 430 calls.
If the 12,500 calls to authors WHERE id = $1 are distributed among the endpoint's requests, that's ~29 calls to authors per request of the endpoint with the N+1 (12,500 / 430). That fits perfectly with an endpoint that returns ~30 books and for each book loads book.author lazy.
Suspect endpoint: GET /books-by-category (or equivalent) that iterates over the response's books and accesses book.author.name on each iteration without eager loading.
3. Solution:
Apply selectinload(Book.author) to the endpoint's query. This turns 1 + N queries into 2 queries:
from sqlalchemy.orm import selectinload
stmt = (
select(Book)
.where(Book.category == category)
.options(selectinload(Book.author))
)
books = (await session.execute(stmt)).scalars().all()
Which module it's from: module 4 (N+1 with SQLAlchemy). This capsule identified the problem; module 4 fixes it.
Post-fix validation: after applying the change, reset pg_stat_statements, repeat the load test, and query again. The query to authors WHERE id = $1 should go from 12,500 to ~430 calls (one per request).
Exercise 3: compare queries across two tops and decide priority
You're given these two queries from the top:
Query A:
total_exec_time: 45,000 ms
calls: 150
mean_exec_time: 300 ms
Query B:
total_exec_time: 30,000 ms
calls: 6,000
mean_exec_time: 5 ms
You estimate that with an index you can bring A down from 300ms to 30ms. You estimate that with eager loading you can reduce B's calls from 6,000 to 60 (keeping mean at 5ms).
Which do you optimize first and why?
See solution
Estimated impact calculation for each fix:
Query A:
- Unit improvement: 300 - 30 = 270 ms saved per execution
- Calls that remain: 150
- Total impact: 270 × 150 = 40,500 ms saved (reducing from 45s to ~4.5s)
Query B:
- Unit improvement: 0 ms (the query still takes 5ms each time)
- Calls eliminated: 6,000 - 60 = 5,940
- Total impact: 5 × 5,940 = 29,700 ms saved (reducing from 30s to 0.3s)
Decision:
Query A first. It has more absolute impact (40.5s vs 29.7s) and probably less effort (adding an index vs refactoring the endpoint with correct eager loading and verifying nothing breaks).
Important nuance:
If both fixes are easy, do them both in the same PR. The formula is for prioritizing when you have to pick just one. In reality, both can often be done in a few hours.
Another nuance:
If Query B represents a hidden N+1 in a critical endpoint (login, checkout) that affects perceived UX, it could be prioritized even though it has less absolute impact on the DB's CPU. The formula is a cost proxy, not a UX proxy.
Exercise 4: write your own query to detect queries with high variability
You want to detect queries whose worst case (max_exec_time) is at least 10x their average (mean_exec_time), because you suspect plan flapping or skewed data. Write the SQL query.
See solution
SELECT
calls,
round(mean_exec_time::numeric, 2) AS mean_ms,
round(max_exec_time::numeric, 2) AS max_ms,
round((max_exec_time / nullif(mean_exec_time, 0))::numeric, 2) AS max_to_mean_ratio,
round(stddev_exec_time::numeric, 2) AS stddev_ms,
query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
AND query NOT LIKE '%pg_catalog%'
AND calls > 10 -- ignore small sampling
AND max_exec_time / nullif(mean_exec_time, 0) > 10
ORDER BY max_to_mean_ratio DESC
LIMIT 10;
Why it works:
max_exec_time / mean_exec_time > 10filters queries whose worst execution was more than 10x the average.calls > 10avoids false positives from small sampling (with 2 executions, if one is very slow, the ratio is enormous but means nothing).nullif(mean_exec_time, 0)avoids division by zero in queries that report mean = 0.- Ordering by
max_to_mean_ratiosurfaces the ones most suspected of plan flapping.
What to do with the results:
The queries that appear here are candidates for:
- Capturing the plan in the worst case with
auto_explain(next capsule). - Checking whether the WHERE filters might be touching very skewed data (e.g.: WHERE status = 'pending' where 99% are 'pending' but the plan assumes 50/50).
- Forcing a stable plan with hints (last resort, not ideal).
Exercise 5: explain to a PM why to optimize query #5 before #1
Your PM tells you: "I see in the report that query #1 represents 45% of the database's time. Why does your plan say you'll start with #5?"
Your additional observation: query #1 has mean_exec_time = 1.2ms and calls = 850,000. Query #5 has mean_exec_time = 1,200ms and calls = 100.
Write your answer in 3-4 sentences, accessible to a non-technical PM but precise.
See solution
Possible answer:
"Query #1 represents 45% of the DB's time because it runs 850,000 times in the period, not because each execution is slow — each call takes only 1.2ms, practically optimal. There's no real margin to optimize that query individually; the work there is to review why the system calls it so many times (probably an N+1), which means refactoring an endpoint and extensive testing. Query #5, on the other hand, takes 1.2 seconds every time it runs, which is a terrible experience for the user who fires it, and it's fixed in hours with an index. I'm going to do both, but starting with #5 gives me a visible improvement for the affected users this week, while I coordinate the refactor of #1 with the backend team for the next sprint."
Why it works:
- Acknowledges the PM's data point (45%) without minimizing it.
- Explains that a very low
mean_timemeans "no margin for individual improvement". - Distinguishes between "aggregate impact on the DB's CPU" (what
total_exec_timeshows) and "impact on perceived UX" (what matters for the user). - Gives a realistic timeline (#5 this week, #1 next sprint).
- Communicates that you'll do both, not just one.
The key insight: total_exec_time is a cost proxy, not a priority proxy. Priority also depends on UX, fix effort, and change risk.
Exercise 6: measure the real effect of a fix with reset
Apply a hypothetical fix to the bookstore (for example, add an index on books(author_id) if it doesn't exist). Measure the real impact by comparing pg_stat_statements before and after.
See solution
Complete workflow:
1. Reset and baseline:
docker exec -it bookstore-pg psql -U bookstore -d bookstore -c \
"SELECT pg_stat_statements_reset();"
2. Generate load:
for i in {1..200}; do
curl -s "http://localhost:8000/books-by-author?author_id=5" > /dev/null
done
3. Measure baseline:
docker exec -it bookstore-pg psql -U bookstore -d bookstore -c "
SELECT calls, round(mean_exec_time::numeric, 2) AS mean_ms,
round(total_exec_time::numeric, 2) AS total_ms
FROM pg_stat_statements
WHERE query LIKE '%books%author_id%';
"
Note the values. Example:
calls | mean_ms | total_ms
-------+---------+----------
200 | 45.30 | 9060.00
4. Apply the fix:
docker exec -it bookstore-pg psql -U bookstore -d bookstore -c \
"CREATE INDEX IF NOT EXISTS idx_books_author_id ON books(author_id);"
5. Reset again:
docker exec -it bookstore-pg psql -U bookstore -d bookstore -c \
"SELECT pg_stat_statements_reset();"
6. Repeat the same load:
for i in {1..200}; do
curl -s "http://localhost:8000/books-by-author?author_id=5" > /dev/null
done
7. Measure post-fix:
docker exec -it bookstore-pg psql -U bookstore -d bookstore -c "
SELECT calls, round(mean_exec_time::numeric, 2) AS mean_ms,
round(total_exec_time::numeric, 2) AS total_ms
FROM pg_stat_statements
WHERE query LIKE '%books%author_id%';
"
Compare:
calls | mean_ms | total_ms
-------+---------+----------
200 | 1.20 | 240.00
Measured improvement: mean dropped from 45.30ms to 1.20ms (97.4% improvement). total dropped from 9.06s to 0.24s (97.4% improvement) over the same load.
Operational lesson: without reset between the two measurements, the accumulated values would have masked the effect of the fix. The discipline of reset → load → measure before and after is what lets you report real improvements with concrete numbers.
Summary and next step
In this capsule you learned:
- The four canonical queries to
pg_stat_statements: bytotal_exec_time(aggregate impact),mean_exec_time(unit slowness),calls(volume),shared_blks_read(I/O cost). - How to read each one and what kind of problem it suggests: the queries that dominate your system vs the ones that are individually slow vs the hidden N+1s vs the working sets out of cache.
- The impact formula (
potential_improvement × frequency) to prioritize fixes with data instead of intuition. - The typical traps when interpreting the tops: confusing slow with frequent, ignoring variability (
stddev,max), skipping the reset. - How to connect the tops with previous modules: high
mean_exec_time→ module 3 (indexes) or module 2 (EXPLAIN); highcalls→ module 4 (N+1); highshared_blks_read→ review ofshared_buffersor covering indexes.
Before moving on, you should be able to:
- Write the four canonical queries from memory (or have them as snippets).
- Distinguish, by looking at a
pg_stat_statementsoutput, whether a top query needs an index, eager loading, or a cache review. - Justify fix priority with the
potential_improvement × frequencyformula. - Apply the reset → load → measure discipline to measure real improvements.
Next capsule — auto_explain: capturing plans in production. You know how to identify problematic queries. But pg_stat_statements only shows you normalized text and aggregate metrics. To understand why a query is slow you need its execution plan. In capsule 02 of module 2 you learned to run EXPLAIN (ANALYZE, BUFFERS) manually; in production you can't do that for every slow query. auto_explain is the solution: it automatically captures the full plan of any query that exceeds a time threshold to the log. Capsule 04 teaches you to configure it, read it from the log, and combine it with pg_stat_statements in an integrated workflow.
Resources
- PostgreSQL 16 —
pg_stat_statementsreference — the complete official reference for columns and configuration. - Lukas Fittl — "Effective query analysis with pg_stat_statements" — a practical overview from the creator of pganalyze.
- Hubert "depesz" Lubaczewski — "Why is my query slow?" — a classic on debugging with
pg_stat_statements. - Crunchy Data — "Tuning pg_stat_statements" — configuration best practices.
- Citus Data — "How to use pg_stat_statements to find slow Postgres queries" — a practical workflow for identifying slow queries.
- PostgreSQL wiki — Slow Query Questions — a classic checklist for reporting and diagnosing slow queries.
Module 5 — Database Performance & Query Tuning Guide