操作环境
Centos 7.0
DELL R720
操作步骤
blktrace使用方法
使用blktrace之前需要挂载debugfs
[root@localhost ~]# blktrace -d /dev/sdb -o - | blkparse -i - 8,16 2 1 0.000000000 12228 Q WS 0 + 256 [dd] 8,16 2 2 0.000004050 12228 G WS 0 + 256 [dd] 8,16 2 3 0.000005738 12228 P N [dd] 8,16 2 4 0.000008127 12228 I WS 0 + 256 [dd] 8,16 2 5 0.000009410 12228 U N [dd] 1 8,16 2 6 0.000011178 12228 D WS 0 + 256 [dd] 8,16 2 7 0.018092900 0 C WS 0 + 256 [0] ....... ....... cpu2 (8,16): Reads Queued: 0,0KiB Writes Queued: 1,128KiB Read Dispatches: 0,0KiB Write Dispatches: 1,128KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 0,0KiB Writes Completed: 1,128KiB Read Merges: 0,0KiB Write Merges: 0,0KiB Read depth: 4 Write depth: 1 PC Reads Queued: 0,0KiB PC Writes Queued: 0,0KiB PC Read Disp.: 1,0KiB PC Write Disp.: 0,0KiB PC Reads Req.: 0 PC Writes Req.: 0 PC Reads Compl.: 0 PC Writes Compl.: 0 IO unplugs: 1 Timer unplugs: 0 cpu3 (8,16): Reads Queued: 1,4KiB Writes Queued: 0,0KiB Read Dispatches: 1,4KiB Write Dispatches: 0,0KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 0,0KiB Writes Completed: 0,0KiB Read Merges: 0,0KiB PC Reads Req.: 0 PC Writes Req.: 0 PC Reads Compl.: 0 PC Writes Compl.: 0 IO unplugs: 1 Timer unplugs: 0 cpu5 (8,16): Reads Queued: 8,32KiB Writes Queued: 0,0KiB Read Dispatches: 8,32KiB Write Dispatches: 0,0KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 9,36KiB Writes Completed: 0,0KiB PC Read Disp.: 6,0KiB PC Reads Req.: 0 PC Writes Req.: 0 PC Reads Compl.: 4 PC Writes Compl.: 0 IO unplugs: 8 Timer unplugs: 0 Total (8,16): Reads Queued: 9,36KiB Writes Queued: 1,128KiB Read Dispatches: 9,36KiB Write Dispatches: 1,128KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 9,36KiB Writes Completed: 1,0KiB PC Reads Queued: 0,0KiB PC Read Disp.: 8,0KiB PC Reads Req.: 0 PC Writes Req.: 0 PC Reads Compl.: 4 PC Writes Compl.: 0 IO unplugs: 10 Timer unplugs: 0 Throughput (R/W): 1,500KiB/s / 5,333KiB/s Events (8,16): 98 entries Skips: 0 forward (0 - 0.0%)
也可以通过blktrace收集硬盘数据至文件中，而后通过blkparse进行查看
[root@localhost ~]# blktrace -d /dev/sdb ^C=== sdb === cpu 0: 1 events,1 KiB data cpu 1: 0 events,0 KiB data cpu 2: 14 events,1 KiB data cpu 3: 12 events,1 KiB data cpu 4: 0 events,0 KiB data cpu 5: 85 events,4 KiB data cpu 6: 0 events,0 KiB data cpu 7: 0 events,0 KiB data Total: 112 events (dropped 0),6 KiB data [root@localhost ~]# blkparse -i sdb Input file sdb.blktrace.0 added Input file sdb.blktrace.2 added Input file sdb.blktrace.3 added Input file sdb.blktrace.5 added 8,16 2 1 0.000000000 12243 Q WS 0 + 256 [dd] 8,16 2 2 0.000004304 12243 G WS 0 + 256 [dd] 8,16 2 3 0.000005577 12243 P N [dd] 8,16 2 4 0.000007906 12243 I WS 0 + 256 [dd] 8,16 2 5 0.000009096 12243 U N [dd] 1 8,16 2 6 0.000011101 12243 D WS 0 + 256 [dd] 8,16 2 7 0.015232277 0 C WS 0 + 256 [0] ...... ...... cpu2 (sdb): Reads Queued: 0,0KiB PC Reads Req.: 0 PC Writes Req.: 0 PC Reads Compl.: 0 PC Writes Compl.: 0 IO unplugs: 1 Timer unplugs: 0 cpu3 (sdb): Reads Queued: 1,0KiB PC Reads Req.: 0 PC Writes Req.: 0 PC Reads Compl.: 0 PC Writes Compl.: 0 IO unplugs: 1 Timer unplugs: 0 cpu5 (sdb): Reads Queued: 8,0KiB PC Reads Req.: 0 PC Writes Req.: 0 PC Reads Compl.: 4 PC Writes Compl.: 0 IO unplugs: 8 Timer unplugs: 0 Total (sdb): Reads Queued: 9,714KiB/s / 6,095KiB/s Events (sdb): 98 entries Skips: 0 forward (0 - 0.0%)
通过btt分析blktrace数据
上面可以发现通过blkparse查看的数据量比较大，不利于查看，通过btt可以对blktrace数据进行自动分析
首先将blktrace的报告合并为一
[root@localhost ~]# blkparse -i sdb -d sdb.blktrace.btt Input file sdb.blktrace.0 added Input file sdb.blktrace.2 added Input file sdb.blktrace.3 added Input file sdb.blktrace.5 added 8,16 2 7 0.015232277 0 C WS 0 + 256 [0] ...... ......
[root@localhost ~]# btt -i sdb.blktrace.btt
==================== All Devices ====================
ALL MIN AVG MAX N
--------------- ------------- ------------- ------------- -----------
Q2Q 0.000097608 0.002396168 0.020167415 9
Q2G 0.000000982 0.000001807 0.000004304 10
G2I 0.000001246 0.000001827 0.000003602 10
I2D 0.000001029 0.000001643 0.000003195 10
D2C 0.000078278 0.001622636 0.015221176 10
Q2C 0.000081559 0.001627913 0.015232277 10
==================== Device Overhead ====================
DEV | Q2G G2I Q2M I2D D2C
---------- | --------- --------- --------- --------- ---------
( 8,16) | 0.1110% 0.1122% 0.0000% 0.1009% 99.6758%
---------- | --------- --------- --------- --------- ---------
Overall | 0.1110% 0.1122% 0.0000% 0.1009% 99.6758%
这里分别列出了IO过程中的几个阶段
Q2G
G2I
I2D
D2C
来查看下Q、G、I、D、C分别代表什么含义
The following table shows the varIoUs actions which may be output.
| Act | Description |
| A | IO was remapped to a different device |
| B | IO bounced |
| C | IO completion |
| D | IO issued to driver |
| F | IO front merged with request on queue |
| G | Get request |
| I | IO inserted onto request queue |
| M | IO back merged with request on queue |
| P | Plug request |
| Q | IO handled by request queue code |
| S | Sleep request |
| T | Unplug due to timeout |
| U | Unplug request |
| X | Split |
根据blktrace官网文档
Q：准备发起IO请求
G:：IO请求生成
I：IO请求插入请求队列中
D：IO请求进行硬盘设备
C：IO请求完成
那么对应的
Q2G：生产IO请求耗费的时间
G2I：IO请求进行IO调取所耗费的时间
I2D：IO请求在IO调度中所耗费的时间
D2C：IO请求在硬件设备中耗费的时间
Q2C = Q2G+G2I+I2D+D2C