Mysql慢查询日志分析及percona-toolkit的使用

开启慢查询日志

配置文件（/etc/my.cnf）里边儿，好像默认是关闭的，开了后重启下mysql服务

slow_query_log=ON    
long_query_time=3   //这儿设置的超过3s
slow_query_log_file=/var/lib/mysql/slow-log0.log	//记录慢查询日志对应的文件

测试表结构和索引

编写一个简单的存储过程，插入1000W条数据

这里查询花了3s以上了，慢查询日志里面应该是有的

分析慢查询日志的工具

mysqldumpslow

MySQL自带的慢查询日志工具，可以搜索慢查询日志中的SQL语句

常用的参数
-s：是表示按照何种方式排序

参数值	说明
c	访问计数
l	锁定时间
r	返回记录
t	查询时间
al	平均锁定时间
ar	平均返回记录数
at	平均查询时间

-t：是top n的意思，即为返回前面多少条的数据
-g：后边可以写一个正则匹配模式，大小写不敏感的

percona-toolkit

一组高级命令行工具的集合，可以查看当前服务的摘要信息，磁盘检测，分析慢查询日志，查找重复索引，实现表同步等等

• 下载

 wget https://www.percona.com/downloads/percona-toolkit/3.0.11/binary/tarball/percona-toolkit-3.0.11_x86_64.tar.gz

• 安装

 tar -xf percona-toolkit-3.0.11_x86_64.tar.gz cd percona-toolkit-3.0.11 perl Makefile.PL make make install

安装可能遇到的错误
Can’t locate ExtUtils/MakeMaker.pm in @INC

yum install -y perl-ExtUtils-CBuilder perl-ExtUtils-MakeMaker

Can’t locate Time/HiRes.pm in @INC

yum install -y perl-Time-HiRes

Can’t locate Digest/MD5.pm in @INC

yum install perl-Digest-MD5.x86_64

• 使用pt-query-digest查看慢查询日志

pt-query-digest /var/lib/mysql/slow-log0.log

• 分析pt-query-digest输出结果

第一部分：总体统计结果

# 该工具执行日志分析的用户时间，系统时间，物理内存占用大小，虚拟内存占用大小
# 160ms user time, 10ms system time, 19.00M rss, 173.37M vsz 
# 工具执行时间 
# Current date: Fri Jan 22 11:36:10 2021 
# 运行分析工具的主机名 
# Hostname: VM-0-13-centos
# 被分析的文件名 
# Files: /var/lib/mysql/slow-log0.log
# 语句总数量，唯一的语句数量，QPS，并发数
# Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
#  日志记录的时间范围
# Time range: all events occurred at 2021-01-22T02:52:21
# 属性 					总计 	最小 	最大 	平均 	95% 	标准 	中等
# Attribute 			total 	min 	max 	avg 	95% 	stddev 	median
# ============ 			======= ======= ======= ======= ======= ======= =======
# 语句执行时间
# Exec time             4s      4s      4s      4s      4s       	0      4s
# 锁占用时间
# Lock time          	171us   171us   171us   171us   171us       0   171us
# 发送到客户端的行数
# Rows sent              1       1       1       1       1       	0       1
# select语句扫描行数
# Rows examine       9.54M   9.54M   9.54M   9.54M   	9.54M       0   9.54M
# 查询的字符数
# Query size            29      29      29      29      29       	0      29

第二部分：查询分组统计结果

# Profile 
# Rank Query ID                           Response time Calls R/Call V/M 
# ==== ================================== ============= ===== ====== =====
# 1    0x460B98281ECA3A02731B68C8200D64DD 3.9450 100.0%  1 	  3.9450  0.00 SELECT tb_use

Rank：所有语句的排名，默认按查询时间降序排列，通过–orderby指定
Query ID：语句的ID，（去掉多余空格和文本字符，计算hash值）
Response：总的响应 时间
time：该查询在本次分析中总的时间占比
calls：执行次数，即本次分析总共有多少条这种类 型的查询语句 R/Call：平均每次执行的响应时间
V/M：响应时间Variance-to-mean的比率 Item： 查询对象

第三部分：每一种查询的详细统计结果 由下面查询的详细统计结果

# Query 1: 0 QPS, 0x concurrency, ID 0x460B98281ECA3A02731B68C8200D64DD at byte 0
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2021-01-22T02:52:21
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100       1
# Exec time    100      4s      4s      4s      4s      4s       0      4s
# Lock time    100   171us   171us   171us   171us   171us       0   171us
# Rows sent    100       1       1       1       1       1       0       1
# Rows examine 100   9.54M   9.54M   9.54M   9.54M   9.54M       0   9.54M
# Query size   100      29      29      29      29      29       0      29
# String:
# Databases    db_mvcc
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `db_mvcc` LIKE 'tb_user'\G
#    SHOW CREATE TABLE `db_mvcc`.`tb_user`\G
# EXPLAIN /*!50100 PARTITIONS*/
select count(id) from tb_user\G

percona-toolkit的常见用法

直接分析慢查询文件

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

分析最近12小时内的查询

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

分析指定时间范围内的查询

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

分析指含有select语句的慢查询

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

针对某个用户的慢查询

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

查询所有所有的全表扫描或full join的慢查询

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

把查询保存到query_review表

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

把查询保存到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

通过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

分析binlog

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

分析general log

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