5.3 Identifying Slow Queries
Figuring out which
queries are slow is usually easier than figuring out
why they're slow and making the
necessary changes to fix them. The easiest way to track them is to
let MySQL do some of the work for you. By enabling the
slow query log, you instruct MySQL to log every query that
takes longer than a specified number of seconds. In addition to the
query, it also logs some other metadata.Here's an example record from a slow query log:
# Time: 030303 0:51:27
# User@Host: user[user] @ client.example.com [192.168.50.12]
# Query_time: 25 Lock_time: 0 Rows_sent: 3949 Rows_examined: 378036
select ArticleHtmlFiles.SourceTag, ArticleHtmlFiles.AuxId from ArticleHtmlFiles left
join Headlines on ArticleHtmlFiles.SourceTag = Headlines.SourceTag and
ArticleHtmlFiles.AuxId = Headlines.AuxId where Headlines.AuxId is NULL;
While the log contains a lot of useful information,
there's one very important bit of information
missing: an idea of why the query was slow.
Sure, if the log says 12,000,000 rows were examined and 1,200,000
sent to the client, you know why it was slow. But things are rarely
that clear cut. Worse yet, you may find a slow query, paste it into
your favorite MySQL client, and find that it executes in a fraction
of a second.You must be careful not to read too much information into the slow
query log. When a query appears in the log, it
doesn't mean that it's a bad
queryor even a slow one. It simply means that the query took a
long time then. It doesn't mean
that the query will take a long time now or in the future.There are any number of reasons why a query may be slow at one time
but not at others:A table may have been locked, causing the query to wait. The
Lock_time indicates how long the query waited for
locks to be released.None of the data or indexes may have been cached in memory yet. This
is common when MySQL is first started or hasn't been
well tuned. Chapter 4 covers this in more
detail.A nightly backup process was running, making all disk I/O
considerably slower.The server may have been handling hundreds of other unrelated queries
at that same time, and there simply wasn't enough
CPU power to do the job efficiently.
The list could go on. The bottom line is this: the slow query log is
nothing more than a partial record of what happened. You can use it
to generate a list of possible suspects, but you really need to
investigate each of them in more depth. Of course, if you happen to
see the same query appearing in the log over and over,
there's a very good chance you have a slow query on
your hands.MySQL also comes with
mysqldumpslow,
a Perl script that can summarize the slow query log and provide a
better idea of how often each slower query executes. That way you
don't waste time trying to optimize a 30-second slow
query that runs once a day, while there are five other 2-second slow
queries that run thousands of time per day.Appendix B contains information on using
mytop to perform real-time query monitoring,
including slow queries.