IT教程 ·

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【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 <5G    #假如黑白select查询:insert,delete,update,则会转换成select举行explain

运用场景:

①:剖析一切的慢查询:

pt-query-digest test2-slow.log --type=slowlog

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 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 10G

# 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 <5G

# 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 xG

# 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 xG

View Code

②:剖析指定数据库的慢查询:

pt-query-digest test2-slow.log --type=slowlog --filter '($event->{db} || "") =~ m/^mysql/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 170ms user time, 20ms system time, 34.21M rss, 98.80M vsz
# Current date: Mon Mar  2 09:17:19 2020
# Hostname: test2
# Files: test2-slow.log
# Overall: 4 total, 1 unique, 0.07 QPS, 0.34x concurrency ________________
# Time range: 2020-03-02T01:13:07 to 2020-03-02T01:14:01
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            18s      4s      6s      5s      6s      1s      4s
# Lock time            3ms   122us     3ms   871us     3ms     1ms     2ms
# Rows sent             32       8       8       8       8       0       8
# Rows examine          32       8       8       8       8       0       8
# Query size           148      37      37      37      37       0      37

# Profile
# Rank Query ID                           Response time  Calls R/Call V/M 
# ==== ================================== ============== ===== ====== ====
#    1 0x1AD46E75EF3D662BDE818F1F36DC02DD 18.4270 100.0%     4 4.6067  0.24 SELECT user

# Query 1: 0.07 QPS, 0.34x concurrency, ID 0x1AD46E75EF3D662BDE818F1F36DC02DD at byte 4782
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.24
# Time range: 2020-03-02T01:13:07 to 2020-03-02T01:14:01
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100       4
# Exec time    100     18s      4s      6s      5s      6s      1s      4s
# Lock time    100     3ms   122us     3ms   871us     3ms     1ms     2ms
# Rows sent    100      32       8       8       8       8       0       8
# Rows examine 100      32       8       8       8       8       0       8
# Query size   100     148      37      37      37      37       0      37
# String:
# Databases    mysql
# Hosts        test2
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `mysql` LIKE 'user'G
#    SHOW CREATE TABLE `mysql`.`user`G
# EXPLAIN /*!50100 PARTITIONS*/
select user,host,sleep(0.8) from userG

View Code

③:剖析指定用户的慢查询:

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

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 180ms user time, 0 system time, 34.13M rss, 98.80M vsz
# Current date: Mon Mar  2 09:20:30 2020
# Hostname: test2
# Files: test2-slow.log
# Overall: 4 total, 1 unique, 0.07 QPS, 0.34x concurrency ________________
# Time range: 2020-03-02T01:13:07 to 2020-03-02T01:14:01
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            18s      4s      6s      5s      6s      1s      4s
# Lock time            3ms   122us     3ms   871us     3ms     1ms     2ms
# Rows sent             32       8       8       8       8       0       8
# Rows examine          32       8       8       8       8       0       8
# Query size           148      37      37      37      37       0      37

# Profile
# Rank Query ID                           Response time  Calls R/Call V/M 
# ==== ================================== ============== ===== ====== ====
#    1 0x1AD46E75EF3D662BDE818F1F36DC02DD 18.4270 100.0%     4 4.6067  0.24 SELECT user

# Query 1: 0.07 QPS, 0.34x concurrency, ID 0x1AD46E75EF3D662BDE818F1F36DC02DD at byte 4779
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.24
# Time range: 2020-03-02T01:13:07 to 2020-03-02T01:14:01
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100       4
# Exec time    100     18s      4s      6s      5s      6s      1s      4s
# Lock time    100     3ms   122us     3ms   871us     3ms     1ms     2ms
# Rows sent    100      32       8       8       8       8       0       8
# Rows examine 100      32       8       8       8       8       0       8
# Query size   100     148      37      37      37      37       0      37
# String:
# Databases    mysql
# Hosts        test2
# Users        zjy
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `mysql` LIKE 'user'G
#    SHOW CREATE TABLE `mysql`.`user`G
# EXPLAIN /*!50100 PARTITIONS*/
select user,host,sleep(0.8) from userG

View Code

④:剖析指定IP的慢查询:

pt-query-digest test2-slow.log --type=slowlog --filter '($event->{host} || $event->{ip} || "") =~ m/^192.168.100.*/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 170ms user time, 20ms system time, 33.98M rss, 98.67M vsz
# Current date: Mon Mar  2 09:28:51 2020
# Hostname: test2
# Files: test2-slow.log
# Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
# Time range: all events occurred at 2020-03-02T01:14:01
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time             6s      6s      6s      6s      6s       0      6s
# Lock time          122us   122us   122us   122us   122us       0   122us
# Rows sent              8       8       8       8       8       0       8
# Rows examine           8       8       8       8       8       0       8
# Query size            37      37      37      37      37       0      37

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x1AD46E75EF3D662BDE818F1F36DC02DD 6.4057 100.0%     1 6.4057  0.00 SELECT user

