最近遇到了MySQL性能问题,使用percona 的 pt-query-digest工具分析性能的瓶颈点。并且pt-query-digest工具要优于MySQL本身自带的mysqldumpslow工具。
查看pt-query-digest工具在ubuntu下的安装流程请看:ubuntu下安装pt-query-digest_一缕阳光a的博客-CSDN博客https://blog.csdn.net/zgaoq/article/details/124710484?spm=1001.2014.3001.5502
先将结果贴上,然后在分析:
[root@xxx log]# pt-query-digest mysql-slow.log
# 110ms user time, 20ms system time, 37.57M rss, 49.25M vsz
# Current date: Wed May 11 15:49:08 2022
# Hostname: aaaa
# Files: /home/ddd/slow_query/slow3306_small.log
# Overall: 10 total, 7 unique, 0.00 QPS, 0.02x concurrency _______________
# Time range: 2022-04-27T15:39:28 to 2022-04-28T14:55:06
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 1648s 500ms 827s 165s 271s 235s 29s
# Lock time 6ms 0 1ms 629us 925us 343us 626us
# Rows sent 1 0 1 0.10 0 0.30 0
# Rows examine 25.35M 1.48k 4.81M 2.53M 4.70M 2.21M 4.70M
# Rows affecte 1.43M 0 488.28k 146.48k 485.50k 222.49k 0
# Bytes sent 4.64G 0 1.08G 475.62M 1.08G 506.28M 106.64M
# Query size 864 13 543 78.55 118.34 147.95 21.45# Profile
# Rank Query ID Response time Calls R/Call
# ==== =================================== =============== ===== ========
# 1 0x7738DBC3D65602BBA1A040E0905E1052 1024.3274 62.2% 2 512.1637 38... UPDATE sbtest?
# 2 0x43ED0F75107CE7B9724C1FA36FFD880F 590.3572 35.8% 4 147.5893 97.58 UPDATE sbtest?
# MISC 0xMISC 33.2763 2.0% 4 8.3191 0.0 <4 ITEMS># Query 1: 0.00 QPS, 0.74x concurrency, ID 0x7738DBC3D65602BBA1A040E0905E1052 at byte 4018
# This item is included in the report because it matches --limit.
# Scores: V/M = 387.17
# Time range: 2022-04-28T14:32:08 to 2022-04-28T14:55:06
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 20 2
# Exec time 62 1024s 197s 827s 512s 827s 445s 512s
# Lock time 29 2ms 926us 932us 929us 932us 4us 929us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 37 9.61M 4.81M 4.81M 4.81M 4.81M 0 4.81M
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 46 2.16G 1.08G 1.08G 1.08G 1.08G 4.24 1.08G
# Query size 5 48 24 24 24 24 0 24
# String:
# Databases test
# Hosts 127.0.0.1
# Last errno 1180
# Users xxxxx
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS FROM `test` LIKE 'sbtest1'\G
# SHOW CREATE TABLE `test`.`sbtest1`\G
update sbtest1 set k=k+2\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select k=k+2 from sbtest1 \G# Query 2: 0.00 QPS, 0.01x concurrency, ID 0x43ED0F75107CE7B9724C1FA36FFD880F at byte 1793
# This item is included in the report because it matches --limit.
# Scores: V/M = 97.58
# Time range: 2022-04-27T16:00:34 to 2022-04-28T14:07:24
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 40 4
# Exec time 35 590s 23s 273s 148s 271s 120s 265s
# Lock time 37 2ms 536us 638us 596us 626us 41us 596us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 41 10.49M 488.28k 4.77M 2.62M 4.70M 2.11M 4.70M
# Rows affecte 66 976.56k 0 488.28k 244.14k 485.50k 242.75k 485.50k
# Bytes sent 51 2.38G 109.52M 1.08G 609.52M 1.08G 500.00M 1.08G
# Query size 10 88 22 22 22 22 0 22
# String:
# Databases test
# Hosts 127.0.0.1
# Last errno 0 (2/50%), 1180 (2/50%)
# Users xxxx
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS FROM `test` LIKE 'sbtest1'\G
# SHOW CREATE TABLE `test`.`sbtest1`\G
update sbtest1 set d=1\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select d=1 from sbtest1 \G
下面根据各个部分进行详解:
第一部分:输出结果的总体信息
说明:执行过程中在用户中所花费的所有时间;
执行过程中内核空间中所花费的所有时间
pt-query-digest进程所分配的内存大小
pt-query-digest进程所分配的虚拟内存大小
# 120ms user time, 10ms system time, 37.39M rss, 49.25M vsz说明:当前日期
# Current date: Wed May 11 15:30:59 2022说明:执行pt-query-digest的主机名
# Hostname: aaaaa说明:被分析的文件名
# Files: /home/ddd/slow_query/slow3306_small.log说明:语句总数量,唯一语句数量,每秒查询量,查询的并发
# Overall: 10 total, 7 unique, 0.00 QPS, 0.02x concurrency _______________说明:执行过程中日志记录的时间范围
# Time range: 2022-04-27T15:39:28 to 2022-04-28T14:55:06
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
说明:执行时间
# Exec time 1648s 500ms 827s 165s 271s 235s 29s
说明:锁占用时间
# Lock time 6ms 0 1ms 629us 925us 343us 626us
说明:发送到客户端的行数
# Rows sent 1 0 1 0.10 0 0.30 0
说明:扫描的语句行数
# Rows examine 25.35M 1.48k 4.81M 2.53M 4.70M 2.21M 4.70M
说明:操作的行数
# Rows affecte 1.43M 0 488.28k 146.48k 485.50k 222.49k 0
说明:发送到客户端的字符数
# Bytes sent 4.64G 0 1.08G 475.62M 1.08G 506.28M 106.64M
说明:查询的字符数
# Query size 864 13 543 78.55 118.34 147.95 21.45
第二部分:输出总体统计信息
SQL语句的等级
Query ID:去掉了中间的符号
Response time:响应时间
Calls: 响应次数
R/Call:每次响应的时间# Profile
# Rank Query ID Response time Calls R/Call
# ==== =================================== =============== ===== ========
# 1 0x7738DBC3D65602BBA1A040E0905E1052 1024.3274 62.2% 2 512.1637 38... UPDATE sbtest?
# 2 0x43ED0F75107CE7B9724C1FA36FFD880F 590.3572 35.8% 4 147.5893 97.58 UPDATE sbtest?
# MISC 0xMISC 33.2763 2.0% 4 8.3191 0.0 <4 ITEMS>
第三部分:输出每列查询的详细信息
以下面这个为例:
说明:查询队列1:每秒查询量,查询的并发,队列1的ID值,4018:表示文中偏移量(查看方法在下面‘偏1’中)
# Query 1: 0.00 QPS, 0.74x concurrency, ID 0x7738DBC3D65602BBA1A040E0905E1052 at byte 4018
# This item is included in the report because it matches --limit.
# Scores: V/M = 387.17
# Time range: 2022-04-28T14:32:08 to 2022-04-28T14:55:06
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 20 2
# Exec time 62 1024s 197s 827s 512s 827s 445s 512s
# Lock time 29 2ms 926us 932us 929us 932us 4us 929us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 37 9.61M 4.81M 4.81M 4.81M 4.81M 0 4.81M
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 46 2.16G 1.08G 1.08G 1.08G 1.08G 4.24 1.08G
# Query size 5 48 24 24 24 24 0 24
# String:
说明:使用的数据库名称
# Databases test
说明:使用的主机IP
# Hosts 127.0.0.1
说明:上次的错误码
# Last errno 1180
说明:使用的用户名
# Users xxx
说明:查询时间分布
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+ ################################################################
说明:执行的慢语句信息
# Tables
# SHOW TABLE STATUS FROM `test` LIKE 'sbtest1'\G
# SHOW CREATE TABLE `test`.`sbtest1`\G
update sbtest1 set k=k+2\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select k=k+2 from sbtest1 \G
总之,percona pt-query-digest工具比较全面的分析了MySQL的慢查询日志,要比MySQL自身的慢日志工具mysqldumpslow要优秀,因此最好使用percona的 pt-query-digest 工具进行慢日志查询。