What the two-stage slow-query loop is and who it is for

Slow-query work goes wrong when it starts from whichever query someone complained about last. The two-stage loop separates deciding what to fix from working out why it is slow, and uses a different tool for each.

Stage one: ranking. pg_stat_statements groups statements that differ only in their constant values into a single normalized entry and accumulates execution counts and timing for each one. Ranking by total time shows which queries consume the most database capacity overall. A 5 ms lookup called millions of times often costs more than a 30-second report that runs once a night. Ranking by mean time alone hides that.

Stage two: diagnosis. For each query near the top of the ranking, EXPLAIN (ANALYZE, BUFFERS) runs the statement and shows the plan the planner chose, with estimated and actual row counts and buffer activity for each node. A large gap between estimated and actual rows usually explains a bad plan better than any single operator does.

The loop exists to stop two habits. The first is adding an index for every slow query, which slows writes and may not help. The second is treating every sequential scan as a bug, even though it is often the cheapest way to read a small table or a large fraction of one.

measure -> rank -> explain -> fix -> verify -> reset -> (back to measure)

This is for backend and platform engineers who own query performance in production and need evidence, not guesses, to justify each change.

 +--------------------+      +------------------------+
 | 1. MEASURE         |      | 2. RANK                |
 | normalized entries |----->| ORDER BY total time,   |
 | calls, total time  |      | not mean time alone    |
 +--------------------+      +------------------------+
           ^                             |
           |                             v  top-N queries
 +--------------------+      +------------------------+
 | 6. RESET           |      | 3. EXPLAIN             |
 | pg_stat_statements |      | (ANALYZE, BUFFERS):    |
 | _reset(): start    |      | estimated vs actual    |
 | a clean baseline   |      | rows, buffer reads     |
 +--------------------+      +------------------------+
           ^                             |
           |                             v
 +--------------------+      +------------------------+
 | 5. VERIFY          |      | 4. FIX                 |
 | re-run EXPLAIN,    |<-----| stats, rewrite, or     |
 | re-rank after load |      | index if plan says so  |
 +--------------------+      +------------------------+

 Stage one (rank):     steps 1-2, driven by pg_stat_statements
 Stage two (diagnose): steps 3-5, driven by EXPLAIN (ANALYZE, BUFFERS)

The two-stage slow-query loop: pg_stat_statements ranks normalized queries by total time, EXPLAIN (ANALYZE, BUFFERS) diagnoses the top entries, and each fix is verified before the statistics are reset and measurement starts again.

Enabling pg_stat_statements and ranking queries by total time

pg_stat_statements needs shared memory allocated at server start, so it must be listed in shared_preload_libraries in postgresql.conf, and the server must be restarted. A reload is not enough. Then run CREATE EXTENSION pg_stat_statements in the database you will query from, which creates the view. Managed services usually set the preload list through their own parameter mechanism rather than direct file access, and that change may still require a restart.

Rank queries by total time, which is calls times mean time. Sorting by mean alone hides cheap queries that run constantly.

Illustrative estimate (assumed numbers, not a benchmark): total = calls × mean. Assume a lookup that averages 5 ms and runs 1,000,000 times a day: 1,000,000 × 5 ms = 5,000 s, about 83 minutes. Assume a nightly report that takes 10 s and runs once: 1 × 10 s = 10 s. The report looks worse per call, but the lookup costs roughly 500 times more database time.

Timing columns were renamed across releases, so run \d pg_stat_statements before writing queries against the view.

Statements are normalized: literals become placeholders such as $1, so similar calls aggregate into one row. This also hides parameter-dependent slowness, where one tenant's value is slow and the rest are fast. Call pg_stat_statements_reset() before a change so the after-measurement isn't mixed with old data.

Limits:

  • Bounded capacity: pg_stat_statements.max caps how many distinct statements are tracked.
  • Eviction: infrequent statements are dropped when the cap is reached.
  • Cumulative stats: counters accumulate since the last reset, which dilutes a recent regression.
  • No recorded plan: the view shows which queries are expensive, not why. Finding out why needs EXPLAIN.
-- 1) In postgresql.conf (keep any libraries already listed), then RESTART the server.
--    A reload does not allocate the shared memory the extension needs.
--      shared_preload_libraries = 'pg_stat_statements'
--      pg_stat_statements.max = 5000   -- cap on distinct statements tracked

-- 2) In the database you will query from, create the view.
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

