EXPLAIN ANALYZE for Rails developers

Where this rule comes from

Every SQL statement Postgres receives goes through two stages before the result comes back. The parser turns the text into a tree. The planner picks how to execute it: which index to scan, which join algorithm to use, in what order. The chosen plan is what actually runs against the data, and two plans for the same SQL can differ by orders of magnitude in cost.

EXPLAIN prints the plan without running it. EXPLAIN ANALYZE runs the query, then prints the plan annotated with what actually happened: real timings, real row counts, real buffer reads. The two are different tools and seniors use both for different reasons.

Most Rails developers learn to spot "Seq Scan" in an EXPLAIN output, panic, and add an index. That reflex is useful at the start. It also leaves a lot of detail on the table. A senior reading the same output looks at five other things first, and often concludes that the seq scan is correct and the slowness lives somewhere else entirely.

This lesson is about those five things and the grammar of plan nodes that lets you find them. The end goal is being able to look at any plan and answer two questions in under thirty seconds: where is the time actually going? and does Postgres's view of the data match reality?

The anti-pattern: "Seq Scan! Add an index!"

A junior dev sees this in their EXPLAIN output:

Seq Scan on posts  (cost=0.00..145.50 rows=8543 width=156)
  Filter: published

They open a migration and add add_index :posts, :published. They re-run EXPLAIN. The plan now uses the index, the EXPLAIN looks "better," and the dev moves on.

Three things wrong with the move. First, the seq scan may have been right. If the posts table has 10,000 rows and 8,500 are published, scanning the table is faster than using an index that points at most of it. Postgres knew this and chose accordingly. The new index will be unused at query time and will slow down every INSERT, UPDATE, and DELETE that touches the table.

Second, the EXPLAIN output without ANALYZE is the planner's guess, not the reality. Cost is a synthetic number in arbitrary units, useful for comparing two plans but not for measuring real time. The planner can be confidently wrong, especially when stats are stale or selectivity is hard to estimate. Without ANALYZE, you are debugging an opinion, not a fact.

Third, the question was wrong to begin with. "Is this using an index?" is a means, not an end. The real question is whether the query is fast enough, and if not, where the time is going. An index scan that takes 200ms is worse than a seq scan that takes 50ms.

How to read a plan

A plan is a tree of nodes. Each node is an operation (scan, join, sort, aggregate) with one or two children. Postgres prints the tree depth-first with indentation. The root of the tree is the topmost line, and execution flows from the leaves up to the root.

Each node has a one-line header that looks like this:

Index Scan using posts_user_id_idx on posts  (cost=0.43..125.34 rows=42 width=156) (actual time=0.018..1.245 rows=38 loops=1)
  Index Cond: (user_id = 1234)
  Filter: published
  Rows Removed by Filter: 4

The first parentheses give the planner's estimate: cost=start..total rows=N width=B. Cost units are synthetic, calibrated to "fetching one disk page" being roughly 1.0. rows is the planner's row estimate, which drives most plan choices: small numbers favour nested loops, large numbers favour hash joins. width is the average byte size of a returned row.

The second parentheses appear only with ANALYZE: actual time=start..total rows=N loops=M. Start is the time to the first row returned, total is the time to the last. rows here is what actually came back. Loops is how many times this node executed (one outer scan can drive the inner scan multiple times in a nested loop).

The lines under the header are conditions and filters. Index Cond is what the index actually scans against. Filter is what gets applied after the scan. Rows Removed by Filter shows how many rows the filter discarded. A high Rows Removed by Filter is a strong signal that the index is doing less work than it should: most of the matching rows are being thrown away after the scan.

The first thing seniors check: estimate vs actual

Open any EXPLAIN ANALYZE output, scan down the plan, and compare the planner's rows= (in the cost parentheses) against the actual rows= (in the actual-time parentheses). When estimated and actual diverge by an order of magnitude or more, the planner's view of the data is wrong, and any plan it picks based on that view is suspect.

A common shape:

Nested Loop  (cost=0.43..892.10 rows=12 width=156) (actual time=2.341..18394.521 rows=84203 loops=1)
  ->  Index Scan on users  (cost=0.43..8.45 rows=1 width=8) (actual time=0.012..0.418 rows=1 loops=1)
        Index Cond: (id = 1234)
  ->  Index Scan on posts  (cost=0.42..884.02 rows=12 width=156) (actual time=0.005..0.218 rows=84203 loops=1)
        Index Cond: (user_id = users.id)

