如何使用Performance Schema诊断磁盘IO很高的问题

2024-04-02 19:55

短信预约 -IT技能 免费直播动态提醒

这篇文章主要介绍如何使用Performance Schema诊断磁盘IO很高的问题，文中介绍的非常详细，具有一定的参考价值，感兴趣的小伙伴们一定要看完！

--运行基准测试，-w5 表示5个数据仓库、-c5 表示5个并发线程、-r30 表示预热30秒、-l1300表示基准测试进行1300秒。

[root@oradb tpcc-mysql-master]# ./tpcc_start -h227.0.0.1 -d tpcc1000 -u root -p "" -w5 -c5 -r30 -l300
./tpcc_start: /usr/lib64/libmysqlclient.so.18: no version information available (required by ./tpcc_start)
***************************************
*** ###easy### TPC-C Load Generator ***
***************************************
option h with value '127.0.0.1'
option d with value 'tpcc1000'
option u with value 'root'
option p with value ''
option w with value '5'
option c with value '5'
option r with value '30'
option l with value '300'
<Parameters>
     [server]: 127.0.0.1
     [port]: 3306
     [DBname]: tpcc1000
       [user]: root
       [pass]:
[warehouse]: 5
[connection]: 5
     [rampup]: 30 (sec.)
    [measure]: 300 (sec.)

RAMP-UP TIME.(30 sec.)

MEASURING START.

10, trx: 422, 95%: 378.265, 99%: 644.077, max_rt: 1339.584, 419|1324.801, 42|446.450, 43|1749.443, 41|716.969
20, trx: 414, 95%: 259.337, 99%: 438.679, max_rt: 806.024, 420|853.354, 42|312.038, 40|622.560, 42|121.157
30, trx: 261, 95%: 421.179, 99%: 740.933, max_rt: 777.106, 258|701.134, 25|457.319, 27|792.212, 26|523.207
40, trx: 277, 95%: 378.151, 99%: 704.172, max_rt: 2002.042, 276|2045.133, 28|429.541, 27|2237.859, 28|130.449
50, trx: 160, 95%: 480.614, 99%: 651.056, max_rt: 985.258, 158|459.083, 16|245.964, 16|1417.654, 16|563.886
60, trx: 90, 95%: 708.824, 99%: 849.042, max_rt: 1323.185, 91|802.244, 9|386.973, 9|1986.407, 9|391.601
70, trx: 74, 95%: 830.939, 99%: 1178.015, max_rt: 1200.446, 72|788.552, 7|733.687, 7|2388.102, 7|115.488
80, trx: 89, 95%: 625.458, 99%: 733.430, max_rt: 943.492, 90|689.570, 9|181.559, 10|2243.094, 9|129.381
90, trx: 71, 95%: 825.238, 99%: 914.197, max_rt: 1154.404, 72|765.741, 8|808.538, 7|2175.806, 7|101.286
100, trx: 88, 95%: 823.264, 99%: 996.208, max_rt: 1183.609, 91|733.170, 8|4.016, 8|2400.345, 9|661.085
110, trx: 150, 95%: 626.770, 99%: 1147.389, max_rt: 1181.055, 146|1080.564, 15|575.601, 15|1947.824, 15|691.386
120, trx: 147, 95%: 637.937, 99%: 1074.584, max_rt: 1171.729, 146|608.253, 14|356.148, 15|2406.227, 15|387.593
130, trx: 234, 95%: 499.237, 99%: 637.937, max_rt: 828.361, 234|704.593, 24|321.325, 23|1181.115, 23|508.533
140, trx: 337, 95%: 325.293, 99%: 688.745, max_rt: 1501.746, 341|1544.483, 34|342.186, 34|1842.396, 34|591.036
150, trx: 334, 95%: 392.334, 99%: 513.331, max_rt: 528.796, 329|443.930, 33|679.107, 33|1037.018, 33|567.419
160, trx: 243, 95%: 396.822, 99%: 632.992, max_rt: 677.771, 244|479.220, 25|198.146, 25|891.251, 24|423.809
170, trx: 218, 95%: 462.133, 99%: 1445.245, max_rt: 1489.565, 224|1350.957, 22|464.090, 22|1756.344, 23|522.397
180, trx: 136, 95%: 586.999, 99%: 900.885, max_rt: 949.145, 134|912.644, 13|309.611, 14|1461.992, 13|618.071
190, trx: 155, 95%: 531.309, 99%: 599.429, max_rt: 619.602, 154|605.849, 16|334.206, 15|1510.990, 15|150.337
200, trx: 90, 95%: 765.965, 99%: 1380.134, max_rt: 1401.853, 90|701.062, 8|444.163, 8|1860.412, 10|527.606
210, trx: 107, 95%: 713.507, 99%: 881.677, max_rt: 909.917, 108|750.593, 11|924.851, 11|1844.187, 10|581.777
220, trx: 131, 95%: 572.938, 99%: 610.475, max_rt: 623.113, 132|591.156, 13|32.647, 14|1560.026, 13|443.198
230, trx: 206, 95%: 601.946, 99%: 972.344, max_rt: 1387.751, 203|943.939, 21|305.626, 20|1550.676, 21|745.400
240, trx: 200, 95%: 610.475, 99%: 707.340, max_rt: 971.274, 200|666.495, 20|370.174, 20|1257.401, 20|617.530
250, trx: 214, 95%: 594.426, 99%: 699.131, max_rt: 963.352, 213|639.747, 21|243.582, 21|1247.193, 21|546.165
260, trx: 157, 95%: 553.551, 99%: 734.529, max_rt: 824.921, 158|1123.786, 16|502.626, 16|1452.954, 16|1307.927
270, trx: 221, 95%: 519.669, 99%: 656.535, max_rt: 732.609, 227|668.130, 23|249.434, 22|1224.523, 23|115.144
280, trx: 295, 95%: 397.655, 99%: 639.850, max_rt: 1076.247, 293|640.412, 29|254.008, 30|1062.539, 29|92.491
290, trx: 271, 95%: 376.457, 99%: 553.882, max_rt: 1564.303, 262|1561.225, 27|236.800, 27|2130.112, 26|1582.071
300, trx: 221, 95%: 442.768, 99%: 620.795, max_rt: 653.794, 226|619.174, 22|424.719, 23|1304.569, 23|141.760

STOPPING THREADS.....

<Raw Results>
[0] sc:0 lt:6013 rt:0 fl:0 avg_rt: 143.9 (5)
[1] sc:532 lt:5479 rt:0 fl:0 avg_rt: 60.7 (5)
[2] sc:288 lt:313 rt:0 fl:0 avg_rt: 50.4 (5)
[3] sc:32 lt:570 rt:0 fl:0 avg_rt: 550.3 (80)
[4] sc:13 lt:588 rt:0 fl:0 avg_rt: 96.3 (20)
in 300 sec.

<Raw Results2(sum ver.)>
[0] sc:0 lt:6013 rt:0 fl:0
[1] sc:532 lt:5479 rt:0 fl:0
[2] sc:288 lt:313 rt:0 fl:0
[3] sc:32 lt:570 rt:0 fl:0
[4] sc:13 lt:588 rt:0 fl:0

<Constraint Check> (all must be [OK])
[transaction percentage]
        Payment: 43.47% (>=43.0%) [OK]
   Order-Status: 4.35% (>= 4.0%) [OK]
       Delivery: 4.35% (>= 4.0%) [OK]
    Stock-Level: 4.35% (>= 4.0%) [OK]
[response time (at least 90% passed)]
      New-Order: 0.00% [NG] *
        Payment: 8.85% [NG] *
   Order-Status: 47.92% [NG] *
       Delivery: 5.32% [NG] *
    Stock-Level: 2.16% [NG] *

<TpmC>
                 1202.600 TpmC
[root@oradb tpcc-mysql-master]#

--收集操作系统性能数据
从下面 iostat -m -x 收集到的数据我们看到IO响应时间非常慢最高达到 254 ms了。
IO 吞吐量也很高，最高达到了7.55 MB。

iostat -m -x 1 30 > iostat_x.txt

avg-cpu: %user   %nice %system %iowait %steal   %idle
          13.27    0.00   14.29   71.94    0.00    0.51

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await svctm %util
sda              28.71    33.66    6.93    0.00     0.16     0.00    48.00     2.94 247.57 142.71 98.91
sdb               0.00 1780.20   25.74 239.60     0.10     7.55    59.04     3.80    9.31   3.36 89.21
scd0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

