RE:NODE

Databases12 min read

MySQL slow query log: enable it, read it, fix what it finds

Turn on the MySQL slow query log, choose long_query_time, summarise it with mysqldumpslow or performance_schema and fix the queries it catches.

0 readers

The slow query log records every statement that takes longer than long_query_time seconds, with how long it took, how many rows it examined and how many it returned. It is off by default, and turning it on needs no restart:

sql
SET GLOBAL slow_query_log = ON;SET GLOBAL long_query_time = 0.5;SET GLOBAL log_output = 'FILE';SHOW VARIABLES LIKE 'slow_query_log_file';

Leave it running through a normal day, summarise it with mysqldumpslow -s t -t 10 to find the ten statement shapes that cost the most total time, and fix them one at a time - nearly always with an index, sometimes by rewriting the query. Two traps: the new long_query_time applies only to connections opened after you change it, and the default threshold of ten seconds is so high it catches almost nothing a web application cares about.

This guide covers MySQL 8.0 and 8.4 LTS: the settings, the log format, the tools that summarise it, what to do when you cannot reach the log file, and the fixes for the problems it usually turns up.

The settings#

VariableDefaultWhat it does
slow_query_logOFFTurns the log on
long_query_time10Threshold in seconds; fractions allowed down to microseconds
slow_query_log_filehost_name-slow.logFile name, in the data directory unless a path is given
log_outputFILEFILE, TABLE (into mysql.slow_log), or both, comma separated
log_queries_not_using_indexesOFFAlso logs fast queries that did a full scan
log_throttle_queries_not_using_indexes0Caps those per minute; 0 means no cap
min_examined_row_limit0Skips statements that examined fewer rows than this
log_slow_admin_statementsOFFIncludes ALTER TABLE, OPTIMIZE, ANALYZE and similar
log_slow_extraOFFAdds extra fields per entry (8.0.14 and later)

All of them are dynamic, so SET GLOBAL works without a restart, and SET PERSIST keeps the value across restarts. Changing global variables needs SYSTEM_VARIABLES_ADMIN, which the root account has and an application user does not.

Choosing long_query_time

Ten seconds made sense for batch reporting in 2005. For a web application, where a page should be done in a few hundred milliseconds, it means the log stays empty while users wait. Reasonable starting points:

  • Web application or API: 0.5 to 1. Anything over half a second in a request path is worth knowing about.
  • Background jobs and reports: 2 to 5, or leave them to a separate account and look at them separately.
  • A short, deliberate capture: 0 logs every statement. Useful for ten minutes to see the full picture of a page load; dangerous left on, because it writes every query to disk.

The catch that confuses everyone: long_query_time has a session value, copied from the global one when a connection opens. An application using a connection pool may keep its connections for hours, and those connections keep the old threshold. Either restart the application after changing it, or wait for the pool to recycle its connections. log_queries_not_using_indexes and slow_query_log itself take effect immediately for everyone.

log_queries_not_using_indexes sounds useful and is mostly noise: it logs every query on a ten-row lookup table and every SELECT COUNT(*) on a small table. If you turn it on, pair it with min_examined_row_limit = 1000 so only scans of real size are recorded, and with log_throttle_queries_not_using_indexes so one hot query cannot flood the file.

Reading an entry#

code
# Time: 2026-10-08T14:02:11.482913Z# User@Host: app[app] @  [198.51.100.7]  Id:    42# Query_time: 2.481920  Lock_time: 0.000004 Rows_sent: 20  Rows_examined: 1840022use appdb;SET timestamp=1791468131;SELECT id, title, created_at FROM postsWHERE status = 'published' ORDER BY created_at DESC LIMIT 20 OFFSET 36000;

Each line carries a clue:

  • Query_time is wall-clock execution time. It includes time spent waiting, so a statement blocked behind another transaction looks slow even if its own work is trivial.
  • Lock_time is time spent acquiring locks. When it accounts for most of Query_time, the query is a victim of contention, not the cause - look at what held the lock, covered in transactions, locking and deadlocks.
  • Rows_sent versus Rows_examined is the single most useful ratio. Twenty rows sent for 1.8 million examined means the server read and discarded almost everything. A good query examines a small multiple of what it returns.
  • User@Host tells you which application or job sent it, which matters when several share a server.

With log_slow_extra = ON, each entry gains fields such as Thread_id, Errno, Bytes_received, Bytes_sent, Read_first, Read_key, Read_next, Sort_merge_passes, Sort_rows, Created_tmp_tables and Created_tmp_disk_tables, which distinguish a sort-heavy query from a scan-heavy one without running it again. Turn it on; the log gets wider but the cost is negligible.

The example above is a classic: deep OFFSET pagination. MySQL has to read and throw away 36,000 rows to return 20, and page 2000 of the archive gets slower than page 1 by exactly that much. The fix is in the last section.

