Percona Toolkit

前两天折腾了mysqlsla，今天才发现hackmysql.com中的工具已沦为历史产物，建议使用Percona Toolkit代替。
一、下载安装

[root@VMUest tools]# wget https://www.percona.com/downloads/percona-toolkit/3.0.2/binary/tarball/percona-toolkit-3.0.2_i386.tar.gz
[root@VMUest tools]# tar xf percona-toolkit-3.0.2_i386.tar.gz -C /usr/local/
[root@VMUest tools]# cd /usr/local/
[root@VMUest local]# mv /usr/local/percona-toolkit-3.0.2/ /usr/local/toolkit

[root@VMUest local]# cd toolkit
[root@VMUest toolkit]# cat README
#配置编译安装
[root@VMUest toolkit]# perl Makefile.PL
Checking if your kit is complete...
Looks good
Warning: prerequisite DBD::mysql 3 not found.
Writing Makefile for percona-toolkit
#根据需求安装，之前mysqlsla已安装部分依赖包
[root@VMUest toolkit]# yum install perl-DBD-MySQL

[root@VMUest toolkit]# perl Makefile.PL
[root@VMUest toolkit]# make && make test && make install

完成后相关工具自动添加到环境变量，我的机器上在/usr/local/bin/目录下有对应的文件

#查看安装了哪些工具
[root@VMUest toolkit]# man percona-toolkit
#查看具体工具如何使用
[root@VMUest toolkit]# man pt-query-digest
[root@VMUest toolkit]# pt-query-digest --help

二、用法示例

#1、直接分析慢查询文件并将结果写入118slow_report.log文件
[root@VMUest ~]# pt-query-digest /myshare/118mysqldumpslow-20161227.log > /myshare/118slow_report.log
[root@VMUest ~]# pt-query-digest --group-by fingerprint --order-by Query_time:sum --limit 10 /myshare/118mysqldumpslow-20161227.log
#2、查看指定fingerprint(参数化Query ID)的语句
[root@VMUest ~]# pt-query-digest /myshare/118mysqldumpslow-20161227.log --filter '$event->{fingerprint} && make_checksum($event->{fingerprint}) eq "6C0C2937AEF1D27C"'
[root@VMUest ~]# pt-query-digest /myshare/118mysqldumpslow-20161227.log --no-report --output slowlog --filter '$event->{fingerprint} && make_checksum($event->{fingerprint}) eq "6C0C2937AEF1D27C"'
#3、指定时间范围内的查询
[root@VMUest ~]# pt-query-digest /myshare/118mysqldumpslow-20161227.log --since '2016-12-27 07:51:20' --until '2016-12-27 10:10:34'
#4、分析含有delete语句的慢查询
[root@VMUest ~]# pt-query-digest --filter '$event->{fingerprint} =~ m/^delete/i' /myshare/118mysqldumpslow-20161227.log
#5、把查询保存到query_review表
[root@VMUest ~]# pt-query-digest --user=mydba --password=mysql5635 --review h=192.168.85.129,P=3306,D=test,t=query_review /myshare/118mysqldumpslow-20161227.log
mysql> select * from test.query_review;
#6、把查询保存到query_history表
[root@VMUest ~]# pt-query-digest --user=mydba --password=mysql5635 --history h=192.168.85.129,P=3306,D=test,t=query_history /myshare/118mysqldumpslow-20161227.log
mysql> select * from test.query_history;
 
#7、分析binlog
[root@VMUest ~]# mysqlbinlog /usr/local/mysql/log/mysql-bin.000001 > /myshare/mysql-bin000001.sql
[root@VMUest ~]# pt-query-digest --type=binlog /myshare/mysql-bin000001.sql
#8、分析general log
mysql> set global general_log_file='/usr/local/mysql/log/mysql-general.log';
mysql> set global general_log =1;
[root@VMUest ~]# pt-query-digest --type=genlog /usr/local/mysql/log/mysql-general.log

三、报告解释

[root@VMUest ~]# pt-query-digest --filter '$event->{fingerprint} =~ m/^delete/i' /myshare/118mysqldumpslow-20161227.log --limit 100%

# 5.4s user time, 80ms system time, 13.06M rss, 17.15M vsz
# Current date: Fri Mar 31 17:37:00 2017
# Hostname: VMUest
# Files: /myshare/118mysqldumpslow-20161227.log
# Overall: 8 total, 2 unique, 0.00 QPS, 0.03x concurrency ________________
# Time range: 2016-12-27 00:00:28 to 00:30:35
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            56s   256us     16s      7s     15s      5s      9s
# Lock time             9s    20us      9s      1s      9s      3s   128us
# Rows sent              0       0       0       0       0       0       0
# Rows examine       2.52M       0 657.18k 322.91k 650.62k 220.00k 410.39k
# Query size           504      56      84      63   80.10   11.21   54.21

