Query Profiling Across Database Engines

1. Find — rank queries by total time

The instinct is to hunt for the query with the worst single run. That's a trap. The query that hurts is the one whose cumulative time is highest: calls × average. pg_stat_statements records exactly that, grouping queries by shape (the literal values are stripped out), so thousands of executions roll up into one rankable row.

-- STEP 1 — FIND the slow query (PostgreSQL).
-- Don't guess. pg_stat_statements records every query the server has run,
-- aggregated by "shape" (literals stripped out), so 50,000 calls of the
-- same SELECT collapse into one row you can rank.

SELECT
    LEFT(query, 60)                       AS query_preview,
    calls,                                -- how many times it ran
    ROUND(total_exec_time::numeric)       AS total_ms,   -- 👈 rank by THIS
    ROUND(mean_exec_time::numeric, 2)     AS
...

2. Read — EXPLAIN (ANALYZE, BUFFERS)

Once you know which query, ask the engine how it runs it. Plain EXPLAIN shows the planner's guess. EXPLAIN ANALYZE actually executes the query and reports the real timings and row counts, and BUFFERS adds the I/O story: which pages came from memory versus disk.

-- STEP 2 — READ its plan with EXPLAIN (ANALYZE, BUFFERS).
-- ANALYZE actually RUNS the query and reports real timings + row counts.
-- BUFFERS shows the I/O: pages served from cache vs read from disk.

EXPLAIN (ANALYZE, BUFFERS)
SELECT c.name, SUM(o.total) AS spent
FROM customers c
JOIN orders o ON o.customer_id = c.id
WHERE o.order_date >= '2024-01-01'
GROUP BY c.name
ORDER BY spent DESC
LIMIT 20;

-- ⚠️ EXPLAIN ANALYZE executes the statement. On an UPDATE/DELETE/INSERT,
--    wrap it in a tra
...

A plan is a tree of nodes, read inside-out: the deepest, most-indented node runs first and feeds its parent. Here's realistic output for that customers/orders query before any tuning. Read it slowly — every number is a clue:

Limit  (cost=21450..21450 rows=20) (actual time=812.4..812.5 rows=20 loops=1)
  ->  Sort  (actual time=812.4..812.4 rows=20 loops=1)
        Sort Key: (sum(o.total)) DESC
        Sort Method: quicksort  Memory: 41kB
        ->  HashAggregate  (actual time=805.1..809.9 rows=4821 loops=1)
              Group Key: c.name
              ->  Hash Join  (actual time=120.3..690.4 rows=486110 loops=1)
                    Hash Cond: (o.customer_id = c.id)
                    ->  Seq Scan on orders o
                          (cost=0.00..18234 rows=512) (actual rows=486110 loops=1)
                          Filter: (order_date >= '2024-01-01')
                          Rows Removed by Filter: 13290
                          Buffers: shared hit=44 read=18102
                    ->  Hash  (actual rows=5000 loops=1)
                          ->  Seq Scan on customers c (actual rows=5000 loops=1)
Planning Time: 0.31 ms
Execution Time: 813.0 ms

Walk through what each line is screaming at you:

• Estimated vs actual rows. The Seq Scan on orders says rows=512 (the planner's guess) but actual rows=486110. A ~1000× mismatch means the planner is flying blind — its statistics are stale. It chose a sequential scan because it thought only 512 rows matched; in reality almost half a million did.
• The costliest node. Subtract a node's start time from its end time. The Seq Scan/Hash Join branch runs from ~120 ms to ~690 ms — roughly 570 ms of the 813 ms total. That sequential scan over orders is the bottleneck; the Sort and Limit are cheap by comparison.
• Buffers (I/O). shared hit=44 means 44 pages were already in cache; read=18102 means 18,102 pages were pulled from disk. Disk reads are orders of magnitude slower than cache hits — a sea of read is a flashing sign that the query is scanning data it shouldn't have to touch.
• Wasted work. Rows Removed by Filter: 13290 plus the huge scan means the engine is reading rows only to throw them away. An index on the filtered column would let it skip straight to the matches.

-- 🎯 YOUR TURN — you don't write SQL here, you DIAGNOSE.
-- Read this EXPLAIN (ANALYZE, BUFFERS) output and fill the blanks in the
-- comments with the node name and the reason it is slow.

--  Limit  (actual time=812.4..812.5 rows=20 loops=1)
--    ->  Sort  (actual time=812.4..812.4 rows=20 loops=1)
--          Sort Key: (sum(o.total)) DESC
--          Sort Method: quicksort  Memory: 41kB
--          ->  HashAggregate  (actual time=805.1..809.9 rows=4821 loops=1)
--                ->  Seq Sca
...

3. Fix — refresh stats, then index

The plan gave you two leads: stale statistics and a missing index. Apply them cheapest-first. ANALYZE resamples the table so the planner's estimates match reality — that alone sometimes flips a bad plan into a good one. If a scan is still happening, an index lets the engine jump straight to matching rows instead of reading the whole table.

-- STEP 3 — FIX. The plan blamed a Seq Scan on "orders" with a stale
-- estimate. Two fixes, applied in order:

-- 3a) Refresh the planner's statistics (cheap; do this first):
ANALYZE orders;

