Skip to content

How to find slow queries in MySQL

Last updated

View as Markdown

Quick answer: Start with performance_schema, not the slow query log. The slow log records individual executions that crossed a time threshold; events_statements_summary_by_digest aggregates every execution by query shape, so it shows total cost. A query taking 40ms a hundred thousand times never reaches the slow log and is usually the bigger bill. Sort by SUM_TIMER_WAIT, and read SUM_ROWS_EXAMINED against SUM_ROWS_SENT to spot a missing index.

There are two questions that sound the same and are not:

  • Which executions were slow? That is the slow query log.
  • Which queries cost me the most? That is performance_schema.

Most of the time you want the second one, and most people reach for the first.

A query that takes 40ms and runs a hundred thousand times an hour will never appear in your slow query log, and it is costing you far more than the 3-second report someone runs twice a day. Total cost is what you are actually paying.

Start with the digest table

Section titled “Start with the digest table”

events_statements_summary_by_digest holds one row per query shape, with the literal values normalized away, so every execution of the same query rolls up together.

Sorted by total time, this is your bill:

SELECT
  LEFT(DIGEST_TEXT, 80)                      AS query,
  COUNT_STAR                                 AS execs,
  ROUND(SUM_TIMER_WAIT / 1000000000000, 2)   AS total_sec,
  ROUND(AVG_TIMER_WAIT / 1000000000, 2)      AS avg_ms,
  SUM_ROWS_EXAMINED                          AS rows_examined,
  SUM_ROWS_SENT                              AS rows_sent
FROM performance_schema.events_statements_summary_by_digest
WHERE SCHEMA_NAME IS NOT NULL
ORDER BY SUM_TIMER_WAIT DESC
LIMIT 20;

The timer columns are in picoseconds, which is the detail that trips everyone up the first time. Divide by 1,000,000,000,000 for seconds, or 1,000,000,000 for milliseconds. Get it wrong and your slowest query looks like it takes four hours.

The ratio that finds the problem

Section titled “The ratio that finds the problem”

rows_examined against rows_sent is the single most useful column pair here.

If a query examines 500,000 rows to return 10, it is doing a scan where it should be doing a lookup. That ratio is the fingerprint of a missing index, and it shows up long before the query is slow enough for anyone to complain:

SELECT
  LEFT(DIGEST_TEXT, 80)                                  AS query,
  COUNT_STAR                                             AS execs,
  SUM_ROWS_EXAMINED                                      AS examined,
  SUM_ROWS_SENT                                          AS sent,
  ROUND(SUM_ROWS_EXAMINED / NULLIF(SUM_ROWS_SENT, 0), 1) AS examined_per_row
FROM performance_schema.events_statements_summary_by_digest
WHERE SCHEMA_NAME IS NOT NULL
  AND SUM_ROWS_SENT > 0
ORDER BY examined_per_row DESC
LIMIT 20;

If the table is empty

Section titled “If the table is empty”

performance_schema = ON does not turn on every consumer, and statements_digest is one you have to check:

SELECT NAME, ENABLED
FROM performance_schema.setup_consumers
WHERE NAME IN ('statements_digest', 'events_statements_current');

Both should read YES. Enable them in your parameter group on RDS and Aurora, or in my.cnf for self-managed. A runtime UPDATE to setup_consumers does not survive a restart or a failover. It works right up until the next one, then silently stops collecting.

The sys schema says the same thing in English

Section titled “The sys schema says the same thing in English”

sys.statement_analysis is a view over the same digest table with the units already converted. It is easier to read and harder to get wrong:

SELECT query, db, exec_count, total_latency, avg_latency, rows_examined_avg, rows_sent_avg
FROM sys.statement_analysis
ORDER BY total_latency DESC
LIMIT 10;

Use sys when you are reading interactively. Use the raw table when you are building something, because the sys views do extra work per row and are slower on a busy server.

When the slow query log is the right tool

Section titled “When the slow query log is the right tool”

Use it when you need the actual parameter values from a specific bad execution, which the digest table has normalized away. Turn it on for a window, capture, turn it off:

SET GLOBAL slow_query_log = 'ON';
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = 'OFF';

Leave log_queries_not_using_indexes off. On a normal workload it writes a line for every small-table lookup where a scan is genuinely the right plan, and the file grows fast enough to matter. It is not a shortlist of problems; it is noise with a promising name.

Measuring one workload cleanly

Section titled “Measuring one workload cleanly”

To attribute cost to a specific job rather than to everything since the server started, reset the counters and re-read:

TRUNCATE performance_schema.events_statements_summary_by_digest;
-- run the workload you care about, then:
SELECT LEFT(DIGEST_TEXT, 80) AS query, COUNT_STAR AS execs,
       ROUND(SUM_TIMER_WAIT / 1000000000000, 2) AS total_sec
FROM performance_schema.events_statements_summary_by_digest
WHERE SCHEMA_NAME IS NOT NULL
ORDER BY SUM_TIMER_WAIT DESC
LIMIT 10;

That truncate is destructive and has no undo. On a shared production server, someone else may be mid-measurement. Say so before you run it.

Section titled “Related”