avg-cpu: %user   %nice %system %iowait %steal   %idle
           5.05    0.00    5.05   89.90    0.00    0.00

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await svctm %util
sda              48.00     0.00   13.00    1.00     0.26     0.14    57.71     1.50 254.21 71.36 99.90
sdb               0.00   889.00    5.00 107.00     0.02     4.24    77.93     4.61   52.71   8.62 96.60
scd0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

avg-cpu: %user   %nice %system %iowait %steal   %idle
           7.69    0.00   10.26   75.90    0.00    6.15

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await svctm %util
sda              77.00    23.00    8.00    1.00     0.40     0.09   112.89     1.31 133.00 110.89 99.80
sdb               0.00 1743.00   18.00 197.00     0.09     7.41    71.52     2.92   12.80   4.40 94.60
scd0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

avg-cpu: %user   %nice %system %iowait %steal   %idle
           6.06    0.00   10.10   72.22    0.00   11.62

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await svctm %util
sda              30.00     5.00    2.00    5.00     0.01     0.04    13.71     1.25 115.71 143.14 100.20
sdb               0.00 1394.00   10.00 155.00     0.04     6.12    76.41     4.05   23.53   5.69 93.90
scd0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.0

从 iostat -t -m 收集到的数据我们看到，IOPS 也很高最高达到 407,测试系统是在单硬盘的笔记本上，IOPS也达到硬盘的
极限了。

iostat -t -m 1 30 > iostat_t.txt

Device:            tps    MB_read/s    MB_wrtn/s    MB_read    MB_wrtn
sda               1.20         0.01         0.09          0          1
sdb             261.95         0.36         4.27          7         85
scd0              0.00         0.00         0.00          0          0

01/21/2017 06:45:46 PM
avg-cpu: %user   %nice %system %iowait %steal   %idle
          17.14    0.00   14.34   50.66    0.00   17.86

Device:            tps    MB_read/s    MB_wrtn/s    MB_read    MB_wrtn
sda               1.05         0.00         0.12          0          2
sdb             407.40         0.48         5.55          9        111
scd0              0.00         0.00         0.00          0          0

01/21/2017 06:46:06 PM
avg-cpu: %user   %nice %system %iowait %steal   %idle
          13.14    0.00   12.27   56.23    0.00   18.36

Device:            tps    MB_read/s    MB_wrtn/s    MB_read    MB_wrtn
sda               0.65         0.00         0.05          0          1
sdb             323.55         0.33         6.32          6        126
scd0              0.00         0.00         0.00          0          0

01/21/2017 06:46:26 PM
avg-cpu: %user   %nice %system %iowait %steal   %idle
          10.05    0.00    8.93   64.61    0.00   16.41

Device:            tps    MB_read/s    MB_wrtn/s    MB_read    MB_wrtn
sda               1.60         0.02         0.01          0          0
sdb             241.15         0.19         5.60          3        111
scd0              0.00         0.00         0.00          0          0

vmstat 监控到的数据显示有比较高的页面交互，说明内存也有瓶颈。

vmstat 1 30 > vmstat.txt

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r b   swpd   free   buff cache   si   so    bi    bo   in   cs us sy id wa st
3 2 81704 38492 49496 473380    0    2    26   177   58 174 1 1 93 5 0
0 4 81704 35268 50280 475740    0    0   284 9168 1929 10386 21 19 23 36 0
5 0 81704 33276 50752 477120    0    0   392 4020 1127 5061 10 11 15 64 0
0 3 81704 30176 51320 479540    0    0   672 8128 1621 7571 14 18 4 65 0
0 1 81704 26200 52348 482244    0    0   660 4404 2400 12050 24 27 10 39 0
2 1 81704 24464 52632 483708    0    0   220 7384 959 4233 9 11 32 48 0
1 1 81704 22356 53144 485080    0    0   296 2060 1457 6707 14 15 10 61 0
1 2 81704 18388 54080 487944    0    0   648 9624 2190 10513 19 21 29 30 0
0 1 81704 16528 54768 489272    0    0   692 6112 2517 12801 28 21 9 41 0
1 2 81704 16660 54268 488368    0    0   312 33024 1118 5572 7 13 15 65 0
0 3 81704 17156 54316 488524    0    0    44 1440 312 711 5 8 22 65 0
0 4 81704 16412 54672 489044    0    0   828 9116 2488 12398 24 27 9 41 0
3 1 81704 15428 55140 490172    0    0   188 4264 1357 6753 14 12 36 38 0
0 4 81704 15428 54844 490380    0    0   380 6348 2247 13382 24 25 18 33 0
0 3 82032 16660 54328 489804    0 328   132 8448 1333 5385 9 16 20 54 0
5 2 82040 16536 54172 490216    0    8   404 7576 1760 8996 20 17 12 51 0
2 2 82140 15916 54456 490860    0 100   128 5292 916 3835 11 9 17 63 0
0 5 82372 16784 54248 490036    0 232   748 6960 1821 9040 16 17 16 51 0
0 4 82372 16296 54424 490768    0    0    44 5856 675 2719 7 7 37 49 0
0 2 82496 16668 54368 490368    0 124   212 3396 1432 7095 14 16 14 56 0
0 2 82708 16544 54240 490460    0 212   324 8772 1189 4446 12 12 24 51 0

从 sar 采集到的数据看到 CPU 使用率在 50%以下，IO等待非常高。
sar 1 100 > sar_cup.txt

Linux 2.6.32-358.el6.x86_64 (oradb)     01/21/2017      _x86_64_        (2 CPU)

08:30:28 PM     CPU     %user     %nice   %system   %iowait    %steal     %idle
08:30:29 PM     all     27.60      0.00     25.52     24.48      0.00     22.40
08:30:30 PM     all     11.92      0.00     17.62     37.82      0.00     32.64
08:30:31 PM     all     33.69      0.00     39.57     12.83      0.00     13.90
08:30:32 PM     all     20.11      0.00     17.99     38.10      0.00     23.81
...
...
08:31:13 PM     all     25.97      0.00     27.92     38.96      0.00      7.14
08:31:14 PM     all     20.31      0.00     22.40     45.83      0.00     11.46
08:31:15 PM     all      9.23      0.00     11.28     57.44      0.00     22.05
08:31:16 PM     all     14.87      0.00     12.82     63.59      0.00      8.72
08:31:17 PM     all      5.58      0.00     10.15     84.26      0.00      0.00
08:31:18 PM     all     10.71      0.00     12.76     72.45      0.00      4.08
08:31:19 PM     all      6.06      0.00      8.08     60.10      0.00     25.76
08:31:20 PM     all      6.03      0.00     11.56     78.39      0.00      4.02

--查询 TOP 等待事件。wait/io/table/sql/handler 、 wait/io/file/innodb/innodb_data_file 、
wait/io/file/innodb/innodb_log_file 从这三个等待事件可以看出SQL语句执行的IO很高。

SELECT EVENT_NAME, COUNT_STAR, SUM_TIMER_WAIT/1000000000/1000 SUM_TIMER_WAIT_S
FROM performance_schema.events_waits_summary_global_by_event_name
WHERE SUM_TIMER_WAIT > 0
ORDER BY SUM_TIMER_WAIT_S DESC limit 10;

+---------------------------------------------+------------+------------------+
| EVENT_NAME                                  | COUNT_STAR | SUM_TIMER_WAIT_S |
+---------------------------------------------+------------+------------------+
| idle                                        |    1676508 |   17307.68345000 |
| wait/io/table/sql/handler                   |    3311993 |    1671.83549048 |
| wait/io/file/innodb/innodb_data_file        |     199031 |    1314.09742473 |
| wait/synch/mutex/innodb/log_sys_mutex       |    2808316 |     892.47430292 |
| wait/io/file/innodb/innodb_log_file         |      89663 |     850.32584669 |
| wait/synch/rwlock/innodb/index_tree_rw_lock |    2156929 |     309.88532722 |
| wait/io/socket/sql/client_connection        |    3362765 |     237.19291335 |
| wait/synch/mutex/innodb/buf_pool_mutex      |    2003905 |     201.11709623 |
| wait/synch/mutex/sql/LOG::LOCK_log          |     581942 |     112.99169113 |
| wait/io/file/sql/slow_log                   |     581946 |      56.83859129 |
+---------------------------------------------+------------+------------------+
10 rows in set (0.17 sec)

