圖文結合帶你搞懂MySQL日志之Slow Query Log（慢查詢日志）

• GreatSQL社區原創內容未經授權不得隨意使用，轉載請聯系小編并注明來源，
• GreatSQL是MySQL的國產分支版本，使用上與MySQL一致，
• 作者：KAiTO
• 文章來源：GreatSQL社區原創

什么是慢查詢日志

MySQL 的慢查詢日志，用來記錄在 MySQL 中回應時間超過閥值的陳述句，具體指運行時間超過 long_query_time 值的SQL，則會被記錄到慢查詢日志中，long_query_time 的默認值為10，意思是運行10秒以上(不含10秒)的陳述句，認為是超出了我們的最大忍耐時間值，

它的主要作用是，幫助我們發現那些執行時間特別長的SQL查詢，并且有針對性地進行優化，從而提高系統的整體效率，當我們的資料庫服務器發生阻塞、運行變慢的時候，檢查一下慢查詢日志，找到那些慢查詢，對解決問題很有幫助，比如一條sq|執行超過5秒鐘，我們就算慢SQL，希望能收集超過5秒的sql，結合explain進行全面分析，

默認情況下，MySQL資料庫沒有開啟慢查詢日志，需要我們手動來設定這個引數，如果不是調優需要的話，一般不建議啟動該引數，因為開啟慢查詢日志會或多或少帶來一定的性能影響

慢查詢日志支持將日志記錄寫入檔案，

如何開啟慢查詢日志

開啟slow_query_log

mysql> show variables like '%slow_query_log%';
+-----------------------------------+--------------------------------+
| Variable_name                     | Value                          |
+-----------------------------------+--------------------------------+
| slow_query_log                    | OFF                            |
| slow_query_log_always_write_time  | 10.000000                      |
| slow_query_log_file               | /var/lib/mysql/KAiTO-slow.log  |
| slow_query_log_use_global_control |                                |
+-----------------------------------+--------------------------------+
4 rows in set (0.00 sec)

# 開啟慢查詢
mysql > set global slow_query_log='ON';
Query OK, 0 rows affected (0.12 sec)

然后我們再來查看下慢查詢日志是否開啟，以及慢查詢日志檔案的位置：

mysql> show variables like '%slow_query_log%';
+-----------------------------------+--------------------------------+
| Variable_name                     | Value                          |
+-----------------------------------+--------------------------------+
| slow_query_log                    | ON                             |
| slow_query_log_always_write_time  | 10.000000                      |
| slow_query_log_file               | /var/lib/mysql/KAiTO-slow.log  |
| slow_query_log_use_global_control |                                |
+-----------------------------------+--------------------------------+
4 rows in set (0.00 sec)

你能看到這時慢查詢分析已經開啟，同時檔案保存在 /var/lib/mysql/KAiTO-slow.log 檔案中，

修改long_query_time閾值

接下來我們來看下慢查詢的時間閾值設定，使用如下命令：

mysql> show variables like '%long_query_time%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)

意思就是超過10秒的SQL陳述句就會被記錄慢查詢日志中，那要如何修改這個閾值呢？

mysql> set global long_query_time = 1;
mysql> show global variables like '%long-query_time%';

或修改 my.cnf 檔案，[mysqld]下增加或修改引數long_query_time、slow_query_log和slow_query_log_file后，然后重啟MySQL服務器，

[mysqld]
slow_query_log=ON #開啟慢查詢日志的開關
slow_query_log_file=/var/lib/mysql/my-slow.log #慢查詢日志的目錄和檔案名資訊
long_query_time=3 #設定慢查詢的閾值為3秒，超出此設定值的SQL即被記錄到慢查詢日志
log_output=FILE # 一般有兩種形式，一種是輸出到檔案FILE中，一種是寫入資料表格table中，會保存到mysql庫的slow_log表中

如果不指定存盤路徑，慢查詢日志將默認存盤到 MySQL 資料庫的資料檔案夾下，如果不指定檔案名，默認檔案名為hostname-slow.log，

補充

• min_examined_row_limit

除了上述變數，控制慢查詢日志的還有一個系統變數: min_examined_row_limit，
這個變數的意思是，查詢掃描過的最少記錄數，這個變數和查詢執行時間，共同組成了判別一個查詢是否是慢查詢的條件，如果查詢掃描過的記錄數大于等于這個變數的值，并且查詢執行時間超過long_query_time的值，那么，這個查詢就被記錄到慢查詢日志中; 反之，則不被記錄到慢查詢日志中，

