本文來源于數據庫內核專欄。

MySQL慢日志（slow log）是MySQL DBA及其他開發(fā)、運維人員需經常關注的一類信息。使用慢日志可找出執(zhí)行時間較長或未走索引等SQL語句，為進行系統(tǒng)調優(yōu)提供依據。本文結合線上案例分析如何正確設置MySQL慢日志參數和使用慢日志功能，并介紹網易云RDS（InnoSQL）對MySQL慢日志功能增強。
MySQL參數組功能
網易云RDS實例提供了參數組管理功能，可通過參數管理界面查看絕大部分常用的MySQL系統(tǒng)參數，用戶可以了解當前運行值和建議值，如下所示：

用戶還可通過參數管理頁面對所列的參數進行修改，點擊“修改參數”按鈕在線設置，點擊“保存修改”即可一鍵完成MySQL主從節(jié)點的參數修改，如下圖：

查看參數管理界面不難發(fā)現，與慢查詢相關的參數較多，這些參數是如何起作用的呢，相互關系又是如何，滿足什么條件的SQL語句才會記錄到慢日志中？只有了解了這些才能更好地利用慢日志進行系統(tǒng)調優(yōu)和問題定位。我們以一個線上案例為依托來介紹如何正確配置慢日志參數：用戶報告他們使用的多個RDS 5.7版本實例慢日志異常，明明執(zhí)行了一分多鐘的SQL語句，卻沒有記錄到慢日志中。還提供了用于復現的SQL語句。
慢日志參數正確配置姿勢
首先，我們需確認該實例是否開啟了慢日志功能，默認情況下，MySQL慢日志功能是關閉的。慢日志開關參數為slow_query_log，可在mysqld啟動命令行或配置文件中顯式指定，若指定slow_query_log=1或不指定值，則表示開啟慢日志，賦值為0表示關閉。用戶可以在運行時動態(tài)開啟和關閉。網易云RDS實例默認開啟慢日志功能，我們確認了該用戶未關閉實例的慢日志開關。
接下來，需確認慢日志記錄位置，MySQL使用log_output參數指定以文件（FILE）還是表(TABLE)的方式來保存慢日志，需要強調的是，僅指定log_output而將slow_query_log置為0并不會記錄慢日志，也就是說slow_query_log才是慢日志的開關。若使用文件形式記錄慢日志，則可通過slow_query_log_file指定文件名，如果用戶沒有顯式指定slow_query_log_file，則MySQL將其初始化為host_name-slow.log，host_name即為運行mysqld的主機名，慢日志文件默認位于MySQL數據目錄。網易云RDS實例不允許用戶修改日志文件路徑，但可以配置log_output參數，通過查詢，確認該實例以文件方式記錄慢日志，查看日志文件確認沒有用戶所述的SQL語句。
由于用戶提供了復現語句，我們執(zhí)行了其SQL語句，確實1分多鐘才返回，通過explain命令發(fā)現其未走索引，掃描了較多的記錄數，再次查看慢日志仍沒有記錄該SQL語句。MySQL會記錄滿足執(zhí)行時間超過long_query_time秒，掃描記錄數超過min_examined_row_limit行的SQL語句。long_query_time參數最小值和默認值分別為1和10s，該參數可以精確到微秒（ms）。如果選擇將慢日志記錄到文件中，那么所記錄的時間精確到微秒，如果記錄到慢日志表（mysql.slow_log）中，那么僅精確到秒，微秒部分被忽略。網易云RDS實例允許用戶設置這兩個參數值，那么是不是用戶調整了上述兩個閾值，導致無法滿足記錄條件呢，進一步查詢發(fā)現也不是問題原因所在。
我們注意到MySQL還有個名為log_queries_not_using_indexes的參數用于控制是否記錄未走索引的SQL查詢，代碼如下：

重點關注箭頭所指內容，如果查詢未走索引或者索引無效，且相關參數開啟，那么warn_no_index設置為true，若同時滿足掃描記錄數超過閾值，也會像慢查詢一樣被記錄，那么是不是該參數未開呢？結果仍是否定的。
找到問題原因
由于數據庫實例中可能有較多不走索引的SQL語句，若開啟log_queries_not_using_indexes，則存在日志文件或表容量增長過快的風險，此時可通過設置log_throttle_queries_not_using_indexes來限制每分鐘寫入慢日志中的不走索引的SQL語句個數，該參數默認為0，表示不開啟，也就是說不對寫入SQL語句條數進行控制。啟用后，系統(tǒng)會在第一條不走索引的查詢執(zhí)行后開啟一個60s的窗口，在該窗口內，僅記錄最多l(xiāng)og_throttle_queries_not_using_indexes條SQL語句。超出部分將被抑制，在時間窗結束時，會打印該窗口內被抑制的慢查詢條數以及這些慢查詢一共花費的時間。下一個統(tǒng)計時間窗并不是馬上創(chuàng)建，而是在下一條不走索引的查詢執(zhí)行后開啟。對應到該線上問題，log_throttle_queries_not_using_indexes被設置為10，在日志文件中看到周期性打印了如下內容：