--查询IO等待很高的表
SELECT OBJECT_TYPE,OBJECT_SCHEMA,OBJECT_NAME,COUNT_STAR,
       SUM_TIMER_WAIT/1000000000/1000 SUM_TIMER_WAIT_S,MIN_TIMER_WAIT/1000000000
       MIN_TIMER_WAIT_MS,AVG_TIMER_WAIT/1000000000 AVG_TIMER_WAIT_MS,
       MAX_TIMER_WAIT/1000000000 MAX_TIMER_WAIT_MS,COUNT_READ,SUM_TIMER_READ
       /1000000000/1000 SUM_TIMER_READ_S,MIN_TIMER_READ/1000000000 MIN_TIMER_READ_MS,
       AVG_TIMER_READ/1000000000 AVG_TIMER_READ_MS,COUNT_WRITE,SUM_TIMER_WRITE/1000000000/1000
       SUM_TIMER_WRITE_S,MIN_TIMER_WRITE/1000000000 MIN_TIMER_WRITE_MS,
       AVG_TIMER_WRITE/1000000000 AVG_TIMER_WRITE_MS,MAX_TIMER_WRITE/1000000000 MAX_TIMER_WRITE_MS,
       COUNT_FETCH,SUM_TIMER_FETCH/1000000000/1000 SUM_TIMER_FETCH_MS,MIN_TIMER_FETCH/1000000000
       MIN_TIMER_FETCH_MS,AVG_TIMER_FETCH/1000000000 AVG_TIMER_FETCH_MS,MAX_TIMER_FETCH/1000000000
       MAX_TIMER_FETCH_MS,COUNT_INSERT,SUM_TIMER_INSERT/1000000000/1000 SUM_TIMER_INSERT_S,
       MIN_TIMER_INSERT/1000000000 MIN_TIMER_INSERT_MS,AVG_TIMER_INSERT/1000000000 AVG_TIMER_INSERT_MS,
       MAX_TIMER_INSERT/1000000000 MAX_TIMER_INSERT_MS,COUNT_UPDATE,SUM_TIMER_UPDATE/1000000000/1000
       SUM_TIMER_UPDATE_S,MIN_TIMER_UPDATE/1000000000 MIN_TIMER_UPDATE_MS,AVG_TIMER_UPDATE/1000000000
       AVG_TIMER_UPDATE_MS,MAX_TIMER_UPDATE/1000000000 MAX_TIMER_UPDATE_MS,COUNT_DELETE,
       SUM_TIMER_DELETE/1000000000/1000 SUM_TIMER_DELETE_S,MIN_TIMER_DELETE/1000000000 MIN_TIMER_DELETE_MS,
       AVG_TIMER_DELETE/1000000000 AVG_TIMER_DELETE_MS,MAX_TIMER_DELETE/1000000000 MAX_TIMER_DELETE_MS
FROM   performance_schema.table_io_waits_summary_by_table
ORDER BY SUM_TIMER_WAIT desc limit 10\G

*************************** 1. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: order_line
         COUNT_STAR: 1455332
   SUM_TIMER_WAIT_S: 574.51256521
MIN_TIMER_WAIT_MS: 0.0000
AVG_TIMER_WAIT_MS: 0.3948
MAX_TIMER_WAIT_MS: 922.2728
         COUNT_READ: 1057831
   SUM_TIMER_READ_S: 6.01709087
MIN_TIMER_READ_MS: 0.0000
AVG_TIMER_READ_MS: 0.0057
        COUNT_WRITE: 397501
SUM_TIMER_WRITE_S: 568.49547434
MIN_TIMER_WRITE_MS: 0.0030
AVG_TIMER_WRITE_MS: 1.4302
MAX_TIMER_WRITE_MS: 922.2728
        COUNT_FETCH: 1057831
SUM_TIMER_FETCH_MS: 6.01709087
MIN_TIMER_FETCH_MS: 0.0000
AVG_TIMER_FETCH_MS: 0.0057
MAX_TIMER_FETCH_MS: 183.5779
       COUNT_INSERT: 199249
SUM_TIMER_INSERT_S: 336.75969226
MIN_TIMER_INSERT_MS: 0.0206
AVG_TIMER_INSERT_MS: 1.6901
MAX_TIMER_INSERT_MS: 922.2728
       COUNT_UPDATE: 198252
SUM_TIMER_UPDATE_S: 231.73578208
MIN_TIMER_UPDATE_MS: 0.0030
AVG_TIMER_UPDATE_MS: 1.1689
MAX_TIMER_UPDATE_MS: 807.1428
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 2. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: stock
         COUNT_STAR: 993140
   SUM_TIMER_WAIT_S: 488.01107930
MIN_TIMER_WAIT_MS: 0.0029
AVG_TIMER_WAIT_MS: 0.4914
MAX_TIMER_WAIT_MS: 1192.9233
         COUNT_READ: 793891
   SUM_TIMER_READ_S: 264.27530673
MIN_TIMER_READ_MS: 0.0029
AVG_TIMER_READ_MS: 0.3329
        COUNT_WRITE: 199249
SUM_TIMER_WRITE_S: 223.73577258
MIN_TIMER_WRITE_MS: 0.0065
AVG_TIMER_WRITE_MS: 1.1229
MAX_TIMER_WRITE_MS: 859.9627
        COUNT_FETCH: 793891
SUM_TIMER_FETCH_MS: 264.27530673
MIN_TIMER_FETCH_MS: 0.0029
AVG_TIMER_FETCH_MS: 0.3329
MAX_TIMER_FETCH_MS: 1192.9233
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 199249
SUM_TIMER_UPDATE_S: 223.73577258
MIN_TIMER_UPDATE_MS: 0.0065
AVG_TIMER_UPDATE_MS: 1.1229
MAX_TIMER_UPDATE_MS: 859.9627
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 3. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: district
         COUNT_STAR: 121076
   SUM_TIMER_WAIT_S: 177.79414354
MIN_TIMER_WAIT_MS: 0.0029
AVG_TIMER_WAIT_MS: 1.4685
MAX_TIMER_WAIT_MS: 924.7429
         COUNT_READ: 81379
   SUM_TIMER_READ_S: 123.04566120
MIN_TIMER_READ_MS: 0.0029
AVG_TIMER_READ_MS: 1.5120
        COUNT_WRITE: 39697
SUM_TIMER_WRITE_S: 54.74848235
MIN_TIMER_WRITE_MS: 0.0059
AVG_TIMER_WRITE_MS: 1.3792
MAX_TIMER_WRITE_MS: 702.2465
        COUNT_FETCH: 81379
SUM_TIMER_FETCH_MS: 123.04566120
MIN_TIMER_FETCH_MS: 0.0029
AVG_TIMER_FETCH_MS: 1.5120
MAX_TIMER_FETCH_MS: 924.7429
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 39697
SUM_TIMER_UPDATE_S: 54.74848235
MIN_TIMER_UPDATE_MS: 0.0059
AVG_TIMER_UPDATE_MS: 1.3792
MAX_TIMER_UPDATE_MS: 702.2465
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 4. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: warehouse
         COUNT_STAR: 79395
   SUM_TIMER_WAIT_S: 151.81620350
MIN_TIMER_WAIT_MS: 0.0024
AVG_TIMER_WAIT_MS: 1.9122
MAX_TIMER_WAIT_MS: 996.6039
         COUNT_READ: 59546
   SUM_TIMER_READ_S: 112.12478330
MIN_TIMER_READ_MS: 0.0024
AVG_TIMER_READ_MS: 1.8830
        COUNT_WRITE: 19849
SUM_TIMER_WRITE_S: 39.69142021
MIN_TIMER_WRITE_MS: 0.0085
AVG_TIMER_WRITE_MS: 1.9997
MAX_TIMER_WRITE_MS: 835.0655
        COUNT_FETCH: 59546
SUM_TIMER_FETCH_MS: 112.12478330
MIN_TIMER_FETCH_MS: 0.0024
AVG_TIMER_FETCH_MS: 1.8830
MAX_TIMER_FETCH_MS: 996.6039
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 19849
SUM_TIMER_UPDATE_S: 39.69142021
MIN_TIMER_UPDATE_MS: 0.0085
AVG_TIMER_UPDATE_MS: 1.9997
MAX_TIMER_UPDATE_MS: 835.0655
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 5. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: customer
         COUNT_STAR: 280988
   SUM_TIMER_WAIT_S: 145.32048467