# Query 1: 0 QPS, 0x concurrency, ID 0x1AD46E75EF3D662BDE818F1F36DC02DD at byte 4779
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-03-02T01:14:01
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100       1
# Exec time    100      6s      6s      6s      6s      6s       0      6s
# Lock time    100   122us   122us   122us   122us   122us       0   122us
# Rows sent    100       8       8       8       8       8       0       8
# Rows examine 100       8       8       8       8       8       0       8
# Query size   100      37      37      37      37      37       0      37
# String:
# Databases    mysql
# Hosts        192.168.100.222
# Users        zjy
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `mysql` LIKE 'user'G
#    SHOW CREATE TABLE `mysql`.`user`G
# EXPLAIN /*!50100 PARTITIONS*/
select user,host,sleep(0.8) from userG

View Code

⑤:剖析指定时刻局限的慢查询:

pt-query-digest test2-slow.log --type=slowlog --since='2020-03-01 15:49:47' --until='2020-03-01 15:52:55'
pt-query-digest test2-slow.log --type=slowlog --since='1583048987' --until='1583049175'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 170ms user time, 20ms system time, 34.03M rss, 98.80M vsz
# Current date: Mon Mar  2 10:05:52 2020
# Hostname: test2
# Files: test2-slow.log
# Overall: 2 total, 2 unique, 0.13 QPS, 0.40x concurrency ________________
# Time range: 2020-03-01T15:49:47 to 2020-03-01T15:50:02
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time             6s      3s      3s      3s      3s     5ms      3s
# Lock time            6ms   190us     6ms     3ms     6ms     4ms     3ms
# Rows sent              6       3       3       3       3       0       3
# Rows examine           6       3       3       3       3       0       3
# Query size            64      30      34      32      34    2.83      32

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x6D482C964694712F6B3445151D7A429C  3.0108 50.1%     1 3.0108  0.00 SELECT x
#    2 0x8430AB741BBC096B102EDAA5ACD08366  3.0033 49.9%     1 3.0033  0.00 SELECT x

# Query 1: 0 QPS, 0x concurrency, ID 0x6D482C964694712F6B3445151D7A429C 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 2020-03-01T15:49:47
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         50       1
# Exec time     50      3s      3s      3s      3s      3s       0      3s
# Lock time     96     6ms     6ms     6ms     6ms     6ms       0     6ms
# Rows sent     50       3       3       3       3       3       0       3
# Rows examine  50       3       3       3       3       3       0       3
# Query size    46      30      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 xG

# Query 2: 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         50       1
# Exec time     49      3s      3s      3s      3s      3s       0      3s
# Lock time      3   190us   190us   190us   190us   190us       0   190us
# Rows sent     50       3       3       3       3       3       0       3
# Rows examine  50       3       3       3       3       3       0       3
# Query size    53      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 xG

View Code

⑥:剖析近来时刻的慢查询(近来10h,单元能够为s、和m):

pt-query-digest test2-slow.log --type=slowlog --since='10h'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 150ms user time, 20ms system time, 34.22M rss, 98.80M vsz
# Current date: Mon Mar  2 10:13:55 2020
# Hostname: test2
# Files: test2-slow.log
# Overall: 4 total, 1 unique, 0.07 QPS, 0.34x concurrency ________________
# Time range: 2020-03-02T01:13:07 to 2020-03-02T01:14:01
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            18s      4s      6s      5s      6s      1s      4s
# Lock time            3ms   122us     3ms   871us     3ms     1ms     2ms
# Rows sent             32       8       8       8       8       0       8
# Rows examine          32       8       8       8       8       0       8
# Query size           148      37      37      37      37       0      37

# Profile
# Rank Query ID                           Response time  Calls R/Call V/M 
# ==== ================================== ============== ===== ====== ====
#    1 0x1AD46E75EF3D662BDE818F1F36DC02DD 18.4270 100.0%     4 4.6067  0.24 SELECT user

# Query 1: 0.07 QPS, 0.34x concurrency, ID 0x1AD46E75EF3D662BDE818F1F36DC02DD at byte 4779
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.24
# Time range: 2020-03-02T01:13:07 to 2020-03-02T01:14:01
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100       4
# Exec time    100     18s      4s      6s      5s      6s      1s      4s
# Lock time    100     3ms   122us     3ms   871us     3ms     1ms     2ms
# Rows sent    100      32       8       8       8       8       0       8
# Rows examine 100      32       8       8       8       8       0       8
# Query size   100     148      37      37      37      37       0      37
# String:
# Databases    mysql
# Hosts        test2 (3/75%), 192.168.100.222 (1/25%)
# Users        zjy
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `mysql` LIKE 'user'G
#    SHOW CREATE TABLE `mysql`.`user`G
# EXPLAIN /*!50100 PARTITIONS*/
select user,host,sleep(0.8) from userG

View Code

⑦:剖析指定查询范例的慢查询:

pt-query-digest test2-slow.log_bak --type=slowlog --filter '$event->{arg} =~ m/^update/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 160ms user time, 0 system time, 33.95M rss, 98.80M vsz
# Current date: Mon Mar  2 10:54:08 2020
# Hostname: test2
# Files: test2-slow.log_bak
# Overall: 2 total, 2 unique, 0.00 QPS, 0.00x concurrency ________________
# Time range: 2020-02-28T10:49:02 to 2020-02-28T12:59:04
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            14s      6s      8s      7s      8s      1s      7s
# Lock time            6ms     2ms     4ms     3ms     4ms     1ms     3ms
# Rows sent             10       2       8       5       8    4.24       5
# Rows examine          10       2       8       5       8    4.24       5
# Query size            89      36      53   44.50      53   12.02   44.50

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x85DD43B595DF4DE2480E3EA0F1B26C9F  8.0111 57.2%     1 8.0111  0.00 UPDATE user sleep mysql.user
#    2 0x836D2825542008408981DFD394A2EB60  6.0065 42.8%     1 6.0065  0.00 UPDATE cluster_name sleep cluster_domain_name

# Query 1: 0 QPS, 0x concurrency, ID 0x85DD43B595DF4DE2480E3EA0F1B26C9F at byte 1614
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-02-28T12:59:04
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         50       1
# Exec time     57      8s      8s      8s      8s      8s       0      8s
# Lock time     37     2ms     2ms     2ms     2ms     2ms       0     2ms
# Rows sent     80       8       8       8       8       8       0       8
# Rows examine  80       8       8       8       8       8       0       8
# Query size    40      36      36      36      36      36       0      36
# String:
# Databases    mysql
# Hosts        test2
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `mysql` LIKE 'user'G
#    SHOW CREATE TABLE `mysql`.`user`G
#    SHOW TABLE STATUS FROM `mysql` LIKE 'sleep'G
#    SHOW CREATE TABLE `mysql`.`sleep`G
#    SHOW TABLE STATUS FROM `mysql` LIKE 'user'G
#    SHOW CREATE TABLE `mysql`.`user`G
update user,sleep(1) from mysql.userG

# Query 2: 0 QPS, 0x concurrency, ID 0x836D2825542008408981DFD394A2EB60 at byte 1118
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-02-28T10:49:02
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         50       1
# Exec time     42      6s      6s      6s      6s      6s       0      6s
# Lock time     62     4ms     4ms     4ms     4ms     4ms       0     4ms
# Rows sent     20       2       2       2       2       2       0       2
# Rows examine  20       2       2       2       2       2       0       2
# Query size    59      53      53      53      53      53       0      53
# String:
# Databases    orchestrator
# Hosts        192.168.163.111
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `orchestrator` LIKE 'cluster_name'G
#    SHOW CREATE TABLE `orchestrator`.`cluster_name`G
#    SHOW TABLE STATUS FROM `orchestrator` LIKE 'sleep'G
#    SHOW CREATE TABLE `orchestrator`.`sleep`G
#    SHOW TABLE STATUS FROM `orchestrator` LIKE 'cluster_domain_name'G
#    SHOW CREATE TABLE `orchestrator`.`cluster_domain_name`G
update cluster_name,sleep(3) from cluster_domain_nameG

View Code

⑧:后续补充中...

2. general log:--type=genlog

属性:

$VAR1 = {
  Query_time => 0,
  Thread_id => '138',
  arg => 'SHOW FULL PROCESSLIST',
  bytes => 21,
  cmd => 'Query',
  db => 'mysql',
  fingerprint => 'show full processlist',
  pos_in_log => 191402,
  ts => '2020-02-29T12:21:53.692656Z'
};

general log 和 slow log的最大区别是--order-by默许从Query_time:sum改成了Query_time:cnt。general log没有实行时刻。

剖析报告分为二部份申明:

第一部份:团体概略申明,同上面的slow log。

第二部份:查询SQL概略申明。

# Query 1: 0 QPS, 0x concurrency, ID 0x0BBD8F114BF69E6F45609ADE347419D3 at byte 1075144
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2020-02-29T09:38:40.431645Z to 2020-02-29T17:03:19.210317Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
-- 次数
# Count         96   16463
-- 实行时刻
# Exec time      0       0       0       0       0       0       0       0
-- 查询字节数
# Query size    90 337.62k      21      21      21      21       0      21
# String:
# Databases    mysql
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
SHOW FULL PROCESSLISTG

①:剖析一切general log:

pt-query-digest test2.log --type=genlog

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 1.1s user time, 10ms system time, 37.23M rss, 101.77M vsz
# Current date: Mon Mar  2 11:54:58 2020
# Hostname: test2
# Files: test2.log
# Overall: 17.15k total, 36 unique, 0 QPS, 0x concurrency ________________
# Time range: 2020-02-29T08:16:40.412968Z to 2020-03-02T02:47:33.305124Z
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size       371.27k       9     215   22.17   20.43   11.62   20.43

# Profile
# Rank Query ID                      Response time Calls R/Call V/M   Item
# ==== ============================= ============= ===== ====== ===== ====
#    1 0x0BBD8F114BF69E6F45609ADE...  0.0000  0.0% 16463 0.0000  0.00 SHOW PROCESSLIST
#    2 0x7417646A9FE969365D51E5F0...  0.0000  0.0%   150 0.0000  0.00 ADMIN CONNECT
# MISC 0xMISC                         0.0000  0.0%   533 0.0000   0.0 <34 ITEMS>

