pt-query-digest[实战系列]

安装

apt install percona-toolkit

开启MySQL慢查询日志

登录MySQL
```
mysql -u root -p
```
开启慢查询日志
```
SET GLOBAL slow_query_log = 1;
```

指定慢查询日志文件的路径和文件名

SET GLOBAL slow_query_log_file = '/var/log/mysql/mysql-slow.log';

指定慢查询阈值(10秒)
```
SET GLOBAL long_query_time = 10;
```

获取慢查询日志mysql-slow.log

# Time: 2022-03-01T10:00:00.000000Z
# User@Host: test[test] @ localhost []  Id: 111
# Query_time: 0.001293  Lock_time: 0.000543 Rows_sent: 1  Rows_examined: 0
SET timestamp=1646149200;
SELECT 1;

# Time: 2022-03-01T10:00:01.000000Z
# User@Host: test[test] @ localhost []  Id: 111
# Query_time: 0.002345  Lock_time: 0.001098 Rows_sent: 10  Rows_examined: 100
SET timestamp=1646149201;
SELECT * FROM test_table WHERE id BETWEEN 1 AND 10;

# Time: 2022-03-01T10:00:02.000000Z
# User@Host: test[test] @ localhost []  Id: 111
# Query_time: 1.000012  Lock_time: 0.000000 Rows_sent: 100  Rows_examined: 1000
SET timestamp=1646149202;
SELECT * FROM test_table WHERE id BETWEEN 1 AND 100;

# Time: 2022-03-01T10:00:03.000000Z
# User@Host: test[test] @ localhost []  Id: 111
# Query_time: 0.000987  Lock_time: 0.000200 Rows_sent: 1  Rows_examined: 10
SET timestamp=1646149203;
SELECT COUNT(*) FROM test_table;

# Time: 2022-03-01T10:00:04.000000Z
# User@Host: test[test] @ localhost []  Id: 111
# Query_time: 5.000125  Lock_time: 0.000000 Rows_sent: 1000  Rows_examined: 10000
SET timestamp=1646149204;
SELECT * FROM test_table;

# Time: 2022-03-01T10:00:05.000000Z
# User@Host: test[test] @ localhost []  Id: 111
# Query_time: 0.000876  Lock_time: 0.000120 Rows_sent: 1  Rows_examined: 0
SET timestamp=1646149205;
SELECT DATABASE();

使用pt-query-digest 分析

pt-query-digest mysql-slow.log

//指定数据库
pt-query-digest mysql-slow.log --type=slowlog --filter '($event->{db} || "") =~ m/^database/i'
//指定用户
pt-query-digest mysql-slow.log --type=slowlog --filter '($event->{user} || "") =~ m/^user/i'
//指定IP
pt-query-digest mysql-slow.log --type=slowlog --filter '($event->{host} || $event->{ip} || "") =~ m/^192.168.1.*/i'
//分析指定时间范围
pt-query-digest mysql-slow.log --type=slowlog --since='2023-03-01 15:49:47' --until='2023-03-01 15:52:55'
pt-query-digest mysql-slow.log --type=slowlog --since='1583048987' --until='1583049175'
//分析最近10h
pt-query-digest test2-slow.log --type=slowlog --since='10h'
//分析指定查询:update
pt-query-digest test2-slow.log_bak --type=slowlog --filter '$event->{arg} =~ m/^update/i'
//完全体
pt-query-digest 
--user=root #
--password=root 
--port=3306 
--review h=192.168.163.132,D=slow_query_log,t=review //重复的sql只保存一条到review表用来审计
--history h=192.168.163.132,D=slow_query_log,t=history //每一条sql都会保存到history表
--limit=0% 
--filter='($event->{Bytes} = length($event->{arg}) and $event->{hostname}="test2") and ($event->{host} || $event->{ip}) !~ m/^localhost$|^192.168.163.1$/i and $event->{arg} =~ m/^select/i' 
--since='2020-03-23 12:00:00' --until='2020-03-23 13:00:00'  //各种筛选条件
/usr/local/mysql/logs/slow.log  //日志路径
--no-report //结果直接输出到表,不需要打印到终端

结果分析

//pt-query-digest执行所使用的的用户时间,系统时间,内存,虚拟内存
# 150ms user time, 20ms system time, 36.27M rss, 102.75M vsz
//pt-query-digest执行时间
# Current date: Fri Mar  3 16:37:05 2023
//主机名
# Hostname: power
//被分析的文件名
# Files: slow_query.log
//执行SQL总数,去重之后的总数,QPS,并发数
# Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
//日志记录的时间范围
# Time range: 2023-03-04T01:56:04 to 2023-03-04T02:12:07
//属性               总计       最小    最大    平均          标准    中等
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
//执行时间
# Exec time            35s      4s      9s      6s      8s      1s      5s
//锁占用时间
# Lock time            5ms    53us     5ms   905us     5ms     2ms   219us
//发送到客户端的行数
# Rows sent          2.00M       0   2.00M 341.68k   1.95M 744.61k  964.41
//扫描的语句行数
# Rows examine      11.00M   1.00M   2.00M   1.83M   1.95M 368.61k   1.95M
//查询的字节数
# Query size           963      20     408  160.50  400.73  165.68  215.41

//简况  一般看这里就能获取你想要的慢查询日志
# Profile
//查询时间倒序排名,hash id,响应时间,占用时间比率,调用次数,平均每次执行时间,V/M/,SQL语句 
# Rank Query ID           Response time Calls R/Call V/M   Item
# ==== ================== ============= ===== ====== ===== ===============
#    1 0x4B011C30D4CF7E58 15.8347 45.8%     3 5.2782  0.00 SELECT shake.person
#    2 0x2DF3B3EE79EB84C8  8.8817 25.7%     1 8.8817  0.00 INSERT SELECT person
#    3 0x17B04D5C3A71462A  5.7755 16.7%     1 5.7755  0.00 SELECT person
#    4 0xA154BD79BFEB9904  4.0845 11.8%     1 4.0845  0.00 INSERT SELECT person

//下面开始按Profile 顺序 输出每列查询的详细信息
# Query 1: 0.00 QPS, 0.02x concurrency, ID 0x4B011C30D4CF7E58 at byte 1419
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-03-04T01:57:16 to 2023-03-04T02:12:07
//属性         百分比 总数
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
//次数
# Count         50       3
# Exec time     45     16s      5s      5s      5s      5s    81ms      5s
# Lock time      8   473us    53us   314us   157us   301us   107us   103us
# Rows sent      0   2.10k     152    1000  717.33  964.41  383.43  964.41
# Rows examine  54   6.00M   2.00M   2.00M   2.00M   1.95M       0   1.95M
# Query size    15     148      49      50   49.33   49.17    0.50   46.83
# String:
# Databases    shake
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `shake` LIKE 'person'\G
#    SHOW CREATE TABLE `shake`.`person`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `shake`.`person` LIMIT 2097000,1000\G

...