如何開啟MySQL慢查詢日志

前言

資料庫日志記錄了使用者對資料庫的各種操作及資料庫發生的各種事件。能幫助資料庫管理者追蹤、分析問題。MySQL提供了錯誤日志、二進制日志、查詢日志、慢查詢日志。

MySQL的慢查詢日志是MySQL提供的一種日志記錄，它用來記錄在MySQL中響應時間超過閥值（long_query_time，機關：秒）的SQL語句。預設情況下，MySQL不啟動慢查詢日志。本文簡單介紹如何開啟慢查詢日志，如何用mysqldumpslow分析慢查詢。

開啟慢查詢日志

修改my.cnf

在配置檔案my.cnf（一般為/etc/my.cnf）中的[mysqld] section增加如下參數。

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/lib/mysql/slow-query.log   # 若沒有指定，預設名字為hostname_slow.log
long_query_time = 1

log_queries_not_using_indexes = 1           

其中，

• slow_query_log = 1
  • 表示開啟慢查詢，0表示關閉
• slow_query_log_file
  • 指定慢查詢日志路徑
  • 需要MySQL對該路徑有寫權限
• long_query_time = 1
  • 表示查詢時間>=1秒才記錄日志
  • 預設10s
• log_queries_not_using_indexes = 1
  • 表明記錄沒有使用索引的 SQL 語句

重新開機MySQL服務

# 重新開機
$ sudo service mysqld restart

# 重新開機後程序如下

root     22373  0.0  0.0  66064  1424 pts/3    S    16:59   0:00 /bin/sh /usr/local/mysql/bin/mysqld_safe --datadir=/var/lib/mysql --socket=/var/lib/mysql/mysql.sock --log-error=/var/log/mysqld.log --pid-file=/var/run/mysqld/mysqld.pid --user=mysql
mysql    22721  0.3  0.5 890996 467040 pts/3   Sl   16:59   0:00 /usr/local/mysql/bin/mysqld --basedir=/usr/local/mysql --datadir=/var/lib/mysql --plugin-dir=/usr/local/mysql/lib/plugin --user=mysql --log-error=/var/log/mysqld.log --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock           

重新開機MySQL後會看到/var/lib/mysql/slow-query.log檔案。

檢查參數

通過如下指令可以檢查上述參數配置情況。

mysql> show variables like 'slow_query%';
+---------------------+-------------------------------+
| Variable_name       | Value                         |
+---------------------+-------------------------------+
| slow_query_log      | ON                            |
| slow_query_log_file | /var/lib/mysql/slow-query.log |
+---------------------+-------------------------------+
2 rows in set (0.00 sec)

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

測試

慢查詢

制造慢查詢并執行。如下。

mysql> select sleep(1);
+----------+
| sleep(1) |
+----------+
|        0 |
+----------+
1 row in set (1.00 sec)           

慢查詢日志

打開慢查詢日志檔案。可以看到上述慢查詢的SQL語句被記錄到日志中。

# Time: 180620 17:13:06
# User@Host: apsara[apsara] @ dc1487859883577.et2sqa [11.239.51.96]  Id:     3
# Query_time: 1.000246  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1529485986;
select sleep(1);           

慢查詢分析工具

mysqldumpslow

mysqldumpslow是MySQL自帶的分析慢查詢的工具。該工具是Perl腳本。

常用參數如下。

-s：排序方式，值如下
    c：查詢次數
    t：查詢時間
    l：鎖定時間
    r：傳回記錄
    ac：平均查詢次數
    al：平均鎖定時間
    ar：平均傳回記錄書
    at：平均查詢時間
-t：top N查詢
-g：正規表達式           

例子

• 我們執行了多次類似如下的查詢。

select * from db_user where name like 'zb%';
select * from db_user where name like 'aaa%';
select * from db_user where name like 'bc%';
...           

• 擷取通路次數最多的5個SQL語句

$ mysqldumpslow -s c -t 5 /var/lib/mysql/slow-query.log

Reading mysql slow query log from /var/lib/mysql/slow-query.log
Count: 15  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), apsara[apsara]@dc1487859883577.et2sqa
  # Query_time: N.N  Lock_time: N.N Rows_sent: N  Rows_examined: N
  SET timestamp=N;
  select * from db_user where name like 'S'

Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), apsara[apsara]@dc1487859883577.et2sqa
  # Query_time: N.N  Lock_time: N.N Rows_sent: N  Rows_examined: N
  use test;
  SET timestamp=N;
  select * from db_user where name like 'S'           

• 按照時間排的top 5個SQL語句

$ mysqldumpslow -s t -t 5 /var/lib/mysql/slow-query.log           

• 按照時間排序且含有'like'的top 5個SQL語句

$ mysqldumpslow -s t -t 3 -g "like" /var/lib/mysql/slow-query.log           

小結

預設情況下，MySQL不啟動慢查詢日志。若要檢查慢查詢，需要我們手動設定這個參數。一般情況下，若非調優需要，不建議啟動該參數，因為開啟慢查詢日志或多或少會帶來一定的性能影響。慢查詢日志支援将日志記錄寫入檔案，也支援将日志記錄寫入資料庫表。

Reference

• https://dev.mysql.com/doc/refman/5.7/en/slow-query-log.html
• https://dev.mysql.com/doc/refman/5.7/en/mysqldumpslow.html