# Profile
# Rank Query ID           Response time  Calls R/Call V/M   Item
# ==== ================== ============== ===== ====== ===== ==============
#    1 0x6C0C2937AEF1D27C 56.1986 100.0%     6 9.3664  1.08 DELETE Ranking
#    2 0xE0735FE2ADE92491   0.0008  0.0%     2 0.0004  0.00 DELETE Rank

# Query 1: 0.00 QPS, 0.03x concurrency, ID 0x6C0C2937AEF1D27C at byte 5162025
# This item is included in the report because it matches --limit.
# Scores: V/M = 1.08
# Time range: 2016-12-27 00:00:28 to 00:30:35
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         75       6
# Exec time     99     56s      5s     16s      9s     15s      3s     10s
# Lock time     99      9s    20us      9s      2s      9s      3s    37us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine 100   2.52M 241.92k 657.18k 430.55k 650.62k 142.45k 487.82k
# Query size    66     336      56      56      56      56       0      56
# String:
# Databases    Zipai
# Hosts        192.168.85.129
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+  ################################
# Tables
#    SHOW TABLE STATUS FROM `Zipai` LIKE 'Ranking'G
#    SHOW CREATE TABLE `Zipai`.`Ranking`G
delete from Ranking where eventTypeID=2 and rankTypeID=7G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select * from  Ranking where eventTypeID=2 and rankTypeID=7G

# Query 2: 0 QPS, 0x concurrency, ID 0xE0735FE2ADE92491 at byte 5183064 __
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2016-12-27 00:02:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         25       2
# Exec time      0   827us   256us   571us   413us   571us   222us   413us
# Lock time      0   730us   205us   525us   365us   525us   226us   365us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    33     168      84      84      84      84       0      84
# String:
# Databases    Zipai (1/50%), test_db (1/50%)
# Hosts        %
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `Zipai` LIKE 'Rank'G
#    SHOW CREATE TABLE `Zipai`.`Rank`G
delete from Rank where typeID=16 or typeID=17 or typeID=13 or typeID=14 or typeID=15G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select * from  Rank where typeID=16 or typeID=17 or typeID=13 or typeID=14 or typeID=15G

3.1、总体统计结果

第一行：此工具执行日志分析时的所用时间、内存资源(rss物理内存占用大小，vsz虚拟内存占用大小)
第二行：分析时的系统时间
第三行：进行分析的主机名，非记录日志的数据库服务器
第四行：分析的日志文件名称
第五行：文件中总共的语句数量(Overall 8)，唯一的语句数量(对语句进行了格式化，unique 2)，QPS，并发数
Time range：查询执行的时间范围
total：总计； min：最小； max：最大； avg：平均；95%：把所有值从小到大排列，位置位于95%的那个数，这个数一般最具有参考价值；median：中位数，把所有值从小到大排列，位置位于中间那个数
Exec time：语句执行时间；Lock time：锁占有时间；Rows sent：发送到客户端的行数；Row examine：扫描的行数；Query size：查询语句的字符数
3.2、查询分组统计结果

Response time：总的响应时间以及该查询在本次分析中总的时间占比
Calls：执行次数，即本次分析总共有多少条这种类型的查询语句
R/Call：平均每次执行的响应时间
Item：查询对象
3.3、每一种查询的详细统计结果

最上面的表格列出了百分比、总计、最大、最小、平均、95%等各项目的统计
Databases：库名
Users：用户
Query_time distribution：查询时间分布, 长短体现区间占比，本例中1s-10s之间查询数量是10s以上的两倍
Tables：查询中涉及到的表
Explain：示例，非select语句会转换为select语句
14:43 2017/6/20 补充

# 参数说明
--limit        95%:20
--outliers     Query_time:1:10

limit默认返回前20条或者总响应时间占比(从大到小)累计达到95%(取最先满足的)最差的查询；outliers默认返回95%栏位的Query_time>=1秒，且执行次数>=10次。最终结果是取limit和outliers的并集。这也就是为什么显示指定limit参数，返回的结果并不全满足limit参数，还会返回匹配outliers的结果。
如果使用了--limit或(和)--outliers参数，在返回结果的第二部分"查询分组统计结果"，rank的最末行是MISC，代表那些没有计算入内的查询统计结果。详细内容参考官方文档pt-query-digest.