Why your Postgres query is slow: reading EXPLAIN ANALYZE

"The database is slow" is almost never true. One or two queries are slow, and they are slow for a reason PostgreSQL will happily tell you, in a format that looks like a wall of parentheses the first few times you see it. This guide is the short version: how to get the plan, the three numbers that matter, and the handful of shapes worth recognising.

First, find the right query

Optimising the query you happen to be annoyed by is a good way to waste an afternoon. Ask the database which statements actually cost you the most. If the pg_stat_statements extension is available on your database, it aggregates every statement by total time:

select calls,
       round(total_exec_time::numeric, 1) as total_ms,
       round(mean_exec_time::numeric, 2)  as mean_ms,
       rows,
       query
from pg_stat_statements
order by total_exec_time desc
limit 20;

Sort by total time rather than mean time. A 40 ms query run 200,000 times an hour hurts far more than a 3-second report someone runs at lunchtime. For something slow right now, pg_stat_activity shows in-flight statements:

select pid, now() - query_start as running_for, state, wait_event_type, query
from pg_stat_activity
where state = 'active' and query not ilike '%pg_stat_activity%'
order by running_for desc;

Getting the plan

Connect with psql over your direct connection string (the pooled one is fine for reads, but session settings like work_mem won't stick through a transaction pooler), then:

explain (analyze, buffers) select …;

Two warnings. First, analyze here means "actually run it" — an explain analyze of an update or delete changes your data. Wrap it if you need to:

begin;
explain (analyze, buffers) delete from events where created_at < now() - interval '1 year';
rollback;

Second, run it twice. The first run may be reading from disk while the second reads from cache, and you want to know which situation you're actually optimising for. buffers tells you: shared hit is cache, shared read came from storage.

The three numbers that matter

A plan node looks like this:

->  Index Scan using orders_customer_id_idx on orders
      (cost=0.43..812.19 rows=250 width=64)
      (actual time=0.031..4.117 rows=18422 loops=1)

1. Estimated rows vs actual rows. The planner expected 250 rows and got 18,422. Every decision above this node — which join type, whether to sort in memory, whether to use an index at all — was made on the basis of that wrong number. Bad estimates are the single most common root cause of a bad plan.

2. Actual time, per loop. The two numbers are startup time (until the first row) and total time (until the last). Both are per execution of that node.

3. Loops. How many times the node ran. A node reading actual time=0.05 rows=1 loops=40000 is not fast — it's two seconds of work, executed one row at a time, which is the classic nested-loop-gone-wrong signature.

Five shapes worth recognising

1. Seq Scan on a big table with a selective filter

Seq Scan plus a large Rows Removed by Filter means Postgres read the whole table to keep a handful of rows. If the filter is selective, that's an index waiting to be created. If it isn't selective — you're keeping 40% of the table — the sequential scan is the right choice and the index wouldn't be used anyway.

2. A row estimate that's out by orders of magnitude

Stale statistics are the usual reason. analyze orders; refreshes them, and autovacuum normally does it for you, but a table that has just been bulk-loaded or migrated can be badly out of date. If the estimate is wrong because two columns are correlated (say suburb and postcode, where the planner assumes independence and multiplies the selectivities into a much smaller number), extended statistics fix it properly:

create statistics orders_geo (dependencies, ndistinct)
  on suburb, postcode from orders;
analyze orders;

3. Nested Loop with a big loop count

Nested loops are excellent when the outer side returns a few rows and terrible when it returns many. If you see thousands of loops over an index scan, look one level up: the outer node's estimate was probably wrong (see shape 2). Fix the estimate and the planner will usually switch to a hash join on its own.

4. Sort spilling to disk

Sort Method: external merge  Disk: 24616kB

The sort didn't fit in work_mem and went to temporary files. Either sort fewer rows (filter earlier, or add an index that already provides the order so the sort disappears entirely), or raise work_mem for that session. Be careful with the second: work_mem is per sort or hash node, so one query with several of them can use several multiples of it, and every concurrent connection can do the same.

5. Index Scan where you expected Index Only Scan

An Index Only Scan can answer the query from the index alone — but only for rows the visibility map marks as all-visible. If you see Heap Fetches: 190000, the table needs a vacuum (or autovacuum is falling behind), and the "index only" scan is quietly visiting the table anyway.

Two habits that prevent most of this

Check the plan before you ship the query, not after it's the top row in pg_stat_statements. On a development database, seed enough rows that the planner behaves like production — with 200 rows in a table it will sequential-scan everything and tell you nothing useful.

Set a statement timeout so a pathological query fails fast instead of holding resources: set statement_timeout = '30s'; in the session, or per role with alter role app set statement_timeout = '30s';. A query that runs for six minutes is rarely a query anyone is still waiting for.

None of this is WattleDB-specific — it's stock PostgreSQL behaviour, and everything above works the same on any Postgres you run. On WattleDB you get the direct connection string for psql in the console, so you can go straight to the plan. If you want to go a level deeper on which index to create, read why your index isn't being used next.