5 min read

How I Find Slow MySQL Queries Before Users Start Complaining

Rows of blinking servers in a data center rack, somewhere in there a query is scanning two million rows

Last month a support ticket landed on a Monday morning: the admin dashboard took eleven seconds to load. MySQL was sitting at 40% CPU, traffic looked normal, and nothing in the app logs pointed anywhere. A year ago I would have spent the afternoon guessing. Now I run a short workflow instead, and it found the culprit in about twenty minutes.

The tools matter less than the sequence: capture the queries, rank them by how much total damage they do, and only then dig into what the database actually did with them. Here is the whole thing.

Start with the slow query log

MySQL's slow query log is off by default, and the default threshold is ten seconds. Ten seconds. A query taking nine and a half never gets logged, and your users have already left by then. So the first job is turning the threshold down to something a web app can live with:

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

This takes effect immediately, no restart needed. One detail that bit me once: SET GLOBAL only applies to new connections. Existing pooled connections keep the old threshold until they reconnect, so if nothing shows up right away, that may be why.

To survive a restart, put it in my.cnf:

[mysqld]
slow_query_log = 1
long_query_time = 0.5
slow_query_log_file = /var/log/mysql/slow.log

There is also log_queries_not_using_indexes. I leave it off on busy servers. It sounds useful, but on a database with lots of small lookup tables it will log half your traffic and fill the disk. If you do turn it on, pair it with min_examined_row_limit so tiny queries stay quiet.

Rank by total time, not by scariest single run

The raw log is unreadable, and reading it top to bottom is a trap. The slowest single query is rarely your biggest problem. A 300ms query that runs four hundred times an hour does far more damage than a 4-second report someone runs once a day. Sort by total time:

mysqldumpslow -s t -t 10 /var/log/mysql/slow.log

mysqldumpslow ships with MySQL and groups similar queries together. If you want richer output, pt-query-digest from Percona Toolkit is the upgrade. Honestly, either is fine. The point is the ranking, not the tool.

Our Monday culprit had exactly this shape. Not the 4-second monster at the top of the file, but a 280ms query that appeared 1,900 times in one hour.

Then ask the database what it actually did

Plain EXPLAIN shows the plan the optimizer expects. Estimates. Useful, but I have been burned by estimates enough times that I don't trust them alone. Since MySQL 8.0.18 there is EXPLAIN ANALYZE, which runs the query and reports real timings and real row counts:

EXPLAIN ANALYZE
SELECT * FROM orders
WHERE customer_id = 12345 AND status = 'pending'
ORDER BY created_at DESC LIMIT 20;
-> Limit: 20 row(s)  (actual time=1839.3..1839.4 rows=20 loops=1)
    -> Sort: orders.created_at DESC, limit input to 20 row(s)  (actual time=1839.2..1839.3 rows=20 loops=1)
        -> Filter: (orders.status = 'pending')  (actual time=0.11..1795.0 rows=64321 loops=1)
            -> Index lookup on orders using idx_customer_id (customer_id=12345)  (actual time=0.08..1721.4 rows=198455 loops=1)

Read the tree bottom up. The two things I check first: where actual time balloons, and where the actual row count is wildly different from the optimizer's estimate. In this output, the index lookup touches 198,000 rows to answer a question about one customer. That is the whole story of the query, right there.

One warning worth shouting: EXPLAIN ANALYZE actually executes the statement. Fine for SELECTs. Do not point it at an UPDATE or DELETE in production, because your "diagnostic" will modify real data.

The fix is usually an index, then you prove it

For the query above, the existing index only covered customer_id, so MySQL fetched every order for that customer and then sorted and filtered in memory. A composite index that matches the WHERE clause and the ORDER BY fixed it:

CREATE INDEX idx_customer_status_created
  ON orders (customer_id, status, created_at);

Same EXPLAIN ANALYZE afterward, and actual time dropped from 1.8 seconds to 0.4 milliseconds. The rule of thumb for column order: equality columns first, the sort column last. I wrote up the full indexing patterns in my post on MySQL indexing, so I won't repeat them here.

Last thing. I keep the setup commands and the config flags I always forget in Snippet Ark, because at 9am on a bad Monday I don't want to be looking up syntax. The workflow itself is short enough to memorize: log, rank, analyze, fix, verify. It hasn't failed me yet.