What pg_stat_statements Actually Tells You About Your Queries

Your slowest query is rarely your most expensive one. A 4-second report that runs twice a day costs your database 8 seconds. A 3-millisecond lookup that runs 40,000 times a minute costs it two minutes of CPU every sixty seconds. Only one of those shows up in a slow query log, and it is the wrong one.

pg_stat_statements settles this argument. It keeps a running total of every top-level statement your server executes, grouped by structure rather than by literal text. Each group is a fingerprint, with one row in the view representing every execution of the same query shape, with the constants stripped out. Every number in this guide is captured from a real instance, and one query on it spent more time being planned than every other statement combined. It runs in 0.2 milliseconds.

What you will learn

• How pg_stat_statements normalizes queries into a fingerprint, and what that collapses.
• Which columns matter: calls, total_exec_time, mean_exec_time, rows, and the buffer counters.
• How to read a real result set and tell an expensive query from a merely slow one.
• How to find planning-dominated queries, which mean_exec_time hides completely.
• What the extension does not capture, so you know when to stop trusting it.

Before you start

You need PostgreSQL 13 or later. The column names used here landed in version 13; on 12 and earlier they are total_time and mean_time, and planning time is not tracked at all. You need superuser access to edit postgresql.conf and restart the server, and the role you query with needs pg_read_all_stats. Without it the view still returns rows, but every query column reads <insufficient privilege>.

Enable pg_stat_statements

pg_stat_statements allocates a fixed block of shared memory at postmaster startup, so it has to be in shared_preload_libraries. This is not a pure CREATE EXTENSION install. Edit postgresql.conf first, then restart:

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements'
pg_stat_statements.max = 10000
pg_stat_statements.track = all
pg_stat_statements.track_planning = on

Then, in psql:

CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

SHOW shared_preload_libraries;
SELECT count(*) FROM pg_stat_statements;

Check the last two statements, not the first. CREATE EXTENSION succeeds whether or not the library is preloaded, so it proves nothing on its own. SHOW should list the extension, and the count should be non-zero within seconds of normal traffic. If instead you get ERROR: pg_stat_statements must be loaded via shared_preload_libraries, the config edit or the restart did not work.

Three settings change what you see. pg_stat_statements.max caps tracked fingerprints at 5,000 by default, and past that Postgres evicts entries by a decaying usage score, roughly least-recently-used. track_planning is off by default, so total_plan_time reads as zero until you enable it. That one is not optional here; it is where this article's main finding comes from. And track defaults to top, recording only the outermost statement, so if your logic lives in PL/pgSQL functions every nested query is billed to the wrapper. Set it to all.

Reset the counters before you measure

The view accumulates from the last reset. On a long-running server that can mean two years of history spanning a migration, a bad deploy, and a schema change you have since reverted.

SELECT pg_stat_statements_reset();

Rank by aggregate cost, not per-call cost

This query does most of the work. It ranks fingerprints by total execution time and puts the evidence beside each one:

SELECT
    substring(query, 1, 60) AS query_fragment,
    calls,
    round(total_exec_time::numeric / 1000, 1) AS total_sec,
    round(mean_exec_time::numeric, 3) AS mean_ms,
    round(total_plan_time::numeric / 1000, 1) AS plan_sec,
    round(rows::numeric / nullif(calls, 0), 1) AS avg_rows,
    round(100.0 * shared_blks_hit /
          nullif(shared_blks_hit + shared_blks_read, 0), 1) AS hit_pct
FROM pg_stat_statements
WHERE query NOT ILIKE '%pg_stat_statements%'
ORDER BY total_exec_time DESC
LIMIT 10;

Here is the actual output from an example PostgreSQL 16 instance holding 5 million rows in a device_metrics table across 500 daily partitions, 1.26 GB on disk against 256 MB of shared_buffers, after a mixed workload of 20,000 device lookups, 20,000 metadata lookups, 200 batch inserts, 20 reporting aggregates, and 3 retention deletes:

query_fragment	calls	total_sec	mean_ms	plan_sec	avg_rows	hit_pct
SELECT date_trunc($1, ts), avg(value) FROM device_metrics WH	20	251.9	12592.544	0.3	489.8	1.5
SELECT * FROM device_metrics WHERE device_id = $1 AND ts > n	20000	4.4	0.221	213	37.8	95.7
SELECT id, name FROM devices WHERE org_id = $1	20000	0.9	0.044	0.2	125	100
INSERT INTO device_metrics (ts, device_id, metric, value, qu	200	0.8	3.843	0	500	100
DELETE FROM device_metrics WHERE ts < now() - interval $1	3	0	16.091	0.1	13510.3	95.4

Two columns decide the question, and they point in different directions. total_sec is what a fingerprint costs your server, while mean_ms is what it costs one user. Read them as a pair, and four cases fall out. High calls with low mean_ms is an application problem: a query in a loop, an ORM N+1, or a dashboard polling faster than anyone reads it, and the fix is batching or caching rather than indexing. Low calls with high mean_ms is a query problem: a missing index, a bad join order, or a scan wider than the result needs. High on both is where you start. Low on both is the healthy majority, and leaving it alone is the correct action.

Every row below is one of those cases.

Row 1 is 251.9 seconds out of 258.0 across every fingerprint on the server, so 98% of execution time belongs to a query called twenty times. Read avg_rows next to hit_pct to see why. It returns 489.8 rows per call, one per day of retention, and does it at a 1.5% cache hit rate. Twenty calls read 2.75 million blocks off disk to produce 9,796 rows.

Row 5 is the trap from the intro. At 16 ms per call the retention DELETE is the second-slowest statement on the box, the first thing an on-call engineer would flag. Three calls, 48 milliseconds total. Ignore it, with one caveat: total_exec_time under-bills any DELETE, because the dead tuples it leaves and the autovacuum passes that clean them up are charged elsewhere. On a partitioned table, DROP TABLE on the oldest partition does the same job in constant time with no vacuum debt.

Use the buffer columns to separate cache misses from CPU

shared_blks_hit counts 8 KB blocks served from the shared buffer cache. shared_blks_read counts blocks that had to come from the OS cache or disk. The hit_pct column above derives from both, and it is worth selecting the raw counts alongside it, because a ratio hides volume. Statements that touched no shared blocks come back blank rather than zero, which is the nullif guard doing its job.

Row 3 sits at 100.0%. It runs 20,000 times, never leaves memory, and costs 0.9 seconds. That is what a healthy fingerprint looks like. Row 4 is the ingest floor, inserting 500 rows per call at 3.8 ms with a perfect hit rate. Neither is worth touching.

Row 1 sits at 1.5%. It scans a 1.26 GB table through a 256 MB cache, so almost nothing it reads is resident, and every block it pulls evicts something another query wanted. That is read amplification, and no index fixes it. The query has to visit every row in the retention window to compute the average.

The 213 seconds mean_ms cannot see

Now look at row 2. It executes in 0.221 milliseconds. By any per-call measure it is the healthiest query in the workload. However, its plan_sec is 213.0.

That is 10.65 milliseconds of planning for 0.221 milliseconds of execution, 48 times more expensive to plan than to run, and 99.7% of all planning time on the server. A slow query log would never show it. mean_exec_time does not include it.

EXPLAIN ANALYZE confirms the ratio and names the cause. Run the query below twice in one session and read the second result. The first pass loads catalog entries for 500 partitions and reports planning time that includes them:

EXPLAIN (ANALYZE, SUMMARY)
SELECT * FROM device_metrics WHERE device_id = 8 AND ts > now() - interval '7 days';

The second result:

Append (cost=0.29..4300.22 rows=539 width=193)
  Subplans Removed: 492
Planning Time: 10.739 ms
Execution Time: 1.354 ms

Subplans Removed: 492 is the tell. The predicate is ts > now() - interval '7 days', and now() is stable rather than constant, so the planner cannot prune at plan time. It builds a subplan for all 500 partitions, then discards 492 of them at execution. Resolving the timestamp in the application and passing a fixed value lets plan-time pruning run instead. Run this in the same session, substituting a real date:

EXPLAIN (ANALYZE, SUMMARY)
SELECT * FROM device_metrics WHERE device_id = 8 AND ts > '2026-07-22'::timestamptz;

And you may see the planning time drop to 0.183 ms. Subplans Removed is gone: same rows, same execution, 59 times less planning.

To fix this, you have to swap now() for a genuine constant. If you use current_date - 7 instead, nothing changes because current_date is stable too and the planner still builds all 500 subplans. Prepared statements and generic plan caching help too. Fewer, larger partitions help more.

Row 2 in the table was visible only because plan_sec happened to sit in the ranking. To sweep for the pattern deliberately, sort by planning time and add the ratio:

SELECT
    substring(query, 1, 60) AS query_fragment,
    calls,
    round(total_plan_time::numeric / 1000, 1) AS plan_sec,
    round(total_exec_time::numeric / 1000, 1) AS exec_sec,
    round((total_plan_time / nullif(calls, 0))::numeric, 3) AS plan_ms_per_call,
    round((100.0 * total_plan_time /
           nullif(total_plan_time + total_exec_time, 0))::numeric, 1) AS plan_pct
FROM pg_stat_statements
WHERE calls > 100
  AND query NOT ILIKE '%pg_stat_statements%'
ORDER BY total_plan_time DESC
LIMIT 10;

Sort by total_plan_time, and do not scan plan_pct on its own. That ratio is a trap: a trivial indexed lookup often plans in more time than it executes because both are microseconds, and on a scratch instance the same column reads 71.8% for a query nobody should touch. plan_ms_per_call is the honest signal. Healthy lookups plan in tens of microseconds. Row 2 planned in 10.65 milliseconds, and multiplied across 20,000 calls that is the 213 seconds. Use plan_pct to confirm what the absolute numbers already flagged, which for row 2 was 98.0%.

When the ranking stops changing

Rows 1 and 2 are both fixable. The pattern underneath them is not.

On a high-frequency time-series workload, total_exec_time, shared_blks_read, and total_plan_time all climb as data volume and partition count grow, even when every query is written correctly. You fix the top fingerprint, it drops to fourth, and two quarters later it is back with the same shape. If your ranking regenerates itself after you fix what is on it, you are measuring architecture, not technique. Columnar storage changes the inputs rather than the query text: a pre-computed rollup answers row 1 without touching 2.75 million blocks. The Optimization Treadmill covers when optimizing further stops paying.

Know the blind spots

Normalization is what makes the ranking possible and also what limits it. WHERE device_id = 42 and WHERE device_id = 9001 collapse into one fingerprint. If one value matches 4 billion rows and another matches an empty range, you get an average that describes neither.

The view also gives you no percentiles, so check max_exec_time before trusting a healthy mean. And it stores no plans. It tells you a query got slower, never that the planner switched from an index scan to a sequential scan. auto_explain fills that gap, but it needs preloading too, and it only logs statements over auto_explain.log_min_duration. Catching a regression in a 0.2 ms query like row 2 means setting that threshold low enough to hurt, so aim it at one fingerprint and turn it off afterward.

One version note: before PostgreSQL 18, IN lists of different lengths produced separate fingerprints, splitting one logical query across several rows. PostgreSQL 18 merges them.

Four more limits are covered above rather than here, because each one distorts a specific number as you read it: track = top bills nested PL/pgSQL queries to the wrapper, pg_stat_statements.max evicts fingerprints once you pass its configured max, track_planning left off makes every total_plan_time read as zero, and total_exec_time under-bills any DELETE because the vacuum work it creates is charged elsewhere.

Sort by planning time next

Reset your statistics, run one peak cycle, and pull the top five fingerprints by total_exec_time. Then run the same query ordered by total_plan_time, because on this instance that second list found the cost center the first one missed. If the same fingerprints keep returning to the top after you fix them, start a Tiger Cloud trial today and run both rankings against columnar storage to see which rows disappear.