MIN_TIMER_WAIT_MS: 0.0001
AVG_TIMER_WAIT_MS: 0.5172
MAX_TIMER_WAIT_MS: 1054.3388
         COUNT_READ: 241279
   SUM_TIMER_READ_S: 97.77801597
MIN_TIMER_READ_MS: 0.0001
AVG_TIMER_READ_MS: 0.4052
        COUNT_WRITE: 39709
SUM_TIMER_WRITE_S: 47.54246870
MIN_TIMER_WRITE_MS: 0.0089
AVG_TIMER_WRITE_MS: 1.1973
MAX_TIMER_WRITE_MS: 691.0986
        COUNT_FETCH: 241279
SUM_TIMER_FETCH_MS: 97.77801597
MIN_TIMER_FETCH_MS: 0.0001
AVG_TIMER_FETCH_MS: 0.4052
MAX_TIMER_FETCH_MS: 1054.3388
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 39709
SUM_TIMER_UPDATE_S: 47.54246870
MIN_TIMER_UPDATE_MS: 0.0089
AVG_TIMER_UPDATE_MS: 1.1973
MAX_TIMER_UPDATE_MS: 691.0986
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 6. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: new_orders
         COUNT_STAR: 79379
   SUM_TIMER_WAIT_S: 68.86707617
MIN_TIMER_WAIT_MS: 0.0064
AVG_TIMER_WAIT_MS: 0.8676
MAX_TIMER_WAIT_MS: 875.6474
         COUNT_READ: 39720
   SUM_TIMER_READ_S: 7.18077003
MIN_TIMER_READ_MS: 0.0064
AVG_TIMER_READ_MS: 0.1808
        COUNT_WRITE: 39659
SUM_TIMER_WRITE_S: 61.68630614
MIN_TIMER_WRITE_MS: 0.0074
AVG_TIMER_WRITE_MS: 1.5554
MAX_TIMER_WRITE_MS: 875.6474
        COUNT_FETCH: 39720
SUM_TIMER_FETCH_MS: 7.18077003
MIN_TIMER_FETCH_MS: 0.0064
AVG_TIMER_FETCH_MS: 0.1808
MAX_TIMER_FETCH_MS: 489.3697
       COUNT_INSERT: 19848
SUM_TIMER_INSERT_S: 36.79682450
MIN_TIMER_INSERT_MS: 0.0140
AVG_TIMER_INSERT_MS: 1.8539
MAX_TIMER_INSERT_MS: 759.8047
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 19811
SUM_TIMER_DELETE_S: 24.88948165
MIN_TIMER_DELETE_MS: 0.0074
AVG_TIMER_DELETE_MS: 1.2563
MAX_TIMER_DELETE_MS: 875.6474
*************************** 7. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: orders
         COUNT_STAR: 83396
   SUM_TIMER_WAIT_S: 39.93340212
MIN_TIMER_WAIT_MS: 0.0044
AVG_TIMER_WAIT_MS: 0.4788
MAX_TIMER_WAIT_MS: 792.5677
         COUNT_READ: 43688
   SUM_TIMER_READ_S: 15.47384546
MIN_TIMER_READ_MS: 0.0044
AVG_TIMER_READ_MS: 0.3542
        COUNT_WRITE: 39708
SUM_TIMER_WRITE_S: 24.45955666
MIN_TIMER_WRITE_MS: 0.0091
AVG_TIMER_WRITE_MS: 0.6160
MAX_TIMER_WRITE_MS: 606.3633
        COUNT_FETCH: 43688
SUM_TIMER_FETCH_MS: 15.47384546
MIN_TIMER_FETCH_MS: 0.0044
AVG_TIMER_FETCH_MS: 0.3542
MAX_TIMER_FETCH_MS: 792.5677
       COUNT_INSERT: 19848
SUM_TIMER_INSERT_S: 13.18987522
MIN_TIMER_INSERT_MS: 0.0246
AVG_TIMER_INSERT_MS: 0.6645
MAX_TIMER_INSERT_MS: 494.0147
       COUNT_UPDATE: 19860
SUM_TIMER_UPDATE_S: 11.26968144
MIN_TIMER_UPDATE_MS: 0.0091
AVG_TIMER_UPDATE_MS: 0.5675
MAX_TIMER_UPDATE_MS: 606.3633
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 8. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: history
         COUNT_STAR: 19849
   SUM_TIMER_WAIT_S: 20.14300773
MIN_TIMER_WAIT_MS: 0.0308
AVG_TIMER_WAIT_MS: 1.0148
MAX_TIMER_WAIT_MS: 748.5716
         COUNT_READ: 0
   SUM_TIMER_READ_S: 0.00000000
MIN_TIMER_READ_MS: 0.0000
AVG_TIMER_READ_MS: 0.0000
        COUNT_WRITE: 19849
SUM_TIMER_WRITE_S: 20.14300773
MIN_TIMER_WRITE_MS: 0.0308
AVG_TIMER_WRITE_MS: 1.0148
MAX_TIMER_WRITE_MS: 748.5716
        COUNT_FETCH: 0
SUM_TIMER_FETCH_MS: 0.00000000
MIN_TIMER_FETCH_MS: 0.0000
AVG_TIMER_FETCH_MS: 0.0000
MAX_TIMER_FETCH_MS: 0.0000
       COUNT_INSERT: 19849
SUM_TIMER_INSERT_S: 20.14300773
MIN_TIMER_INSERT_MS: 0.0308
AVG_TIMER_INSERT_MS: 1.0148
MAX_TIMER_INSERT_MS: 748.5716
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 9. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: item
         COUNT_STAR: 199431
   SUM_TIMER_WAIT_S: 5.39589117
MIN_TIMER_WAIT_MS: 0.0034
AVG_TIMER_WAIT_MS: 0.0271
MAX_TIMER_WAIT_MS: 260.9822
         COUNT_READ: 199431
   SUM_TIMER_READ_S: 5.39589117
MIN_TIMER_READ_MS: 0.0034
AVG_TIMER_READ_MS: 0.0271
        COUNT_WRITE: 0
SUM_TIMER_WRITE_S: 0.00000000
MIN_TIMER_WRITE_MS: 0.0000
AVG_TIMER_WRITE_MS: 0.0000
MAX_TIMER_WRITE_MS: 0.0000
        COUNT_FETCH: 199431
SUM_TIMER_FETCH_MS: 5.39589117
MIN_TIMER_FETCH_MS: 0.0034
AVG_TIMER_FETCH_MS: 0.0271
MAX_TIMER_FETCH_MS: 260.9822
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 10. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: test
        OBJECT_NAME: t1
         COUNT_STAR: 7
   SUM_TIMER_WAIT_S: 0.04163705
MIN_TIMER_WAIT_MS: 0.0008
AVG_TIMER_WAIT_MS: 5.9482
MAX_TIMER_WAIT_MS: 41.5725
         COUNT_READ: 7
   SUM_TIMER_READ_S: 0.04163705
MIN_TIMER_READ_MS: 0.0008
AVG_TIMER_READ_MS: 5.9482
        COUNT_WRITE: 0
SUM_TIMER_WRITE_S: 0.00000000
MIN_TIMER_WRITE_MS: 0.0000
AVG_TIMER_WRITE_MS: 0.0000
MAX_TIMER_WRITE_MS: 0.0000
        COUNT_FETCH: 7
SUM_TIMER_FETCH_MS: 0.04163705
MIN_TIMER_FETCH_MS: 0.0008
AVG_TIMER_FETCH_MS: 5.9482
MAX_TIMER_FETCH_MS: 41.5725
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
10 rows in set (0.00 sec)