mysql> show variables like 'min%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| min_examined_row_limit | 0     |
+------------------------+-------+
1 row in set (0.01 sec)

你也可以根據需要，通過修改 my.cnf 檔案，來修改min_examined_row_limit的值，

除了記錄普通的慢查詢之外，MySQL 還提供了兩個引數來讓我們記錄未使用索引的查詢，它們分別是：log-queries-not-using-indexes 和 log_throttle_queries_not_using_indexes

• log-queries-not-using-indexes

系統變數log-queries-not-using-indexes作用是未使用索引的查詢也被記錄到慢查詢日志中，

• log_throttle_queries_not_using_indexes

可通過設定 log_throttle_queries_not_using_indexes 來限制每分鐘寫入慢日志中的不走索引的SQL陳述句個數，該引數默認為 0，表示不開啟，也就是說不對寫入SQL陳述句條數進行控制，

在生產環境下，如果沒有使用索引，那么此類 SQL 陳述句會頻繁地被記錄到 slow log，從而導致 slow log 檔案大小不斷增加，我們可以通過調整此引數進行配置，

• log_slow_extra

如果啟用 log_slow_extra 系統變數（從 MySQL 8.0.14 開始提供），服務器會在日志寫入幾個額外欄位，若要記錄bytes_received 與 bytes_sent這兩個欄位則需要開啟

• percona slow log

GreatSQL是源于Percona Server的分支版本，除了Percona Server已有的穩定可靠、高效、管理更方便等優勢外，特別是進一步提升了MGR(MySQL Group Replication)的性能及可靠性，以及眾多bug修復，這就是為什么在使用GreatSQL查看慢查詢日志時，會有Query_time、Lock_time等資訊，這些都是我們GreatSQL源于Percona Server的原因，使查詢內容更加豐富，更多的資料可以使得我們更好的排查錯誤，

通過一個簡單的案例來展示：
我們先把慢查詢日志打開且設定時間閾值大于1秒就記錄：

#開啟慢查詢日志
mysql> set global slow_query_log='ON';
Query OK, 0 rows affected (0.00 sec)
#時間閾值超過1秒就記錄
mysql> set global long_query_time = 1;
Query OK, 0 rows affected (0.01 sec)
mysql> show variables like '%long_query_time%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
#查看已經被記錄的慢查詢數量
mysql> SHOW GLOBAL STATUS LIKE '%Slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 3     |
+---------------+-------+
1 row in set (0.01 sec)

寫一條SQL陳述句使得使用時間大于1秒

mysql> SELECT * FROM `student` WHERE id>1000 AND `name`='Yunxi';
+---------+-------+-------+------+---------+
| 9999715 |   707 | Yunxi |  863 |      71 |
.......省略
| 9999999 |   418 | Yunxi |  793 |     734 |
+---------+-------+-------+------+---------+
166949 rows in set (3.94 sec)
mysql> SHOW GLOBAL STATUS LIKE '%Slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 4     |
+---------------+-------+
1 row in set (0.00 sec)

可以看到此條SQL已經被記錄，接下來我們去查看慢查詢日志：

# Time: 2022-12-14T15:01:34.892085Z
# User@Host: root[root] @ localhost []  Id:     8
# Query_time: 3.985637  Lock_time: 0.000138 Rows_sent: 165346  Rows_examined: 9900000 Thread_id: 8 Errno: 0 Killed: 0 Bytes_received: 0 Bytes_sent: 4848540 Read_first: 0 Read_last: 0 Read_key: 1 Read_next: 9900000 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 0 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2022-12-14T15:01:30.906448Z End: 2022-12-14T15:01:34.892085Z Schema: slow Rows_affected: 0
# Tmp_tables: 0  Tmp_disk_tables: 0  Tmp_table_sizes: 0
# InnoDB_trx_id: 0
# Full_scan: No  Full_join: No  Tmp_table: No  Tmp_table_on_disk: No
# Filesort: No  Filesort_on_disk: No  Merge_passes: 0
#   InnoDB_IO_r_ops: 27606  InnoDB_IO_r_bytes: 452296704  InnoDB_IO_r_wait: 0.220474
#   InnoDB_rec_lock_wait: 0.000000  InnoDB_queue_wait: 0.000000
#   InnoDB_pages_distinct: 8191
use slow;
SET timestamp=1671030090;
SELECT * FROM `student` WHERE id>100000 AND `name`='Yunxi';

可以看到慢查詢日志記錄的非常詳細，從上述日志中能看到幾個資訊：