Summarising with mysqldumpslow#

A day's log can hold thousands of entries, most of them the same few statements with different values. mysqldumpslow, a Perl script shipped with the MySQL server, groups them by shape - replacing numbers with N and strings with 'S' - and totals them:

bash
# Top 10 by total time: the queries that cost you the most overall$ mysqldumpslow -s t -t 10 /var/lib/mysql/db-slow.log# Top 10 by count: the ones that run constantly$ mysqldumpslow -s c -t 10 /var/lib/mysql/db-slow.log# Only statements touching the orders table$ mysqldumpslow -s t -g 'orders' /var/lib/mysql/db-slow.log
code
Count: 1412  Time=1.84s (2598s)  Lock=0.00s (0s)  Rows=20.0 (28240), app[app]@[198.51.100.7]  SELECT id, title, created_at FROM posts  WHERE status = 'S' ORDER BY created_at DESC LIMIT N OFFSET N

Sort by total time (-s t) first. A query taking 30 seconds once a day matters less than one taking 0.6 seconds 4,000 times a day, and total time is what puts them in the right order. The figures in parentheses are totals; outside them, averages.

pt-query-digest from Percona Toolkit does the same job with more detail - percentiles, a query fingerprint ID, EXPLAIN suggestions - and is worth installing if you analyse logs often. Both tools need the file on a machine where you can run them; copy it down with SFTP or scp rather than running analysis on a small database server.

When you cannot read the log file#

On a hosted database you may not have a shell on the database machine. Two routes do not need one.

Log to a table. With log_output = 'TABLE', entries go into mysql.slow_log, readable with SQL:

sql
SET GLOBAL log_output = 'TABLE';SET GLOBAL slow_query_log = ON;SELECT start_time, query_time, rows_sent, rows_examined, LEFT(sql_text, 200) AS queryFROM mysql.slow_logORDER BY query_time DESCLIMIT 20;

The table uses the CSV engine, has no indexes, and grows until you empty it with TRUNCATE TABLE mysql.slow_log. Fine for a day of capture, not for leaving on for months.

Use performance_schema digests. MySQL already aggregates every statement by shape in performance_schema, whether or not the slow log is on, with no threshold at all. This is often better than the log, because it catches the fast query that runs a million times:

sql
SELECT schema_name,       count_star                          AS calls,       ROUND(sum_timer_wait / 1e12, 1)     AS total_s,       ROUND(avg_timer_wait / 1e9, 1)      AS avg_ms,       sum_rows_examined, sum_rows_sent,       LEFT(digest_text, 120)              AS queryFROM performance_schema.events_statements_summary_by_digestWHERE schema_name = 'appdb'ORDER BY sum_timer_wait DESCLIMIT 10;

Timer values are in picoseconds, hence the divisions. The sys schema wraps the same data in friendlier views: sys.statement_analysis (everything, sorted by total latency), sys.statements_with_full_table_scans, sys.statements_with_sorting, sys.statements_with_temp_tables and sys.statements_with_runtimes_in_95th_percentile. The counters reset when the server restarts, or on demand with TRUNCATE TABLE performance_schema.events_statements_summary_by_digest, which is the way to measure a clean before and after.

On RE:NODE the root password for each MySQL server is generated for you, so both routes are available without asking anyone: SET GLOBAL for the slow log settings, and full read access to performance_schema and sys.

Fixing what it finds#

The same handful of causes account for most entries.

No usable index. Rows_examined in the hundreds of thousands, EXPLAIN showing type: ALL or a weak ref. Add an index that matches the WHERE and ORDER BY, equality columns first. MySQL indexes and EXPLAIN covers how to design it and how to confirm it worked.

Deep OFFSET pagination. LIMIT 20 OFFSET 36000 reads 36,020 rows. Replace it with keyset pagination: remember the last row's sort value and continue from there.

sql
-- Instead of OFFSET, continue after the last row the user sawSELECT id, title, created_at FROM postsWHERE status = 'published'  AND (created_at < '2026-03-14 09:12:00'       OR (created_at = '2026-03-14 09:12:00' AND id < 88213))ORDER BY created_at DESC, id DESCLIMIT 20;

With an index on (status, created_at, id), every page costs the same twenty rows.

Functions on indexed columns. WHERE DATE(created_at) = '2026-10-08' cannot use an index on created_at. Rewrite as a range: created_at >= '2026-10-08' AND created_at < '2026-10-09'.

**SELECT * on wide tables.** Reading every column, including large TEXT and JSON, when the page shows three. Name the columns; with the right index the query may become covering and skip the table entirely.

`ORDER BY RAND()`. Generates a random value for every row and sorts them all. For "a random featured item", pick a random ID in the application, or pre-shuffle into a small table.