--查询IO等待很高的索引
SELECT OBJECT_TYPE,OBJECT_SCHEMA,OBJECT_NAME,INDEX_NAME,COUNT_STAR,
       SUM_TIMER_WAIT/1000000000/1000 SUM_TIMER_WAIT_S,MIN_TIMER_WAIT/1000000000
       MIN_TIMER_WAIT_MS,AVG_TIMER_WAIT/1000000000 AVG_TIMER_WAIT_MS,
       MAX_TIMER_WAIT/1000000000 MAX_TIMER_WAIT_MS,COUNT_READ,SUM_TIMER_READ
       /1000000000/1000 SUM_TIMER_READ_S,MIN_TIMER_READ/1000000000 MIN_TIMER_READ_MS,
       AVG_TIMER_READ/1000000000 AVG_TIMER_READ_MS,COUNT_WRITE,SUM_TIMER_WRITE/1000000000/1000
       SUM_TIMER_WRITE_S,MIN_TIMER_WRITE/1000000000 MIN_TIMER_WRITE_MS,
       AVG_TIMER_WRITE/1000000000 AVG_TIMER_WRITE_MS,MAX_TIMER_WRITE/1000000000 MAX_TIMER_WRITE_MS,
       COUNT_FETCH,SUM_TIMER_FETCH/1000000000/1000 SUM_TIMER_FETCH_MS,MIN_TIMER_FETCH/1000000000
       MIN_TIMER_FETCH_MS,AVG_TIMER_FETCH/1000000000 AVG_TIMER_FETCH_MS,MAX_TIMER_FETCH/1000000000
       MAX_TIMER_FETCH_MS,COUNT_INSERT,SUM_TIMER_INSERT/1000000000/1000 SUM_TIMER_INSERT_S,
       MIN_TIMER_INSERT/1000000000 MIN_TIMER_INSERT_MS,AVG_TIMER_INSERT/1000000000 AVG_TIMER_INSERT_MS,
       MAX_TIMER_INSERT/1000000000 MAX_TIMER_INSERT_MS,COUNT_UPDATE,SUM_TIMER_UPDATE/1000000000/1000
       SUM_TIMER_UPDATE_S,MIN_TIMER_UPDATE/1000000000 MIN_TIMER_UPDATE_MS,AVG_TIMER_UPDATE/1000000000
       AVG_TIMER_UPDATE_MS,MAX_TIMER_UPDATE/1000000000 MAX_TIMER_UPDATE_MS,COUNT_DELETE,
       SUM_TIMER_DELETE/1000000000/1000 SUM_TIMER_DELETE_S,MIN_TIMER_DELETE/1000000000 MIN_TIMER_DELETE_MS,
       AVG_TIMER_DELETE/1000000000 AVG_TIMER_DELETE_MS,MAX_TIMER_DELETE/1000000000 MAX_TIMER_DELETE_MS
FROM   performance_schema.table_io_waits_summary_by_index_usage
ORDER BY SUM_TIMER_WAIT desc limit 10\G

*************************** 1. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: stock
         INDEX_NAME: PRIMARY
         COUNT_STAR: 993140
   SUM_TIMER_WAIT_S: 488.01107930
MIN_TIMER_WAIT_MS: 0.0029
AVG_TIMER_WAIT_MS: 0.4914
MAX_TIMER_WAIT_MS: 1192.9233
         COUNT_READ: 793891
   SUM_TIMER_READ_S: 264.27530673
MIN_TIMER_READ_MS: 0.0029
AVG_TIMER_READ_MS: 0.3329
        COUNT_WRITE: 199249
SUM_TIMER_WRITE_S: 223.73577258
MIN_TIMER_WRITE_MS: 0.0065
AVG_TIMER_WRITE_MS: 1.1229
MAX_TIMER_WRITE_MS: 859.9627
        COUNT_FETCH: 793891
SUM_TIMER_FETCH_MS: 264.27530673
MIN_TIMER_FETCH_MS: 0.0029
AVG_TIMER_FETCH_MS: 0.3329
MAX_TIMER_FETCH_MS: 1192.9233
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 199249
SUM_TIMER_UPDATE_S: 223.73577258
MIN_TIMER_UPDATE_MS: 0.0065
AVG_TIMER_UPDATE_MS: 1.1229
MAX_TIMER_UPDATE_MS: 859.9627
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 2. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: order_line
         INDEX_NAME: NULL     >>>该表没有使用索引，但在慢查询SQL查询该表的SQL占的比例并不大，所以没使用索引不是IO高的根本原因。
         COUNT_STAR: 397987
   SUM_TIMER_WAIT_S: 340.21943418
MIN_TIMER_WAIT_MS: 0.0024
AVG_TIMER_WAIT_MS: 0.8549
MAX_TIMER_WAIT_MS: 922.2728
         COUNT_READ: 198738
   SUM_TIMER_READ_S: 3.45974192
MIN_TIMER_READ_MS: 0.0024
AVG_TIMER_READ_MS: 0.0174
        COUNT_WRITE: 199249
SUM_TIMER_WRITE_S: 336.75969226
MIN_TIMER_WRITE_MS: 0.0206
AVG_TIMER_WRITE_MS: 1.6901
MAX_TIMER_WRITE_MS: 922.2728
        COUNT_FETCH: 198738
SUM_TIMER_FETCH_MS: 3.45974192
MIN_TIMER_FETCH_MS: 0.0024
AVG_TIMER_FETCH_MS: 0.0174
MAX_TIMER_FETCH_MS: 179.3644
       COUNT_INSERT: 199249
SUM_TIMER_INSERT_S: 336.75969226
MIN_TIMER_INSERT_MS: 0.0206
AVG_TIMER_INSERT_MS: 1.6901
MAX_TIMER_INSERT_MS: 922.2728
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 3. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: order_line
         INDEX_NAME: PRIMARY
         COUNT_STAR: 1057345
   SUM_TIMER_WAIT_S: 234.29313103
MIN_TIMER_WAIT_MS: 0.0000
AVG_TIMER_WAIT_MS: 0.2216
MAX_TIMER_WAIT_MS: 807.1428
         COUNT_READ: 859093
   SUM_TIMER_READ_S: 2.55734895
MIN_TIMER_READ_MS: 0.0000
AVG_TIMER_READ_MS: 0.0030
        COUNT_WRITE: 198252
SUM_TIMER_WRITE_S: 231.73578208
MIN_TIMER_WRITE_MS: 0.0030
AVG_TIMER_WRITE_MS: 1.1689
MAX_TIMER_WRITE_MS: 807.1428
        COUNT_FETCH: 859093
SUM_TIMER_FETCH_MS: 2.55734895
MIN_TIMER_FETCH_MS: 0.0000
AVG_TIMER_FETCH_MS: 0.0030
MAX_TIMER_FETCH_MS: 183.5779
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 198252
SUM_TIMER_UPDATE_S: 231.73578208
MIN_TIMER_UPDATE_MS: 0.0030
AVG_TIMER_UPDATE_MS: 1.1689
MAX_TIMER_UPDATE_MS: 807.1428
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 4. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: district
         INDEX_NAME: PRIMARY
         COUNT_STAR: 121076
   SUM_TIMER_WAIT_S: 177.79414354
MIN_TIMER_WAIT_MS: 0.0029
AVG_TIMER_WAIT_MS: 1.4685
MAX_TIMER_WAIT_MS: 924.7429
         COUNT_READ: 81379
   SUM_TIMER_READ_S: 123.04566120
MIN_TIMER_READ_MS: 0.0029
AVG_TIMER_READ_MS: 1.5120
        COUNT_WRITE: 39697
SUM_TIMER_WRITE_S: 54.74848235
MIN_TIMER_WRITE_MS: 0.0059
AVG_TIMER_WRITE_MS: 1.3792
MAX_TIMER_WRITE_MS: 702.2465
        COUNT_FETCH: 81379
SUM_TIMER_FETCH_MS: 123.04566120
MIN_TIMER_FETCH_MS: 0.0029
AVG_TIMER_FETCH_MS: 1.5120
MAX_TIMER_FETCH_MS: 924.7429
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 39697
SUM_TIMER_UPDATE_S: 54.74848235
MIN_TIMER_UPDATE_MS: 0.0059
AVG_TIMER_UPDATE_MS: 1.3792
MAX_TIMER_UPDATE_MS: 702.2465
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 5. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: warehouse
         INDEX_NAME: PRIMARY
         COUNT_STAR: 79395
   SUM_TIMER_WAIT_S: 151.81620350
MIN_TIMER_WAIT_MS: 0.0024
AVG_TIMER_WAIT_MS: 1.9122
MAX_TIMER_WAIT_MS: 996.6039
         COUNT_READ: 59546
   SUM_TIMER_READ_S: 112.12478330