-- 3b) Give the filter an index so the engine stops scanning every row.
--     CONCURRENTLY builds it WITHOUT locking writes on a live table:
CREATE INDEX CONCURRENTLY idx_orders_custdate
ON orders (customer_id, order_date);

-- A composite index ordered (customer_id, order_date) serves the JOIN key
-- AND
...

4. Verify — prove it got faster

A fix you didn't measure is a guess you got lucky with. Re-run the identical EXPLAIN (ANALYZE, BUFFERS) and check three things: the Seq Scan became an Index Scan, shared read dropped sharply, and actual rows now lines up with the estimate. Then reset pg_stat_statements so the next day's numbers measure the new world, not the old.

-- STEP 4 — VERIFY. Re-run the SAME EXPLAIN (ANALYZE, BUFFERS) and confirm
-- the node changed and the numbers fell. Then reset the counters so you can
-- measure the win in production over the next day.

EXPLAIN (ANALYZE, BUFFERS)
SELECT c.name, SUM(o.total) AS spent
FROM customers c
JOIN orders o ON o.customer_id = c.id
WHERE o.order_date >= '2024-01-01'
GROUP BY c.name
ORDER BY spent DESC
LIMIT 20;

-- Expect: "Seq Scan on orders" → "Index Scan using idx_orders_custdate",
-- shared read (disk
...

Here's the same query's plan after ANALYZE and the index — note the node, the buffers, and the time:

Limit  (actual time=8.9..9.0 rows=20 loops=1)
  ->  Sort  (actual time=8.9..8.9 rows=20 loops=1)
        ->  HashAggregate  (actual time=2.1..7.4 rows=4821 loops=1)
              ->  Nested Loop  (actual time=0.05..1.9 rows=4821 loops=1)
                    ->  Index Scan using idx_orders_custdate on orders o
                          (cost=0.42..210 rows=4800) (actual rows=4821 loops=1)
                          Index Cond: (order_date >= '2024-01-01')
                          Buffers: shared hit=812 read=3
Execution Time: 9.2 ms

From 813 ms to 9 ms: the Seq Scan is now an Index Scan, read collapsed from 18,102 pages to 3, and the estimate (4,800) finally matches actual (4,821). That's a verified win — not a hopeful one.

-- 🎯 YOUR TURN — write the query that finds the WORST offender.
-- Goal: from pg_stat_statements, return the single query pattern with the
-- largest CUMULATIVE execution time (the one worth fixing first).

SELECT LEFT(query, 60) AS query_preview, calls, total_exec_time
FROM pg_stat_statements
ORDER BY ___ DESC          -- 👉 which column ranks by TOTAL time, not average?
LIMIT ___;                 -- 👉 we only want the single top offender

-- ✅ Expected: ORDER BY total_exec_time DESC LIMIT 1;
...

5. The same loop in MySQL

MySQL changes the tools, not the method. To find, use the slow query log (writes any query over long_query_time to a file) or query the Performance Schema, which aggregates by digest just like pg_stat_statements. To read, MySQL 8.0+ has its own EXPLAIN ANALYZE; in plain EXPLAIN the type column is the headline — ALL means a full table scan, while ref/eq_ref/const mean it's using an index.

-- MySQL: same workflow, different tools.

-- FIND — the slow query log captures anything over long_query_time.
-- Set in my.cnf (or at runtime with SET GLOBAL ...):
--   slow_query_log      = ON
--   slow_query_log_file = /var/log/mysql/slow.log
--   long_query_time     = 1     -- seconds; log queries slower than this

-- FIND (live, no log file) — Performance Schema aggregates by digest,
-- exactly like pg_stat_statements:
SELECT
    LEFT(DIGEST_TEXT, 60)        AS query_preview,
    COUNT_STA
...

6. The same loop in SQL Server

SQL Server's Query Store is a built-in flight recorder: switch it on once and it keeps every query's plans and runtime stats over time, which makes it brilliant for spotting a query that regressed after a deploy. To find, rank sys.query_store_runtime_stats by total duration. To read, capture the actual execution plan (SET STATISTICS XML ON, or "Include Actual Execution Plan" in SSMS) and look at the operator with the highest cost percentage — a thick connecting arrow means a lot of rows are flowing, often the sign of a missing index.

-- SQL Server: Query Store is the built-in flight recorder.

-- Turn it on once per database; it then captures plans + runtime stats:
--   ALTER DATABASE mydb SET QUERY_STORE = ON;

-- FIND the top offenders by total duration (avg × executions):
SELECT TOP 5
    qt.query_sql_text,
    rs.count_executions,
    rs.avg_duration / 1000.0                              AS avg_ms,
    (rs.avg_duration * rs.count_executions) / 1000.0      AS total_ms,
    rs.avg_logical_io_reads                          
...

-- 🎯 MINI-CHALLENGE — profile and propose a fix.
-- Scenario: an API endpoint that lists a user's recent pending orders is
-- timing out. The query is:
--
--   SELECT * FROM orders
--   WHERE customer_id = 42 AND status = 'pending'
--   ORDER BY order_date DESC
--   LIMIT 25;
--
-- pg_stat_statements shows it runs ~30,000×/day at ~280 ms each, and its
-- EXPLAIN (ANALYZE, BUFFERS) shows: "Seq Scan on orders", actual rows close
-- to the planner's estimate (stats are fine), high "shared read".
-
...