Mysql慢查詢分析

 

一、關於數據庫性能分析

數據庫服務器的性能：
我們將性能定義為完成某件任務所需要的時間，性能即響應時間，這是應該很重要的原則，
我們通過任務的響應時間而不是資源來測量時間。
性能：即完成任務的響應時間,單位時每個任務花費的時間。
任務：查詢或者語句，如SELECT、UPDATE、DELETE。
所以我們優化時，首先要知道，時間花在哪些地方。這是第二個原則。

性能剖析：
任務花費時間分為：執行時間和的等待時間。
優化執行時間：通過測量定位不同的子任務花費的時間，然后優化去掉一些子任務，降低子任務的執行頻率或者提升子任務的效率。
等待時間：多種原因引起，分析更為復雜。

性能剖析的一般步驟：
1.測量所花費的時間，使用查詢日志。
2.然后對結果進行統計和排序，將重要的任務排到前面。

1.采集查詢日志
我們如果要測量查詢語句所花費的時間，就要捕獲Mysql的查詢到日志文件中。
Mysql為我們提高了以下的日志來捕獲查詢：
慢查詢日志：io開銷低，測量精度最高的查詢時間的工具。
通用日志：很少用於分析查詢，不包含響應時間和執行計划。
注意：長期開啟慢日志，需要消耗大量的磁盤空間，需要部署日志輪轉工具，或者只在需要采集查詢的時候開啟。

Mysql5.1及以后的版本，可以通過設置long_query_time為0來捕獲所有的查詢，查詢的響應單位為微秒級。

2.分析查詢日志
分析時，我們需要分析慢查詢日志，不要之間打開整個慢查詢日志進行分析，利用工具將慢查詢日志生成剖析報告。
這里推薦使用pt-query-digest,它分析功能強大，還支持將慢查詢報告保存到數據庫中，已經追蹤工作負載隨時間的變化。
一般情況只需要將慢查詢日志文件作為參數傳遞給pt-query-digest,它會將查詢報告打印處理。

所以我們使用分析工具是為找到值得我們優化的查詢。

以下來源：https://www.cnblogs.com/saneri/p/6656161.html

慢查詢日志相關參數

MySQL 慢查詢的相關參數解釋：slow_query_log ：是否開啟慢查詢日志，1表示開啟，0表示關閉。

1 2 3 4 5 6

slow_query_log    ：是否開啟慢查詢日志，1表示開啟，0表示關閉。 log-slow-queries  ：舊版（5.6以下版本）MySQL數據庫慢查詢日志存儲路徑。可以不設置該參數，系統則會默認給一個缺省的文件host_name-slow.log slow-query-log-file：新版（5.6及以上版本）MySQL數據庫慢查詢日志存儲路徑。可以不設置該參數，系統則會默認給一個缺省的文件host_name-slow.log long_query_time ：慢查詢閾值，當查詢時間多於設定的閾值時，記錄日志。 log_queries_not_using_indexes：未使用索引的查詢也被記錄到慢查詢日志中（可選項）。 log_output：日志存儲方式。log_output= 'FILE' 表示將日志存入文件，默認值是 'FILE' 。log_output= 'TABLE' 表示將日志存入數據庫，這樣日志信息就會被寫入到mysql.slow_log表中。MySQL數據<br>庫支持同時兩種日志存儲方式，配置的時候以逗號隔開即可，如：log_output= 'FILE,TABLE' 。日志記錄到系統的專用日志表中，要比記錄到文件耗費更多的系統資源，因此對於需要啟用慢查詢日志，又需<br>要能夠獲得更高的系統性能，那么建議優先記錄到文件。

慢查詢日志配置

默認情況下slow_query_log的值為OFF，表示慢查詢日志是禁用的，可以通過設置slow_query_log的值來開啟，如下所示：

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21

mysql> show variables like  '%slow_query_log%' ; +---------------------+------------------------------------------+ | Variable_name       | Value                                    | +---------------------+------------------------------------------+ | slow_query_log      | OFF                                      | | slow_query_log_file | /usr/local/mysql/data/localhost-slow.log | +---------------------+------------------------------------------+ 2 rows  in  set  (0.00 sec)   mysql>  set  global slow_query_log=1; Query OK, 0 rows affected (0.00 sec)   mysql> show variables like  '%slow_query_log%' ; +---------------------+------------------------------------------+ | Variable_name       | Value                                    | +---------------------+------------------------------------------+ | slow_query_log      | ON                                       | | slow_query_log_file | /usr/local/mysql/data/localhost-slow.log | +---------------------+------------------------------------------+ 2 rows  in  set  (0.00 sec) #使用set global slow_query_log=1開啟了慢查詢日志只對當前數據庫生效，MySQL重啟后則會失效。如果要永久生效，就必須修改配置文件my.cnf（其它系統變量也是如此）