# Query 1: 0 QPS, 0x concurrency, ID 0x0BBD8F114BF69E6F45609ADE347419D3 at byte 1075144
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2020-02-29T09:38:40.431645Z to 2020-02-29T17:03:19.210317Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         96   16463
# Exec time      0       0       0       0       0       0       0       0
# Query size    90 337.62k      21      21      21      21       0      21
# String:
# Databases    mysql
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
SHOW FULL PROCESSLISTG

# Query 2: 0 QPS, 0x concurrency, ID 0x7417646A9FE969365D51E5F01B88B79E at byte 1079129
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2020-02-29T08:16:42.510608Z to 2020-03-02T02:47:30.977613Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     150
# Exec time      0       0       0       0       0       0       0       0
# Query size     1   4.39k      30      30      30      30       0      30
# String:
# Databases    mysql (146/97%), test (3/2%), xyz (1/0%)
# Hosts        test2 (148/98%), localhost (2/1%)
# Users        root (148/98%), debian-sys... (2/1%)
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
administrator command: ConnectG

View Code

②:剖析指定数据库的general log:

pt-query-digest test2.log --type=genlog --filter '($event->{db} || "") =~ m/^xyz/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 760ms user time, 0 system time, 33.97M rss, 98.79M vsz
# Current date: Mon Mar  2 11:58:25 2020
# Hostname: test2
# Files: test2.log
# Overall: 19 total, 7 unique, 0 QPS, 0x concurrency _____________________
# Time range: 2020-02-29T08:16:42.510608Z to 2020-03-02T03:57:21.856375Z
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size           374      11      32   19.68   28.75    5.67   16.81

# Profile
# Rank Query ID                          Response time Calls R/Call V/M   
# ==== ================================= ============= ===== ====== ===== 
#    1 0x13CE8196A68B6EDD5056FEA7A295...  0.0000  0.0%    11 0.0000  0.00 SELECT opa
# MISC 0xMISC                             0.0000  0.0%     8 0.0000   0.0 <6 ITEMS>

# Query 1: 0 QPS, 0x concurrency, ID 0x13CE8196A68B6EDD5056FEA7A29521B5 at byte 1079780
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2020-02-29T08:16:53.573687Z to 2020-03-02T03:56:54.493066Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         57      11
# Exec time      0       0       0       0       0       0       0       0
# Query size    50     187      17      17      17      17       0      17
# String:
# Databases    xyz
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `xyz` LIKE 'opa'G
#    SHOW CREATE TABLE `xyz`.`opa`G
# EXPLAIN /*!50100 PARTITIONS*/
select * from opaG

View Code

③:剖析指定用户的general log:

pt-query-digest test2.log --type=genlog --filter '($event->{user} || "") =~ m/^rep/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 760ms user time, 40ms system time, 34.09M rss, 98.66M vsz
# Current date: Mon Mar  2 12:01:37 2020
# Hostname: test2
# Files: test2.log
# Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
# Time range: all events occurred at 2020-03-02T04:01:10.355849Z
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size            30      30      30      30      30       0      30

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x7417646A9FE969365D51E5F01B88B79E  0.0000  0.0%     1 0.0000  0.00 ADMIN CONNECT

# Query 1: 0 QPS, 0x concurrency, ID 0x7417646A9FE969365D51E5F01B88B79E at byte 1080607
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-03-02T04:01:10.355849Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100       1
# Exec time      0       0       0       0       0       0       0       0
# Query size   100      30      30      30      30      30       0      30
# String:
# Databases    xyz
# Hosts        test2
# Users        rep
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
administrator command: ConnectG

View Code

④:剖析指定IP的general log:只能查询有衔接信息的一行

pt-query-digest test2.log --type=genlog --filter '($event->{host} || $event->{ip} || "") =~ m/^192.168.163.1/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 680ms user time, 10ms system time, 34.10M rss, 98.67M vsz
# Current date: Mon Mar  2 12:07:37 2020
# Hostname: test2
# Files: test2.log
# Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
# Time range: all events occurred at 2020-03-02T04:04:44.525323Z
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size            30      30      30      30      30       0      30

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x7417646A9FE969365D51E5F01B88B79E  0.0000  0.0%     1 0.0000  0.00 ADMIN CONNECT

# Query 1: 0 QPS, 0x concurrency, ID 0x7417646A9FE969365D51E5F01B88B79E at byte 1080854
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-03-02T04:04:44.525323Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100       1
# Exec time      0       0       0       0       0       0       0       0
# Query size   100      30      30      30      30      30       0      30
# String:
# Databases    xyz
# Hosts        192.168.163.1
# Users        rep
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
administrator command: ConnectG

View Code

⑤:剖析指定时刻局限的general log:

由于since、until是和属性ts举行比较的,而ts示意慢查询的timestamp,general log的ts花样不支持。

Argument "2020-03-02T03:56:40.729571Z" isn't numeric in numeric ge (>=) at /usr/bin/pt-query-digest line 13828

⑥:剖析指定查询范例的general log:

pt-query-digest test2.log --type=genlog --filter '$event->{arg} =~ m/^update/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 800ms user time, 20ms system time, 34.14M rss, 98.66M vsz
# Current date: Mon Mar  2 12:53:22 2020
# Hostname: test2
# Files: test2.log
# Overall: 3 total, 2 unique, 0 QPS, 0x concurrency ______________________
# Time range: 2020-03-01T15:51:00.127775Z to 2020-03-01T15:51:41.615228Z
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size           117      29      44      39   42.48    6.47   42.48

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x80ADD689782BEAD7D70ED30064A844AE  0.0000  0.0%     2 0.0000  0.00 UPDATE host
#    2 0xD2D49F3A84020704D76F13F185D17AF0  0.0000  0.0%     1 0.0000  0.00 UPDATE host

# Query 1: 0 QPS, 0x concurrency, ID 0x80ADD689782BEAD7D70ED30064A844AE at byte 1076295
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2020-03-01T15:51:00.127775Z to 2020-03-01T15:51:41.615228Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         66       2
# Exec time      0       0       0       0       0       0       0       0
# Query size    75      88      44      44      44      44       0      44
# String:
# Databases    test
# 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
update host set hostname = concat('test',id)G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  hostname = concat('test',id) from host G

# Query 2: 0 QPS, 0x concurrency, ID 0xD2D49F3A84020704D76F13F185D17AF0 at byte 1076124
# 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:51:18.804090Z
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         33       1
# Exec time      0       0       0       0       0       0       0       0
# Query size    24      29      29      29      29      29       0      29
# String:
# Databases    test
# 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
update host set hostname = ''G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  hostname = '' from host G

View Code

⑦:后续补充中...

3. binlog:--type=binlog

属性:

$VAR1 = {
  Query_time => '0',
  Thread_id => '176',
  arg => '...',
  bytes => 40,
  cmd => 'Query',
  db => 'xyz',
  end_log_pos => '695',
  error_code => '0',
  fingerprint => '...',
  offset => '583',
  pos_in_log => 1942,
  server_id => '1',
  timestamp => '1583133657',
  ts => '200302 15:20:57'
};

注重: 在测试的时刻发明,binlog假如是ROW形式,则剖析不出SQL信息?

由于没有用户(user)、IP属性,所以不能经由过程它们剖析。

准备:在剖析binlog之前,须要先把binlog转换成文本:

 mysqlbinlog --no-defaults -vv --base64-output=DECODE-ROWS mysql-bin.000053 >mysql-bin.000053.txt

① 剖析一切binlog:

pt-query-digest /var/log/mysql/mysql-bin.000053.txt --type=binlog

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 150ms user time, 30ms system time, 34.53M rss, 99.06M vsz
# Current date: Mon Mar  2 15:43:19 2020
# Hostname: test2
# Files: /var/log/mysql/mysql-bin.000053.txt
# Overall: 4 total, 6 unique, 0.03 QPS, 0x concurrency ___________________
# Time range: 2020-03-02 15:18:30 to 15:20:57
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size           213       5      71   30.43   69.19   23.03   38.53
# @@session.au           1       1       1       1       1       0       1
# @@session.au           1       1       1       1       1       0       1
# @@session.au           1       1       1       1       1       0       1
# @@session.ch          33      33      33      33      33       0      33
# @@session.co          33      33      33      33      33       0      33
# @@session.co           8       8       8       8       8       0       8
# @@session.fo           1       1       1       1       1       0       1
# @@session.lc           0       0       0       0       0       0       0
# @@session.ps         176     176     176     176     176       0     176
# @@session.sq           0       0       0       0       0       0       0
# @@session.sq       1.34G   1.34G   1.34G   1.34G   1.34G       0   1.34G
# @@session.un           1       1       1       1       1       0       1
# error code             0       0       0       0       0       0       0

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x82CE37495437A097404F41D8B9BC40F5  0.0000  0.0%     1 0.0000  0.00 UPDATE opa
#    2 0x8D589AFA4DFAEEED85FFF5AA78E5FF6A  0.0000  0.0%     2 0.0000  0.00 BEGIN
#    3 0x22F19246E8077C1AD6C6EBCA2A2AA193  0.0000  0.0%     1 0.0000  0.00 UPDATE opa

# Query 1: 0 QPS, 0x concurrency, ID 0x82CE37495437A097404F41D8B9BC40F5 at byte 1942
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-03-02 15:20:57
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         25       1
# Exec time      0       0       0       0       0       0       0       0
# Query size    18      40      40      40      40      40       0      40
# error code     0       0       0       0       0       0       0       0
# String:
# Databases    xyz
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `xyz` LIKE 'opa'G
#    SHOW CREATE TABLE `xyz`.`opa`G
update opa set name = concat(id,name,id)G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  name = concat(id,name,id) from opa G