• 1.這個SQL的耗時3.985637秒，
• 2.回傳結果有165346行，總共需要掃描9900000行資料，如果掃描行數很多，但回傳行數很少，說明該SQL效率很低，可能索引不當，
• 3.Read_* 等幾個指標表示這個SQL讀記錄的方式，是否順序讀、隨機讀等，
• 4.Sort_* 等幾個指標表示該SQL是否產生了排序，及其代價，如果有且代價較大，需要想辦法優化，
• 5.tmp 等幾個指標表示該SQL是否產生臨時表，及其代價，如果有且代價較大，需要想辦法優化，
• 6.Full_scan/Full_join表示是否產生了全表掃描或全表JOIN，如果有且SQL耗時較大，需要想辦法優化，
• 7.InnoDB_IO_* 等幾個指標表示InnoDB邏輯讀相關資料，
• 8.InnoDB_rec_lock_wait 表示是否有行鎖等待，
• 9.InnoDB_queue_wait 表示是否有排隊等待，
• 10.InnoDB_pages_distinct 表示該SQL總共讀取了多少個InnoDB page，是個非常重要的指標，

GreatSQL可以作為MySQL或Percona Server的可選替代方案，用于線上生產環境，完全免費并兼容MySQL或Percona Server，綜上，如果在生產環境中已經用上Percona Server的話，那么也可以放心使用GreatSQL，詳情可見：（https://greatsql.cn/doc/#!&v=47_6_0）了解更多GreatSQL內容

查看慢查詢數目

查詢當前系統中有多少條慢查詢記錄

SHOW GLOBAL STATUS LIKE '%Slow_queries%';

慢查詢日志分析工具

在生產環境中，如果要手工分析日志，查找、分析SQL，顯然是個體力活，MySQL提供了日志分析工具 mysqldumpslow ，或者是可以使用另一個工具pt-query-digest，
它可以從logs、processlist、和 tcpdump 來分析 MySQL 的狀況，logs包括 slow log、general log、binlog，也可以把分析結果輸出到檔案中，或則把檔案寫到表中，分析程序是先對查詢陳述句的條件進行引數化，然后對引數化以后的查詢進行分組統計，統計出各查詢的執行時間、次數、占比等，可以借助分析結果找出問題進行優化，

關閉慢查詢日志

作者建議除了調優需要開，正常還是不要開了

MySQL服務器停止慢查詢日志功能的方法：

• 方式1

[mysqld]
slow_query_log=OFF

• 方式2

SET GLOBAL slow_query_log=off;

洗掉慢查詢日志

mysql> show variables like '%slow_query_log%';
+-----------------------------------+--------------------------------+
| Variable_name                     | Value                          |
+-----------------------------------+--------------------------------+
| slow_query_log                    | ON                             |
| slow_query_log_always_write_time  | 10.000000                      |
| slow_query_log_file               | /var/lib/mysql/zhyno1-slow.log |
| slow_query_log_use_global_control |                                |
+-----------------------------------+--------------------------------+
4 rows in set (0.00 sec)

通過以上查詢可以看到慢查詢日志的目錄，在該目錄下手動洗掉慢查詢日志檔案即可，或使用命令 mysqladmin 來洗掉,mysqladmin 命令的語法如下：mysqladmin -uroot -p flush-logs執行該命令后，命令列會提示輸入密碼，輸入正確密碼后，將執行洗掉操作，新的慢查詢日志會直接覆寫舊的查詢日志，不需要再手動洗掉，

注意
慢查詢日志都是使用mysqladmin flush-logs命令來洗掉重建的，使用時一定要注意，一旦執行了這個命令，慢查詢日志都只存在新的日志檔案中，如果需要舊的查詢日志，就必須事先備份，

參考文章

• 《MySQL是怎樣運行的--從根兒上理解MySQL》—小孩子4919（https://juejin.cn/book/6844733769996304392）

Enjoy GreatSQL ??

關于 GreatSQL

GreatSQL是由萬里資料庫維護的MySQL分支，專注于提升MGR可靠性及性能，支持InnoDB并行查詢特性，是適用于金融級應用的MySQL分支版本，

相關鏈接： GreatSQL社區 Gitee GitHub Bilibili

GreatSQL社區：

捉蟲活動詳情：https://greatsql.cn/thread-97-1-1.html

社區博客有獎征稿詳情：https://greatsql.cn/thread-100-1-1.html

技術交流群：

微信：掃碼添加GreatSQL社區助手微信好友，發送驗證資訊加群，

標籤：其他

上一篇：數字化時代，校園生活還可以這樣過

下一篇：MongoDB - 副本集簡介