MySQL 慢日志分析
pt-query-digest基本使用：
https://www.percona.com/downloads/percona-toolkit/LATEST/
选择对应版本
下载完毕后上传到对应目录/server/tools/
MySQL配置文件：
1 [mysqld] 2 basedir=/application/mysql 3 datadir=/application/mysql/data 4 socket=/tmp/mysql.sock 5 log-error=/var/log/mysql.log 6 log-bin=/data/mysql/mysql-bin 7 server-id=6 8 port=3306 9 secure-file-priv=/tmp 10 binlog_format=row 11 slow_query_log=1 12 slow_query_log_file=/data/mysql/slow.log 13 long_query_time=0.05 14 log_queries_not_using_indexes 15 [client] 16 socket=/tmp/mysql.sock
项目code
1 #------------------------------------------------------------------------------- 2 # 3 # 模拟slow日志分析 4 # 通过percona-toolkit-3.0.10_x86_64.tar.gz 5 # Author：nod 6 # Date:18-08-05 7 #------------------------------------------------------------------------------- 8 9 #------------------------------------------------------------------------------- 10 # 模拟环境数据 11 #------------------------------------------------------------------------------- 12 mysql> use world; 13 Database changed 14 15 mysql> create table t1 select * from city; 16 Query OK, 4079 rows affected (0.24 sec) 17 Records: 4079 Duplicates: 0 Warnings: 0 18 19 mysql> insert into t1 select * from t1; 20 Query OK, 4079 rows affected (0.76 sec) 21 Records: 4079 Duplicates: 0 Warnings: 0 22 23 mysql> insert into t1 select * from t1; 24 Query OK, 8158 rows affected (0.15 sec) 25 Records: 8158 Duplicates: 0 Warnings: 0 26 27 mysql> insert into t1 select * from t1; 28 Query OK, 16316 rows affected (0.29 sec) 29 Records: 16316 Duplicates: 0 Warnings: 0 30 31 mysql> insert into t1 select * from t1; 32 Query OK, 32632 rows affected (0.36 sec) 33 Records: 32632 Duplicates: 0 Warnings: 0 34 35 mysql> insert into t1 select * from t1; 36 Query OK, 65264 rows affected (0.64 sec) 37 Records: 65264 Duplicates: 0 Warnings: 0 38 39 mysql> insert into t1 select * from t1; 40 Query OK, 130528 rows affected (1.98 sec) 41 Records: 130528 Duplicates: 0 Warnings: 0 42 43 mysql> insert into t1 select * from t1; 44 Query OK, 261056 rows affected (3.20 sec) 45 Records: 261056 Duplicates: 0 Warnings: 0 46 47 mysql> insert into t1 select * from t1; 48 Query OK, 522112 rows affected (6.63 sec) 49 Records: 522112 Duplicates: 0 Warnings: 0 50 51 mysql> insert into t1 select * from t1; 52 Query OK, 1044224 rows affected (25.21 sec) 53 Records: 1044224 Duplicates: 0 Warnings: 0 54 55 mysql> insert into t1 select * from t1; 56 Query OK, 2088448 rows affected (40.06 sec) 57 Records: 2088448 Duplicates: 0 Warnings: 0 58 59 mysql> select count(*) from t1; 60 +----------+ 61 | count(*) | 62 +----------+ 63 | 4176896 | 64 +----------+ 65 1 row in set (1.79 sec) 66 67 mysql> delete from t1 where id>2000; 68 Query OK, 2128896 rows affected (26.41 sec) 69 70 mysql> select count(*) from t1; 71 +----------+ 72 | count(*) | 73 +----------+ 74 | 2048000 | 75 +----------+ 76 1 row in set (11.60 sec) 77 78 #------------------------------------------------------------------------------- 79 # 安装 percona-toolkit-3.0.10_x86_64.tar.gz 80 #------------------------------------------------------------------------------- 81 82 yum install -y perl-Time-HiRes 83 cd /server/tools/ 84 tar xf percona-toolkit-3.0.10_x86_64.tar.gz 85 pwd 86 /server/tools/percona-toolkit-3.0.10/bin 87 88 89 #------------------------------------------------------------------------------- 90 # 分析slowlog 91 #------------------------------------------------------------------------------- 92 [root@db01 bin]# ./pt-query-digest /data/mysql/slow.log 93 94 # 130ms user time, 10ms system time, 20.77M rss, 169.70M vsz 95 # Current date: Sun Aug 5 13:07:02 2018 96 # Hostname: db01 97 # 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 median 101 # ============ ======= ======= ======= ======= ======= ======= ======= 102 # Exec time 120s 936us 40s 6s 25s 11s 356ms 103 # Lock time 37ms 0 32ms 2ms 348us 7ms 176us 104 # 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.59k 106 # Query size 608 16 34 28.95 30.19 4.17 30.19 107 108 # Profile 109 # Rank Query ID Response time Calls R/Call V/M Item 110 # ==== ================== ============= ===== ======= ===== ============== 111 # 1 0xD990BC7C09F20BDA 79.3335 66.2% 13 6.1026 21.42 INSERT SELECT t? 112 # 2 0x6F6EB4D37DDD5C23 26.4109 22.0% 1 26.4109 0.00 DELETE t? 113 # 3 0x0EBF4AD96B6F67E7 13.4005 11.2% 3 4.4668 5.59 SELECT t? 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 median 121 # ============ === ======= ======= ======= ======= ======= ======= ======= 122 # Count 61 13 123 # Exec time 66 79s 8ms 40s 6s 25s 11s 690ms 124 # Lock time 7 3ms 169us 360us 209us 273us 56us 167us 125 # 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.20k 127 # Query size 66 403 31 31 31 31 0 31 128 # String: 129 # Databases world 130 # Hosts localhost 131 # Users root 132 # Query_time distribution 133 # 1us 134 # 10us 135 # 100us 136 # 1ms ###################################### 137 # 10ms 138 # 100ms ################################################################ 139 # 1s ###################################### 140 # 10s+ ######################### 141 # Tables 142 # SHOW TABLE STATUS FROM `world` LIKE 't1'\G 143 # SHOW CREATE TABLE `world`.`t1`\G 144 insert into t1 select * from t1\G 145 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 median 151 # ============ === ======= ======= ======= ======= ======= ======= ======= 152 # Count 4 1 153 # Exec time 22 26s 26s 26s 26s 26s 0 26s 154 # Lock time 0 302us 302us 302us 302us 302us 0 302us 155 # 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.98M 157 # Query size 4 28 28 28 28 28 0 28 158 # String: 159 # Databases world 160 # Hosts localhost 161 # Users root 162 # Query_time distribution 163 # 1us 164 # 10us 165 # 100us 166 # 1ms 167 # 10ms 168 # 100ms 169 # 1s 170 # 10s+ ################################################################ 171 # Tables 172 # SHOW TABLE STATUS FROM `world` LIKE 't1'\G 173 # SHOW CREATE TABLE `world`.`t1`\G 174 delete from t1 where id>2000\G 175 # Converted for EXPLAIN 176 # EXPLAIN /*!50100 PARTITIONS*/ 177 select * from t1 where id>2000\G 178 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 median 184 # ============ === ======= ======= ======= ======= ======= ======= ======= 185 # Count 14 3 186 # Exec time 11 13s 3ms 12s 4s 11s 5s 2s 187 # Lock time 1 507us 92us 277us 169us 273us 78us 131us 188 # 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.95M 190 # Query size 11 69 23 23 23 23 0 23 191 # String: 192 # Databases world 193 # Hosts localhost 194 # Users root 195 # Query_time distribution 196 # 1us 197 # 10us 198 # 100us 199 # 1ms ################################################################ 200 # 10ms 201 # 100ms 202 # 1s ################################################################ 203 # 10s+ ################################################################ 204 # Tables 205 # SHOW TABLE STATUS FROM `world` LIKE 't1'\G 206 # SHOW CREATE TABLE `world`.`t1`\G 207 # EXPLAIN /*!50100 PARTITIONS*/ 208 select count(*) from t1\G
