背景
关于pt-query-digest的使用场景和方法在percona-toolkit 之 【pt-query-digest】介绍文章里已经做了详细说明,现在开始介绍下如何使用,以及常用的命令。
使用场景
在上一篇pt-query-digest可以从logs、processlist、和tcpdump 来分析MySQL的状况,logs包括slow log、general log、binlog。也可以把分析结果输出到文件中,或则把文件写到表中。使用方法:
pt-query-digest [OPTIONS] [FILES] [DSN]
下面我们开始说明日常的一些操作方法。
一 日志类型方面
1. slow log:--type=slowlog
属性:属性=values
$VAR1 = { Lock_time => '0.000122', Query_time => '6.405714', Rows_examined => '8', Rows_sent => '8', Thread_id => '165', arg => 'select user,host,sleep(0.8) from user', bytes => 37, cmd => 'Query', db => 'mysql', fingerprint => 'select user,host,sleep(?) from user', host => '192.168.100.222', ip => '192.168.163.132', pos_in_log => 4779, timestamp => '1583111641', ts => '2020-03-02T01:14:01', user => 'zjy' };
分析报告分为二部分说明:
第一部分:总体概况说明
-- 分析消耗的用户CPU时间,系统CPU时间,物理内存占用大小,虚拟内存占用大小 # 190ms user time, 10ms system time, 34.25M rss, 98.80M vsz -- 分析的当前日期 # Current date: Sun Mar 1 23:55:53 2020 -- 分析的主机名 # Hostname: test2 -- 分析的文件名 # Files: test2-slow.log -- 分析的整体情况:语句总数量,唯一语句数量,QPS和并发数 # Overall: 8 total, 4 unique, 0.03 QPS, 0.08x concurrency ________________ -- 分析日志的时间范围 # Time range: 2020-03-01T15:49:47 to 2020-03-01T15:54:16 --属性 总计 最小 最大 平均 95% 标准 中等 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= -- 执行时间 # Exec time 21s 2s 5s 3s 5s 986ms 2s -- 锁时间 # Lock time 16ms 190us 6ms 2ms 6ms 2ms 2ms -- 发送到客户端的行数 # Rows sent 36 3 10 4.50 9.83 2.10 3.89 -- 扫描行数 # Rows examine 36 3 10 4.50 9.83 2.10 3.89 -- 查询的字节数 # Query size 451 30 65 56.38 62.76 13.61 62.76 /*如果在此地方想新增一些属性,可以用--filter来进行设置 比如:--filter '($event->{Row_ratio} = $event->{Rows_sent}/($event->{Rows_examined}))' ,会新增Row ratio属性*/ -- 概况统计 # Profile -- 排名,查询指纹,总响应时间及百分比,执行次数,执行平均响应时间,响应时间Variance-to-mean的比率,查询对象 # Rank Query ID Response time Calls R/Call V/M # ==== ================================== ============= ===== ====== ===== # 1 0x5C3D88030F0258F752A830BD792DF4BA 10.0392 47.7% 5 2.0078 0.00 SELECT host # 2 0x02DFE94A93ADC62623BF2E1E98C17EC3 5.0108 23.8% 1 5.0108 0.00 SELECT host # 3 0x6D482C964694712F6B3445151D7A429C 3.0108 14.3% 1 3.0108 0.00 SELECT x # 4 0x8430AB741BBC096B102EDAA5ACD08366 3.0033 14.3% 1 3.0033 0.00 SELECT x
# MISC 0xMISC 2.0002 3.3% 1 2.9911 0.00 <35 ITEMS> #剩余查询的显示
第二部分:查询SQL概况说明
-- 查询的顺序号(和第一部分的Rank对应),QPS,并发,查询指纹, # Query 1: 0.08 QPS, 0.16x concurrency, ID 0x5C3D88030F0258F752A830BD792DF4BA at byte 739 # This item is included in the report because it matches --limit. -- 响应比率 # Scores: V/M = 0.00 -- 分析查询的时间范围 # Time range: 2020-03-01T15:53:12 to 2020-03-01T15:54:16 -- 属性,百分比,总数,最小,最大,95%,标准,中等 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= -- 次数 # Count 55 5 -- 执行时间 # Exec time 38 10s 2s 2s 2s 2s 0 2s -- 锁时间 # Lock time 38 7ms 209us 6ms 1ms 6ms 2ms 273us -- 发送到客户端的行数 # Rows sent 43 20 4 4 4 4 0 4 -- 扫描行数 # Rows examine 43 20 4 4 4 4 0 4 -- 查询的字节数 # Query size 63 325 65 65 65 65 0 65 -- 发送和扫描行数比值,用第一部分提到的--filter来进行设置 # Row ratio 55 5 1 1 1 1 0 1 # String: -- 数据库 # Databases test -- 主机 # Hosts test2 -- 查询用户 # Users root -- 查询执行时间分布的直方图:1微妙、10微妙、100微妙、10毫秒、100毫秒,1秒,10秒以上查询的分布情况 # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ -- 表信息 # Tables # SHOW TABLE STATUS FROM `test` LIKE 'host'\G # SHOW CREATE TABLE `test`.`host`\G -- 执行计划信息 # EXPLAIN /*!50100 PARTITIONS*/ -- 查询SQL select id,hostname,agent_version,sleep(0.5) from host where id <5\G #如果是非select查询:insert,delete,update,则会转换成select进行explain
使用场景:
①:分析所有的慢查询:
pt-query-digest test2-slow.log --type=slowlog
# 180ms user time, 10ms system time, 34.17M rss, 98.79M vsz # Current date: Mon Mar 2 00:50:10 2020 # Hostname: test2 # Files: test2-slow.log # Overall: 15 total, 4 unique, 0.01 QPS, 0.02x concurrency _______________ # Time range: 2020-03-01T15:49:47 to 2020-03-01T16:32:44 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # Exec time 55s 2s 6s 4s 5s 1s 3s # Lock time 20ms 126us 6ms 1ms 6ms 2ms 273us # Rows sent 99 3 10 6.60 9.83 3.17 3.89 # Rows examine 99 3 10 6.60 9.83 3.17 3.89 # Query size 853 30 65 56.87 62.76 12.41 59.77 # Profile # Rank Query ID Response time Calls R/Call V/M # ==== ================================== ============= ===== ====== ===== # 1 0x02DFE94A93ADC62623BF2E1E98C17EC3 35.6617 65.2% 7 5.0945 0.01 SELECT host # 2 0x5C3D88030F0258F752A830BD792DF4BA 10.0392 18.3% 5 2.0078 0.00 SELECT host # 3 0x6D482C964694712F6B3445151D7A429C 6.0137 11.0% 2 3.0069 0.00 SELECT x # 4 0x8430AB741BBC096B102EDAA5ACD08366 3.0033 5.5% 1 3.0033 0.00 SELECT x # Query 1: 0.00 QPS, 0.02x concurrency, ID 0x02DFE94A93ADC62623BF2E1E98C17EC3 at byte 3120 # This item is included in the report because it matches --limit. # Scores: V/M = 0.01 # Time range: 2020-03-01T15:52:55 to 2020-03-01T16:31:56 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 46 7 # Exec time 65 36s 5s 6s 5s 5s 178ms 5s # Lock time 30 6ms 126us 3ms 863us 2ms 1ms 214us # Rows sent 70 70 10 10 10 10 0 10 # Rows examine 70 70 10 10 10 10 0 10 # Query size 50 434 62 62 62 62 0 62 # String: # Databases test # Hosts test2 # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # Tables # SHOW TABLE STATUS FROM `test` LIKE 'host'\G # SHOW CREATE TABLE `test`.`host`\G # EXPLAIN /*!50100 PARTITIONS*/ select id,hostname,agent_version,sleep(0.5) from host limit 10\G # Query 2: 0.08 QPS, 0.16x concurrency, ID 0x5C3D88030F0258F752A830BD792DF4BA at byte 739 # This item is included in the report because it matches --limit. # Scores: V/M = 0.00 # Time range: 2020-03-01T15:53:12 to 2020-03-01T15:54:16 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 33 5 # Exec time 18 10s 2s 2s 2s 2s 0 2s # Lock time 36 7ms 209us 6ms 1ms 6ms 2ms 273us # Rows sent 20 20 4 4 4 4 0 4 # Rows examine 20 20 4 4 4 4 0 4 # Query size 38 325 65 65 65 65 0 65 # String: # Databases test # Hosts test2 # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # Tables # SHOW TABLE STATUS FROM `test` LIKE 'host'\G # SHOW CREATE TABLE `test`.`host`\G # EXPLAIN /*!50100 PARTITIONS*/ select id,hostname,agent_version,sleep(0.5) from host where id <5\G # Query 3: 0.00 QPS, 0.00x concurrency, ID 0x6D482C964694712F6B3445151D7A429C at byte 0 # This item is included in the report because it matches --limit. # Scores: V/M = 0.00 # Time range: 2020-03-01T15:49:47 to 2020-03-01T16:32:44 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 13 2 # Exec time 10 6s 3s 3s 3s 3s 6ms 3s # Lock time 32 6ms 301us 6ms 3ms 6ms 4ms 3ms # Rows sent 6 6 3 3 3 3 0 3 # Rows examine 6 6 3 3 3 3 0 3 # Query size 7 60 30 30 30 30 0 30 # String: # Databases test # Hosts test2 # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # Tables # SHOW TABLE STATUS FROM `test` LIKE 'x'\G # SHOW CREATE TABLE `test`.`x`\G # EXPLAIN /*!50100 PARTITIONS*/ select id,name,sleep(1) from x\G # Query 4: 0 QPS, 0x concurrency, ID 0x8430AB741BBC096B102EDAA5ACD08366 at byte 241 # This item is included in the report because it matches --limit. # Scores: V/M = 0.00 # Time range: all events occurred at 2020-03-01T15:50:02 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 6 1 # Exec time 5 3s 3s 3s 3s 3s 0 3s # Lock time 0 190us 190us 190us 190us 190us 0 190us # Rows sent 3 3 3 3 3 3 0 3 # Rows examine 3 3 3 3 3 3 0 3 # Query size 3 34 34 34 34 34 0 34 # String: # Databases test # Hosts test2 # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # Tables # SHOW TABLE STATUS FROM `test` LIKE 'x'\G # SHOW CREATE TABLE `test`.`x`\G # EXPLAIN /*!50100 PARTITIONS*/ select id,name,age,sleep(1) from x\G