學會讀懂 MySql 的慢查詢日誌，讀懂mysql查詢日誌

學會讀懂 MySql 的慢查詢日誌，讀懂mysql查詢日誌
在前邊的部落格《何時、如何開啟 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。