-- 3) Confirm column names for your release before relying on them.
--    Recent releases use total_exec_time / mean_exec_time;
--    older ones used total_time / mean_time.
-- \d pg_stat_statements

-- 4) Rank by total time (calls x mean), not mean alone, so cheap
--    but very frequent statements surface.
SELECT queryid,
       calls,
       round(total_exec_time::numeric, 1) 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_of_total,
       left(query, 80) AS normalized_query  -- literals shown as $1, $2, ...
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 20;

-- 5) Before deploying a fix, clear the counters so the after-measurement
--    is not diluted by stats accumulated before the change.
SELECT pg_stat_statements_reset();

-- ...deploy the change, let representative traffic run, then re-run step 4.

Enables pg_stat_statements, ranks normalized statements by total execution time with their share of overall time, and resets the counters to bracket a before-and-after measurement.

Running EXPLAIN (ANALYZE, BUFFERS) safely

EXPLAIN ANALYZE does not simulate the query. It runs the statement to completion and then reports what happened. A DELETE deletes rows and an UPDATE takes row locks. Wrap any write in BEGIN ... ROLLBACK so the changes are discarded.

Rolling back does not undo everything:

  • Sequences: values consumed by nextval are not returned.
  • Triggers: they fire, and any external work they start may already be done.
  • Locks: they are held until the rollback completes.

Run statements with side effects like these, or statements that take minutes, on staging or a replica. Don't run them against the primary.

Timing overhead

ANALYZE reads the clock at the start and end of every node execution. On a plan where a node runs millions of times, such as the inner side of a nested loop, those clock calls can inflate total runtime. On some hardware the inflation is noticeable. If you only need actual versus estimated row counts, add TIMING OFF. You keep the per-node row counts and loop counts, and you still get total execution time.

When the test differs from production

A query you paste into psql with literal values gets a plan built for those exact values. The application may use prepared statements. After several executions, the server can switch those to a generic plan that ignores the specific parameter values. That generic plan can be much worse for skewed data, so a fast psql run proves little.

Staging data can mislead in a similar way. Smaller tables, stale statistics or a different value distribution can all change the plan choice.

Caching is the other trap. With BUFFERS, compare shared hit against read. Engineers often run the query twice and report only the second, fully cached run. That hides the disk reads your users actually wait on.

-- 1. Writes: EXPLAIN ANALYZE really executes the UPDATE, so discard it.
--    Sequence values, trigger side effects and lock waits are NOT undone.
BEGIN;
EXPLAIN (ANALYZE, BUFFERS)
UPDATE orders
SET    status = 'archived'
WHERE  created_at < '2024-01-01';
ROLLBACK;

-- 2. Row counts only: skip per-node clock reads on loop-heavy plans.
--    Per-node rows and loops are still reported, and so is total execution time.
EXPLAIN (ANALYZE, BUFFERS, TIMING OFF)
SELECT o.id, c.name
FROM   orders o
JOIN   customers c ON c.id = o.customer_id
WHERE  o.status = 'pending';

-- 3. Approximate the application's generic plan instead of a literal-value plan.
--    plan_cache_mode requires PostgreSQL 12 or later.
PREPARE orders_by_customer(bigint) AS
  SELECT * FROM orders WHERE customer_id = $1;

BEGIN;
SET LOCAL plan_cache_mode = force_generic_plan;
EXPLAIN (ANALYZE, BUFFERS) EXECUTE orders_by_customer(42);  -- generic plan
SET LOCAL plan_cache_mode = force_custom_plan;
EXPLAIN (ANALYZE, BUFFERS) EXECUTE orders_by_customer(42);  -- plan for this value
ROLLBACK;

DEALLOCATE orders_by_customer;

-- 4. When reading BUFFERS output, record the FIRST run as well as the cached rerun:
--    'shared read=N' is disk or OS-cache I/O, and 'shared hit=N' is already in shared_buffers.

Shows how to roll back an analyzed write, use TIMING OFF when only row counts matter, and compare a forced generic plan with a custom plan so a psql test matches how an application's prepared statements are planned.

How to read a query plan node by node

Start at the most deeply indented node and work outward. Each parent consumes its children's output, so the innermost scans tell you where rows originate and where time first accumulates.

An annotated sample

