• Call A Developer Google+
  • Like Us on Facebook
  • @calladeveloper on Twitter
  • Subscribe to our Blog
  • Skype: calladeveloper
  • Call us on Gtalk

Thursday, March 28, 2013

HowTo: Read the MySQL Slow Query Log

How to read the MySQL Slow Query Log

If you followed along with the first post in our MySQL Optimization Series, you learned how to enable slow query logging on mysql and should have that turned on. (If not go ahead and follow the steps in that article now). Today we're going to take a look at how to read the slow query log and see what we can do with this data.

Go ahead and tail your slow query log and make sure you have at least one slow query in there. If you don't you can make one:

root@server# mysql -e 'SELECT SLEEP(8);'

All the above query will do is "sleep" (do nothing) for 8 seconds. This should be long enough to be logged in your slow query log (I usually recommend logging queries taking longer than 2 or 3 seconds)

First let's check out what a slow query log entry looks like:

root@server# tail /var/log/slowqueries
# Time: 130320  7:30:26
# User@Host: 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 go over what each line means:

  • The first line shows the time the query was logged. The format is YYMMDD H:M:S. We can see the query above was logged at 2013 March 20th at 7:30am - NOTE: This is server time, which may be different from your local time
  • Next, we'll see the MySQL user, database, and hostname
  • The third line shows the total query time, the Lock time, the number of Rows "sent" or returned, and the number of rows examined during the query.
  • Below that you'll see SET timestamp=UNIXTIME; < this is the time the query actually happened. It is good to check that you're not looking at a problem that happened months ago if you're trying to figure out why something is slow right now. I'll explain how to turn that into a usable time below
  • The final line shows the full query.

To get a human-readable timestamp from the Unix Epoch, you can use the date -d command, type date -d @ (including the @ sign) and paste the timestamp from the log immediately after the @ (no space):

root@server# date -d @1363779026
Wed Mar 20 07:30:26 EDT 2013

In this case we can see the query was run and logged at the same time - on an overloaded server that may not always be the case. So remember that the SET timestamp= value is when the actual query was run.

Now I'm going to show you how I solved a real problem on one of my websites using the mysql slow query log. Your query is going to be different, but the information is the same.

how to read mysql slow query log

I am using a plugin called Tweet Blender on a Wordpress blog (different site) to automatically display relevant tweets to my keywords. Unfortunately someone either realized that or just happened to spam Twitter with one of my keywords in the tweet or username - either way, the end result was that I was displaying Twitter spam on my site. Because tweets only stay on there for a short time, this was not something I noticed on the actual site. But when I looked in my slow query log, it was obvious.

I had several very similar queries showing a tweet with spammy text (always the same) and after a while the number of queries caused some of them to run slow. Most people would have likely had their sites suspended or getting errors if this happened because it was a fairly large number of requests, but my server is well tuned for performance, so there was no noticeable effect. Luckily I am logging slow queries so I was able to see this information and quickly determine the issue.

Fixing it was simple - Tweet Blender has awesome filtering features so I just added that Twitter username to my "exclude" list (along with several more spam keywords) and it hasn't been an issue since. It does show how useful it is to monitor your sites and logs, even if it's just a quick check once a week on each site / server.

And that is how you read the slow query log in MySQL. Simple and useful, right?

If you want help making mysql faster, Call A Developer.

Further Reading:

21 comments:

  1. This comment has been removed by the author.

    ReplyDelete
  2. nice blog and very informative and now i would like to share something. With the help of wordpress plugin developer we can get developed superb wordpress website at affordable cost.

    ReplyDelete
  3. I have a point which i don't understand clearly.
    # Time: 130320 7:30:26
    >The first line shows the time the query was logged.
    This is the time:
    - Query begin to execute
    Or query execute finishing?
    Thank

    ReplyDelete
  4. Thank you for your clear explanation. You can develop Digital Marketing Company in Chennai with our industry experts best training

    ReplyDelete
  5. This comment has been removed by the author.

    ReplyDelete
  6. Hi,

    Thanks for sharing a very interesting article about HowTo: Read the MySQL Slow Query Log. This is very useful information for online blog review readers. Keep it up such a great article like this.

    Regards,
    WondersMind,
    Web Design Company Bangalore

    ReplyDelete
  7. An architect would regularly give 3 or 4 ideas to you to browse to grow further. Ideally at this stage you will have a course that your are sensibly content with. Try not to be apprehensive at this phase to voice your assessment about whats working and whats not. logo design service

    ReplyDelete
  8. Thank you for sharing your opinion on this topic, This blog is very beneficial for those who has very little knowledge about this topic. I always read your blog and shared with my friends. You are a great writer.
    Sports Betting Software Development

    ReplyDelete

  9. Pro Cochin House Shifting and Moving Packers predominantly focus on the safe transportation of your goods through the safe hands & at the right place with no hassles. ( Best House Shifting Services in Kochi, House Shifting in Ernakulam ) We have originated since 2014 and since then, we focus on the motto “Reliable Delivery through us”. To manifest our work & safeguard the assurance, we the Pro Cochin House Shifting and Moving Packers mainly concentrate on the highest quality packing with fast & reliable delivery at your doorstep in & around Kerala. ( House Shifting in Edappally, and House Shifting in Thrippunithura ) We provide premier packing with no point of worries right from the packing till the delivery. We trust & protect the concerns of our customers. ( House Shifting in Kakkanad, and House Shifting in Kalamassery )

    ReplyDelete
  10. Nice blog. It is very helpful.
    We are helping eCommerce businesses by increasing their customer reach and growing revenue through the optimal combination tools, and user-centric solutions. Being India’s leading eCommerce software development company, we help B2B & B2C clients drive their customers’ satisfaction, expand their right potential audiences and boost sales upto 100%.
    Ecommerce development Company


    ReplyDelete
  11. awesome !!! it is very helpful blog .thank you for sharing this blog. IT OUTSOURCING



    ReplyDelete
  12. Really I enjoy your site with effective and useful information. It is included very nice post with a lot of our resources.thanks for share. i enjoy this post.
    Microsoft Dynamics CRM Support
    Microsoft Dynamics CRM Training
    Microsoft Dynamics CRM Migration
    Microsoft Dynamics Development & Customization
    Microsoft Dynamics CRM Integration

    ReplyDelete
  13. By reading your blog i got very useful information... Many blog I come across these days really not provide anything that attracts others, but believe me the way you interact is literally awesome.Thanks for this information.
    FINANCIALFORCE SUPPORT SERVICES
    FINANCIALFORCE ACCOUNTING SERVICES
    FINANCIALFORCE ERP SERVICES
    FINANCIALFORCE IMPLEMENTATION SERVICES

    ReplyDelete