The slow query log with long_query_time set to zero

A slow query log at the usual one-second threshold shows the report that takes four seconds and hides the nine hundred queries of eight milliseconds that the product page issues on every request. The second is more often the actual problem, and the only way to see it is to lower the threshold to zero for a few minutes.

SET GLOBAL slow_query_log      = 1;
SET GLOBAL slow_query_log_file = '/var/log/mysql/profile.log';
SET GLOBAL long_query_time     = 0;   -- log everything

-- exercise the pages, then put it back
SET GLOBAL long_query_time     = 1;

-- sort by count, not by time
-- mysqldumpslow -s c -t 20 /var/log/mysql/profile.log

Sorting mysqldumpslow by count rather than by total time is the half people skip, and it is what makes an N+1 visible: four hundred executions of the same normalised statement is a loop in the application, not a query to optimise. Two things to know before running it. long_query_time is a session variable with a global default, so connections that are already open keep the value they had when they connected — behind a persistent pool, setting the global changes nothing until the pool recycles. And at zero the file grows by megabytes a minute on a busy server, so this is a window of a few minutes with a timer set, not a configuration change.