一、簡介
pt-query-digest是用于分析mysql慢查詢的一個工具，它可以分析binlog、General log、slowlog，也可以通過SHOWPROCESSLIST或者通過tcpdump抓取的MySQL協定資料來進行分析。可以把分析結果輸出到檔案中，分析過程是先對查詢語句的條件進行參數化，然後對參數化以後的查詢進行分組統計，統計出各查詢的執行時間、次數、占比等，可以借助分析結果找出問題進行優化。
二、安裝pt-query-digest
pt-query-digest是percona-toolkit裡面一個工具，其作用就是分析慢查詢日志，将MySQL慢查詢日志進行統計并友好的顯示出來
1、安裝依賴包
[[email protected]_server bin]# yum install perl-DBI perl-DBD-MySQL perl-IO-Socket-SSL perl-Digest-MD5 -y
2、下載下傳percona-toolkit二進制包
[[email protected]_server conf.d]# mkdir /usr/local/src/percona-toolkit
[[email protected]_server conf.d]# cd /usr/local/src/percona-toolkit
[[email protected]_server percona-toolkit]# wget https://www.percona.com/downloads/percona-toolkit/3.0.10/binary/tarball/percona-toolkit-3.0.10_x86_64.tar.gz
--2020-04-07 16:44:49-- https://www.percona.com/downloads/percona-toolkit/3.0.10/binary/tarball/percona-toolkit-3.0.10_x86_64.tar.gz
正在解析主機 www.percona.com... 74.121.199.234正在連接配接 www.percona.com|74.121.199.234|:443... 已連接配接。
已發出 HTTP 請求，正在等待回應... 200OK
長度：8170395 (7.8M) [application/x-gzip]
正在儲存至: “percona-toolkit-3.0.10_x86_64.tar.gz”
28% [============================> ] 2,312,153 693K/s eta(英國中部時33% [==================================> ] 2,770,905 759K/s eta(英國中部時39% [========================================> ] 3,229,657 817K/s eta(英國中部時45% [==============================================> ] 3,688,409 871K/s eta(英國中部時50% [====================================================> ] 4,147,161 916K/s eta(英國中部時56% [==========================================================> ] 4,605,913 953K/s eta(英國中部時61% [================================================================> ] 5,064,665 986K/s eta(英國中部時67% [======================================================================> ] 5,523,417 1014K/s eta(英國中部時73% [============================================================================> ] 5,982,169 1.02M/s eta(英國中部時77% [=================================================================================> ] 6,326,233 1.01M/s eta(英國中部時83% [=======================================================================================> ] 6,850,521 1.10M/s eta(英國中部時87% [============================================================================================> ] 7,178,201 1.15M/s eta(英國中部時91% [================================================================================================> ] 7,505,881 1.25M/s eta(英國中部時96% [=====================================================================================================> ] 7,866,329 1.29M/s eta(英國中部時100%[=========================================================================================================>] 8,170,395 1.37M/s in 7.1s
2020-04-07 16:44:59 (1.09 MB/s) - 已儲存 “percona-toolkit-3.0.10_x86_64.tar.gz” [8170395/8170395])
[[email protected]_server percona-toolkit]#
解壓
[[email protected]_server percona-toolkit]# tar -zxvf percona-toolkit-3.0.10_x86_64.tar.gz
percona-toolkit-3.0.10/percona-toolkit-3.0.10/CONTRIBUTE.md
percona-toolkit-3.0.10/Makefile.PL
percona-toolkit-3.0.10/docker-compose.yml
percona-toolkit-3.0.10/CONTRIBUTING.md
percona-toolkit-3.0.10/Gopkg.lock
percona-toolkit-3.0.10/README.md
percona-toolkit-3.0.10/bin/percona-toolkit-3.0.10/bin/pt-summary
percona-toolkit-3.0.10/bin/pt-slave-delay
percona-toolkit-3.0.10/bin/pt-mongodb-query-digest
percona-toolkit-3.0.10/bin/pt-slave-restart
percona-toolkit-3.0.10/bin/pt-variable-advisor
percona-toolkit-3.0.10/bin/pt-fingerprint
percona-toolkit-3.0.10/bin/pt-secure-collect
percona-toolkit-3.0.10/bin/pt-index-usage
percona-toolkit-3.0.10/bin/pt-archiver
percona-toolkit-3.0.10/bin/pt-findpercona-toolkit-3.0.10/bin/pt-heartbeat
percona-toolkit-3.0.10/bin/pt-fifo-splitpercona-toolkit-3.0.10/bin/pt-fk-error-logger
percona-toolkit-3.0.10/bin/pt-mysql-summary
percona-toolkit-3.0.10/bin/pt-online-schema-change
percona-toolkit-3.0.10/bin/pt-table-usage
percona-toolkit-3.0.10/bin/pt-align
percona-toolkit-3.0.10/bin/pt-query-digest
percona-toolkit-3.0.10/bin/pt-ioprofile
percona-toolkit-3.0.10/bin/pt-visual-explain
percona-toolkit-3.0.10/bin/pt-stalk
percona-toolkit-3.0.10/bin/pt-mext
percona-toolkit-3.0.10/bin/pt-table-checksum
percona-toolkit-3.0.10/bin/pt-show-grants
percona-toolkit-3.0.10/bin/pt-pmp
percona-toolkit-3.0.10/bin/pt-upgrade
percona-toolkit-3.0.10/bin/pt-diskstats
percona-toolkit-3.0.10/bin/pt-sift
percona-toolkit-3.0.10/bin/pt-config-diffpercona-toolkit-3.0.10/bin/pt-slave-findpercona-toolkit-3.0.10/bin/pt-killpercona-toolkit-3.0.10/bin/pt-duplicate-key-checker
percona-toolkit-3.0.10/bin/pt-deadlock-logger
percona-toolkit-3.0.10/bin/pt-mongodb-summary
percona-toolkit-3.0.10/bin/pt-table-syncpercona-toolkit-3.0.10/lib/percona-toolkit-3.0.10/docs/percona-toolkit-3.0.10/docs/percona-toolkit.pod
percona-toolkit-3.0.10/Gopkg.toml
percona-toolkit-3.0.10/MANIFEST
percona-toolkit-3.0.10/COPYING
percona-toolkit-3.0.10/Changelog
percona-toolkit-3.0.10/INSTALL
[[email protected]_server percona-toolkit]# mv percona-toolkit-3.0.10 /usr/local/
3、運作檢視版本
[[email protected]_server bin]# ./pt-query-digest --version
pt-query-digest 3.0.10[[email protected]_server bin]#
pt-query-digest: 慢查詢日志分析統計
pt-summary:伺服器摘要
pt-diskstats:伺服器磁盤監測
pt-msyql-summary:mysql服務狀态摘要
三、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：中位數，把所有值從小到大排列，位置位于中間那個數
[[email protected]_server bin]# ./pt-query-digest /home/mysql_data/mysql/zabbix_server-slow.log
# A software update is available:
# 490ms usertime, 40ms system time, 26.75M rss, 223.77Mvsz
# Currentdate: Wed Apr 8 09:50:22 2020# Hostname: zabbix_server.jinglong
# Files:/home/mysql_data/mysql/zabbix_server-slow.log
# Overall:4 total, 4 unique, 0.00 QPS, 0.06x concurrency ________________
# Time range:2020-04-07T06:34:40 to 2020-04-07T09:16:18# Attribute total min max avg95%stddev median
#============ ======= ======= ======= ======= ======= ======= =======# Exectime628s 106ms 536s 157s 511s 212s 300s
# Locktime 368us 0146us 92us 144us 54us 132us
# Rows sent3 0 1 0.75 0.99 0.43 0.99# Rows examine161.34M 0 146.78M 40.34M 142.90M 60.09M 78.66M# Query size527 27 425 131.75 420.77 167.83 231.62# Profile
# Rank Query ID Responsetime Calls R/Call V/M Item
#==== ================== ============== ===== ======== ===== ============#1 0x99E696CEDECCBA36 536.4558 85.4% 1 536.4558 0.00SELECT history
#2 0x47C7D572627422FB 91.3777 14.5% 1 91.3777 0.00SELECT trends
# MISC 0xMISC0.3991 0.1% 2 0.1996 0.0 <2 ITEMS># Query1: 0 QPS, 0x concurrency, ID 0x99E696CEDECCBA36 at byte 483______
# This item is includedin the report because it matches --limit.
# Scores: V/M = 0.00# Time range: all events occurred at2020-04-07T06:42:47# Attribute pct total min max avg95%stddev median
#============ === ======= ======= ======= ======= ======= ======= =======# Count25 1# Exectime 85 536s 536s 536s 536s 536s 0536s
# Locktime 39 146us 146us 146us 146us 146us 0146us
# Rows sent33 1 1 1 1 1 0 1# Rows examine90 146.78M 146.78M 146.78M 146.78M 146.78M 0 146.78M# Query size8 43 43 43 43 43 0 43# String:
# Hosts172.28.146.109# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+################################################################
# Tables
# SHOW TABLE STATUS LIKE'history'\G
# SHOW CREATE TABLE `history`\G
# EXPLAIN
select count(*) from history
LIMIT0, 1000\G
# Query2: 0 QPS, 0x concurrency, ID 0x47C7D572627422FB at byte 241______
# This item is includedin the report because it matches --limit.
# Scores: V/M = 0.00# Time range: all events occurred at2020-04-07T06:38:39# Attribute pct total min max avg95%stddev median
#============ === ======= ======= ======= ======= ======= ======= =======# Count25 1# Exectime 14 91s 91s 91s 91s 91s 091s
# Locktime 27 102us 102us 102us 102us 102us 0102us
# Rows sent33 1 1 1 1 1 0 1# Rows examine9 14.56M 14.56M 14.56M 14.56M 14.56M 0 14.56M# Query size5 27 27 27 27 27 0 27# String:
# Hosts zabbix_server
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+################################################################
# Tables
# SHOW TABLE STATUS LIKE'trends'\G
# SHOW CREATE TABLE `trends`\G
# EXPLAIN
select count(*) from trends\G
[[email protected]_server bin]#
1、總體統計結果
# 490ms user time, 40ms system time, 26.75M rss, 223.77Mvsz
# Currentdate: Wed Apr 8 09:50:22 2020# Hostname: zabbix_server.jinglong
# Files:/home/mysql_data/mysql/zabbix_server-slow.log
# Overall:4 total, 4 unique, 0.00 QPS, 0.06x concurrency ________________
# Time range:2020-04-07T06:34:40 to 2020-04-07T09:16:18# Attribute total min max avg95%stddev median
#============ ======= ======= ======= ======= ======= ======= =======# Exectime628s 106ms 536s 157s 511s 212s 300s
# Locktime 368us 0146us 92us 144us 54us 132us
# Rows sent3 0 1 0.75 0.99 0.43 0.99# Rows examine161.34M 0 146.78M 40.34M 142.90M 60.09M 78.66M# Query size527 27 425 131.75 420.77 167.83 231.62
該工具執行日志分析的使用者時間，系統時間，實體記憶體占用大小，虛拟記憶體占用大小
#490ms user time, 40ms system time, 26.75M rss, 223.77Mvsz
工具執行時間
Current date: Wed Apr 8 09:50:22 2020
運作分析工具的主機名
Hostname: zabbix_server.jinglong
被分析的檔案名
Files: /home/mysql_data/mysql/zabbix_server-slow.log
語句總數量，唯一的語句數量，QPS，并發數
Overall: 4 total, 4 unique, 0.00 QPS, 0.06x concurrency
查詢執行的時間範圍
Time range: 2020-04-07T06:34:40 to 2020-04-07T09:16:18
屬性 屬性占整個報告百分比 總計 最小 最大 平均 95% 标準 中等
Attribute pct total min max avg 95%stddev median
語句執行時間 鎖占用時間語句傳回行數 語句掃描行數 查詢的字元數
Exec time Lock time Rows sent Rows examine Query size
2、分組統計結果
# Profile
# Rank Query ID Responsetime Calls R/Call V/M Item
#==== ================== ============== ===== ======== ===== ============#1 0x99E696CEDECCBA36 536.4558 85.4% 1 536.4558 0.00SELECT history
#2 0x47C7D572627422FB 91.3777 14.5% 1 91.3777 0.00SELECT trends
# MISC 0xMISC0.3991 0.1% 2 0.1996 0.0 <2 ITEMS>
Rank:所有語句的排名，預設按查詢時間降序排列，通過--order-by指定
Query ID:語句的ID，(去掉多餘空格和文本字元，計算hash值)
Response:總的響應時間
time:該查詢在本次分析中總的時間占比
calls：執行次數，即本次分析總共有多少條這種類型的查詢語句
R/Call：平均每次執行的響應時間
V/M：響應時間Variance-to-mean的比率
Item：查詢對象
3、每一種查詢的詳細統計結果
# Query 1: 0 QPS, 0x concurrency, ID 0x99E696CEDECCBA36 at byte 483______
# This item is includedin the report because it matches --limit.
# Scores: V/M = 0.00# Time range: all events occurred at2020-04-07T06:42:47# Attribute pct total min max avg95%stddev median
#============ === ======= ======= ======= ======= ======= ======= =======# Count25 1# Exectime 85 536s 536s 536s 536s 536s 0536s
# Locktime 39 146us 146us 146us 146us 146us 0146us
# Rows sent33 1 1 1 1 1 0 1# Rows examine90 146.78M 146.78M 146.78M 146.78M 146.78M 0 146.78M# Query size8 43 43 43 43 43 0 43# String:
# Hosts172.28.146.109# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+################################################################
# Tables
# SHOW TABLE STATUS LIKE'history'\G
# SHOW CREATE TABLE `history`\G
# EXPLAIN
select count(*) from history
LIMIT0, 1000\G
# Query2: 0 QPS, 0x concurrency, ID 0x47C7D572627422FB at byte 241______
# This item is includedin the report because it matches --limit.
# Scores: V/M = 0.00# Time range: all events occurred at2020-04-07T06:38:39# Attribute pct total min max avg95%stddev median
#============ === ======= ======= ======= ======= ======= ======= =======# Count25 1# Exectime 14 91s 91s 91s 91s 91s 091s
# Locktime 27 102us 102us 102us 102us 102us 0102us
# Rows sent33 1 1 1 1 1 0 1# Rows examine9 14.56M 14.56M 14.56M 14.56M 14.56M 0 14.56M# Query size5 27 27 27 27 27 0 27# String:
# Hosts zabbix_server
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+################################################################
# Tables
# SHOW TABLE STATUS LIKE'trends'\G
# SHOW CREATE TABLE `trends`\G
# EXPLAIN
select count(*) from trends\G
[[email protected]_server bin]#
Query 1: 0 QPS, 0x concurrency, ID 0x99E696CEDECCBA36 at byte 483
ID：查詢的ID号，和上圖的Query ID對應
Count->total 表示查詢執行了25次
Exec time->pct表示執行時間總共站了所有查詢的百分之十四
Exec time->total 表示執行時間總共91s
Exec time->min 表示最小執行時間
Exec time->max 表示最大執行時間
Exec time->avg 表示平均執行時間
Exec time->95% 表示有百分之95的執行時間小于91s
Exec time->stddev 标準偏差，表示所有值偏離平均值的波動程度 (計算這個是從百分之95來算出的，排除了特别大的數)
Exec time->median 中間的那個值 (計算這個是從百分之95來算出的，排除了特别大的數)
Query_time distribution：查詢時間分布, 長短展現區間占比
Tables：查詢中涉及到的表
EXPLAIN：SQL語句
五、用法示例
1、将結果輸出到報告檔案
[[email protected]_server bin]# ./pt-query-digest /home/mysql_data/mysql/zabbix_server-slow.log >/home/slow_report.log
[[email protected]_server bin]# vim /home/slow_report.log1
2 # 450ms user time, 50ms system time, 24.53M rss, 209.02Mvsz3 # Current date: Wed Apr 8 10:49:23 2020
4# Hostname: zabbix_server.jinglong5 # Files: /home/mysql_data/mysql/zabbix_server-slow.log6 # Overall: 6 total, 5 unique, 0.00 QPS, 0.01x concurrency ________________7 # Time range: 2020-04-07T06:34:40 to 2020-04-08T02:38:33
8 # Attribute total min max avg 95%stddev median9 # ============ ======= ======= ======= ======= ======= ======= =======
10 # Exec time642s 106ms 536s 107s 511s 186s 49s11 # Lock time 368us 0146us 61us 144us 61us 108us12 # Rows sent 5 0 1 0.83 0.99 0.37 0.99
13 # Rows examine 161.34M 0 146.78M 26.89M 142.90M 52.45M 0
14 # Query size 558 15 425 93 420.77 147.43 37.09
15
16# Profile17 # Rank Query ID Response time Calls R/Call V/M Item18 # ==== ================== ============== ===== ======== ===== ============
19 # 1 0x99E696CEDECCBA36 536.4558 83.5% 1 536.4558 0.00SELECT history20 # 2 0x47C7D572627422FB 91.3777 14.2% 1 91.3777 0.00SELECT trends21 # MISC 0xMISC 14.3996 2.2% 4 3.5999 0.0 <3 ITEMS>
22
23 # Query 1: 0 QPS, 0x concurrency, ID 0x99E696CEDECCBA36 at byte 483______24 # This item is included in the report because it matches --limit.25 # Scores: V/M = 0.00
26 # Time range: all events occurred at 2020-04-07T06:42:47
27 # Attribute pct total min max avg 95%stddev median28 # ============ === ======= ======= ======= ======= ======= ======= =======
29 # Count 16 1
30 # Exec time 83 536s 536s 536s 536s 536s 0536s31 # Lock time 39 146us 146us 146us 146us 146us 0146us32 # Rows sent 20 1 1 1 1 1 0 1
33 # Rows examine 90 146.78M 146.78M 146.78M 146.78M 146.78M 0 146.78M
34 # Query size 7 43 43 43 43 43 0 43
35# String:36 # Hosts 172.28.146.109
37# Users root38# Query_time distribution39# 1us40# 10us41# 100us42# 1ms43# 10ms44# 100ms45# 1s46 # 10s+################################################################47# Tables48 # SHOW TABLE STATUS LIKE 'history'\G49# SHOW CREATE TABLE `history`\G50 # EXPLAIN
51 select count(*) from history52 LIMIT 0, 1000\G53
54 # Query 2: 0 QPS, 0x concurrency, ID 0x47C7D572627422FB at byte 241______55 # This item is included in the report because it matches --limit.56 # Scores: V/M = 0.00
57 # Time range: all events occurred at 2020-04-07T06:38:39
58 # Attribute pct total min max avg 95%stddev median59 # ============ === ======= ======= ======= ======= ======= ======= =======
60 # Count 16 1
61 # Exec time 14 91s 91s 91s 91s 91s 091s62 # Lock time 27 102us 102us 102us 102us 102us 0102us63 # Rows sent 20 1 1 1 1 1 0 1
64 # Rows examine 9 14.56M 14.56M 14.56M 14.56M 14.56M 0 14.56M
65 # Query size 4 27 27 27 27 27 0 27
66# String:67# Hosts zabbix_server68# Users root69# Query_time distribution70# 1us71# 10us72# 100us73# 1ms74# 10ms75# 100ms76# 1s77 # 10s+################################################################78# Tables79 # SHOW TABLE STATUS LIKE 'trends'\G80# SHOW CREATE TABLE `trends`\G81 # EXPLAIN
82 select count(*) from trends\G
[[email protected]_server bin]#
2、分析最近10小時内的查詢
[[email protected]_server bin]# ./pt-query-digest --since=10h /home/mysql_data/mysql/zabbix_server-slow.log
3.分析指定時間範圍内的查詢
[[email protected]_server bin]# ./pt-query-digest --since='2020-04-08 00:00:00' --until='2020-04-08 11:00:00' /home/mysql_data/mysql/zabbix_server-slow.log
4.分析指含有select語句的慢查詢
[[email protected]_server bin]# ./pt-query-digest --filter '$event->{fingerprint}=~ m/^select/i' /home/mysql_data/mysql/zabbix_server-slow.log
5.針對某個使用者的慢查詢
[[email protected]_server bin]# ./pt-query-digest --filter '($event->{user}||"")=~ m/^root/i' /home/mysql_data/mysql/zabbix_server-slow.log
6.查詢所有所有的全表掃描或full join的慢查詢
[[email protected]_server bin]# ./pt-query-digest --filter '(($event->{Full_scan}||"") eq "yes")||(($event->{Full_join}||"") eq "yes")' /home/mysql_data/mysql/zabbix_server-slow.log
7.把查詢儲存到指定資料庫的query_review表
[[email protected]_server bin]# ./pt-query-digest --user=root --password=xxxxxxx --review h=172.28.18.75,D=slow_query_log,t=global_query_review /home/mysql_data/mysql/zabbix_server-slow.log
mysql>use slow_query_log;
Reading table informationforcompletion of table and column names
You can turn off this feature to get a quicker startup with-A
Database changed
mysql> select *from global_query_view;
ERROR1146 (42S02): Table 'slow_query_log.global_query_view' doesn't exist
mysql> select *from global_query_review;+----------------------+---------------------------------------------+----------------------------------------------------+---------------------+---------------------+-------------+-------------+----------+-----------------+
| checksum | fingerprint | sample | first_seen | last_seen | reviewed_by | reviewed_on | comments | reviewed_status |
+----------------------+---------------------------------------------+----------------------------------------------------+---------------------+---------------------+-------------+-------------+----------+-----------------+
| 5172337384313070331 | select count(*) from trends | select count(*) from trends | 2020-04-07 06:38:39 | 2020-04-07 06:38:39 | NULL | NULL | NULL | NULL |
| 6514775613177967797 | select count(*) from `history_uint` limit ? | select count(*) from `history_uint`
LIMIT0, 1000 | 2020-04-08 02:56:46 | 2020-04-08 02:56:46 | NULL | NULL | NULL | NULL |
| 11089716947691813430 | select count(*) from history limit ? | select count(*) from history
LIMIT0, 1000 | 2020-04-07 06:42:47 | 2020-04-07 06:42:47 | NULL | NULL | NULL | NULL |
+----------------------+---------------------------------------------+----------------------------------------------------+---------------------+---------------------+-------------+-------------+----------+-----------------+
3 rows in set (0.00 sec
已經儲存到資料表裡了