Finding the query that is actually slow

MySQL Course · lesson 19 of 21 · 6 min read

EXPLAIN ANALYZE, the slow log and performance_schema - evidence over intuition.

Open this lesson in the learning hub

Key points

  • EXPLAIN shows the plan the optimiser intends. EXPLAIN ANALYZE runs the query and reports actual rows and time per step, which is what exposes a bad estimate.
  • The gap between estimated and actual rows is the most useful single signal. An estimate of 10 against an actual of 400,000 means the statistics are stale, and the plan was chosen on bad information.
  • In the plan, the type column is a quick quality scale: const and eq_ref are ideal, range is fine, index is a full index scan, and ALL is a full table scan.
  • Using filesort and Using temporary mean the engine is sorting or materialising outside the index - usually fixable with an index that already provides the order.
  • The slow query log finds problems you did not think to look for. Set a low threshold in staging and read the aggregate, not individual entries.
  • performance_schema ranks statement digests by total time, which is the right lens: a 5ms query run a million times costs far more than a 2-second report run once a day.

Example

-- Estimated plan.
EXPLAIN SELECT * FROM orders WHERE customer_id = 5 AND status = 'PAID';
--   type: ref   key: idx_cust_status   rows: 12   filtered: 100.00

-- Actual execution - this is the one that finds bad estimates.
EXPLAIN ANALYZE SELECT o.*, c.name FROM orders o
JOIN customers c ON c.id = o.customer_id WHERE o.status = 'PAID';

--   -> Nested loop inner join  (cost=1234 rows=10)
--        (actual time=0.05..842.3 rows=400000 loops=1)
--                                      ^^^^^^
--   estimated 10, actual 400,000 -> the optimiser chose on bad stats.
--   Fix: ANALYZE TABLE orders;

-- The type column, best to worst:
--   system, const   one row, by primary key            ideal
--   eq_ref          one row per join, unique index     ideal
--   ref             several rows, non-unique index     good
--   range           an index range scan                fine
--   index           FULL index scan                    suspicious
--   ALL             FULL TABLE SCAN                    usually the bug

-- Slow query log - find what you did not know to look for.
SET GLOBAL slow_query_log = 1;
SET GLOBAL long_query_time = 0.2;
SET GLOBAL log_queries_not_using_indexes = 1;
--   then aggregate rather than reading it line by line:
--   pt-query-digest /var/lib/mysql/slow.log

-- performance_schema: rank by TOTAL time, not by worst single run.
SELECT DIGEST_TEXT,
       COUNT_STAR                        AS calls,
       ROUND(SUM_TIMER_WAIT/1e12, 2)     AS total_sec,
       ROUND(AVG_TIMER_WAIT/1e9, 2)      AS avg_ms,
       SUM_ROWS_EXAMINED / NULLIF(SUM_ROWS_SENT, 0) AS examined_per_row
FROM performance_schema.events_statements_summary_by_digest
ORDER BY SUM_TIMER_WAIT DESC LIMIT 10;

--   examined_per_row is the tell: 1 is perfect indexing,
--   10,000 means the engine reads 10,000 rows to return one.

EXPLAIN ANALYZE exposes bad estimates, and ranking digests by total time finds the cheap query run a million times.

This is a reading copy. The full lesson — with the visual explainer, the interactive lab and a Run button for the code — lives in the MySQL Course course, and every lesson in it is listed on the MySQL Course contents page.