mysql 慢日志分析_MySQL 慢日志分析-CSDN博客

本文链接：https://blog.csdn.net/weixin_30472793/article/details/113440000

本文介绍了一次使用Percona Toolkit进行慢查询日志分析的实际操作过程。通过对MySQL数据库中的大量数据插入及删除操作，模拟生成了慢查询日志，并利用pt-query-digest工具进行了深入分析，展示了如何定位及优化慢查询。

摘要生成于 C知道，由 DeepSeek-R1 满血版支持，前往体验 >

1 #-------------------------------------------------------------------------------

2 #3 # 模拟slow日志分析4 # 通过percona-toolkit-3.0.10_x86_64.tar.gz5 # Author：nod6 # Date:18-08-05

7 #-------------------------------------------------------------------------------

9 #-------------------------------------------------------------------------------

10 # 模拟环境数据11 #-------------------------------------------------------------------------------

12 mysql> useworld;13 Databasechanged14

15 mysql> create table t1 select * fromcity;16 Query OK, 4079 rows affected (0.24sec)17 Records: 4079 Duplicates: 0 Warnings: 0

19 mysql> insert into t1 select * fromt1;20 Query OK, 4079 rows affected (0.76sec)21 Records: 4079 Duplicates: 0 Warnings: 0

23 mysql> insert into t1 select * fromt1;24 Query OK, 8158 rows affected (0.15sec)25 Records: 8158 Duplicates: 0 Warnings: 0

27 mysql> insert into t1 select * fromt1;28 Query OK, 16316 rows affected (0.29sec)29 Records: 16316 Duplicates: 0 Warnings: 0

31 mysql> insert into t1 select * fromt1;32 Query OK, 32632 rows affected (0.36sec)33 Records: 32632 Duplicates: 0 Warnings: 0

35 mysql> insert into t1 select * fromt1;36 Query OK, 65264 rows affected (0.64sec)37 Records: 65264 Duplicates: 0 Warnings: 0

39 mysql> insert into t1 select * fromt1;40 Query OK, 130528 rows affected (1.98sec)41 Records: 130528 Duplicates: 0 Warnings: 0

43 mysql> insert into t1 select * fromt1;44 Query OK, 261056 rows affected (3.20sec)45 Records: 261056 Duplicates: 0 Warnings: 0

47 mysql> insert into t1 select * fromt1;48 Query OK, 522112 rows affected (6.63sec)49 Records: 522112 Duplicates: 0 Warnings: 0

51 mysql> insert into t1 select * fromt1;52 Query OK, 1044224 rows affected (25.21sec)53 Records: 1044224 Duplicates: 0 Warnings: 0

55 mysql> insert into t1 select * fromt1;56 Query OK, 2088448 rows affected (40.06sec)57 Records: 2088448 Duplicates: 0 Warnings: 0

59 mysql> select count(*) fromt1;60 +----------+

61 | count(*) |

62 +----------+

63 | 4176896 |

64 +----------+

65 1 row in set (1.79sec)66

67 mysql> delete from t1 where id>2000;68 Query OK, 2128896 rows affected (26.41sec)69

70 mysql> select count(*) fromt1;71 +----------+

72 | count(*) |

73 +----------+

74 | 2048000 |

75 +----------+

76 1 row in set (11.60sec)77

78 #-------------------------------------------------------------------------------

79 # 安装 percona-toolkit-3.0.10_x86_64.tar.gz80 #-------------------------------------------------------------------------------

82 yum install -y perl-Time-HiRes83 cd /server/tools/

84 tar xf percona-toolkit-3.0.10_x86_64.tar.gz85 pwd86 /server/tools/percona-toolkit-3.0.10/bin87

89 #-------------------------------------------------------------------------------

90 # 分析slowlog91 #-------------------------------------------------------------------------------

92 [root@db01 bin]# ./pt-query-digest /data/mysql/slow.log

94 # 130ms user time, 10ms system time, 20.77M rss, 169.70M vsz95 # Current date: Sun Aug 5 13:07:02 2018

96 # Hostname: db0197 # Files: /data/mysql/slow.log

98 # Overall: 21 total, 7 unique, 0.01 QPS, 0.05x concurrency _______________99 # Time range: 2018-08-05 12:24:28 to 13:06:55

100 # Attribute total min max avg 95%stddev median101 # ============ ======= ======= ======= ======= ======= ======= =======

102 # Exectime 120s 936us 40s 6s 25s 11s 356ms103 # Lock time 37ms 032ms 2ms 348us 7ms 176us104 # Rows sent 3 0 1 0.14 0.99 0.35 0

105 # Rows examine 17.90M 0 3.98M 872.95k 3.86M 1.37M 31.59k106 # Query size 608 16 34 28.95 30.19 4.17 30.19