Postgres expected user 1234 to have 12 posts. They have 84,203. The planner picked a nested loop because nested loops are great when the inner side returns a handful of rows per outer row. With 84,000 rows per outer row, the nested loop is wrong. A hash join would have finished in milliseconds. The query takes 18 seconds because of one bad estimate at the top of the plan.

The fix is not to rewrite the query. The fix is to run ANALYZE posts; to refresh the table statistics, then re-explain. If the estimate now matches reality, the plan will too. If the estimate is still wrong after ANALYZE, the statistics targets may need raising or an extended statistic may be needed (covered in lesson 2). The senior reflex is "check stats before you touch the SQL."

The grammar of plan nodes

A small vocabulary covers most plans you will see in a Rails app.

Seq Scan reads every row of a table. Right when most rows match the filter, or when the table is small enough that one sequential read is cheaper than an index lookup plus heap fetches. Index Scan walks an index, then fetches the matching rows from the heap. Right when the index is selective (returns a small fraction of the table). Index Only Scan answers the query entirely from the index, with no heap fetches. The best case for read-heavy queries; requires a covering index where every column the query needs is in the index.

Bitmap Heap Scan and Bitmap Index Scan appear together. The bitmap index scan builds an in-memory bitmap of matching row positions; the bitmap heap scan fetches them in physical disk order. This is what Postgres picks when an index would be selective but the matching rows are scattered across the heap, or when multiple indexes can be combined.

For joins, three shapes dominate. Nested Loop: for each outer row, look up matching inner rows. Right when the outer side is small or when there is an index on the inner join column. Hash Join: build an in-memory hash on the smaller side, probe with the larger. Right for equality joins on large inputs. Merge Join: both inputs arrive sorted, walk through them in parallel. Right when both sides are already sorted (often because both come from an index).

The other nodes you will recognize at a glance: Sort (sort rows for ORDER BY or as input to a merge join), Aggregate and HashAggregate (GROUP BY), Limit, Unique, Materialize (cache the inner side of a nested loop). The full list is in the Postgres docs; the ones above cover 95% of what shows up in real Rails query plans.

EXPLAIN ANALYZE + BUFFERS for the full picture

Time tells you the symptom. Buffers tell you why. Run with the BUFFERS option:

EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM posts WHERE user_id = 1234;

Each plan node now reports the IO it did:

Index Scan using posts_user_id_idx on posts  (...)
  Index Cond: (user_id = 1234)
  Buffers: shared hit=8 read=42

shared hit is pages found in Postgres's buffer cache (RAM). shared read is pages read from disk. A query that does 100,000 buffer reads is doing serious IO and the time will be dominated by disk speed, not Postgres's internal work. A query that does 50 hits and zero reads is cache-hot and the time is all CPU.

The senior use of BUFFERS is recognising "this query is slow because it is cold." A query that shows 10,000 reads on a cold cache and 50 hits on a warm cache will look totally different in EXPLAIN ANALYZE depending on the order you ran them. Production performance depends on which case is normal. Run EXPLAIN ANALYZE twice in a row; the second run is the warm-cache reality.

Running it from Rails

Active Record gives you .explain on any relation:

Post.where(user_id: 1234).where(published: true).order(created_at: :desc).limit(20).explain

This returns the EXPLAIN output as a string. It does not run ANALYZE by default; for that, use .explain(:analyze, :buffers) on Rails 7.1+. Older Rails versions need to drop into raw SQL:

ActiveRecord::Base.connection.execute(
  "EXPLAIN (ANALYZE, BUFFERS) " + relation.to_sql
).each { |row| puts row["QUERY PLAN"] }

For finding which queries to explain in the first place, install the pg_stat_statements extension on the database. It records cumulative timings per normalized query and is the single biggest signal for finding slow queries in a production app. Set it up once, then check it weekly. The query at the top of the "total time" leaderboard is almost always worth an EXPLAIN ANALYZE.

The principle at play

A query plan is a hypothesis the planner made based on what it knows about the data, and ANALYZE is the experiment that tests the hypothesis. Most slow-query investigations are about finding where the hypothesis broke. Estimates that diverge from reality are the loudest signal that something has changed underneath the planner's feet.

The senior approach to slow queries is not "add an index" or "rewrite the SQL." It is "read the plan, find where time and rows diverge from expectations, ask why." Indexes and rewrites are downstream of that question. Sometimes the answer is an index. Often the answer is stale statistics, a bad estimate the planner could not have made better, or a query that is fast in development against 100 rows and slow in production against 10 million. The plan tells you which.

Lesson 2 picks up the planner side: when statistics go stale, what extended statistics buy you, and how to read pg_stat_user_tables to spot the tables most likely to be lying to the planner today.