The following plan uses assumed values and is an illustrative example, not a measured result.

  • Nested Loop: estimated rows=50, actual rows=48,000, loops=1
    • Seq Scan on orders: estimated rows=50, actual rows=48,000, loops=1
    • Index Scan using customers_pkey: actual time=0.020..0.025, rows=1, loops=48,000

On every node, compare estimated rows with actual rows. In this plan the planner expected 50 orders and got 48,000. That roughly 1,000× gap explains the plan choice. A nested loop is cheap for 50 outer rows and expensive for 48,000. Treat a large estimate-versus-actual gap as your primary signal of a bad plan. The slow node is often only the downstream victim of a wrong row estimate.

On the inner side of a nested loop, actual time and rows are per-loop averages, so multiply them by loops. Here 0.025 ms × 48,000 ≈ 1.2 s, even though the inner node looks trivial at first glance.

Reading BUFFERS

shared hit counts pages found in PostgreSQL's buffer cache, and read counts pages requested from the OS. A node dominated by hits is CPU- or memory-bound. A node with many reads may be waiting on storage.

Enable track_io_timing to replace that guess with measured I/O wait time per node. This setting reads the clock on every I/O. On systems with slow clock sources that overhead can be significant, so check it with pg_test_timing before enabling track_io_timing broadly.

-- Before enabling I/O timing broadly, check clock overhead from the shell:
--   $ pg_test_timing
-- High per-call timing overhead means track_io_timing will add noticeable cost.

-- Enable I/O timing for this session only, for a targeted investigation.
-- Changing this setting requires superuser or a granted SET privilege.
SET track_io_timing = on;

-- ANALYZE runs the query and reports actual rows, time and loops per node.
-- BUFFERS adds shared hit/read counts, plus I/O timings when track_io_timing is on.
-- Note: ANALYZE really executes the statement, so wrap writes in a transaction you roll back.
EXPLAIN (ANALYZE, BUFFERS)
SELECT o.id, o.total, c.name
FROM orders o
JOIN customers c ON c.id = o.customer_id
WHERE o.status = 'pending'
  AND o.created_at >= now() - interval '7 days';

-- What to look for in the output:
--  1. Start at the most deeply indented node and work outward.
--  2. On each node, compare estimated rows= with actual rows=. A large gap is the primary signal.
--  3. On a nested loop's inner side, multiply actual time and rows by loops.
--  4. Buffers: shared hit=... read=... Mostly hits points to CPU/memory-bound work.
--     Many reads, together with the I/O timing lines, point to storage waits.

-- If the estimates were wrong, refresh statistics and compare the plan again.
ANALYZE orders;

RESET track_io_timing;

Enables track_io_timing for one session, runs EXPLAIN (ANALYZE, BUFFERS) on a sample join, and lists what to check in the plan: row estimates against actuals, per-loop multiplication, and buffer hits against reads.

When a seq scan is correct and when to avoid treating it as a fix target

A Seq Scan reads every page of the table in physical order. That access pattern is cheap per page, and the planner reflects this by assigning seq_page_cost a lower default than random_page_cost. An index scan has to traverse the index and then fetch heap pages that may be scattered across the table. On a table that fits in a handful of pages, that extra traversal costs more than reading the whole table. On a query that returns a large share of the rows, the scattered heap fetches touch most pages anyway, often more than once. In both cases a Seq Scan is the correct plan, and adding an index will not help.

Treat the Seq Scan as a target only when the plan shows evidence of wasted work:

Situation What the plan shows Action
Small table Low actual time, few buffers read Leave it
Large fraction of rows returned Rows returned close to table size Leave it, or reduce the rows the query asks for
Selective filter, no usable index Rows Removed by Filter far exceeds rows returned Add an index that matches the predicate
Wrong selectivity estimate Estimated rows differ from actual rows by orders of magnitude Fix the statistics (next section)

To check whether an index plan would really be faster, run SET enable_seqscan = off in your own session, then run EXPLAIN ANALYZE again. This setting does not forbid sequential scans. It makes the planner strongly avoid them, so you can compare actual timings of the two plans. Treat the result as a diagnostic and do not ship it. If the index plan wins, the planner's cost estimates were wrong. Forcing the setting would hide that error, and the same misestimate would then distort joins and other queries the setting never touches. The same applies to enable_nestloop, enable_hashjoin, and the related planner switches.

Fixing misestimates and mapping plan symptoms to fixes