MIN_TIMER_READ_MS: 0.0024
AVG_TIMER_READ_MS: 1.8830
        COUNT_WRITE: 19849
SUM_TIMER_WRITE_S: 39.69142021
MIN_TIMER_WRITE_MS: 0.0085
AVG_TIMER_WRITE_MS: 1.9997
MAX_TIMER_WRITE_MS: 835.0655
        COUNT_FETCH: 59546
SUM_TIMER_FETCH_MS: 112.12478330
MIN_TIMER_FETCH_MS: 0.0024
AVG_TIMER_FETCH_MS: 1.8830
MAX_TIMER_FETCH_MS: 996.6039
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 19849
SUM_TIMER_UPDATE_S: 39.69142021
MIN_TIMER_UPDATE_MS: 0.0085
AVG_TIMER_UPDATE_MS: 1.9997
MAX_TIMER_UPDATE_MS: 835.0655
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 6. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: customer
         INDEX_NAME: PRIMARY
         COUNT_STAR: 129750
   SUM_TIMER_WAIT_S: 137.78393999
MIN_TIMER_WAIT_MS: 0.0078
AVG_TIMER_WAIT_MS: 1.0619
MAX_TIMER_WAIT_MS: 1054.3388
         COUNT_READ: 90041
   SUM_TIMER_READ_S: 90.24147129
MIN_TIMER_READ_MS: 0.0078
AVG_TIMER_READ_MS: 1.0022
        COUNT_WRITE: 39709
SUM_TIMER_WRITE_S: 47.54246870
MIN_TIMER_WRITE_MS: 0.0089
AVG_TIMER_WRITE_MS: 1.1973
MAX_TIMER_WRITE_MS: 691.0986
        COUNT_FETCH: 90041
SUM_TIMER_FETCH_MS: 90.24147129
MIN_TIMER_FETCH_MS: 0.0078
AVG_TIMER_FETCH_MS: 1.0022
MAX_TIMER_FETCH_MS: 1054.3388
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 39709
SUM_TIMER_UPDATE_S: 47.54246870
MIN_TIMER_UPDATE_MS: 0.0089
AVG_TIMER_UPDATE_MS: 1.1973
MAX_TIMER_UPDATE_MS: 691.0986
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 7. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: new_orders
         INDEX_NAME: NULL
         COUNT_STAR: 19848
   SUM_TIMER_WAIT_S: 36.79682450
MIN_TIMER_WAIT_MS: 0.0140
AVG_TIMER_WAIT_MS: 1.8539
MAX_TIMER_WAIT_MS: 759.8047
         COUNT_READ: 0
   SUM_TIMER_READ_S: 0.00000000
MIN_TIMER_READ_MS: 0.0000
AVG_TIMER_READ_MS: 0.0000
        COUNT_WRITE: 19848
SUM_TIMER_WRITE_S: 36.79682450
MIN_TIMER_WRITE_MS: 0.0140
AVG_TIMER_WRITE_MS: 1.8539
MAX_TIMER_WRITE_MS: 759.8047
        COUNT_FETCH: 0
SUM_TIMER_FETCH_MS: 0.00000000
MIN_TIMER_FETCH_MS: 0.0000
AVG_TIMER_FETCH_MS: 0.0000
MAX_TIMER_FETCH_MS: 0.0000
       COUNT_INSERT: 19848
SUM_TIMER_INSERT_S: 36.79682450
MIN_TIMER_INSERT_MS: 0.0140
AVG_TIMER_INSERT_MS: 1.8539
MAX_TIMER_INSERT_MS: 759.8047
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 8. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: new_orders
         INDEX_NAME: PRIMARY
         COUNT_STAR: 59531
   SUM_TIMER_WAIT_S: 32.07025167
MIN_TIMER_WAIT_MS: 0.0064
AVG_TIMER_WAIT_MS: 0.5387
MAX_TIMER_WAIT_MS: 875.6474
         COUNT_READ: 39720
   SUM_TIMER_READ_S: 7.18077003
MIN_TIMER_READ_MS: 0.0064
AVG_TIMER_READ_MS: 0.1808
        COUNT_WRITE: 19811
SUM_TIMER_WRITE_S: 24.88948165
MIN_TIMER_WRITE_MS: 0.0074
AVG_TIMER_WRITE_MS: 1.2563
MAX_TIMER_WRITE_MS: 875.6474
        COUNT_FETCH: 39720
SUM_TIMER_FETCH_MS: 7.18077003
MIN_TIMER_FETCH_MS: 0.0064
AVG_TIMER_FETCH_MS: 0.1808
MAX_TIMER_FETCH_MS: 489.3697
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 19811
SUM_TIMER_DELETE_S: 24.88948165
MIN_TIMER_DELETE_MS: 0.0074
AVG_TIMER_DELETE_MS: 1.2563
MAX_TIMER_DELETE_MS: 875.6474
*************************** 9. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: orders
         INDEX_NAME: PRIMARY
         COUNT_STAR: 61564
   SUM_TIMER_WAIT_S: 26.57727358
MIN_TIMER_WAIT_MS: 0.0044
AVG_TIMER_WAIT_MS: 0.4317
MAX_TIMER_WAIT_MS: 792.5677
         COUNT_READ: 41704
   SUM_TIMER_READ_S: 15.30759214
MIN_TIMER_READ_MS: 0.0044
AVG_TIMER_READ_MS: 0.3671
        COUNT_WRITE: 19860
SUM_TIMER_WRITE_S: 11.26968144
MIN_TIMER_WRITE_MS: 0.0091
AVG_TIMER_WRITE_MS: 0.5675
MAX_TIMER_WRITE_MS: 606.3633
        COUNT_FETCH: 41704
SUM_TIMER_FETCH_MS: 15.30759214
MIN_TIMER_FETCH_MS: 0.0044
AVG_TIMER_FETCH_MS: 0.3671
MAX_TIMER_FETCH_MS: 792.5677
       COUNT_INSERT: 0
SUM_TIMER_INSERT_S: 0.00000000
MIN_TIMER_INSERT_MS: 0.0000
AVG_TIMER_INSERT_MS: 0.0000
MAX_TIMER_INSERT_MS: 0.0000
       COUNT_UPDATE: 19860
SUM_TIMER_UPDATE_S: 11.26968144
MIN_TIMER_UPDATE_MS: 0.0091
AVG_TIMER_UPDATE_MS: 0.5675
MAX_TIMER_UPDATE_MS: 606.3633
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
*************************** 10. row ***************************
        OBJECT_TYPE: TABLE
      OBJECT_SCHEMA: tpcc1000
        OBJECT_NAME: history
         INDEX_NAME: NULL
         COUNT_STAR: 19849
   SUM_TIMER_WAIT_S: 20.14300773
MIN_TIMER_WAIT_MS: 0.0308
AVG_TIMER_WAIT_MS: 1.0148
MAX_TIMER_WAIT_MS: 748.5716
         COUNT_READ: 0
   SUM_TIMER_READ_S: 0.00000000
MIN_TIMER_READ_MS: 0.0000
AVG_TIMER_READ_MS: 0.0000
        COUNT_WRITE: 19849
SUM_TIMER_WRITE_S: 20.14300773
MIN_TIMER_WRITE_MS: 0.0308
AVG_TIMER_WRITE_MS: 1.0148
MAX_TIMER_WRITE_MS: 748.5716
        COUNT_FETCH: 0
SUM_TIMER_FETCH_MS: 0.00000000
MIN_TIMER_FETCH_MS: 0.0000
AVG_TIMER_FETCH_MS: 0.0000
MAX_TIMER_FETCH_MS: 0.0000
       COUNT_INSERT: 19849
SUM_TIMER_INSERT_S: 20.14300773
MIN_TIMER_INSERT_MS: 0.0308
AVG_TIMER_INSERT_MS: 1.0148
MAX_TIMER_INSERT_MS: 748.5716
       COUNT_UPDATE: 0
SUM_TIMER_UPDATE_S: 0.00000000
MIN_TIMER_UPDATE_MS: 0.0000
AVG_TIMER_UPDATE_MS: 0.0000
MAX_TIMER_UPDATE_MS: 0.0000
       COUNT_DELETE: 0
SUM_TIMER_DELETE_S: 0.00000000
MIN_TIMER_DELETE_MS: 0.0000
AVG_TIMER_DELETE_MS: 0.0000
MAX_TIMER_DELETE_MS: 0.0000
10 rows in set (0.01 sec)