# Query 2: 0.01 QPS, 0x concurrency, ID 0x8D589AFA4DFAEEED85FFF5AA78E5FF6A at byte 1780
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2020-03-02 15:18:30 to 15:20:57
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         50       2
# Exec time      0       0       0       0       0       0       0       0
# Query size     4      10       5       5       5       5       0       5
# @@session.au 100       1       1       1       1       1       0       1
# @@session.au 100       1       1       1       1       1       0       1
# @@session.au 100       1       1       1       1       1       0       1
# @@session.ch 100      33      33      33      33      33       0      33
# @@session.co 100      33      33      33      33      33       0      33
# @@session.co 100       8       8       8       8       8       0       8
# @@session.fo 100       1       1       1       1       1       0       1
# @@session.lc   0       0       0       0       0       0       0       0
# @@session.ps 100     176     176     176     176     176       0     176
# @@session.sq   0       0       0       0       0       0       0       0
# @@session.sq 100   1.34G   1.34G   1.34G   1.34G   1.34G       0   1.34G
# @@session.un 100       1       1       1       1       1       0       1
# error code     0       0       0       0       0       0       0       0
# String:
# @@session.co default
# Databases    xyz
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
BEGING

# Query 3: 0 QPS, 0x concurrency, ID 0x22F19246E8077C1AD6C6EBCA2A2AA193 at byte 1289
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-03-02 15:18:30
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         25       1
# Exec time      0       0       0       0       0       0       0       0
# Query size    19      42      42      42      42      42       0      42
# error code     0       0       0       0       0       0       0       0
# String:
# Databases    xyz
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `xyz` LIKE 'opa'G
#    SHOW CREATE TABLE `xyz`.`opa`G
update opa set name = concat(name,id,name)G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  name = concat(name,id,name) from opa G

View Code

②:剖析指定数据库的bin log:

 pt-query-digest /var/log/mysql/mysql-bin.000053.txt --type=binlog --filter '($event->{db} || "") =~ m/^xyz/i'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 160ms user time, 20ms system time, 33.99M rss, 98.66M vsz
# Current date: Mon Mar  2 15:45:49 2020
# Hostname: test2
# Files: /var/log/mysql/mysql-bin.000053.txt
# Overall: 3 total, 6 unique, 0.02 QPS, 0x concurrency ___________________
# Time range: 2020-03-02 15:18:30 to 15:20:57
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size           208       5      71   34.67   69.19   22.41   41.47
# error code             0       0       0       0       0       0       0

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x82CE37495437A097404F41D8B9BC40F5  0.0000  0.0%     1 0.0000  0.00 UPDATE opa
# MISC 0xMISC                              0.0000  0.0%     2 0.0000   0.0 <2 ITEMS>

# Query 1: 0 QPS, 0x concurrency, ID 0x82CE37495437A097404F41D8B9BC40F5 at byte 1942
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-03-02 15:20:57
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         33       1
# Exec time      0       0       0       0       0       0       0       0
# Query size    19      40      40      40      40      40       0      40
# error code     0       0       0       0       0       0       0       0
# String:
# Databases    xyz
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `xyz` LIKE 'opa'G
#    SHOW CREATE TABLE `xyz`.`opa`G
update opa set name = concat(id,name,id)G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  name = concat(id,name,id) from opa G

View Code

③:剖析指定时刻局限的binlog

pt-query-digest /var/log/mysql/mysql-bin.000053.txt --type=binlog --since='2020-03-01 15:49:47' --until='2020-03-05 15:52:55'

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

# 170ms user time, 10ms system time, 34.39M rss, 99.05M vsz
# Current date: Mon Mar  2 16:00:25 2020
# Hostname: test2
# Files: /var/log/mysql/mysql-bin.000053.txt
# Overall: 4 total, 6 unique, 0.03 QPS, 0x concurrency ___________________
# Time range: 2020-03-02 15:18:30 to 15:20:57
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time              0       0       0       0       0       0       0
# Query size           213       5      71   30.43   69.19   23.03   38.53
# @@session.au           1       1       1       1       1       0       1
# @@session.au           1       1       1       1       1       0       1
# @@session.au           1       1       1       1       1       0       1
# @@session.ch          33      33      33      33      33       0      33
# @@session.co          33      33      33      33      33       0      33
# @@session.co           8       8       8       8       8       0       8
# @@session.fo           1       1       1       1       1       0       1
# @@session.lc           0       0       0       0       0       0       0
# @@session.ps         176     176     176     176     176       0     176
# @@session.sq           0       0       0       0       0       0       0
# @@session.sq       1.34G   1.34G   1.34G   1.34G   1.34G       0   1.34G
# @@session.un           1       1       1       1       1       0       1
# error code             0       0       0       0       0       0       0

# Profile
# Rank Query ID                           Response time Calls R/Call V/M  
# ==== ================================== ============= ===== ====== =====
#    1 0x82CE37495437A097404F41D8B9BC40F5  0.0000  0.0%     1 0.0000  0.00 UPDATE opa
#    2 0x8D589AFA4DFAEEED85FFF5AA78E5FF6A  0.0000  0.0%     2 0.0000  0.00 BEGIN
# MISC 0xMISC                              0.0000  0.0%     1 0.0000   0.0 <1 ITEMS>