Start with the estimates, because a wrong row count misleads every downstream choice of join method, scan type and memory. Fix it in this order:

  1. Stale statistics. Run ANALYZE on the table, especially after bulk loads, where autovacuum may not have caught up.
  2. Skewed columns. Raise the column's sampling depth with ALTER TABLE … ALTER COLUMN … SET STATISTICS. A larger sample captures more of the frequent values and a finer histogram.
  3. Correlated columns. Use CREATE STATISTICS on columns like city and postal_code. By default the planner multiplies their selectivities as if they were independent, which underestimates the row count.

Re-run the plan after each step. Rewrite the query only if estimates and actuals still diverge.

Symptom-to-fix map

Plan symptom Likely cause Fix
Seq scan or large Rows Removed by Filter on a selective multi-column predicate Missing composite index, or leading column doesn't match the equality filters Index with equality columns first, then range or sort columns
Index exists but isn't used on lower(email) = … or a mismatched-type comparison Function or implicit cast applied to the column Expression index, or compare using the column's own type
Sort Method: external merge Disk, or Batches greater than 1 on a Hash node Operation exceeded work_mem Raise work_mem for that workload
Rows fetched far exceed rows returned with LIMIT … OFFSET Every skipped row is read and then discarded Keyset pagination: WHERE (created_at, id) < (…) ORDER BY … LIMIT

Both fixes have costs. Every index slows writes, takes disk space and adds vacuum work, so add one only for a query that ranks high in pg_stat_statements. work_mem is allocated per sort or hash operation, in every backend, so a single query can use several multiples of it. Set it with SET LOCAL in the transaction or ALTER ROLE … SET for the reporting role, not globally.

Verifying fixes, alternatives, and impact on engineering time

Verify with realistic data, then with real traffic

Rerun EXPLAIN (ANALYZE, BUFFERS) against production-sized data and the parameter values that were slow. A plan that improves on a small staging table can regress at full scale or for a skewed parameter value. When the plan holds up, deploy the change, call pg_stat_statements_reset(), and let a representative traffic window pass (a full business day, or a full batch cycle). Then compare mean_exec_time and total_exec_time against the numbers you recorded earlier. One fast manual run does not prove the fix. Lower aggregate time under real load does.

For plans you can't reproduce manually, use auto_explain alongside the other tools. With auto_explain.log_analyze on, every statement gets per-node timing instrumentation, including statements that finish too quickly to be logged. To limit that overhead, set a conservative auto_explain.log_min_duration, use auto_explain.sample_rate, and consider turning auto_explain.log_timing off.

Approach What it gives you Production overhead Best for
pg_stat_statements Aggregated time per normalized query Low Deciding what to tune
Manual EXPLAIN (ANALYZE, BUFFERS) Full plan with actual rows and buffers Runs the query once Diagnosing one query
auto_explain Plans of slow statements in the logs Moderate to high with analyze; reduce with sampling Intermittent or parameter-dependent plans
log_min_duration_statement Query text and duration, no plan Low Finding outliers

Ranking queries by total time puts your effort on the work that actually consumes the server. A query that takes 2 ms but runs millions of times usually matters more than a rare 10-second report. Working from estimate gaps instead of guesses also prevents speculative indexes. Each unneeded index slows every write and adds vacuum work for as long as it exists.

How OneEnv can help

Disclosure: OneEnv is the product behind this blog.

OneEnv (oneenv.io) is a workspace-based governance platform for the things services share — environment variables, database structure, API routes and validation rules. A change to a shared value is staged on a branch, reviewed once, and then every affected service explicitly approves or rejects it before it goes live, so you can see who a change touches before it ships instead of finding out in production.

Applied to postgresql explain analyze slow query, this is where it helps:

Saves time

  • Every service that inherits a shared value is listed in one place, so nobody searches repos and chats to find out who is affected.
  • One review per branch replaces coordinating each team separately; each service still keeps its own approve/reject.
  • Changing a route's URL or method automatically notifies the services that consume it — no hunting through repos for callers.

Saves cost

  • Fewer production incidents and rollbacks caused by a shared value, route or column changing under a consumer unannounced.
  • Less duplicated configuration to maintain: one shared definition inherited by many services.
  • Consumers learn about a breaking change at review time rather than from production errors.
  • OneEnv has a free plan (1 workspace, unlimited services and members, full governance), so trying it costs nothing.

These are qualitative benefits, not measured results — how much you save depends on how many services share the value.

Want to try it? Start at oneenv.io.