確實符合上面描述的現象，用戶的慢日志應該是被抑制了，匯總到了359里面去。我們嘗試將log_throttle_queries_not_using_indexes設置為0，再執(zhí)行對應的SQL語句，果然在日志文件中記錄了相應的SQL語句。這個線上問題似乎已經定位到了，就是系統(tǒng)產生的不走索引的慢日志太多，而設置的log_throttle_queries_not_using_indexes太小，導致無法正常記錄用戶未走索引的慢日志。但還有一個疑惑點沒有解決，那就是log_throttle_queries_not_using_indexes為0時，每分鐘并沒有打印超過10條慢日志，更沒有throttle提示的359條這么多，那么設置為10的時候用戶提供的那條SQL語句應該被記錄到慢日志中才對啊，為何沒有記錄，原因何在？其實，仔細看下MySQL記錄不走索引的日志的代碼邏輯可以找到答案：

上圖是記錄慢日志的主邏輯，是否記錄日志由函數log_slow_applicable控制，該函數先前已分析了一部分，我們進一步看該函數的其他相關內容，見下圖紅框：

suppress_logging是個決定性的變量，只有它為false，該SQL語句才可能被記錄。其結果就跟log_throttle_queries_not_using_indexes相關，我們進一步看下log_throttle_qni.log相關實現，如下圖：

eligible即為warn_no_index，inc_log_count()函數在1分鐘內不走索引的語句總數超過log_throttle_queries_not_using_indexes時返回值為true，只有warn_no_index和inc_log_count()返回值都為true，suppress_current才為true，而suppress_current即為suppress_logging。
通過對上述2個截圖內容進行分析，可以解答之前的疑惑點：log_throttle_queries_not_using_indexes統(tǒng)計的是所有不走索引的語句，其中有些語句因為不滿足掃描記錄數的約束而不會記錄到慢日志中，這就是為什么該值為10的時候，慢日志文件中并沒有10條記錄。因為這10條中有8條SQL語句由于掃描記錄數太少并沒有被記錄。

這也解惑了上圖中359這個數字，它這個時間窗內不走索引的SQL語句總數。所以，log_throttle_queries_not_using_indexes是個很關鍵的參數，設置不當會無法正常記錄不走索引的慢查詢，導致慢日志功能部分失效。
InnoSQL慢日志功能增強
還有部分RDS實例用戶問我們，為什么我的SQL語句執(zhí)行時間沒有超過所設置的long_query_time，而且走了索引，但還是被記錄到慢日志中，是不是出Bug了？其實這不是Bug，而是因為網易云RDS使用的InnoSQL（網易維護的MySQL開源分支）版本對慢日志做了優(yōu)化，除了考察SQL語句的執(zhí)行時間外，還關注該查詢所需的磁盤頁面（Disk Page）數，因為所需的頁面數目過多，也可能會對系統(tǒng)負載造成較大影響。為了能夠量化統(tǒng)計，我們收集了SQL查詢所需讀取的總頁面數和這些頁面中實際進行IO的次數，分別記錄為logical_reads和physical_reads，前者包括命中InnoDB Buffer Pool和未命中需要進行IO的頁面請求。通過引入slow_query_type和long_query_io兩個參數為用戶提供該功能。前者可設置為0/1/2/3。1表示啟用基于執(zhí)行時間來記錄慢日志，2表示基于搜索總頁面數來記錄慢日志，3是1和2的合集。所以在InnoSQL中，SQL查詢只需滿足執(zhí)行時間夠長或所需總頁面數夠多即可記錄到慢日志中。代碼實現片段如下：

頁面數閾值通過long_query_io參數來衡量，用戶可動態(tài)設置，如果總頁面數m_logical_reads超過了該值，即使執(zhí)行時間未超標，也會被記錄。相應的，RDS實例慢日志表結構和慢日志文件輸出內容也增加了新的字段。

上圖即為InnoSQL版的slow_log表結構，其中，logical_reads和physical_reads為InnoSQL增加字段。同樣的，慢日志文件的輸出內容也增加了兩個字段，如下所示：

除了以上詳細描述的內容外，MySQL慢日志模塊還有如下幾個特性值得關注：

1. 進行慢日志統(tǒng)計及慢日志中所記錄的時間并不包括該SQL語句開始執(zhí)行前獲取鎖所需等待的時間；
2. MySQL在SQL語句執(zhí)行完且所持有的鎖均已釋放后才將其寫入慢日志中，所以慢日志中的SQL語句記錄順序并不能準確反映這些SQL語句的實際執(zhí)行順序；
3. 每條慢日志都包含一個時間戳，若寫入文件中，log_timestamps 參數用于將慢日志時間戳轉化為指定時區(qū)的時間。但該參數對于mysql.slow_log表中的慢日志不起作用；
4. 可通過設置log_slow_slave_statements來開啟MySQL從庫的慢日志功能；
5. ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE等表管理操作也能夠被記錄到慢日志中，可通過log_slow_admin_statements選項開啟。

網易云數據庫RDS是一種穩(wěn)定可靠、可彈性伸縮的在線關系型數據庫服務，當前支持MySQL引擎，提供基礎版，高可用版，金融版針對不同業(yè)務場景的高可用解決方案，同時提供多重安全防護措施，性能監(jiān)控體系，專業(yè)的數據庫備份、恢復及優(yōu)化方案，使您能專注于應用開發(fā)和業(yè)務發(fā)展。

本文來源于數據庫內核專欄。由作者溫正湖授權發(fā)布

原文：MySQL慢日志線上問題分析及功能優(yōu)化

了解 網易云 ：

網易云官網：https://www.163yun.com

新用戶大禮包：https://www.163yun.com/gift

總結

以上是生活随笔為你收集整理的MySQL慢日志线上问题分析及功能优化的全部內容，希望文章能夠幫你解決所遇到的問題。

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