Hunting Slow Queries with pg_stat_statements
KU
Kiril Urbonas
6 days ago • 4 min read•1 view
The dashboard said the database was fine. It wasn't. Here's how pg_stat_statements found the query eating 40% of our Postgres CPU.
CPU on the primary was pinned at 85% every afternoon and the on-call graph just said "database busy," which is not a finding, it's a shrug. The slow query log was quiet because no single query crossed our 500ms log_min_duration_statement threshold. The killer wasn't one slow query. It was a fast query run forty thousand times a minute. pg_stat_statements is the only tool that shows you that, because it aggregates by query shape, not by individual execution.
It ships with Postgres but isn't loaded by default. You need it in shared_preload_libraries, which means a restart. Plan for that.
# postgresql.conf
shared_preload_libraries = 'pg_stat_statements'
pg_stat_statements.max = 10000
pg_stat_statements.track = top
Then create the extension in the database you care about:
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;
track = top records top-level statements but not queries called inside functions. If most of your logic lives in PL/pgSQL, switch to track = all, but be aware it adds overhead and inflates the table.
Everyone sorts by mean_exec_time and finds some analytics query that runs once a day and takes nine seconds. Who cares. That's nine seconds a day. Sort by total_exec_time instead, because total time is what's actually consuming your CPU.
SELECT
substring(query, 1, 80) AS short_query,
calls,
round(total_exec_time::numeric, 0) AS total_ms,
round(mean_exec_time::numeric, 2) AS mean_ms,
round((100 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 1) AS pct
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 15;
That pct column is the one to read first. It tells you what share of total execution time each query shape owns. Our afternoon culprit showed up immediately:
short_query | calls | total_ms | mean_ms | pct
------------------------------------------------+----------+-----------+---------+------
SELECT * FROM sessions WHERE token = $1 | 38412007 | 4820193 | 0.13 | 41.2
UPDATE users SET last_seen = $1 WHERE id = $2 | 9120334 | 1210556 | 0.13 | 10.3
0.13ms per call. Fast. But 38 million calls. That one query was 41% of all database time. The fix wasn't a better index (it was already index-only), it was a caching layer in the app so we stopped hitting Postgres to validate every session token on every request. We put sessions in Redis and that top line dropped off the chart the next day.
pg_stat_statements also tracks block hits versus reads, which tells you whether a query is served from shared buffers or hitting disk.
SELECT
substring(query, 1, 60) AS short_query,
shared_blks_hit,
shared_blks_read,
round(100.0 * shared_blks_hit /
nullif(shared_blks_hit + shared_blks_read, 0), 1) AS hit_pct
FROM pg_stat_statements
WHERE shared_blks_hit + shared_blks_read > 100000
ORDER BY shared_blks_read DESC
LIMIT 10;
A query with a low hit_pct and high shared_blks_read is going to disk a lot, which usually means it's scanning more data than it should or your working set doesn't fit in RAM. We found a reporting query at 62% hit ratio that a partial index on status = 'active' pushed to 99%.
The stats are cumulative since the last reset (or last restart). If you're chasing a problem that started an hour ago, cumulative stats from three weeks ago drown the signal. Reset, wait, then read.
SELECT pg_stat_statements_reset();
-- wait 10 minutes during the problem window
-- then run the total_exec_time query above
We reset at the start of every incident investigation. The counters that matter are the ones that move during the problem, not the all-time totals dominated by whatever runs most often overall.
One gotcha: on a replica, pg_stat_statements tracks that replica's own query traffic, not the primary's. If your reads go to a replica pool, check each one, because your slow read might live on a node you weren't looking at.
Install it on every Postgres instance you run, today, and always sort by total_exec_time first. The slow query log lies to you by design, it only shows queries slow enough individually to cross a threshold, and it's completely blind to the death-by-a-million-fast-queries pattern that causes most real CPU problems. pg_stat_statements costs a restart to enable and a few percent overhead to run, and it has paid for itself in the first incident every single time.
Get the latest tutorials, guides, and insights on AI, DevOps, Cloud, and Infrastructure delivered directly to your inbox.
How we cut auth redirect latency to single-digit milliseconds and ran A/B tests without a flash of wrong content, using Vercel Edge Middleware.
Our node image shipped 240 CVEs, most from OS packages we never called. Moving to distroless dropped the count to single digits and cut image size by 70%.
Explore more articles in this category
The Backstage demo always wows leadership. Then six months later the catalog has 400 stale entries and nobody trusts it. Here's what got ours to actually stick.
We inherited 200-odd AWS resources built by hand over four years, with no state file anywhere. Here's how import blocks and a generation workflow got them under Terraform without a rebuild.
A single ALTER TABLE took a lock and stalled every write for 40 seconds during peak traffic. Expand-contract is how we stopped shipping outages.
Evergreen posts worth revisiting.
