Why is this query slow?

The symptom

A revenue report by country, for web orders placed in the last 30 days:

WITH web_orders AS (
  SELECT id, customer_id FROM commerce.orders
  WHERE  channel = 'web' AND placed_at >= now() - interval '30 days'
)
SELECT c.country,
       count(*)           AS items,
       sum(oi.line_total) AS revenue,
       rank() OVER (ORDER BY sum(oi.line_total) DESC) AS rank
FROM   web_orders w
JOIN   crm.customers c         ON c.id = w.customer_id
JOIN   commerce.order_items oi ON oi.order_id = w.id
GROUP  BY c.country
ORDER  BY revenue DESC;

It returns 24 rows and takes 4.6 seconds. commerce.orders has 12,000,000 rows and two indexes that contain placed_at. Nothing about the query looks wrong.

What the Plan tab shows

Run the statement, then click Plan next to Result above the rows (Pro). Seqora does not read your run. It runs its own EXPLAIN, estimates first, and for a read statement follows with EXPLAIN ANALYZE inside a transaction it rolls back. The header says EXPLAIN ANALYZE, the execution and planning time (4,581 ms and 2.4 ms here) and the work_mem in force. The rest of the tab is five parts. This section takes them one at a time, in the order your eye meets them.

The row flow

The Flow lens draws the plan right to left, from the tables into the result. Each band is the rows leaving a node, as wide as the count across every loop, so a node that ran many times is drawn at its total. Six things on this flow matter for this query.

The row flow of the report. Rows run right to left, from the tables into the result.

Read it as a story. Markers 1 and 3 say the scan read everything and kept little. Marker 2 says the planner thought it would keep almost nothing, so it chose joins that probe an index once per kept row, and marker 4 says those probes ran 206,880 times instead of 612. The seconds are in the scan, marker 5, and in the probes.

The wheel beside a scan

Every scan has a wheel on its left: the table, drawn as a ring. Double-click one in the app for the TABLE WHEEL guide, which labels its parts and prints the table's numbers. This is the wheel of orders.

The wheel beside Seq Scan on orders, drawn large, with the guide's own labels.

Where the time went

The strip above the canvas splits the 4,581 ms by node. Hover a segment for Self time, the node minus its inputs, Share and With inputs.

The time strip of the report, one segment per node, widest first.

Two of the three seconds that are not the scan are those loops. The aggregate and the sort take almost nothing.

Findings

Seqora reads the plan for the patterns worth a sentence and lists them under the canvas, with a numbered badge on the node each one sits on. Both of these sit on the scan, so the flow above shows one badge.

The findings panel for the report: two findings, both on Seq Scan on orders.

The inspector

Click the scan and the inspector opens on the right. It puts the scan's numbers on rulers and bars, and lists the indexes the planner could have used.

The inspector for Seq Scan on orders, with the suggested index at the bottom of its index list.

Under the index list, heap order sketches how placed_at sits in the table, with its correlation of 0.99. It matters once the index exists, because an index range on a column the table is sorted by reads neighbouring pages.

All of it together

That is every part. Here is the whole thing they came from: the Plan tab as the app shows it, with the text plan from the SQL editor beside it.

The three things to look at first

Any plan, from the top:

1. The node with the biggest self time. That is where the seconds are.
2. The lowest node whose estimate is off by 10× or more. Every decision above it was made on a wrong number.
3. A scan that reads far more than it keeps. That is a missing or unusable index.

On this plan all three point at the same node, which is common. The scan of orders is the biggest self time. It is the lowest node with a bad estimate, 612 against 206,880. And it reads 12,000,000 rows to keep 206,880, because no index on orders starts with channel.

The bad estimate explains the rest. orders was analysed 41 days ago, and most of the last 30 days of orders arrived after that. The planner priced the joins for 612 rows, and for 612 rows a Nested Loop that probes an index per row is the right call. It ran that loop 206,880 times against order_items, and the join above it 620,640 times against customers. The join above the loops expected 1,836 rows and produced 620,640. Two of the three seconds in the strip are those loops.

What to do

In this order:

1. ANALYZE commerce.orders; The Estimate off finding copies it. It reads a sample of the table and takes seconds. Seqora cannot prove ANALYZE is read-only, so a locked connection rejects it: unlock from the sidebar, run it, and confirm the Review high-risk SQL panel. Capture the plan again and the estimate is close to 206,880, so the planner switches both joins to Hash Joins. The scan is still a Seq Scan, so this alone fixes the loops and not the 1,640 ms.
2. CREATE INDEX orders_channel_placed_idx ON commerce.orders (channel, placed_at DESC); This is the suggested index. Before building it on a 12-million-row table, test it: Will this index help? shows what Test tells you and what it cannot. Copy CREATE INDEX copies the CONCURRENTLY form, which is the one to run on a table people are writing to.

Caveats

• EXPLAIN ANALYZE runs the query. A read that takes 4.6 seconds takes 4.6 seconds again when you open Plan.
• Seqora analyzes reads on its own. For an UPDATE, DELETE or INSERT it shows estimates and offers Analyze in rollback, which runs the statement inside BEGIN … ROLLBACK. That needs an unlocked connection, and it asks Run this statement to analyze it? first, because sequence values, trigger side effects and the locks it takes are not undone. On production you type RUN before Run and roll back.
• The inspector's Rows per loop is per loop. order_items returning 3 rows is 3 rows each of 206,880 times. The bands in the flow are already multiplied.
• commerce.orders was last analysed 41 days ago in the copy behind this page. Yours was probably analysed last night by autovacuum, and the estimate will be closer. The missing index is the same either way.
• The numbers above come from a 12-million-row copy of the sample. A smaller copy gives the same plan shape with smaller numbers.
• SQLite shows estimates only, with no timings. MySQL and MariaDB analyze reads only. MySQL, MariaDB and SQLite has the table.