Let's take a look at how to read these slow query logs.
Before you trace a slow query log, you must first ensure that you have a slow query at least once. If you are not able to make one yourself:
[Email protected]# mysql-e ' SELECT SLEEP (8);
There's only one thing you can do with this: "Sleep" (do nothing) for eight seconds. This length should be enough to be recorded in your slow query log (I usually recommend slow query logging for queries longer than 2 or 3 seconds).
First, let's look at what a slow query log entry looks like:
[Email protected]# tail/var/log/slowqueries
# time:130320 7:30:26
# [email protected]: db_user[db_database] @ localhost []
# query_time:4.545309 lock_time:0.000069 rows_sent:219 rows_examined:254
SET timestamp=1363779026;
SELECT option_name, option_value from wp_options WHERE autoload = ' yes ';
Let's take a look at what each line means:
- The first line represents the time when the log was logged. The format is YYMMDD h:m:s. We can see the above query recorded on March 20, 2013 7:30-Note: This is the server time, may be different from your local time
- We can then see the MYSQL user, server, and host name
- The third row represents the total query time, the lock time, the number of rows to send, or the row to return, and the number of rows checked during the query
- The next thing we see is SET timestamp=unixtime, which is the time the query actually occurred. If you want to find some slow queries now, by checking this it will not happen what you are checking is a slow query that happened a few months ago. I'll show you how to turn it into a useful time.
- The last line shows the complete query statement
To turn Unix time into a human-readable time, you can use the date-d command. Enter date-d @ (remember to include the @ symbol), and then paste the timestamp in the log after @ (no spaces between them):
[Email protected]# date-d @1363779026
Wed Mar 07:30:26 EDT 2013
In the example above, we can see that the log is logged while the query is in progress-but it is often not the case for a server that is overloaded. So remember:SET timestamp= value is the execution time of the actual query.
Now let me show you how I use the MySql slow query log to solve a real problem on one of my sites. Your query may not be the same as this, but the principle of solving the problem is interlinked.
I used a plugin called Tweet Blender on a blog site to automatically display the relevant tweets into my keywords. Unfortunately, some people found this and used the keywords in my microblog to send some spam tweets-anyway, the end result is that some spam tweets appear on my blog site. I didn't find any problem on my website until I looked at the slow query log because it wasn't long on my website.
My site has several similar queries for microblogs with spam (often the same spam), and after a period of time these queries are so large that some of them are running slowly. When this happens, because the number of requests is very large, some friends of the site is likely to be suspended animation or direct error, but my server has been very good performance tuning, so there is no obvious impact. Fortunately, I was in the slow query log to see the situation in time and quickly resolved the problem.
The solution to this problem is simple-Tweet Blender has a nice filtering feature, I just add the microblog username and some spam keywords to the "exclude" list, and then there's no such problem anymore. That's how important it is to monitor our own sites and logs, even if it's a one-time-per-week check for each site/server.
Read MySQL slow query log