Counting large tables. SELECT COUNT(*) FROM events on an InnoDB table with millions of rows scans an index every time, because InnoDB keeps no exact row count. Cache the number, maintain a counter, or show an estimate from information_schema.tables.

Lock waits. High Lock_time, or Query_time far above what EXPLAIN ANALYZE shows when you run it alone. The query is waiting for another transaction. Find the long transaction in sys.innodb_lock_waits or information_schema.innodb_trx, and keep transactions short.

The N+1 pattern. Never appears in the slow log, because each query is fast. Shows up in the digest table as one statement with a huge count_star - the same SELECT ... WHERE post_id = ? run once per row of a list. Fix it in the application with a join or an IN (...) batch.

A one-day investigation, step by step#

When someone says "the site is slow" and nobody knows why, this routine gets from complaint to cause in a day without guessing.

  1. Take a baseline. Reset the digest counters with TRUNCATE TABLE performance_schema.events_statements_summary_by_digest so the numbers you read tomorrow cover only today.
  2. Turn the slow log on at a threshold your users would notice - 0.5 for a website - with log_slow_extra = ON, and restart the application or let its pool recycle so its connections pick up the new value.
  3. Leave it through the busiest part of the day. A capture taken at 3 a.m. finds the backup job and nothing else.
  4. Rank by total time, from mysqldumpslow -s t or the digest query. Write down the top five statement shapes with their call counts and average times.
  5. For each, take one real example from the log - with its actual parameter values, because a plan can differ between a customer with five orders and one with fifty thousand - and run EXPLAIN ANALYZE on it.
  6. Classify it: missing index, wrong index, query shape (offset, function on a column, SELECT *), lock wait, or legitimately heavy work that needs caching or a summary table.
  7. Fix the top one, deploy, and check its digest numbers the next day before moving to the second.

The order matters more than it looks. Fixing one statement often changes the picture for the others: a missing index that made one query scan a table also made it hold the buffer pool hostage, pushing other queries' pages out of memory. Those other queries get faster without being touched, and you would have wasted effort optimising them first.

It is also worth checking, before any of this, that the database is actually where the time goes. If the slowest statement in a day of logging at half a second is a 0.6-second report, the database is not why pages take four seconds; look at the application, external API calls, or the server's CPU. The slow log is just as useful for ruling the database out as for finding the problem in it.

Keeping the log from becoming a problem#

A slow log with a low threshold on a busy server grows quickly, and on a 10 or 20 GB volume a forgotten log is a real way to fill the disk. Rotate it:

bash
$ mv /var/lib/mysql/db-slow.log /var/lib/mysql/db-slow.log.1$ mysql -u root -p -e "FLUSH SLOW LOGS;"

FLUSH SLOW LOGS closes and reopens the file, so MySQL starts a fresh one under the original name. On a system with logrotate, a stanza using postrotate with that command does it nightly. Without file access, turn the log off when the investigation is over (SET GLOBAL slow_query_log = OFF) and empty mysql.slow_log if you used the table.

A sensible permanent setting on a small server: slow log on, threshold at one second, log_slow_extra on, log_queries_not_using_indexes off, and a weekly look at mysqldumpslow or the digest view. That costs almost nothing and turns "the site feels slow" into a list. Logs worth keeping and monitoring that tells you something put it alongside the rest of what to collect, and the memory side of a slow server is in InnoDB tuning for small servers.

FAQ#

Does the slow query log slow MySQL down?

Hardly, at a sensible threshold: writing a few hundred entries an hour is nothing. At long_query_time = 0 on a busy server it writes every statement, which costs disk I/O and space, so keep that for short captures. log_output = 'TABLE' is somewhat slower than a file.

I set long_query_time but nothing is logged. Why?

Usually because the application's connections were opened before the change and still carry the old session value. Restart the application or wait for its pool to recycle. Also check that slow_query_log is ON, that min_examined_row_limit is not filtering everything out, and that you are looking at the file named in slow_query_log_file.

Can I log slow queries for one user only?

Not with a per-user setting, but you can change it per session: an application can run SET SESSION long_query_time = 0.2 on its own connections (no special privilege needed for the session value), and a reporting job can set a higher one. Filtering by user afterwards is easy with mysqldumpslow or by the user_host column in mysql.slow_log.

What is a good Rows_examined to Rows_sent ratio?

For lookups and list pages, single digits to low tens. Aggregates are the exception: a SUM over a month of orders legitimately examines many rows to return one. For those, the question is whether a covering index or a summary table could do it with less.

Is the slow query log the same as the general log?

No. The general query log records every statement and every connection, slow or not, and is too heavy to leave on. The slow log records only statements over the threshold, with timing data. Use the general log for minutes at a time when you need to see exactly what an application sends.


Comments

Completely anonymous: no account, no email, no cookie. We store the name you type, the text and the time - nothing else. Links are limited and markup is not rendered.

0/2000