# Query 1: 0 QPS, 0x concurrency, ID 0x82CE37495437A097404F41D8B9BC40F5 at byte 1942
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-03-02 15:20:57
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         25       1
# Exec time      0       0       0       0       0       0       0       0
# Query size    18      40      40      40      40      40       0      40
# error code     0       0       0       0       0       0       0       0
# String:
# Databases    xyz
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `xyz` LIKE 'opa'G
#    SHOW CREATE TABLE `xyz`.`opa`G
update opa set name = concat(id,name,id)G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  name = concat(id,name,id) from opa G

# Query 2: 0.01 QPS, 0x concurrency, ID 0x8D589AFA4DFAEEED85FFF5AA78E5FF6A at byte 1780
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2020-03-02 15:18:30 to 15:20:57
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         50       2
# Exec time      0       0       0       0       0       0       0       0
# Query size     4      10       5       5       5       5       0       5
# @@session.au 100       1       1       1       1       1       0       1
# @@session.au 100       1       1       1       1       1       0       1
# @@session.au 100       1       1       1       1       1       0       1
# @@session.ch 100      33      33      33      33      33       0      33
# @@session.co 100      33      33      33      33      33       0      33
# @@session.co 100       8       8       8       8       8       0       8
# @@session.fo 100       1       1       1       1       1       0       1
# @@session.lc   0       0       0       0       0       0       0       0
# @@session.ps 100     176     176     176     176     176       0     176
# @@session.sq   0       0       0       0       0       0       0       0
# @@session.sq 100   1.34G   1.34G   1.34G   1.34G   1.34G       0   1.34G
# @@session.un 100       1       1       1       1       1       0       1
# error code     0       0       0       0       0       0       0       0
# String:
# @@session.co default
# Databases    xyz
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
BEGING

View Code

④:剖析近来时刻的binlog

pt-query-digest /var/log/mysql/mysql-bin.000053.txt --type=binlog --since='60m'

⑤:剖析指定范例的binlog

pt-query-digest /var/log/mysql/mysql-bin.000053.txt --type=binlog  --filter '$event->{arg} =~ m/^update/i'

⑥:后续补充中...

4. processlist

①:抓取show processlist的慢查,转存到指定文件:

-- 距离1s实行show full processlist 拉取processlist中定阅到的慢查询转存到指定的文件。
pt-query-digest --processlist h=192.168.163.132,u=root,p=root --interval=1  --output=slowlog > /tmp/process.log

申明:比较适用于一些云数据库没有看慢查文件的权限。

②:剖析show processlist的慢查:合营--run-time运用,能够限定实行时刻,到时刻(--iterations=1)以后退出而且打印剖析。

-- 距离1s实行show full processlist,永久运转,每30秒生成一次报告
pt-query-digest --processlist h=192.168.163.132,u=root,p=root --interval=1  --run-time-mode=clock --run-time=30s --iterations=0

申明:比较适用于一些问题排查方面的事情。

5. tcpdump

先抓包:

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.log保存到MySQL

1,查询&审计转存到表

pt-query-digest --review u=root,p=root,h=192.168.163.132,P=3306,D=xyz,t=query_review --create-review-table test2-slow.log

申明:把慢查询纪录到数据库xyz的query_review表中:

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张
percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第2张

mysql> select * from query_reviewG
*************************** 1. row ***************************
   checksum: 02DFE94A93ADC62623BF2E1E98C17EC3
fingerprint: select id,hostname,agent_version,sleep(?) from host limit ?
     sample: select id,hostname,agent_version,sleep(0.5) from host limit 10
 first_seen: 2020-03-03 00:07:55
  last_seen: 2020-03-03 00:08:01
reviewed_by: NULL
reviewed_on: NULL
   comments: NULL
*************************** 2. row ***************************
   checksum: 37FD1F8E9516984F7D77EB5364A382DD
fingerprint: select id,name,sleep(?) from opa
     sample: select id,name,sleep(0.5) from opa
 first_seen: 2020-03-03 00:06:50
  last_seen: 2020-03-03 00:07:04
reviewed_by: NULL
reviewed_on: NULL
   comments: NULL
*************************** 3. row ***************************
   checksum: 8430AB741BBC096B102EDAA5ACD08366
fingerprint: select id,name,age,sleep(?) from x
     sample: select id,name,age,sleep(1) from x
 first_seen: 2020-03-03 00:08:15
  last_seen: 2020-03-03 00:08:15
reviewed_by: NULL
reviewed_on: NULL
   comments: NULL
*************************** 4. row ***************************
   checksum: D4B20686AF10136F85E9FAE50E04AE92
fingerprint: select name,sleep(?) from opa
     sample: select name,sleep(0.5) from opa
 first_seen: 2020-03-03 00:07:20
  last_seen: 2020-03-03 00:07:26
reviewed_by: NULL
reviewed_on: NULL
   comments: NULL

View Code

表列申明:

COLUMN       MEANING
===========  ====================================================
checksum     查询指纹的64位校验和
fingerprint  查询的笼统版本;它的主键
sample       查询样本的文本
first_seen   此类查询的最早时刻戳
last_seen    此类查询的近来时刻戳
reviewed_by  假如设置,今后将跳过查询
reviewed_on  没有给予任何特别寄义
comments     没有给予任何特别寄义

