在前邊的博客《 何時、如何開啟 MySql 日志？》中，我們了解到了如何啟用 MySql 的慢查詢日志。今天我們來看一下如何去讀懂這些慢查詢日志。
在跟蹤慢查詢日志之前，首先你得保證最少發生過一次慢查詢。如果你沒有可以自己制造一個：
root@server# mysql -e 'SELECT SLEEP(8);
上述操作所做的事情只有一個："睡"(啥也不做)八秒。這個長度應該足以被記錄在你的慢查詢日志里了(我通常推薦針對長于 2 或 3 秒的查詢進行慢查詢記錄)。
首先，我們看看一個慢速查詢日志條目是什么樣子的：
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';
我們來過一下每一行所代表的意思：

• 第一行表示記錄日志時的時間。其格式是 YYMMDD H:M:S。我們可以看出上面的查詢記錄于 2013 年 3 月 20 日上午 7:30 - 注意：這個是服務器時間，可能跟你本地時間有所不同
• 然后，我們可以看到 MySql 用戶、服務器以及主機名
• 第三行表示總的查詢時間、鎖定時間、"發送"或者返回的行數、查詢過程中所檢查的行數
• 接下來我們看到的是 SET timestamp=UNIXTIME; 這是查詢實際發生的時間。如果你想找現在的一些慢查詢，通過檢查這個就不會發生你所檢查的是幾個月之前所發生的慢查詢了。下邊我會介紹如何將其變成一個有用的時間
• 最后一行顯示完整的查詢語句

要將 Unix 時間轉成一個人類可讀的時間，可以使用 date -d 命令。輸入 date -d @(記得要包括 @ 符號)，然后在 @(之間沒有空格)后粘貼日志中的時間戳：
root@server# date -d @1363779026
Wed Mar 20 07:30:26 EDT 2013
上面例子中我們可以看到查詢進行的同時記錄了該日志 - 但是對于一臺超負載的服務器常常并非如此。因此記住： SET timestamp= value 才是實際的查詢的執行時間。

現在我來演示一下我是如何使用 MySql 慢查詢日志來解決我的某個網站上的一個真實問題的。你的查詢可能與此不太一樣，但是解決問題的原理是相通的。

我在一個博客網站上使用了一個名為 Tweet Blender 的插件來自動顯示相關微博到我的關鍵字中。不幸的是，一些人發現了這個并使用我的微博中的關鍵字來發一些垃圾微博 - 不管怎樣，最終結果就是我的博客網站上顯示的是一些垃圾微博。因為相關微博在我的網站存在的時間并不長，所以我在網站上并沒有發現什么問題，直到我查看慢查詢日志。
我的網站對帶有垃圾信息(垃圾信息常常都是一樣的)的微博進行了幾個類似的查詢，經過一段時間后這些查詢的數量太大以致其中的一些運行遲緩。當這種情況發生的時候，由于請求的數量非常大，有些朋友的網站很可能會因此假死或者直接報錯，但是我的服務器經過很好的性能調優，因此并沒有很明顯的影響。幸運的是當時我正在進行慢查詢日志查看，及時發現了這一情況并迅速解決了這個問題。
這個問題的解決很簡單 - Tweet Blender 具備一個漂亮的過濾功能，我只需將該微博用戶名以及一些垃圾關鍵字添加到 "exclude" 列表，之后就再也沒有這種問題了。這樣看來，對我們自己網站以及日志的監控是多么重要，即使是一星期對每個站點/服務器只進行一次快速檢查。
原文鏈接： http://calladeveloper.blogspot.com/2013/03/howto-read-mysql-slow-query-log.html。

總結

以上是生活随笔為你收集整理的学会读懂 MySql 的慢查询日志的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。