修改my.cnf文件，增加或修改參數slow_query_log 和slow_query_log_file后，然后重啟MySQL服務器，如下所示:

slow_query_log =1
slow_query_log_file=/usr/local/mysql/data/localhost-slow.log

mysql> show variables like 'slow_query%';
+---------------------+---------------------+
| Variable_name       | Value               |
+---------------------+---------------------+
| slow_query_log      | ON                  |
| slow_query_log_file | /usr/local/mysql/data/localhost-slow.log |
+---------------------+---------------------+
2 rows in set (0.00 sec)
 
mysql> 
#慢查詢的參數slow_query_log_file ，它指定慢查詢日志文件的存放路徑，系統默認會給一個缺省的文件host_name-slow.log

      那么開啟了慢查詢日志后，什么樣的SQL才會記錄到慢查詢日志里面呢？ 這個是由參數long_query_time控制，默認情況下long_query_time的值為10秒，可以使用命令修改，也可以在my.cnf參數里面修改。關於運行時間正好等於long_query_time的情況，並不會被記錄下來。也就是說，在mysql源碼里是判斷大於long_query_time，而非大於等於。從MySQL 5.1開始，long_query_time開始以微秒記錄SQL語句運行時間，之前僅用秒為單位記錄。如果記錄到表里面，只會記錄整數部分，不會記錄微秒部分。

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21

mysql> show variables like  'long_query_time' ; +-----------------+-----------+ | Variable_name   | Value     | +-----------------+-----------+ | long_query_time | 10.000000 | +-----------------+-----------+ 1 row  in  set  (0.00 sec)   mysql> mysql>  set  global long_query_time=4; Query OK, 0 rows affected (0.00 sec)   mysql> show variables like  'long_query_time' ; +-----------------+-----------+ | Variable_name   | Value     | +-----------------+-----------+ | long_query_time | 10.000000 | +-----------------+-----------+ 1 row  in  set  (0.00 sec)   mysql>

     如上所示，我修改了變量long_query_time，但是查詢變量long_query_time的值還是10，難道沒有修改到呢？注意：使用命令 set global long_query_time=4修改后，需要重新連接或新開一個會話才能看到修改值。你用show variables like 'long_query_time'查看是當前會話的變量值，你也可以不用重新連接會話，而是用show global variables like '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)

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

mysql> 

log_output 參數是指定日志的存儲方式。log_output='FILE'表示將日志存入文件，默認值是'FILE'。log_output='TABLE'表示將日志存入數據庫，這樣日志信息就會被寫入到mysql.slow_log表中。MySQL數據庫支持同時兩種日志存儲方式，配置的時候以逗號隔開即可，如：log_output='FILE,TABLE'。日志記錄到系統的專用日志表中，要比記錄到文件耗費更多的系統資源，因此對於需要啟用慢查詢日志，又需要能夠獲得更高的系統性能，那么建議優先記錄到文件.

1 2 3 4 5 6 7 8 9

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

系統變量log-queries-not-using-indexes：未使用索引的查詢也被記錄到慢查詢日志中（可選項）。如果調優的話，建議開啟這個選項。另外，開啟了這個參數，其實使用full index scan的sql也會被記錄到慢查詢日志。

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20

mysql> show variables like  'log_queries_not_using_indexes' ; +-------------------------------+-------+ | Variable_name                 | Value | +-------------------------------+-------+ | log_queries_not_using_indexes | OFF   | +-------------------------------+-------+ 1 row  in  set  (0.00 sec)    mysql>  set  global log_queries_not_using_indexes=1; Query OK, 0 rows affected (0.00 sec)    mysql> show variables like  'log_queries_not_using_indexes' ; +-------------------------------+-------+ | Variable_name                 | Value | +-------------------------------+-------+ | log_queries_not_using_indexes | ON    | +-------------------------------+-------+ 1 row  in  set  (0.00 sec)    mysql>

系統變量log_slow_admin_statements表示是否將慢管理語句例如ANALYZE TABLE和ALTER TABLE等記入慢查詢日志

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

mysql> 

另外，如果你想查詢有多少條慢查詢記錄，可以使用系統變量。