107

108 # Profile109 # Rank Query ID Response time Calls R/Call V/M Item110 # ==== ================== ============= ===== ======= ===== ==============

111 # 1 0xD990BC7C09F20BDA 79.3335 66.2% 13 6.1026 21.42 INSERT SELECTt?112 # 2 0x6F6EB4D37DDD5C23 26.4109 22.0% 1 26.4109 0.00 DELETEt?113 # 3 0x0EBF4AD96B6F67E7 13.4005 11.2% 3 4.4668 5.59 SELECTt?114 # MISC 0xMISC 0.6675 0.6% 4 0.1669 0.0 <4 ITEMS>

115

116 # Query 1: 0.01 QPS, 0.03x concurrency, ID 0xD990BC7C09F20BDA at byte 3738

117 # This item is included in the report because it matches --limit.

118 # Scores: V/M = 21.42

119 # Time range: 2018-08-05 12:25:20 to 13:04:52

120 # Attribute pct total min max avg 95%stddev median121 # ============ === ======= ======= ======= ======= ======= ======= =======

122 # Count 61 13

123 # Exec time 6679s 8ms 40s 6s 25s 11s 690ms124 # Lock time 73ms 169us 360us 209us 273us 56us 167us125 # Rows sent 0 0 0 0 0 0 0 0

126 # Rows examine 44 7.97M 3.98k 3.98M 627.85k 1.95M 1.09M 93.20k127 # Query size 66 403 31 31 31 31 0 31

128 # String:129 # Databases world130 # Hosts localhost131 # Users root132 # Query_time distribution133 # 1us134 # 10us135 # 100us136 # 1ms ######################################137 # 10ms138 # 100ms ################################################################139 # 1s ######################################140 # 10s+#########################141 # Tables142 # SHOW TABLE STATUS FROM `world` LIKE 't1'\G143 # SHOW CREATE TABLE`world`.`t1`\G144 insert into t1 select * fromt1\G145

146 # Query 2: 0 QPS, 0x concurrency, ID 0x6F6EB4D37DDD5C23 at byte 4159_____147 # This item is included in the report because it matches --limit.

148 # Scores: V/M = 0.00

149 # Time range: all events occurred at 2018-08-05 13:06:30

150 # Attribute pct total min max avg 95%stddev median151 # ============ === ======= ======= ======= ======= ======= ======= =======

152 # Count 4 1

153 # Exec time 22 26s 26s 26s 26s 26s 026s154 # Lock time 0 302us 302us 302us 302us 302us 0302us155 # Rows sent 0 0 0 0 0 0 0 0

156 # Rows examine 22 3.98M 3.98M 3.98M 3.98M 3.98M 0 3.98M157 # Query size 4 28 28 28 28 28 0 28

158 # String:159 # Databases world160 # Hosts localhost161 # Users root162 # Query_time distribution163 # 1us164 # 10us165 # 100us166 # 1ms167 # 10ms168 # 100ms169 # 1s170 # 10s+################################################################171 # Tables172 # SHOW TABLE STATUS FROM `world` LIKE 't1'\G173 # SHOW CREATE TABLE`world`.`t1`\G174 delete from t1 where id>2000\G175 # Converted forEXPLAIN176 # EXPLAIN /*!50100 PARTITIONS*/

177 select * from t1 where id>2000\G178

179 # Query 3: 0.00 QPS, 0.01x concurrency, ID 0x0EBF4AD96B6F67E7 at byte 4371

180 # This item is included in the report because it matches --limit.

181 # Scores: V/M = 5.59

182 # Time range: 2018-08-05 12:25:43 to 13:06:55

183 # Attribute pct total min max avg 95%stddev median184 # ============ === ======= ======= ======= ======= ======= ======= =======

185 # Count 14 3

186 # Exec time 1113s 3ms 12s 4s 11s 5s 2s187 # Lock time 1507us 92us 277us 169us 273us 78us 131us188 # Rows sent 100 3 1 1 1 1 0 1

189 # Rows examine 33 5.94M 3.98k 3.98M 1.98M 3.86M 1.58M 1.95M190 # Query size 11 69 23 23 23 23 0 23

191 # String:192 # Databases world193 # Hosts localhost194 # Users root195 # Query_time distribution196 # 1us197 # 10us198 # 100us199 # 1ms ################################################################200 # 10ms201 # 100ms202 # 1s ################################################################203 # 10s+################################################################204 # Tables205 # SHOW TABLE STATUS FROM `world` LIKE 't1'\G206 # SHOW CREATE TABLE`world`.`t1`\G207 # EXPLAIN /*!50100 PARTITIONS*/

208 select count(*) from t1\G