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

GreatSQL社區原創內容未經授權不得隨意使用，轉載請聯繫小編並註明來源。 GreatSQL是MySQL的國產分支版本，使用上與MySQL一致。作者：KAiTO 文章來源：GreatSQL社區原創什麼是慢查詢日誌 MySQL 的慢查詢日誌，用來記錄在 MySQL 中響應時間超過閥值的語句，具體 ...

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作用是未使用索引的查詢也被記錄到慢查詢日誌中。

amIpmEdO1DQh2jHqBodZ4NI3NbqlGgb9Yyak2yq15lG

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