mysql> show global status like '%slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 0     |
+---------------+-------+
1 row in set (0.00 sec)

mysql> 

 

 

二、pt-query-digest簡介

pt-query-digest是用於分析mysql慢查詢的一個工具，它可以分析binlog、General log、slowlog，也可以通過SHOWPROCESSLIST或者通過tcpdump抓取的MySQL協議數據來進行分析。可以把分析結果輸出到文件中，分析過程是先對查詢語句的條件進行參數化，然后對參數化以后的查詢進行分組統計，統計出各查詢的執行時間、次數、占比等，可以借助分析結果找出問題進行優化。

三、安裝pt-query-digest

1.下載頁面：https://www.percona.com/doc/percona-toolkit/2.2/installation.html
2.perl的模塊

yum install -y perl-CPAN perl-Time-HiRes

3.安裝步驟
方法一：rpm安裝

cd /usr/local/src
wget percona.com/get/percona-toolkit.rpm
yum install -y percona-toolkit.rpm

工具安裝目錄在：/usr/bin

方法二：源碼安裝

cd /usr/local/src
wget percona.com/get/percona-toolkit.tar.gz
tar zxf percona-toolkit.tar.gz
cd percona-toolkit-2.2.19
perl Makefile.PL PREFIX=/usr/local/percona-toolkit
make && make install

工具安裝目錄在：/usr/local/percona-toolkit/bin

4.各工具用法簡介（詳細內容：https://www.percona.com/doc/percona-toolkit/2.2/index.html）
(1)慢查詢日志分析統計

pt-query-digest /usr/local/mysql/data/slow.log

(2)服務器摘要

pt-summary 

(3)服務器磁盤監測

pt-diskstats 

(4)mysql服務狀態摘要

pt-mysql-summary -- --user=root --password=root 

 

四、pt-query-digest語法及重要選項

pt-query-digest [OPTIONS] [FILES] [DSN]
--create-review-table  當使用--review參數把分析結果輸出到表中時，如果沒有表就自動創建。
--create-history-table  當使用--history參數把分析結果輸出到表中時，如果沒有表就自動創建。
--filter  對輸入的慢查詢按指定的字符串進行匹配過濾后再進行分析
--limit    限制輸出結果百分比或數量，默認值是20,即將最慢的20條語句輸出，如果是50%則按總響應時間占比從大到小排序，輸出到總和達到50%位置截止。
--host  mysql服務器地址
--user  mysql用戶名
--password  mysql用戶密碼
--history 將分析結果保存到表中，分析結果比較詳細，下次再使用--history時，如果存在相同的語句，且查詢所在的時間區間和歷史表中的不同，則會記錄到數據表中，可以通過查詢同一CHECKSUM來比較某類型查詢的歷史變化。
--review 將分析結果保存到表中，這個分析只是對查詢條件進行參數化，一個類型的查詢一條記錄，比較簡單。當下次使用--review時，如果存在相同的語句分析，就不會記錄到數據表中。
--output 分析結果輸出類型，值可以是report(標准分析報告)、slowlog(Mysql slow log)、json、json-anon，一般使用report，以便於閱讀。
--since 從什么時間開始分析，值為字符串，可以是指定的某個”yyyy-mm-dd [hh:mm:ss]”格式的時間點，也可以是簡單的一個時間值：s(秒)、h(小時)、m(分鍾)、d(天)，如12h就表示從12小時前開始統計。
--until 截止時間，配合—since可以分析一段時間內的慢查詢。

 

五、分析pt-query-digest輸出結果

第一部分：總體統計結果
Overall：總共有多少條查詢
Time range：查詢執行的時間范圍
unique：唯一查詢數量，即對查詢條件進行參數化以后，總共有多少個不同的查詢
total：總計   min：最小   max：最大  avg：平均
95%：把所有值從小到大排列，位置位於95%的那個數，這個數一般最具有參考價值
median：中位數，把所有值從小到大排列，位置位於中間那個數

