Confirming what you already know, for future reference:
"The time to acquire the initial locks is not counted as execution time."
— http://dev.mysql.com/doc/refman/5.6/en/slow-query-log.html
It stands to reason, at least to me, that a "slow query" is best defined as a query that is poorly-optimized and takes longer than it should even when run in isolation. It follows from that, that queries which only coincidentally take a long time to run because of circumstances unrelated to the query itself -- such as waiting for table locks -- should not be included in the slow query log.
I base this on two things: intuition, since the slow query log can also "log_queries_not_using_indexes" -- which is presumably also intended to catch bad optimization before the data set grows to the point that the queries actually turn into "slow" queries... and the fact that it doesn't seem to have been designed that way just because it was easier to implement or for any architectural limitation.
In sql/sql_class.h
:
void update_server_status()
{
ulonglong end_utime_of_query= current_utime();
if (end_utime_of_query > utime_after_lock + variables.long_query_time)
server_status|= SERVER_QUERY_WAS_SLOW;
}
If utime_after_lock
were replaced with start_utime
... that should drive the behavior you are expecting. YMMV, but that's what it looks like from here, from a brief look into the source code.
Alternately, you could write a script in your favorite language to hold a connection to the server and execute SHOW PROCESSLIST
every "n" seconds. The script would "remember" what each thread's Time
value was from iteration to iteration, and could report execution times to you with the granularity of the polling interval when it found interesting patterns. When it sees an interesting query, it could switch to SHOW FULL PROCESSLIST
to get the entire body of the query.
I would poll my servers for their processlist (not "full") at 1 second intervals -- yes, in production -- and display the number of threads and the current longest-running query on my real-time status dashboard and have never seen evidence of an ill-effect from this.