Write by lyc at 2018-12-27
MySQL慢查询分析工具pt-query-digest详解
一、分析slow_log
直接输入慢查询日志，并以文件形式输出。
1
2
3
4
5
|
$ pt-query-digest slow_log_3306.log > 3306_slow_report.log
$ pt-query-digest --since "2019-12-09 12:00:00" --until "2019-12-09 23:59:59" 20191209_xxx.xxx.50.244_3306_slowlog.log > /data/slave4.log
|
二、报告解析
第一部分：总体统计结果
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
| 1
2 # A software update is available:
3
该工具分析本日志分析的：
用户时间 系统时间 占用物理内存 占用虚拟内存
4 # 970ms user time, 20ms system time, 29.49M rss, 242.44M vsz
工具执行时间：
5 # Current date: Thu Dec 27 11:36:39 2018
运行分析工具的主机名：
6 # Hostname: 10-19-148-181
被分析的文件名：
7 # Files: slow_log_3306.log
sql总数量 唯一的sql数量 QPS 并发数
8 # Overall: 2.60k total, 18 unique, 0.00 QPS, 0.08x concurrency ___________
日志记录的时间范围：
9 # Time range: 2018-11-23 09:59:41 to 2018-12-27 11:31:30
#总计 最小 最大 平均 95% 标准 中等
10 # Attribute total min max avg 95% stddev median
11 # ============ ======= ======= ======= ======= ======= ======= =======
12 # Exec time 231456s 1s 1330s 89s 299s 94s 60s # 语句执行时间
13 # Lock time 1s 0 685ms 394us 113us 13ms 66us # 锁占用时间
14 # Rows sent 602.84k 0 596.89k 237.88 9.83 11.58k 0 # 发送到客户端的行数
15 # Rows examine 1.84G 0 5.13M 741.84k 1.20M 500.64k 650.62k # SELECT语句扫描行数
16 # Query size 355.66k 44 373 140.34 143.84 20.16 143.84 # 查询的字符数
17
|
第二部分：查询分组统计结果
- Rank：所有语句的排名，默认按查询时间降序排列，通过–order-by指定
- Query ID：语句的ID，（去掉多余空格和文本字符，计算hash值）
- Response time：总的响应时间，该查询在本次分析中总的时间占比
- calls：执行次数，即本次分析总共有多少条这种类型的查询语句
- R/Call：平均每次执行的响应时间
- V/M：响应时间Variance-to-mean的比率
- Item：查询对象
1
2
3
4
5
6
7
8
| 18 # Profile
19 # Rank Query ID Response time Calls R/Call V/M
20 # ==== ============================ ================= ===== ======== =====
21 # 1 0x861A615D07600E9927D917C... 222369.0758 96.1% 1977 112.4780 76.93 SELECT xxxxxx_picsetlink_?_tb
22 # 2 0x69918FCB31F36E7496F9F2A... 6845.4683 3.0% 547 12.5146 0.23 SELECT mini_netnamesign_tb
23 # 6 0x91F7A133489C334B1796DFE... 132.6936 0.1% 12 11.0578 0.07 SELECT xxxxxx_statday_share_tb
24 # MISC 0xMISC 2108.3884 0.9% 59 35.7354 0.0 <15 ITEMS>
25
|
第三部分：详细分析结果
- Query：和第二部分的Rank对应，序号的意思
- ID：查询的ID号，和第二部分的Query ID对应
- Databases：数据库名
- Hosts：主机
- Users：用户
- Query_time distribution ：查询时间分布，长短体现区间占比。
- Tables：查询中涉及到的表
- Explain：SQL语句
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
| 26 # Query 1: 0.03 QPS, 3.19x concurrency, ID 0x861A615D07600E9927D917CFF0145BC0 at byte 559320
27 # This item is included in the report because it matches --limit.
28 # Scores: V/M = 76.93
29 # Time range: 2018-11-26 16:07:06 to 2018-11-27 11:27:30
30 # Attribute pct total min max avg 95% stddev median
31 # ============ === ======= ======= ======= ======= ======= ======= =======
32 # Count 76 1977
33 # Exec time 96 222369s 10s 335s 112s 314s 93s 60s
34 # Lock time 95 976ms 44us 685ms 493us 108us 15ms 66us
35 # Rows sent 0 0 0 0 0 0 0 0
36 # Rows examine 92 1.70G 87.50k 1.21M 900.04k 1.20M 414.95k 1.20M
37 # Query size 78 279.95k 145 145 145 145 0 145
38 # String:
39 # Databases DATABASE_NAME
40 # Hosts xxx.xxx.xxx.xxx
41 # Users DATABASE_NAME
42 # Query_time distribution
43 # 1us
44 # 10us
45 # 100us
46 # 1ms
47 # 10ms
48 # 100ms
49 # 1s
50 # 10s+ ################################################################
51 # Tables
52 # SHOW TABLE STATUS FROM `DATABASE_NAME` LIKE 'xxxxxx_picsetlink_8_tb'\G
53 # SHOW CREATE TABLE `DATABASE_NAME`.`xxxxxx_picsetlink_8_tb`\G
54 # EXPLAIN /*!50100 PARTITIONS*/
55 /*xxxxxxInterfaceSite*/ SELECT * FROM `xxxxxx_picsetlink_8_tb` WHERE UserID=109828178 and SetID=955279 AND PicType=0 ORDER BY ID DESC LIMIT 0,9\G
56
57 # Query 2: 0.00 QPS, 0.00x concurrency, ID 0x69918FCB31F36E7496F9F2A7033102F0 at byte 188874
58 # This item is included in the report because it matches --outliers.
59 # Scores: V/M = 0.23
60 # Time range: 2018-11-26 16:17:11 to 2018-12-12 17:12:19
61 # Attribute pct total min max avg 95% stddev median
62 # ============ === ======= ======= ======= ======= ======= ======= =======
63 # Count 21 547
64 # Exec time 2 6845s 10s 20s 13s 15s 2s 12s
65 # Lock time 4 42ms 46us 469us 76us 125us 34us 63us
66 # Rows sent 0 5.34k 10 10 10 10 0 10
67 # Rows examine 4 79.14M 148.10k 157.32k 148.15k 143.37k 542.13 143.37k
68 # Query size 17 62.50k 117 117 117 117 0 117
69 # String:
70 # Databases DATABASE_NAME
71 # Hosts xxx.xxx.xxx.xxx
72 # Users DATABASE_NAME
73 # Query_time distribution
74 # 1us
75 # 10us
76 # 100us
77 # 1ms
78 # 10ms
79 # 100ms
80 # 1s
81 # 10s+ ################################################################
82 # Tables
83 # SHOW TABLE STATUS FROM `DATABASE_NAME` LIKE 'mini_netnamesign_tb'\G
84 # SHOW CREATE TABLE `DATABASE_NAME`.`mini_netnamesign_tb`\G
85 # EXPLAIN /*!50100 PARTITIONS*/
86 /*MiniEmoji*/ SELECT MainTitle FROM `mini_netnamesign_tb` WHERE Type=2 AND Category!=3 ORDER BY RAND() LIMIT 0,10\G
87
88 # Query 6: 0.03 QPS, 0.33x concurrency, ID 0x91F7A133489C334B1796DFE0CD4FDF38 at byte 311538
89 # This item is included in the report because it matches --outliers.
90 # Scores: V/M = 0.07
91 # Time range: 2018-11-26 16:18:37 to 16:25:22
92 # Attribute pct total min max avg 95% stddev median
93 # ============ === ======= ======= ======= ======= ======= ======= =======
94 # Count 0 12
95 # Exec time 0 133s 10s 13s 11s 12s 891ms 11s
96 # Lock time 0 1ms 73us 105us 87us 103us 10us 84us
97 # Rows sent 0 1 0 1 0.08 0 0.27 0
98 # Rows examine 0 5.97M 509.41k 509.44k 509.44k 485.50k 0 485.50k
99 # Query size 0 1.87k 156 160 159.33 158.58 2 158.58
100 # String:
101 # Databases DATABASE_NAME
102 # Hosts xxx.xxx.xxx.xxx
103 # Users DATABASE_NAME
104 # Query_time distribution
105 # 1us
106 # 10us
107 # 100us
108 # 1ms
109 # 10ms
110 # 100ms
111 # 1s
112 # 10s+ ################################################################
113 # Tables
114 # SHOW TABLE STATUS FROM `DATABASE_NAME` LIKE 'xxxxxx_statday_share_tb'\G
115 # SHOW CREATE TABLE `DATABASE_NAME`.`xxxxxx_statday_share_tb`\G
116 # EXPLAIN /*!50100 PARTITIONS*/
117 /*WallPaperDown*/ SELECT * FROM xxxxxx_statday_share_tb where PicInfoID=701396 and StatDate>='2018-11-26 00:00:00' and StatDate<='2018-11-26 23:59:59' LIMIT 1\G
|
