MySQL慢查詢日誌釋疑總結
之前寫了一篇 “ ofollow,noindex">SQL/">MySQL慢查詢日誌總結 “ ，總結了一些MySQL慢查詢日誌常用的相關知識，這裡總結一下在工作當中遇到關於MySQL慢查詢日誌的相關細節問題，有些是釋疑或自己有疑惑，自己測試驗證、解惑方面的知識。此篇只是總結個人的一些經驗，不足之處，敬請指正！
1： 為什麼在慢查詢日誌裡面出現Query_time小於long_query_time閥值的SQL語句呢？
例如，如下截圖，long_query_time=5， 但是Query_time小於1秒的SQL都記錄到慢查詢日誌當中了。
相信有些人遇到這個問題的時候覺得很奇怪，其實這個不是bug，而是你設定了系統變數log_queries_not_using_indexes ,這個系統變數開啟後，
會將那些未使用索引的SQL也被記錄到慢查詢日誌中，另外，full index scan的SQL也會被記錄到慢查詢日誌。所以，當滿足這些條件的SQL，即
使Query_time時間小於long_query_time的值，也會被記錄到慢查詢日誌。
2： 使用日誌分析工具mysqldumpslow分析有些日誌非常慢，如何加快？
mysqldumpslow -s t -t 10 /var/lib/mysql/MyDB-slow.log
1: 出現這種情況是因為慢查詢日誌變得很大（個人遇到的案例，慢查詢日誌就有2G多了），所以，需要每天或每週切分慢查詢日誌。設定一個Crontab作業即可。
/var/lib/mysql/DB-Server-slow.log.20181112
/var/lib/mysql/DB-Server-slow.log.20181113
/var/lib/mysql/DB-Server-slow.log.20181114
/var/lib/mysql/DB-Server-slow.log.20181115
2: 開啟了系統變數log_queries_not_using_indexes後，如果系統設計糟糕，未使用索引的SQL很多，那麼這一類的日誌可能會有很多，所以還有個特別的開關log_throttle_queries_not_using_indexes用於限制每分鐘輸出未使用索引的日誌數量。
3：mysqldumpslow的生成報告中的Count、 Time、 Lock、Rows代表具體意思。
mysqldumpslow -s c -t 10 /var/lib/mysql/MyDB-slow.log 使用mysqldumpslow分析慢查詢日誌分析獲取訪問次數最多的10個SQL。
Count ： 表示這個SQL總共執行了195674次（慢查詢日誌中出現的次數）
Time 表示執行時間，後面括號裡面的38s 表示這個SQL語句累計的執行耗費時間為38秒。其實就是單次執行的時間和總共執行消耗的時間的區別。
Lock 表示鎖定時間，後面括號裡面表示這些SQL累計的鎖定時間為48s
Rows 表示返回的記錄數，括號裡面表示所有SQL語句累計返回記錄數
然後我們看看慢查詢日誌的相關資訊：
# Time: 2018-11-15T01:43:51.338167Z
這個表示日誌記錄的時間，確切的說是SQL執行完的時間點。注意這個時間有可能跟系統當前時間不一致，它可能是UTC時間。這個要看系統變數log_timestamps是UTC還是system。
mysql> show variables like 'log_timestamps'; +----------------+-------+ | Variable_name | Value | +----------------+-------+ | log_timestamps | UTC | +----------------+-------+ 1 row in set (0.01 sec) mysql> set global log_timestamps=system; Query OK, 0 rows affected (0.00 sec)
# User@Host: xxx[xxx] @ [xxx.xxx.xxx.xxx] Id: 23781
客戶端的賬戶資訊，兩個使用者名稱（第一個是授權賬戶，第二個為登入賬戶），客戶端IP地址，還有mysqld的執行緒ID。
# Query_time: 16.480118 Lock_time: 0.000239 Rows_sent: 1 Rows_examined: 348011
查詢執行的資訊，包括查詢時長，鎖持有時長，返回客戶端的行數，優化器掃描行數。通常需要優化的就是最後一個內容，儘量減少SQL語句掃描的資料行數
#use xxx;
#SET timestamp=1542246231;
這個是時間戳，你可以將其轉換為時間格式（注意時區），如下所示：
[root@mylnx02 ~]# date -d @1542246231
Thu Nov 15 09:43:51 CST 2018
[root@DB-Server ~]# date -d @1542246231
Wed Nov 14 20:43:51 EST 2018
4： 如何分析慢查詢日誌一段時間內的資料呢？
mysqldumpslow這款工具沒有提供相關引數分析某個日期範圍內的慢查詢日誌，也就是說沒法提供精細的搜尋、分析。如果要分析某段時間內的慢查詢日誌可以使用工具pt-query-digest
如果實在需要使用mysqldumpslow分析某段時間內的慢查詢SQL，可以藉助awk命令的幫助。如下樣例所示
#取出一天時間的慢查詢日誌
# awk '/# Time: 2018-11-14/,/# Time: 2018-11-15/' DB-Server-slow.log > DB-Server-slow.log.20181114
#取出2018-11-14號4點到6點之間兩個小時的資料
#awk '/# Time: 2018-11-14T04/,/# Time: 2018-11-14T06/' DB-Server-slow.log > slow_04_06.log
5： 關於慢查詢日誌中query_time和lock_time的關係。
只有當一個SQL的執行時間（ 不包括鎖等待的時間 lock_time ）>long_query_time的時候，才會判定為慢查詢SQL；但是判定為慢查詢SQL之後，輸出的Query_time包括了（執行時間+鎖等待時間），並且也會輸出Lock_time時間。當一個SQL的執行時間（排除lock_time）小於long_query_time的時候（即使他鎖等待超過了很久），也不會記錄到慢查詢日誌當中的。
6: mysqldumpslow相關引數的詳細資訊
# mysqldumpslow --help Usage: mysqldumpslow [ OPTS... ] [ LOGS... ] Parse and summarize the MySQL slow query log. Options are --verbose verbose #顯示詳細資訊 --debug debug #除錯模式下執行。 --help write this text to standard output -v verbose #顯示詳細資訊 -d debug #除錯模式下執行。 -s ORDER what to sort by (al, at, ar, c, l, r, t), 'at' is default 排序方式，at是預設方式 al: average lock time #平均鎖定時間排序 ar: average rows sent #平均傳送行數排序 at: average query time #平均查詢時間排序 c: count #執行次數排序 l: lock time #鎖定時間排序 r: rows sent #總結果行數排序 t: query time #總查詢時間排序 -r reverse the sort order (largest last instead of first) #倒序資訊排序 -t NUM just show the top n queries #只顯示前n個查詢 -a don't abstract all numbers to N and strings to 'S' -n NUM abstract numbers with at least n digits within names -g PATTERN grep: only consider stmts that include this string #根據字串篩選慢查詢日誌 -h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard), default is '*', i.e. match all #根據伺服器名稱選擇慢查詢日誌 -i NAME name of server instance (if using mysql.server startup script) #根據伺服器MySQL例項名稱選擇慢查詢日誌。 -l don't subtract lock time from total time #不要從總時間減去鎖定時間
7: 系統變數 Slow_queries 會統計慢查詢出現的次數。
mysql> show global status like '%slow%'; +---------------------+--------+ | Variable_name | Value | +---------------------+--------+ | Slow_launch_threads | 0 | | Slow_queries | 120 | +---------------------+--------+
8：系統變數slow_launch_time 是什麼？ 跟慢查詢日誌有關係嗎？
如果建立執行緒需要的時間比slow_launch_time多，伺服器會增加Slow_launch_threads的狀態變數的數量。其實這個狀態變數跟慢查詢沒有什麼關係。之所以放到這裡，是有人問過這個問題！
參考資料：