# 該工具執行日志分析的用戶時間，系統時間，物理內存占用大小，虛擬內存占用大小
# 340ms user time, 140ms system time, 23.99M rss, 203.11M vsz
# 工具執行時間
# Current date: Fri Nov 25 02:37:18 2016
# 運行分析工具的主機名
# Hostname: localhost.localdomain
# 被分析的文件名
# Files: slow.log
# 語句總數量，唯一的語句數量，QPS，並發數
# Overall: 2 total, 2 unique, 0.01 QPS, 0.01x concurrency ________________
# 日志記錄的時間范圍
# Time range: 2016-11-22 06:06:18 to 06:11:40
# 屬性               總計      最小    最大    平均    95%  標准    中等
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# 語句執行時間
# Exec time             3s   640ms      2s      1s      2s   999ms      1s
# 鎖占用時間
# Lock time            1ms       0     1ms   723us     1ms     1ms   723us
# 發送到客戶端的行數
# Rows sent              5       1       4    2.50       4    2.12    2.50
# select語句掃描行數
# Rows examine     186.17k       0 186.17k  93.09k 186.17k 131.64k  93.09k
# 查詢的字符數
# Query size           455      15     440  227.50     440  300.52  227.50

第二部分：查詢分組統計結果
Rank：所有語句的排名，默認按查詢時間降序排列，通過--order-by指定
Query ID：語句的ID，（去掉多余空格和文本字符，計算hash值）
Response：總的響應時間
time：該查詢在本次分析中總的時間占比
calls：執行次數，即本次分析總共有多少條這種類型的查詢語句
R/Call：平均每次執行的響應時間
V/M：響應時間Variance-to-mean的比率
Item：查詢對象

# Profile
# Rank Query ID           Response time Calls R/Call V/M   Item
# ==== ================== ============= ===== ====== ===== ===============
#    1 0xF9A57DD5A41825CA  2.0529 76.2%     1 2.0529  0.00 SELECT
#    2 0x4194D8F83F4F9365  0.6401 23.8%     1 0.6401  0.00 SELECT wx_member_base

第三部分：每一種查詢的詳細統計結果
由下面查詢的詳細統計結果，最上面的表格列出了執行次數、最大、最小、平均、95%等各項目的統計。
ID：查詢的ID號，和上圖的Query ID對應
Databases：數據庫名
Users：各個用戶執行的次數（占比）
Query_time distribution ：查詢時間分布, 長短體現區間占比，本例中1s-10s之間查詢數量是10s以上的兩倍。
Tables：查詢中涉及到的表
Explain：SQL語句

# Query 1: 0 QPS, 0x concurrency, ID 0xF9A57DD5A41825CA at byte 802 ______
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2016-11-22 06:11:40
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         50       1
# Exec time     76      2s      2s      2s      2s      2s       0      2s
# Lock time      0       0       0       0       0       0       0       0
# Rows sent     20       1       1       1       1       1       0       1
# Rows examine   0       0       0       0       0       0       0       0
# Query size     3      15      15      15      15      15       0      15
# String:
# Databases    test
# Hosts        192.168.8.1
# Users        mysql
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# EXPLAIN /*!50100 PARTITIONS*/
select sleep(2)\G

 

六、用法示例

1.直接分析慢查詢文件:

pt-query-digest  slow.log > slow_report.log

2.分析最近12小時內的查詢：

pt-query-digest  --since=12h  slow.log > slow_report2.log

3.分析指定時間范圍內的查詢：

pt-query-digest slow.log --since '2017-01-07 09:30:00' --until '2017-01-07 10:00:00'> > slow_report3.log

4.分析指含有select語句的慢查詢

pt-query-digest --filter '$event->{fingerprint} =~ m/^select/i' slow.log> slow_report4.log

5.針對某個用戶的慢查詢

pt-query-digest --filter '($event->{user} || "") =~ m/^root/i' slow.log> slow_report5.log

6.查詢所有所有的全表掃描或full join的慢查詢

pt-query-digest --filter '(($event->{Full_scan} || "") eq "yes") ||(($event->{Full_join} || "") eq "yes")' slow.log> slow_report6.log

7.把查詢保存到query_review表

pt-query-digest --user=root –password=abc123 --review  h=localhost,D=test,t=query_review--create-review-table  slow.log

8.把查詢保存到query_history表

pt-query-digest  --user=root –password=abc123 --review  h=localhost,D=test,t=query_history--create-review-table  slow.log_0001
pt-query-digest  --user=root –password=abc123 --review  h=localhost,D=test,t=query_history--create-review-table  slow.log_0002

9.通過tcpdump抓取mysql的tcp協議數據，然后再分析

tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > mysql.tcp.txt
pt-query-digest --type tcpdump mysql.tcp.txt> slow_report9.log

10.分析binlog

mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql
pt-query-digest  --type=binlog  mysql-bin000093.sql > slow_report10.log

11.分析general log

pt-query-digest  --type=genlog  localhost.log > slow_report11.log

轉載原文:https://www.cnblogs.com/luyucheng/p/6265873.html

作者：成九