MySQL Slow Query Log: Turn It On, Read It, Find What Matters

The MySQL slow query log is where most performance work should start. It records every statement that ran longer than a threshold you choose, with timings and row counts, and it costs very little to keep on. Yet on many servers we look at it is either disabled, which is the default, or enabled with the default 10-second threshold, which in a web application means it catches almost nothing until users are already complaining.

What gets logged, and what doesn't

According to the MySQL manual, a statement is written to the slow query log only if all of these are true:

1. It is not an administrative statement such as ALTER TABLE or OPTIMIZE TABLE, unless log_slow_admin_statements is on.
2. It took at least long_query_time seconds, or log_queries_not_using_indexes is on and the query used no index for row lookups.
3. It examined at least min_examined_row_limit rows.
4. It was not suppressed by log_throttle_queries_not_using_indexes.

A few details are worth knowing before you trust the log:

• Time spent acquiring the initial locks is not counted as execution time. A query that sat for 40 seconds waiting on a row lock may look fast here. For that kind of problem see our guide to "Lock wait timeout exceeded".
• Entries are written after the statement finishes and its locks are released, so the order in the file can differ from the order of execution.
• Statements that fail to parse are not logged, and passwords in logged statements are rewritten.
• On replicas, replicated statements are not logged unless log_slow_replica_statements is on, and even then it has no effect for row-based replication.

Turn it on without a restart

All the main settings are dynamic, so you can start collecting data on a live server:

SET GLOBAL slow_query_log_file = '/var/log/mysql/slow.log';
SET GLOBAL long_query_time = 1;
SET GLOBAL log_slow_extra = ON;
SET GLOBAL slow_query_log = ON;

-- check where it goes and that FILE output is enabled
SHOW GLOBAL VARIABLES WHERE Variable_name IN
  ('slow_query_log', 'slow_query_log_file', 'long_query_time', 'log_output');

If you don't set a file name, MySQL writes to host_name-slow.log in the data directory. Check log_output as well: if it doesn't include FILE, nothing is written to the file even though the log is "enabled".

One trap catches almost everyone. long_query_time also exists per session, and session variables are initialised from the global values when a client connects. Your SET GLOBAL only applies to new connections. An application with a long-lived connection pool keeps using the old 10-second threshold until its connections are recycled. If the log stays suspiciously empty after the change, this is usually why.

Settings made with SET GLOBAL are lost on restart. Once you are happy with them, put them in the configuration file or use SET PERSIST.

Choosing long_query_time

There is no universal right number, but the default of 10 seconds is almost always too high for an OLTP application. The value can go down to 0, with microsecond resolution. Two approaches work well in practice:

• A steady threshold for everyday monitoring, low enough to catch queries your users notice. For many web applications we start around one second and lower it as the obvious problems get fixed.
• A short full capture. Setting long_query_time = 0 for a limited window, say 15 minutes at peak, logs every statement. That gives you the full picture, including fast queries that run millions of times. It also writes a lot, so watch disk space and switch it back.

log_queries_not_using_indexes sounds useful but is noisy: it also logs small, fast scans that are perfectly fine. If you turn it on, set log_throttle_queries_not_using_indexes to cap how many such entries are written per minute. min_examined_row_limit helps filter out trivial queries.

Reading an entry

A typical entry looks like this:

# Query_time: 3.412907  Lock_time: 0.000012 Rows_sent: 20  Rows_examined: 1843210
SET timestamp=1762070400;
SELECT * FROM orders WHERE customer_email = '...' ORDER BY created_at DESC LIMIT 20;

The most useful number is often not Query_time but the ratio between Rows_examined and Rows_sent. Here MySQL read 1.8 million rows to return 20. That is almost always a missing or unusable index, and it is the kind of query that gets dramatically slower as the table grows.

With log_slow_extra on, each entry also includes handler counters (Read_rnd_next and friends), sort counters, temporary tables created in memory and on disk, bytes sent and received, and error number. A large Read_rnd_next means a full scan; Created_tmp_disk_tables above zero means a sort or group by spilled to disk.

Don't read the file, summarise it

A busy server can write gigabytes of slow log a day. Reading it top to bottom is pointless, because the individual slowest query is rarely the one that costs you most. A 30-second report that runs once a night matters less than a 200 ms query that runs 50,000 times an hour.

MySQL ships with mysqldumpslow, which groups similar queries. The more common tool is pt-query-digest from Percona Toolkit:

# top queries by total time over the last 24 hours
pt-query-digest --since 24h /var/log/mysql/slow.log > slow-report.txt

# only SELECTs
pt-query-digest --filter '$event->{arg} =~ m/^select/i' /var/log/mysql/slow.log

By default it ranks query fingerprints by total execution time (Query_time:sum) and reports the top 95% or the top 20, whichever comes first. The profile at the top of the report shows, for each fingerprint, its share of total response time, number of calls, average time per call and a variance-to-mean ratio. High variance means a query that is usually fast and sometimes terrible, which is often a sign of locking or of a plan that changes with parameter values. Below the profile, each query gets its own section with percentiles, a time histogram and a sample statement you can feed to EXPLAIN.

No access to the log file? Use Performance Schema

On managed services, or when you need numbers right now, the events_statements_summary_by_digest table gives you the same kind of ranking without any log file. It aggregates statements by normalised text and schema since the last reset:

SELECT SCHEMA_NAME,
       LEFT(DIGEST_TEXT, 120)               AS query,
       COUNT_STAR                           AS calls,
       ROUND(SUM_TIMER_WAIT / 1e12, 1)      AS total_s,
       ROUND(QUANTILE_95 / 1e12, 3)         AS p95_s,
       SUM_ROWS_EXAMINED, SUM_ROWS_SENT,
       SUM_NO_INDEX_USED
FROM performance_schema.events_statements_summary_by_digest
ORDER BY SUM_TIMER_WAIT DESC
LIMIT 10;

Timer columns are in picoseconds, hence the division by 1e12. SUM_NO_INDEX_USED counts executions that did a full scan. To measure a specific period, note the numbers before and after, or clear the table with TRUNCATE TABLE. The table has a fixed size set by performance_schema_digests_size; when it fills up, new statements are lumped into a row with a NULL digest. If that row is large, the manual suggests increasing the size.

Keep it running

• Rotate the file. After moving it, run FLUSH SLOW LOGS so MySQL reopens a new file.
• Run a digest on a schedule, daily or weekly, and compare it with the previous one. A new fingerprint near the top usually arrived with a recent deployment.
• After a fix, confirm it with EXPLAIN ANALYZE and with the next digest, not with a single fast run on a warm cache.

The method behind this is the same on any engine; our PostgreSQL slow query checklist walks through it from the PostgreSQL side.