注重:假如表中的纪录reviewed_by被设了值,则下次运转pt-query-digest --review不会显现该query。

2,查询剖析目标转存到表

pt-query-digest --history u=root,p=root,h=192.168.163.132,P=3306,D=xyz,t=query_review_history --create-review-table test2-slow.log

申明:把慢查询纪录的剖析目标转存到数据库xyz的query_review_history表中:

percona-toolkit 之 【pt-query-digest】使用,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容,percona-toolkit 之 【pt-query-digest】先容 IT教程 第1张

mysql> select * from query_review_historyG
*************************** 1. row ***************************
                    checksum: 02DFE94A93ADC62623BF2E1E98C17EC3
                      sample: select id,hostname,agent_version,sleep(0.5) from host limit 10
                      ts_min: 2020-03-03 00:07:55
                      ts_max: 2020-03-03 00:08:01
                      ts_cnt: 2
              Query_time_sum: 10.0236
              Query_time_min: 5.00726
              Query_time_max: 5.01629
           Query_time_pct_95: 5.01629
           Query_time_stddev: 0.00638659
           Query_time_median: 5.01178
               Lock_time_sum: 0.004069
               Lock_time_min: 0.000299
               Lock_time_max: 0.00377
            Lock_time_pct_95: 0.00377
            Lock_time_stddev: 0.00245437
            Lock_time_median: 0.0020345
               Rows_sent_sum: 20
               Rows_sent_min: 10
               Rows_sent_max: 10
            Rows_sent_pct_95: 10
            Rows_sent_stddev: 0
            Rows_sent_median: 10
           Rows_examined_sum: 20
           Rows_examined_min: 10
           Rows_examined_max: 10
        Rows_examined_pct_95: 10
        Rows_examined_stddev: 0
        Rows_examined_median: 10
           Rows_affected_sum: NULL
           Rows_affected_min: NULL
           Rows_affected_max: NULL
        Rows_affected_pct_95: NULL
        Rows_affected_stddev: NULL
        Rows_affected_median: NULL
               Rows_read_sum: NULL
               Rows_read_min: NULL
               Rows_read_max: NULL
            Rows_read_pct_95: NULL
            Rows_read_stddev: NULL
            Rows_read_median: NULL
            Merge_passes_sum: NULL
            Merge_passes_min: NULL
            Merge_passes_max: NULL
         Merge_passes_pct_95: NULL
         Merge_passes_stddev: NULL
         Merge_passes_median: NULL
         InnoDB_IO_r_ops_min: NULL
         InnoDB_IO_r_ops_max: NULL
      InnoDB_IO_r_ops_pct_95: NULL
      InnoDB_IO_r_ops_stddev: NULL
      InnoDB_IO_r_ops_median: NULL
       InnoDB_IO_r_bytes_min: NULL
       InnoDB_IO_r_bytes_max: NULL
    InnoDB_IO_r_bytes_pct_95: NULL
    InnoDB_IO_r_bytes_stddev: NULL
    InnoDB_IO_r_bytes_median: NULL
        InnoDB_IO_r_wait_min: NULL
        InnoDB_IO_r_wait_max: NULL
     InnoDB_IO_r_wait_pct_95: NULL
     InnoDB_IO_r_wait_stddev: NULL
     InnoDB_IO_r_wait_median: NULL
    InnoDB_rec_lock_wait_min: NULL
    InnoDB_rec_lock_wait_max: NULL
 InnoDB_rec_lock_wait_pct_95: NULL
 InnoDB_rec_lock_wait_stddev: NULL
 InnoDB_rec_lock_wait_median: NULL
       InnoDB_queue_wait_min: NULL
       InnoDB_queue_wait_max: NULL
    InnoDB_queue_wait_pct_95: NULL
    InnoDB_queue_wait_stddev: NULL
    InnoDB_queue_wait_median: NULL
   InnoDB_pages_distinct_min: NULL
   InnoDB_pages_distinct_max: NULL
InnoDB_pages_distinct_pct_95: NULL
InnoDB_pages_distinct_stddev: NULL
InnoDB_pages_distinct_median: NULL
                  QC_Hit_cnt: NULL
                  QC_Hit_sum: NULL
               Full_scan_cnt: NULL
               Full_scan_sum: NULL
               Full_join_cnt: NULL
               Full_join_sum: NULL
               Tmp_table_cnt: NULL
               Tmp_table_sum: NULL
       Tmp_table_on_disk_cnt: NULL
       Tmp_table_on_disk_sum: NULL
                Filesort_cnt: NULL
                Filesort_sum: NULL
        Filesort_on_disk_cnt: NULL
        Filesort_on_disk_sum: NULL

View Code

注重:经由过程report打印出来的信息转存到表中。针对1,2生成的表能够举行关联,来找出那些没有被审计的SQL。经由过程这2个参数,能够做成一个MySQL的慢查询审计平台,如

三 总结:

      本文大抵申清楚明了的运用要领,其参数的引见申明能够看也能够直接去官网看文档。如果有更多的比较经常使用的要领,会不定期的更新该文章。

 

 

Elasticsearch系列---深入全文搜索

参与评论