--查看文件IO（表物理IO）

SELECT
file_name,
event_name,
SUM_NUMBER_OF_BYTES_READ/1024/1024 SUM_NUMBER_OF_BYTES_READ_M,
SUM_NUMBER_OF_BYTES_WRITE/1024/1024 SUM_NUMBER_OF_BYTES_WRITE_M,
(SUM_NUMBER_OF_BYTES_READ + SUM_NUMBER_OF_BYTES_WRITE)/1024/1024 IO_MB
FROM file_summary_by_instance
ORDER BY SUM_NUMBER_OF_BYTES_READ + SUM_NUMBER_OF_BYTES_WRITE DESC LIMIT 10\G

*************************** 1. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/ibdata1 >>> 物理IO最高的是公共表空间
                 event_name: wait/io/file/innodb/innodb_data_file
SUM_NUMBER_OF_BYTES_READ_M: 10.37500000 >>> 总的读的IO吞吐量有10.37 MB
SUM_NUMBER_OF_BYTES_WRITE_M: 2356.90625000 >>> 总的写的IO吞吐量有 2.3GB
                      IO_MB: 2367.28125000 >>> 读+写总的吞吐量
*************************** 2. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/tpcc1000/stock.ibd
                 event_name: wait/io/file/innodb/innodb_data_file
SUM_NUMBER_OF_BYTES_READ_M: 160.96875000
SUM_NUMBER_OF_BYTES_WRITE_M: 942.14062500
                      IO_MB: 1103.10937500
*************************** 3. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/tpcc1000/order_line.ibd
                 event_name: wait/io/file/innodb/innodb_data_file
SUM_NUMBER_OF_BYTES_READ_M: 80.43750000
SUM_NUMBER_OF_BYTES_WRITE_M: 579.42187500
                      IO_MB: 659.85937500
*************************** 4. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/tpcc1000/customer.ibd
                 event_name: wait/io/file/innodb/innodb_data_file
SUM_NUMBER_OF_BYTES_READ_M: 97.34375000
SUM_NUMBER_OF_BYTES_WRITE_M: 420.35937500
                      IO_MB: 517.70312500
*************************** 5. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/mysql-bin.000050
                 event_name: wait/io/file/sql/binlog
SUM_NUMBER_OF_BYTES_READ_M: 0.00000000
SUM_NUMBER_OF_BYTES_WRITE_M: 271.28146362
                      IO_MB: 271.28146362
*************************** 6. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/oradb-slow.log
                 event_name: wait/io/file/sql/slow_log
SUM_NUMBER_OF_BYTES_READ_M: 0.00000000
SUM_NUMBER_OF_BYTES_WRITE_M: 151.00771809
                      IO_MB: 151.00771809
*************************** 7. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/ib_logfile1
                 event_name: wait/io/file/innodb/innodb_log_file
SUM_NUMBER_OF_BYTES_READ_M: 0.00000000
SUM_NUMBER_OF_BYTES_WRITE_M: 98.52099609
                      IO_MB: 98.52099609
*************************** 8. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/tpcc1000/orders.ibd
                 event_name: wait/io/file/innodb/innodb_data_file
SUM_NUMBER_OF_BYTES_READ_M: 10.82812500
SUM_NUMBER_OF_BYTES_WRITE_M: 83.92187500
                      IO_MB: 94.75000000
*************************** 9. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/ib_logfile0
                 event_name: wait/io/file/innodb/innodb_log_file
SUM_NUMBER_OF_BYTES_READ_M: 0.06640625
SUM_NUMBER_OF_BYTES_WRITE_M: 92.53320313
                      IO_MB: 92.59960938
*************************** 10. row ***************************
                  file_name: /app/oracle/oradata2/mysql-5.5.37/data/tpcc1000/history.ibd
                 event_name: wait/io/file/innodb/innodb_data_file
SUM_NUMBER_OF_BYTES_READ_M: 6.95312500
SUM_NUMBER_OF_BYTES_WRITE_M: 79.03125000
                      IO_MB: 85.98437500
10 rows in set (0.00 sec)

--查看哪类SQL执行最多（这里的数据不准）

SELECT
DIGEST_TEXT,
COUNT_STAR,
FIRST_SEEN,
LAST_SEEN
FROM events_statements_summary_by_digest
ORDER BY COUNT_STAR DESC limit 10\G

*************************** 1. row ***************************
DIGEST_TEXT: COMMIT
COUNT_STAR: 63356
FIRST_SEEN: 2017-01-21 15:35:47
LAST_SEEN: 2017-01-21 20:35:32
*************************** 2. row ***************************
DIGEST_TEXT: SELECT ?
COUNT_STAR: 400
FIRST_SEEN: 2017-01-21 15:35:53
LAST_SEEN: 2017-01-21 15:39:22
*************************** 3. row ***************************
DIGEST_TEXT: SELECT @@`version_comment` LIMIT ?
COUNT_STAR: 202
FIRST_SEEN: 2017-01-21 15:35:53
LAST_SEEN: 2017-01-21 19:49:04
*************************** 4. row ***************************
DIGEST_TEXT: SELECT SYSDATE ( )
COUNT_STAR: 200
FIRST_SEEN: 2017-01-21 15:35:53
LAST_SEEN: 2017-01-21 15:39:22
*************************** 5. row ***************************
DIGEST_TEXT: SHOW FULL PROCESSLIST
COUNT_STAR: 200
FIRST_SEEN: 2017-01-21 15:35:53
LAST_SEEN: 2017-01-21 15:39:22
*************************** 6. row ***************************
DIGEST_TEXT: ROLLBACK
COUNT_STAR: 182
FIRST_SEEN: 2017-01-21 15:35:49
LAST_SEEN: 2017-01-21 20:35:30
*************************** 7. row ***************************
DIGEST_TEXT: SET `autocommit` = ?
COUNT_STAR: 15
FIRST_SEEN: 2017-01-21 15:35:47
LAST_SEEN: 2017-01-21 20:30:02
*************************** 8. row ***************************
DIGEST_TEXT: SHOW TABLES
COUNT_STAR: 10
FIRST_SEEN: 2017-01-21 16:04:25
LAST_SEEN: 2017-01-21 20:22:45
*************************** 9. row ***************************
DIGEST_TEXT: SELECT `DIGEST_TEXT` , `COUNT_STAR` , `FIRST_SEEN` , `LAST_SEEN` FROM `events_statements_summary_by_digest` ORDER BY `COUNT_STAR` DESC LIMIT ?
COUNT_STAR: 7
FIRST_SEEN: 2017-01-21 16:29:49
LAST_SEEN: 2017-01-21 20:29:15
*************************** 10. row ***************************
DIGEST_TEXT: SELECT * FROM `events_statements_history_long` LIMIT ?
COUNT_STAR: 5
FIRST_SEEN: 2017-01-21 16:58:11
LAST_SEEN: 2017-01-21 20:15:26
10 rows in set (0.10 sec)

--使用 percona-toolkit 工具包中的 pt-query-digest 分析慢查询日志

1）按SQL总的执行时间倒序排序

bin/pt-query-digest /app/oracle/oradata2/mysql-5.5.37/data/oradb-slow.log > /root/t_slow.log

vi /root/t_slow.log

# 111.9s user time, 3s system time, 27.37M rss, 213.67M vsz
# Current date: Sat Jan 21 20:59:49 2017
# Hostname: oradb
# Files: /app/oracle/oradata2/mysql-5.5.37/data/oradb-slow.log
# Overall: 581.89k total, 72 unique, 185.26 QPS, 0.46x concurrency _______
# Time range: 2017-01-21 19:51:04 to 20:43:25
# Attribute          total     min     max     avg     95% stddev median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          1451s     2us      2s     2ms     2ms    27ms   185us
# Lock time           100s       0   772ms   172us    98us     6ms    28us
# Rows sent        495.44k       0     240    0.87    0.99    6.74    0.99
# Rows examine     915.55k       0   9.86k    1.61    0.99   38.60    0.99
# Query size        61.07M       6   1.61k 110.06 202.40   65.27   80.10

# Exec time          1451s     2us      2s     2ms     2ms    27ms   185us
SQL 总的执行时间1451秒，最小执行时间 2微秒，最大执行时间2秒，平均执行时间2毫秒，
95%的SQL的执行时间是在2毫秒内。

# Rows examine     915.55k       0   9.86k    1.61    0.99   38.60    0.99
总共扫描的记录数915.55k行，最小扫描的记录数0行，最大9.86K行，平均每条SQL扫描
1.61行记录。

# Profile
# Rank Query ID           Response time Calls R/Call V/M   Item
# ==== ================== ============== ====== ====== ===== =============
#    1 0x813031B8BBC3B329 803.1365 55.3% 21958 0.0366 0.32 COMMIT
#    2 0x10BEBFE721A275F6 131.7278 9.1% 69014 0.0019 0.23 INSERT order_line
#    3 0x6E70441DF63ACD21 96.4736 6.6% 69014 0.0014 0.23 UPDATE stock
#    4 0xA0352AA54FDD5DF2 78.3874 5.4%   6880 0.0114 0.29 UPDATE order_line
#    5 0xBD195A4F9D50914F 59.1810 4.1% 69014 0.0009 0.17 SELECT stock
#    6 0x255C57D761A899A9 49.3528 3.4%   6880 0.0072 0.28 UPDATE warehouse
#    7 0xF078A9E73D7A8520 27.6673 1.9%   6880 0.0040 0.30 UPDATE district
#    8 0xAC36DBE122042A66 26.6088 1.8%    688 0.0387 0.25 SELECT order_line
#    9 0x5E61FF668A8E8456 26.1919 1.8% 136940 0.0002 0.01 SELECT stock
#   10 0xE5E8C12332AD11C5 23.5297 1.6%   6880 0.0034 0.28 SELECT district
#   11 0xBF40A4C7016F2BAE 19.5937 1.4% 69077 0.0003 0.01 SELECT item
#   12 0x2276F0D2E8CC6E22 16.1207 1.1%   6880 0.0023 0.22 UPDATE district
#   13 0xBDF3FABA5EEB789B 11.3701 0.8%   6880 0.0017 0.32 INSERT new_orders
#   14 0x0C3504CBDCA1EC89   9.0605 0.6%   6880 0.0013 0.17 UPDATE customer
#   15 0x87E52FB8E2D495CA   8.8660 0.6%   6880 0.0013 0.20 DELETE new_orders
# MISC 0xMISC              63.9267 4.4% 91150 0.0007   0.0 <57 ITEMS>

# Query 1: 66.54 QPS, 2.43x concurrency, ID 0x813031B8BBC3B329 at byte 51257227
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.32
# Time range: 2017-01-21 20:30:02 to 20:35:32
# Attribute    pct   total     min     max     avg     95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          3   21958
# Exec time     55    803s    19us      2s    37ms   266ms   108ms     4ms
# Lock time      0       0       0       0       0       0       0       0
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size     0 128.66k       6       6       6       6       0       6
# String:
# Databases    tpcc1000
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
# 10us ####
# 100us #
#   1ms ################################################################
# 10ms #############
# 100ms #######
#    1s #
# 10s+
commit\G

排在第一位的慢查询SQL是 commit，平均执行时间为37毫秒，结合之前操作系统监控看到的磁盘IO平均可以
确定是磁盘IO太慢导致事务日志写入太慢。

2)按总扫描的记录数倒序排序SQL

bin/pt-query-digest --order-by Rows_examined:sum /app/oracle/oradata2/mysql-5.5.37/data/oradb-slow.log > /root/olm/re_slow.log

# 116.3s user time, 14.7s system time, 27.39M rss, 213.69M vsz
# Current date: Sun Jan 22 22:25:35 2017
# Hostname: oradb
# Files: /app/oracle/oradata2/mysql-5.5.37/data/oradb-slow.log
# Overall: 581.90k total, 73 unique, 70.92 QPS, 114.26x concurrency ______
# Time range: 2017-01-21 19:51:04 to 22:07:49
# Attribute          total     min     max     avg     95% stddev median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          1451s     2us      2s     2ms     2ms    27ms   185us
# Lock time           100s       0   772ms   172us    98us     6ms    28us
# Rows sent        495.45k       0     240    0.87    0.99    6.74    0.99
# Rows examine     915.55k       0   9.86k    1.61    0.99   38.60    0.99
# Query size        61.07M       6   1.61k 110.06 202.40   65.27   80.10

# Profile
# Rank Query ID           Response time   Calls R/Call V/M   Item
# ==== ================== =============== ====== ====== ===== ============
#    1 0x34E08C93481AC44D    3.6333 0.3%    688 0.0053 0.24 SELECT order_line
#    2 0xA0352AA54FDD5DF2   78.3874 5.4%   6880 0.0114 0.29 UPDATE order_line
#    3 0x6E70441DF63ACD21   96.4736 6.6% 69014 0.0014 0.23 UPDATE stock
#    4 0xBD195A4F9D50914F   59.1810 4.1% 69014 0.0009 0.17 SELECT stock
#    5 0xBF40A4C7016F2BAE   19.5937 1.4% 69077 0.0003 0.01 SELECT item
#    6 0xDCEAE5528D1D6AA4    4.2239 0.3%   6880 0.0006 0.02 SELECT order_line
#    7 0xD2D067B217E6ECF4    0.2005 0.0%      4 0.0501 0.06 SELECT events_statements_history_long
#    8 0x9577D48F480A1260    2.5192 0.2%   4582 0.0005 0.01 SELECT customer
#    9 0xFDB1B7AE94BF0D5A    2.0895 0.1%   4196 0.0005 0.00 SELECT customer
#   10 0x5E61FF668A8E8456   26.1919 1.8% 136940 0.0002 0.01 SELECT stock
#   11 0x7064EE837B0630F6    0.0397 0.0%      1 0.0397 0.00 SELECT events_statements_history_long
#   12 0x9DF5733F64228474    0.0880 0.0%      1 0.0880 0.00 SELECT events_statements_history_long
#   13 0x7E33C8E1F7454B77    0.0202 0.0%      1 0.0202 0.00 SELECT events_statements_history_long
#   14 0x7291A49FA41F66A0    0.0269 0.0%      1 0.0269 0.00 SELECT events_statements_history_long
#   15 0xAC36DBE122042A66   26.6088 1.8%    688 0.0387 0.25 SELECT order_line
#   16 0x2276F0D2E8CC6E22   16.1207 1.1%   6880 0.0023 0.22 UPDATE district
#   17 0xE5E8C12332AD11C5   23.5297 1.6%   6880 0.0034 0.28 SELECT district
#   18 0xFFDA79BA14F0A223    4.1791 0.3%   6880 0.0006 0.11 SELECT customer warehouse
#   19 0x0C3DA99DF6138EB1    3.2631 0.2%   6880 0.0005 0.03 SELECT customer
#   20 0xBD63269DF214E485    2.0032 0.1%   6880 0.0003 0.00 SELECT district
# MISC 0xMISC             1082.9009 74.6% 179530 0.0060   0.0 <53 ITEMS>
# Profile

# Query 1: 2.08 QPS, 832.48x concurrency, ID 0x34E08C93481AC44D at byte 57744259
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.24
# Time range: 2017-01-21 20:30:02 to 20:35:32
# Attribute    pct   total     min     max     avg     95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     688
# Exec time      0      4s   342us   556ms     5ms     5ms    36ms   839us
# Lock time      0    42ms    20us     4ms    60us   125us   165us    36us
# Rows sent     26 133.73k     166     240 199.04 212.52   12.86 192.76 >>>平均每次执行返回 199.04 条记录，平均每次执行扫描 399.3条记录，
# Rows examine 29 268.28k     332     480 399.30 441.81   26.25 381.65 >>> 提取记录数与扫描记录数不高不适合建索引
# Query size     0 80.01k     119     120 119.08 118.34    0.00 118.34
# String:
# Databases    tpcc1000
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
# 10us
# 100us ################################################################
#   1ms ##################################################
# 10ms ###
# 100ms #
#    1s
# 10s+
# Tables
#    SHOW TABLE STATUS FROM `tpcc1000` LIKE 'order_line'\G
#    SHOW CREATE TABLE `tpcc1000`.`order_line`\G
# EXPLAIN
SELECT DISTINCT ol_i_id FROM order_line WHERE ol_w_id = 5 AND ol_d_id = 5 AND ol_o_id < 3399 AND ol_o_id >= (3399 - 20)\G