分类目录归档：IO

利用blktrace分析IO性能

2019/02/15 vmunix

在Linux系统上，如果I/O发生性能问题，有没有办法进一步定位故障位置呢？iostat等最常用的工具肯定是指望不上的，【容易被误读的iostat】一文中解释过await表示单个I/O所需的平均时间，但它同时包含了I/O Scheduler所消耗的时间和硬件所消耗的时间，所以不能作为硬件性能的指标，至于iostat的svctm更是一个废弃的指标，手册上已经明确说明了的。blktrace在这种场合就能派上用场，因为它能记录I/O所经历的各个步骤，从中可以分析是IO Scheduler慢还是硬件响应慢。

blktrace的原理

一个I/O请求进入block layer之后，可能会经历下面的过程：

Remap: 可能被DM(Device Mapper)或MD(Multiple Device, Software RAID) remap到其它设备
Split: 可能会因为I/O请求与扇区边界未对齐、或者size太大而被分拆(split)成多个物理I/O
Merge: 可能会因为与其它I/O请求的物理位置相邻而合并(merge)成一个I/O
被IO Scheduler依照调度策略发送给driver
被driver提交给硬件，经过HBA、电缆（光纤、网线等）、交换机（SAN或网络）、最后到达存储设备，设备完成IO请求之后再把结果发回。

blktrace能记录I/O所经历的各个步骤，来看一下它记录的数据，包含9个字段，下图标示了其中8个字段的含义，大致的意思是“哪个进程在访问哪个硬盘的哪个扇区，进行什么操作，进行到哪个步骤，时间戳是多少”：

第7个字段在上图中没有标出来，它表示操作类型，具体含义是：”R” for Read, “W” for Write, “D” for block, “B” for Barrier operation。

第6个字段是Event，代表了一个I/O请求所经历的各个阶段，具体含义在blkparse的手册页中有解释，其中最重要的几个阶段如下：

Q – 即将生成IO请求
|
G – IO请求生成
|
I – IO请求进入IO Scheduler队列
|
D – IO请求进入driver
|
C – IO请求执行完毕

根据以上步骤对应的时间戳就可以计算出I/O请求在每个阶段所消耗的时间：

Q2G – 生成IO请求所消耗的时间，包括remap和split的时间；
G2I – IO请求进入IO Scheduler所消耗的时间，包括merge的时间；
I2D – IO请求在IO Scheduler中等待的时间；
D2C – IO请求在driver和硬件上所消耗的时间；
Q2C – 整个IO请求所消耗的时间(Q2I + I2D + D2C = Q2C)，相当于iostat的await。

如果I/O性能慢的话，以上指标有助于进一步定位缓慢发生的地方：
D2C可以作为硬件性能的指标；
I2D可以作为IO Scheduler性能的指标。

附上event速查表：

blktrace的用法

使用blktrace需要挂载debugfs：
$ mount -t debugfs debugfs /sys/kernel/debug

利用blktrace查看实时数据的方法，比如要看的硬盘是sdb：
$ blktrace -d /dev/sdb -o – | blkparse -i –
需要停止的时候，按Ctrl-C。

以上命令也可以用下面的脚本代替：
$ btrace /dev/sdb

利用blktrace把数据记录在文件里，以供事后分析：
$ blktrace -d /dev/sdb
缺省的输出文件名是 sdb.blktrace.<cpu>，每个CPU对应一个文件。
你也可以用-o参数指定自己的输出文件名。

利用blkparse命令分析blktrace记录的数据：
$ blkparse -i sdb

$ blktrace -d /dev/sdb
$ blkparse -i sdb
  # 第一个IO开始：
  8,16   1        1     0.000000000 18166  Q   R 0 + 1 [dd]
  8,16   1        0     0.000009827     0  m   N cfq18166S  /user.slice alloced
  8,16   1        2     0.000010451 18166  G   R 0 + 1 [dd]
  8,16   1        3     0.000011056 18166  P   N [dd]
  8,16   1        4     0.000012255 18166  I   R 0 + 1 [dd]
  8,16   1        0     0.000013477     0  m   N cfq18166S  /user.slice insert_request
  8,16   1        0     0.000014526     0  m   N cfq18166S  /user.slice add_to_rr
  8,16   1        5     0.000016643 18166  U   N [dd] 1
  8,16   1        0     0.000017522     0  m   N cfq workload slice:300
  8,16   1        0     0.000018880     0  m   N cfq18166S  /user.slice set_active wl_class:0 wl_type:2
  8,16   1        0     0.000020594     0  m   N cfq18166S  /user.slice fifo=          (null)
  8,16   1        0     0.000021462     0  m   N cfq18166S  /user.slice dispatch_insert
  8,16   1        0     0.000022898     0  m   N cfq18166S  /user.slice dispatched a request
  8,16   1        0     0.000023786     0  m   N cfq18166S  /user.slice activate rq, drv=1
  8,16   1        6     0.000023977 18166  D   R 0 + 1 [dd]
  8,16   0        1     0.014270153     0  C   R 0 + 1 [0]
  # 第一个IO结束。
  8,16   0        0     0.014278115     0  m   N cfq18166S  /user.slice complete rqnoidle 0
  8,16   0        0     0.014280044     0  m   N cfq18166S  /user.slice set_slice=100
  8,16   0        0     0.014282217     0  m   N cfq18166S  /user.slice arm_idle: 8 group_idle: 0
  8,16   0        0     0.014282728     0  m   N cfq schedule dispatch
  # 第二个IO开始：
  8,16   1        7     0.014298247 18166  Q   R 1 + 1 [dd]
  8,16   1        8     0.014300522 18166  G   R 1 + 1 [dd]
  8,16   1        9     0.014300984 18166  P   N [dd]
  8,16   1       10     0.014301996 18166  I   R 1 + 1 [dd]
  8,16   1        0     0.014303864     0  m   N cfq18166S  /user.slice insert_request
  8,16   1       11     0.014304981 18166  U   N [dd] 1
  8,16   1        0     0.014306368     0  m   N cfq18166S  /user.slice dispatch_insert
  8,16   1        0     0.014307793     0  m   N cfq18166S  /user.slice dispatched a request
  8,16   1        0     0.014308763     0  m   N cfq18166S  /user.slice activate rq, drv=1
  8,16   1       12     0.014308962 18166  D   R 1 + 1 [dd]
  8,16   0        2     0.014518615     0  C   R 1 + 1 [0]
  # 第二个IO结束。
  8,16   0        0     0.014523548     0  m   N cfq18166S  /user.slice complete rqnoidle 0
  8,16   0        0     0.014525334     0  m   N cfq18166S  /user.slice arm_idle: 8 group_idle: 0
  8,16   0        0     0.014525676     0  m   N cfq schedule dispatch
  # 第三个IO开始：
  8,16   1       13     0.014531022 18166  Q   R 2 + 1 [dd]
  ...

$ blktrace -d /dev/sdb

$ blkparse -i sdb

# 第一个IO开始：

8,16 1 1 0.000000000 18166 Q R 0 + 1 [dd]

8,16 1 0 0.000009827 0 m N cfq18166S /user.slice alloced

8,16 1 2 0.000010451 18166 G R 0 + 1 [dd]

8,16 1 3 0.000011056 18166 P N [dd]

8,16 1 4 0.000012255 18166 I R 0 + 1 [dd]

8,16 1 0 0.000013477 0 m N cfq18166S /user.slice insert_request

8,16 1 0 0.000014526 0 m N cfq18166S /user.slice add_to_rr

8,16 1 5 0.000016643 18166 U N [dd] 1

8,16 1 0 0.000017522 0 m N cfq workload slice:300

8,16 1 0 0.000018880 0 m N cfq18166S /user.slice set_active wl_class:0 wl_type:2

8,16 1 0 0.000020594 0 m N cfq18166S /user.slice fifo= (null)

8,16 1 0 0.000021462 0 m N cfq18166S /user.slice dispatch_insert

8,16 1 0 0.000022898 0 m N cfq18166S /user.slice dispatched a request

8,16 1 0 0.000023786 0 m N cfq18166S /user.slice activate rq, drv=1

8,16 1 6 0.000023977 18166 D R 0 + 1 [dd]

8,16 0 1 0.014270153 0 C R 0 + 1 [0]

# 第一个IO结束。

8,16 0 0 0.014278115 0 m N cfq18166S /user.slice complete rqnoidle 0

8,16 0 0 0.014280044 0 m N cfq18166S /user.slice set_slice=100

8,16 0 0 0.014282217 0 m N cfq18166S /user.slice arm_idle: 8 group_idle: 0

8,16 0 0 0.014282728 0 m N cfq schedule dispatch

# 第二个IO开始：

8,16 1 7 0.014298247 18166 Q R 1 + 1 [dd]

8,16 1 8 0.014300522 18166 G R 1 + 1 [dd]

8,16 1 9 0.014300984 18166 P N [dd]

8,16 1 10 0.014301996 18166 I R 1 + 1 [dd]

8,16 1 0 0.014303864 0 m N cfq18166S /user.slice insert_request

8,16 1 11 0.014304981 18166 U N [dd] 1

8,16 1 0 0.014306368 0 m N cfq18166S /user.slice dispatch_insert

8,16 1 0 0.014307793 0 m N cfq18166S /user.slice dispatched a request

8,16 1 0 0.014308763 0 m N cfq18166S /user.slice activate rq, drv=1

8,16 1 12 0.014308962 18166 D R 1 + 1 [dd]

8,16 0 2 0.014518615 0 C R 1 + 1 [0]

# 第二个IO结束。

8,16 0 0 0.014523548 0 m N cfq18166S /user.slice complete rqnoidle 0

8,16 0 0 0.014525334 0 m N cfq18166S /user.slice arm_idle: 8 group_idle: 0

8,16 0 0 0.014525676 0 m N cfq schedule dispatch

# 第三个IO开始：

8,16 1 13 0.014531022 18166 Q R 2 + 1 [dd]

...

注：
在以上数据中，有一些记录的event类型是”m”，那是IO Scheduler的调度信息，对研究IO Scheduler问题有意义：

cfq18166S – cfq是IO Scheduler的名称，18166是进程号，”S”表示Sync(同步IO)，如果异步IO则用“A”表示(Async)；
它们的第三列sequence number都是0；
它们表示IO Scheduler内部的关键函数，上例中是cfq，代码参见block/cfq-iosched.c，以下是各关键字所对应的内部函数：
alloced <<< cfq_find_alloc_queue()
insert_request <<< cfq_insert_request()
add_to_rr <<< cfq_add_cfqq_rr()
cfq workload slice:300 <<< choose_wl_class_and_type()
set_active wl_class:0 wl_type:2 <<< __cfq_set_active_queue()
fifo= (null) <<< cfq_check_fifo()
dispatch_insert <<< cfq_dispatch_insert()
dispatched a request <<< cfq_dispatch_requests()
activate rq, drv=1 <<< cfq_activate_request()
complete rqnoidle 0 <<< cfq_completed_request()
set_slice=100 <<< cfq_set_prio_slice()
arm_idle: 8 group_idle: 0 <<< cfq_arm_slice_timer()
cfq schedule dispatch <<< cfq_schedule_dispatch()

利用btt分析blktrace数据

blkparse只是将blktrace数据转成可以人工阅读的格式，由于数据量通常很大，人工分析并不轻松。btt是对blktrace数据进行自动分析的工具。

btt不能分析实时数据，只能对blktrace保存的数据文件进行分析。使用方法：
把原本按CPU分别保存的文件合并成一个，合并后的文件名为sdb.blktrace.bin：
$ blkparse -i sdb -d sdb.blktrace.bin
执行btt对sdb.blktrace.bin进行分析：
$ btt -i sdb.blktrace.bin

下面是一个btt实例：

...
            ALL           MIN           AVG           MAX           N
--------------- ------------- ------------- ------------- -----------

Q2Q               0.000138923   0.000154010   0.014298247       94558
Q2G               0.000001154   0.000001661   0.000017313       94559
G2I               0.000000883   0.000001197   0.000012011       94559
I2D               0.000004722   0.000005761   0.000027286       94559
D2C               0.000118840   0.000129201   0.014246176       94558
Q2C               0.000125953   0.000137820   0.014270153       94558

==================== Device Overhead ====================

       DEV |       Q2G       G2I       Q2M       I2D       D2C
---------- | --------- --------- --------- --------- ---------
 (  8, 16) |   1.2050%   0.8688%   0.0000%   4.1801%  93.7461%
---------- | --------- --------- --------- --------- ---------
   Overall |   1.2050%   0.8688%   0.0000%   4.1801%  93.7461%
...

...

ALL MIN AVG MAX N

--------------- ------------- ------------- ------------- -----------

Q2Q 0.000138923 0.000154010 0.014298247 94558

Q2G 0.000001154 0.000001661 0.000017313 94559

G2I 0.000000883 0.000001197 0.000012011 94559

I2D 0.000004722 0.000005761 0.000027286 94559

D2C 0.000118840 0.000129201 0.014246176 94558

Q2C 0.000125953 0.000137820 0.014270153 94558

==================== Device Overhead ====================

DEV | Q2G G2I Q2M I2D D2C

---------- | --------- --------- --------- --------- ---------

( 8, 16) | 1.2050% 0.8688% 0.0000% 4.1801% 93.7461%

---------- | --------- --------- --------- --------- ---------

Overall | 1.2050% 0.8688% 0.0000% 4.1801% 93.7461%

...

我们看到93.7461%的时间消耗在D2C，也就是硬件层，这是正常的，我们说过D2C是衡量硬件性能的指标，这里单个IO平均0.129201毫秒，已经是相当快了，单个IO最慢14.246176 毫秒，不算坏。Q2G和G2I都很小，完全正常。I2D稍微有点大，应该是cfq scheduler的调度策略造成的，你可以试试其它scheduler，比如deadline，比较两者的差异，然后选择最适合你应用特点的那个。

利用blktrace数据自制分析工具

blktrace在block layer采集了每一个I/O的数据，可以用于完成一些非常深入的分析任务，以下是一个利用它分析应用系统的I/O模式的例子：
剖析生产系统的I/O模式

IO、性能工具

剖析生产系统的I/O模式

2019/02/13 vmunix

了解I/O的特点对于优化系统性能非常重要，I/O是顺序的还是随机的，是读操作还是写操作，读写的比例是多少，I/O数据块的大小，这些都是影响性能的关键因素。很多存储设备都基于特定的I/O模式做过调校，通用的测试工具跑分都相当漂亮，然而一到实际环境区别就来了，同样的应用环境下，不同的设备表现可能天差地别。我就见过不同厂商的设备，档次差不多，测试跑分高的那个在生产环境下的IO响应速度却慢了十倍。所以跑分高的设备真的不一定适合你的应用。

如果能够模拟出应用的I/O模式，那么在问题复现、乃至设备选型等方面都会有很大帮助。在此之前，了解I/O模式是第一步，这并不容易，像iostat之类的工具只能看到平均值，然而应用系统的I/O请求有可能是波浪式的，一秒之内也可以时高时低，I/O延迟可能平均值不高但是波动很大，而且I/O块大小也可以是变化的，尤其现在大数据应用的块大小可能在很大的范围内变化，与过去常见的交易型数据库有所不同，它们的块大小基本是固定的。

要剖析生产系统的I/O模式，好像没有现成的工具。但是我们可以利用blktrace自己做一个，blktrace在内核的block layer记录每一个I/O，提供了分析的素材。它记录的格式如下：

下面是一个简化版的示例，主要利用了Event “Q”和”C”，分别表示IO开始和IO完成，两者之间的耗时就相当于iostat看到的await，但blktrace可以精确到单个IO：

#!/bin/bash

if [ $# -ne 1 ]; then
        echo "Usage: $0 <block_device_name>"
        exit
fi
if [ ! -b $1 ]; then
        echo "could not find block device $1"
        exit
fi

duration=10
echo "running blktrace for $duration seconds to collect data..."
timeout $duration blktrace -d $1 >/dev/null 2>&1

DEVNAME=`basename $1`

echo "parsing blktrace data..."
blkparse -i $DEVNAME |sort -g -k8 -k10 -k4 |awk '
BEGIN   {
        total_read=0;
        total_write=0;
        maxwait_read=0;
        maxwait_write=0;
}
{
        if ($6=="Q") {
                queue_ts=$4;
                block=$8;
                nblock=$10;
                rw=$7;
        };
        if ($6=="C" && $8==block && $10==nblock && $7==rw) {
                await=$4-queue_ts;
                if (rw=="R") {
                        if (await>maxwait_read) maxwait_read=await;
                        total_read++;
                        read_count_block[nblock]++;
                        if (await>0.001) read_count1++;
                        if (await>0.01) read_count10++;
                        if (await>0.02) read_count20++;
                        if (await>0.03) read_count30++;
                }
                if (rw=="W") {
                        if (await>maxwait_write) maxwait_write=await;
                        total_write++;
                        write_count_block[nblock]++;
                        if (await>0.001) write_count1++;
                        if (await>0.01) write_count10++;
                        if (await>0.02) write_count20++;
                        if (await>0.03) write_count30++;
                }
        }
} END   {
        printf("========\nsummary:\n========\n");
        printf("total number of reads: %d\n", total_read);
        printf("total number of writes: %d\n", total_write);
        printf("slowest read : %.6f second\n", maxwait_read);
        printf("slowest write: %.6f second\n", maxwait_write);
        printf("reads\n> 1ms: %d\n>10ms: %d\n>20ms: %d\n>30ms: %d\n", read_count1, read_count10, read_count20, read_count30);
        printf("writes\n> 1ms: %d\n>10ms: %d\n>20ms: %d\n>30ms: %d\n", write_count1, write_count10, write_count20, write_count30);
        printf("\nblock size:%16s\n","Read Count");
        for (i in read_count_block)
                printf("%10d:%16d\n", i, read_count_block[i]);
        printf("\nblock size:%16s\n","Write Count");
        for (i in write_count_block)
                printf("%10d:%16d\n", i, write_count_block[i]);
}'

#!/bin/bash

if [ $# -ne 1 ]; then

echo "Usage: $0 <block_device_name>"

exit

if [ ! -b $1 ]; then

echo "could not find block device $1"

exit

duration=10

echo "running blktrace for $duration seconds to collect data..."

timeout $duration blktrace -d $1 >/dev/null 2>&1

DEVNAME=`basename $1`

echo "parsing blktrace data..."

blkparse -i $DEVNAME |sort -g -k8 -k10 -k4 |awk '

BEGIN {

total_read=0;

total_write=0;

maxwait_read=0;

maxwait_write=0;

}

{

if ($6=="Q") {

queue_ts=$4;

block=$8;

nblock=$10;

rw=$7;

};

if ($6=="C" && $8==block && $10==nblock && $7==rw) {

await=$4-queue_ts;

if (rw=="R") {

if (await>maxwait_read) maxwait_read=await;

total_read++;

read_count_block[nblock]++;

if (await>0.001) read_count1++;

if (await>0.01) read_count10++;

if (await>0.02) read_count20++;

if (await>0.03) read_count30++;

}

if (rw=="W") {

if (await>maxwait_write) maxwait_write=await;

total_write++;

write_count_block[nblock]++;

if (await>0.001) write_count1++;

if (await>0.01) write_count10++;

if (await>0.02) write_count20++;

if (await>0.03) write_count30++;

}

} END {

printf("========\nsummary:\n========\n");

printf("total number of reads: %d\n", total_read);

printf("total number of writes: %d\n", total_write);

printf("slowest read : %.6f second\n", maxwait_read);

printf("slowest write: %.6f second\n", maxwait_write);

printf("reads\n> 1ms: %d\n>10ms: %d\n>20ms: %d\n>30ms: %d\n", read_count1, read_count10, read_count20, read_count30);

printf("writes\n> 1ms: %d\n>10ms: %d\n>20ms: %d\n>30ms: %d\n", write_count1, write_count10, write_count20, write_count30);

printf("\nblock size:%16s\n","Read Count");

for (i in read_count_block)

printf("%10d:%16d\n", i, read_count_block[i]);

printf("\nblock size:%16s\n","Write Count");

for (i in write_count_block)

printf("%10d:%16d\n", i, write_count_block[i]);

输出示例：

========
summary:
========
total number of reads: 1081513
total number of writes: 0
slowest read : 0.032560 second
slowest write: 0.000000 second
reads
> 1ms: 18253
>10ms: 17058
>20ms: 17045
>30ms: 780
writes
> 1ms: 0
>10ms: 0
>20ms: 0
>30ms: 0

block size:      Read Count
       256:           93756
       248:            1538
        64:           98084
        56:            7475
         8:          101218
        48:           15889
       240:            1637
       232:            1651
       224:            1942
        40:           21693
       216:            1811
        32:          197893
       208:            1907
        24:           37787
       128:           97382
        16:          399850

========

summary:

========

total number of reads: 1081513

total number of writes: 0

slowest read : 0.032560 second

slowest write: 0.000000 second

reads

> 1ms: 18253

>10ms: 17058

>20ms: 17045

>30ms: 780

writes

> 1ms: 0

>10ms: 0

>20ms: 0

>30ms: 0

block size: Read Count

256: 93756

248: 1538

64: 98084

56: 7475

8: 101218

48: 15889

240: 1637

232: 1651

224: 1942

40: 21693

216: 1811

32: 197893

208: 1907

24: 37787

128: 97382

16: 399850

这个例子统计了IO的读/写数量、最大延迟、延迟的分布情况、块大小及数量，这些信息比iostat要具体得多，有助于进一步了解系统的IO模式。blktrace数据还有更多的利用空间等待你去发掘，譬如还可以根据时间戳去统计每个毫秒内的IO数，有助于更微观地了解IO请求数量的波动。

参考：
利用BLKTRACE分析IO性能

IO、性能工具

容易被误读的iostat

2016/11/29 vmunix

iostat(1)是在Linux系统上查看I/O性能最基本的工具，然而对于那些熟悉其它UNIX系统的人来说它是很容易被误读的。比如在HP-UX上 avserv（相当于Linux上的 svctm）是最重要的I/O指标，反映了硬盘设备的性能，它是指I/O请求从SCSI层发出、到I/O完成之后返回SCSI层所消耗的时间，不包括在SCSI队列中的等待时间，所以avserv体现了硬盘设备处理I/O的速度，又被称为disk service time，如果avserv很大，那么肯定是硬件出问题了。然而Linux上svctm的含义截然不同，事实上在iostat(1)和sar(1)的man page上都说了不要相信svctm，该指标将被废弃：
“Warning! Do not trust this field any more. This field will be removed in a future sysstat version.”

在Linux上，每个I/O的平均耗时是用await表示的，但它不能反映硬盘设备的性能，因为await不仅包括硬盘设备处理I/O的时间，还包括了在队列中等待的时间。I/O请求在队列中的时候尚未发送给硬盘设备，即队列中的等待时间不是硬盘设备消耗的，所以说await体现不了硬盘设备的速度，内核的问题比如I/O调度器什么的也有可能导致await变大。那么有没有哪个指标可以衡量硬盘设备的性能呢？非常遗憾的是，iostat(1)和sar(1)都没有，这是因为它们所依赖的/proc/diskstats不提供这项数据。要真正理解iostat的输出结果，应该从理解/proc/diskstats开始。

# cat /proc/diskstats
   8       0 sda 239219 1806 37281259 2513275 904326 88832 50268824 26816609 0 4753060 29329105
   8       1 sda1 338 0 53241 6959 154 0 5496 3724 0 6337 10683
   8       2 sda2 238695 1797 37226458 2504489 620322 88832 50263328 25266599 0 3297988 27770221
   8      16 sdb 1009117 481 1011773 127319 0 0 0 0 0 126604 126604
   8      17 sdb1 1008792 480 1010929 127078 0 0 0 0 0 126363 126363
 253       0 dm-0 1005 0 8040 15137 30146 0 241168 2490230 0 30911 2505369
 253       1 dm-1 192791 0 35500457 2376087 359162 0 44095600 22949466 0 2312433 25325563
 253       2 dm-2 47132 0 1717329 183565 496207 0 5926560 7348763 0 2517753 7532688

# cat /proc/diskstats

8 0 sda 239219 1806 37281259 2513275 904326 88832 50268824 26816609 0 4753060 29329105

8 1 sda1 338 0 53241 6959 154 0 5496 3724 0 6337 10683

8 2 sda2 238695 1797 37226458 2504489 620322 88832 50263328 25266599 0 3297988 27770221

8 16 sdb 1009117 481 1011773 127319 0 0 0 0 0 126604 126604

8 17 sdb1 1008792 480 1010929 127078 0 0 0 0 0 126363 126363

253 0 dm-0 1005 0 8040 15137 30146 0 241168 2490230 0 30911 2505369

253 1 dm-1 192791 0 35500457 2376087 359162 0 44095600 22949466 0 2312433 25325563

253 2 dm-2 47132 0 1717329 183565 496207 0 5926560 7348763 0 2517753 7532688

/proc/diskstats有11个字段，以下内核文档解释了它们的含义https://www.kernel.org/doc/Documentation/iostats.txt，我重新表述了一下，注意除了字段#9之外都是累计值，从系统启动之后一直累加：

(rd_ios)读操作的次数。
(rd_merges)合并读操作的次数。如果两个读操作读取相邻的数据块时，可以被合并成一个，以提高效率。合并的操作通常是I/O scheduler（也叫elevator）负责的。
(rd_sectors)读取的扇区数量。
(rd_ticks)读操作消耗的时间（以毫秒为单位）。每个读操作从__make_request()开始计时，到end_that_request_last()为止，包括了在队列中等待的时间。
(wr_ios)写操作的次数。
(wr_merges)合并写操作的次数。
(wr_sectors)写入的扇区数量。
(wr_ticks)写操作消耗的时间（以毫秒为单位）。
(in_flight)当前未完成的I/O数量。在I/O请求进入队列时该值加1，在I/O结束时该值减1。
注意：是I/O请求进入队列时，而不是提交给硬盘设备时。
(io_ticks)该设备用于处理I/O的自然时间(wall-clock time)。
请注意io_ticks与rd_ticks(字段#4)和wr_ticks(字段#8)的区别，rd_ticks和wr_ticks是把每一个I/O所消耗的时间累加在一起，因为硬盘设备通常可以并行处理多个I/O，所以rd_ticks和wr_ticks往往会比自然时间大。而io_ticks表示该设备有I/O（即非空闲）的时间，不考虑I/O有多少，只考虑有没有。在实际计算时，字段#9(in_flight)不为零的时候io_ticks保持计时，字段#9(in_flight)为零的时候io_ticks停止计时。
(time_in_queue)对字段#10(io_ticks)的加权值。字段#10(io_ticks)是自然时间，不考虑当前有几个I/O，而time_in_queue是用当前的I/O数量（即字段#9 in-flight）乘以自然时间。虽然该字段的名称是time_in_queue，但并不真的只是在队列中的时间，其中还包含了硬盘处理I/O的时间。iostat在计算avgqu-sz时会用到这个字段。

iostat(1)是以/proc/diskstats为基础计算出来的，因为/proc/diskstats并未把队列等待时间和硬盘处理时间分开，所以凡是以它为基础的工具都不可能分别提供disk service time以及与queue有关的值。
注：下面的公式中“Δ”表示两次取样之间的差值，“Δt”表示采样周期。

tps：每秒I/O次数=[(Δrd_ios+Δwr_ios)/Δt]
- r/s：每秒读操作的次数=[Δrd_ios/Δt]
- w/s：每秒写操作的次数=[Δwr_ios/Δt]
rkB/s：每秒读取的千字节数=[Δrd_sectors/Δt]*[512/1024]
wkB/s：每秒写入的千字节数=[Δwr_sectors/Δt]*[512/1024]
rrqm/s：每秒合并读操作的次数=[Δrd_merges/Δt]
wrqm/s：每秒合并写操作的次数=[Δwr_merges/Δt]
avgrq-sz：每个I/O的平均扇区数=[Δrd_sectors+Δwr_sectors]/[Δrd_ios+Δwr_ios]
avgqu-sz：平均未完成的I/O请求数量=[Δtime_in_queue/Δt]
（手册上说是队列里的平均I/O请求数量，更恰当的理解应该是平均未完成的I/O请求数量。）
await：每个I/O平均所需的时间=[Δrd_ticks+Δwr_ticks]/[Δrd_ios+Δwr_ios]
（不仅包括硬盘设备处理I/O的时间，还包括了在kernel队列中等待的时间。）
- r_await：每个读操作平均所需的时间=[Δrd_ticks/Δrd_ios]
  不仅包括硬盘设备读操作的时间，还包括了在kernel队列中等待的时间。
- w_await：每个写操作平均所需的时间=[Δwr_ticks/Δwr_ios]
  不仅包括硬盘设备写操作的时间，还包括了在kernel队列中等待的时间。
%util：该硬盘设备的繁忙比率=[Δio_ticks/Δt]
表示该设备有I/O（即非空闲）的时间比率，不考虑I/O有多少，只考虑有没有。
svctm：已被废弃的指标，没什么意义，svctm=[util/tput]

对iostat(1)的恰当解读有助于正确地分析问题，我们结合实际案例进一步讨论。

关于rrqm/s和wrqm/s

前面讲过，如果两个I/O操作发生在相邻的数据块时，它们可以被合并成一个，以提高效率，合并的操作通常是I/O scheduler（也叫elevator）负责的。

以下案例对许多硬盘设备执行同样的压力测试，结果惟有sdb比其它硬盘都更快一些，可是硬盘型号都一样，为什么sdb的表现不一样？

可以看到其它硬盘的rrqm/s都为0，而sdb不是，就是说发生了I/O合并，所以效率更高，r/s和rMB/s都更高，我们知道I/O合并是内核的I/O scheduler（elevator）负责的，于是检查了sdb的/sys/block/sdb/queue/scheduler，发现它与别的硬盘用了不同的I/O scheduler，所以表现也不一样。

%util与硬盘设备饱和度

%util表示该设备有I/O（即非空闲）的时间比率，不考虑I/O有多少，只考虑有没有。由于现代硬盘设备都有并行处理多个I/O请求的能力，所以%util即使达到100%也不意味着设备饱和了。举个简化的例子：某硬盘处理单个I/O需要0.1秒，有能力同时处理10个I/O请求，那么当10个I/O请求依次顺序提交的时候，需要1秒才能全部完成，在1秒的采样周期里%util达到100%；而如果10个I/O请求一次性提交的话，0.1秒就全部完成，在1秒的采样周期里%util只有10%。可见，即使%util高达100%，硬盘也仍然有可能还有余力处理更多的I/O请求，即没有达到饱和状态。那么iostat(1)有没有哪个指标可以衡量硬盘设备的饱和程度呢？很遗憾，没有。

await多大才算有问题

await是单个I/O所消耗的时间，包括硬盘设备处理I/O的时间和I/O请求在kernel队列中等待的时间，正常情况下队列等待时间可以忽略不计，姑且把await当作衡量硬盘速度的指标吧，那么多大算是正常呢？
对于SSD，从0.0x毫秒到1.x毫秒不等，具体看产品手册；
对于机械硬盘，可以参考以下文档中的计算方法：
http://cseweb.ucsd.edu/classes/wi01/cse102/sol2.pdf
大致来说一万转的机械硬盘是8.38毫秒，包括寻道时间、旋转延迟、传输时间。

在实践中，要根据应用场景来判断await是否正常，如果I/O模式很随机、I/O负载比较高，会导致磁头乱跑，寻道时间长，那么相应地await要估算得大一些；如果I/O模式是顺序读写，只有单一进程产生I/O负载，那么寻道时间和旋转延迟都可以忽略不计，主要考虑传输时间，相应地await就应该很小，甚至不到1毫秒。在以下实例中，await是7.50毫秒，似乎并不大，但考虑到这是一个dd测试，属于顺序读操作，而且只有单一任务在该硬盘上，这里的await应该不到1毫秒才算正常：

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util
sdg               0.00     0.00  133.00    0.00  2128.00     0.00    16.00     1.00    7.50   7.49  99.60

1 2	Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util sdg 0.00 0.00 133.00 0.00 2128.00 0.00 16.00 1.00 7.50 7.49 99.60

对磁盘阵列来说，因为有硬件缓存，写操作不等落盘就算完成，所以写操作的service time大大加快了，如果磁盘阵列的写操作不在一两个毫秒以内就算慢的了；读操作则未必，不在缓存中的数据仍然需要读取物理硬盘，单个小数据块的读取速度跟单盘差不多。

IO、性能工具

disk 100% busy，谁造成的？

2016/11/16 vmunix

iostat等命令看到的是系统级的统计，比如下例中我们看到/dev/sdb很忙，如果要追查是哪个进程导致的I/O繁忙，应该怎么办？

# iostat -xd
...
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sdb               0.00     0.00 6781.67    0.00  3390.83     0.00     1.00     0.85    0.13    0.13    0.00   0.13  85.03
dm-0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
dm-1              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
dm-2              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
...

# iostat -xd

...

Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util

sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

sdb 0.00 0.00 6781.67 0.00 3390.83 0.00 1.00 0.85 0.13 0.13 0.00 0.13 85.03

dm-0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

dm-1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

dm-2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

...

进程的内核数据结构中包含了I/O数量的统计：

struct task_struct {
...
         struct task_io_accounting ioac;
...
};

struct task_struct {

...

struct task_io_accounting ioac;

...

};

可以直接在 /proc/<pid>/io 中看到：

# cat /proc/3088/io
rchar: 125119 //在read(),pread(),readv(),sendfile等系统调用中读取的字节数
wchar: 632    //在write(),pwrite(),writev(),sendfile等系统调用中写入的字节数
syscr: 111    //调用read(),pread(),readv(),sendfile等系统调用的次数
syscw: 79     //调用write(),pwrite(),writev(),sendfile等系统调用的次数
read_bytes: 425984 //进程读取的物理I/O字节数，包括mmap pagein，在submit_bio()中统计的
write_bytes: 0     //进程写出的物理I/O字节数，包括mmap pageout，在submit_bio()中统计的
cancelled_write_bytes: 0 //如果进程截短了cache中的文件，事实上就减少了原本要发生的写I/O

# cat /proc/3088/io

rchar: 125119 //在read(),pread(),readv(),sendfile等系统调用中读取的字节数

wchar: 632 //在write(),pwrite(),writev(),sendfile等系统调用中写入的字节数

syscr: 111 //调用read(),pread(),readv(),sendfile等系统调用的次数

syscw: 79 //调用write(),pwrite(),writev(),sendfile等系统调用的次数

read_bytes: 425984 //进程读取的物理I/O字节数，包括mmap pagein，在submit_bio()中统计的

write_bytes: 0 //进程写出的物理I/O字节数，包括mmap pageout，在submit_bio()中统计的

cancelled_write_bytes: 0 //如果进程截短了cache中的文件，事实上就减少了原本要发生的写I/O

我们关心的是实际发生的物理I/O，从上面的注释可知，应该关注 read_bytes 和 write_bytes。请注意这都是历史累计值，从进程开始执行之初就一直累加。如果要观察动态变化情况，可以使用 pidstat 命令，它就是利用了/proc/<pid>/io 中的原始数据计算单位时间内的增量：

# pidstat -d 2 2
Linux 3.10.0-229.14.1.el7.x86_64 (bj71s060)     11/16/2016      _x86_64_       (2 CPU)

12:30:15 PM   UID       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
12:30:17 PM     0     14772   3362.25      0.00      0.00  dd

12:30:17 PM   UID       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
12:30:19 PM     0     14772   3371.25      0.00      0.00  dd

# pidstat -d 2 2

Linux 3.10.0-229.14.1.el7.x86_64 (bj71s060) 11/16/2016 _x86_64_ (2 CPU)

12:30:15 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s Command

12:30:17 PM 0 14772 3362.25 0.00 0.00 dd

12:30:17 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s Command

12:30:19 PM 0 14772 3371.25 0.00 0.00 dd

另外还有一个常用的命令 iotop 也可以观察进程的动态I/O：

Actual DISK READ:       3.31 M/s | Actual DISK WRITE:       0.00 B/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND          
14772 be/4 root        3.31 M/s    0.00 B/s  0.00 % 61.99 % dd if=/de~lag=direct
    1 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % systemd -~rialize 24
    2 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kthreadd]
...

Actual DISK READ: 3.31 M/s | Actual DISK WRITE: 0.00 B/s

TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND

14772 be/4 root 3.31 M/s 0.00 B/s 0.00 % 61.99 % dd if=/de~lag=direct

1 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % systemd -~rialize 24

2 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kthreadd]

...

pidstat 和 iotop 也有不足之处，它们无法具体到某个硬盘设备，如果系统中有很多硬盘设备，都在忙，而我们只想看某一个特定的硬盘的I/O来自哪些进程，这两个命令就帮不上忙了。怎么办呢？可以用上万能工具SystemTap。比如：我们希望找出访问/dev/sdb的进程，可以用下列脚本，它的原理是对submit_bio下探针：

#! /usr/bin/env stap

global device_of_interest

probe begin {
  device_of_interest = $1
  printf ("device of interest: 0x%x\n", device_of_interest)
}

probe kernel.function("submit_bio")
{
  dev = $bio->bi_bdev->bd_dev
  if (dev == device_of_interest)
    printf ("[%s](%d) dev:0x%x rw:%d size:%d\n",
            execname(), pid(), dev, $rw, $bio->bi_size)
}

#! /usr/bin/env stap

global device_of_interest

probe begin {

device_of_interest = $1

printf ("device of interest: 0x%x\n", device_of_interest)

}

probe kernel.function("submit_bio")

{

dev = $bio->bi_bdev->bd_dev

if (dev == device_of_interest)

printf ("[%s](%d) dev:0x%x rw:%d size:%d\n",

execname(), pid(), dev, $rw, $bio->bi_size)

}

这个脚本需要在命令行参数中指定需要监控的硬盘设备号，得到这个设备号的方法如下：

# ll /dev/sdb
brw-rw----. 1 root disk 8, 16 Oct 24 15:52 /dev/sdb

Major number(12-bit):  8 i.e. 0x8
Minor number(20-bit): 16 i.e. 0x00010
合在一起得到设备号： 0x800010

# ll /dev/sdb

brw-rw----. 1 root disk 8, 16 Oct 24 15:52 /dev/sdb

Major number(12-bit): 8 i.e. 0x8

Minor number(20-bit): 16 i.e. 0x00010

合在一起得到设备号： 0x800010

执行脚本，我们看到：

# ./dev_task_io.stp 0x800010
device of interest: 0x800010
[dd](31202) dev:0x800010 rw:0 size:512
[dd](31202) dev:0x800010 rw:0 size:512
[dd](31202) dev:0x800010 rw:0 size:512
[dd](31202) dev:0x800010 rw:0 size:512
[dd](31202) dev:0x800010 rw:0 size:512
...

# ./dev_task_io.stp 0x800010

device of interest: 0x800010

[dd](31202) dev:0x800010 rw:0 size:512

...

结果很令人满意，我们看到是进程号为31202的dd命令在对/dev/sdb进行读操作。

IO、性能工具

理解 %iowait (%wio)

2016/02/25 vmunix

%iowait 是 “sar -u” 等工具检查CPU使用率时显示的一个指标，在Linux上显示为 %iowait，在有的Unix版本上显示为 %wio，含义都是一样的。这个指标常常被误读，很多人把它当作I/O问题的征兆，我自己每隔一段时间就会遇到对 %iowait 紧张兮兮的客户，不得不费尽唇舌反复解释。事实上这个指标所含的信息量非常少，不能单独用来判断系统有没有I/O问题。在此我们详细探讨一下它真正的含义，先从man page上的解释开始：

09:35:06 AM     CPU     %user     %nice   %system   %iowait    %steal     %idle
09:35:07 AM     all      0.00      0.00      0.00      0.00      0.00    100.00
09:35:08 AM     all      0.51      0.00      2.53     13.13      0.00     83.84
09:35:09 AM     all      1.54      0.00      7.69     39.49      0.00     51.28
09:35:10 AM     all      2.04      0.00      9.18     39.80      0.00     48.98
09:35:11 AM     all      1.02      0.00      7.65     40.31      0.00     51.02

09:35:06 AM CPU %user %nice %system %iowait %steal %idle

09:35:07 AM all 0.00 0.00 0.00 0.00 0.00 100.00

09:35:08 AM all 0.51 0.00 2.53 13.13 0.00 83.84

09:35:09 AM all 1.54 0.00 7.69 39.49 0.00 51.28

09:35:10 AM all 2.04 0.00 9.18 39.80 0.00 48.98

09:35:11 AM all 1.02 0.00 7.65 40.31 0.00 51.02

Linux:
%iowait
Percentage of time that the CPU or CPUs were idle during
which the system had an outstanding disk I/O request.

HP-UX:
%wio
idle with some process waiting for I/O (only block I/O, raw
I/O, or VM pageins/swapins indicated).

Linux和HP-UX的man page分别从两个角度描述了这个指标：Linux着眼于I/O，强调的是仍有未完成的I/O请求；而HP-UX着眼于进程，强调的是仍有进程在等待I/O。二者所说的是同一件事的两个方面，合在一起就完整了，就是：至少有一个I/O请求尚未完成，有进程因为等待它而休眠。

我们不妨采纳Linux的措辞，%iowait 表示在一个采样周期内有百分之几的时间属于以下情况：CPU空闲、并且有仍未完成的I/O请求。

对 %iowait 常见的误解有两个：一是误以为 %iowait 表示CPU不能工作的时间，二是误以为 %iowait 表示I/O有瓶颈。

第一种误解太低级了，%iowait 的首要条件就是CPU空闲，既然空闲当然就可以接受运行任务，只是因为没有可运行的进程，CPU才进入空闲状态的。那为什么没有可运行的进程呢？因为进程都处于休眠状态、在等待某个特定事件：比如等待定时器、或者来自网络的数据、或者键盘输入、或者等待I/O操作完成，等等。

第二种误解更常见，为什么人们会认为 %iowait 偏高是有I/O瓶颈的迹象呢？他们的理由是：”%iowait 的第一个条件是CPU空闲，意即所有的进程都在休眠，第二个条件是仍有未完成的I/O请求，意味着进程休眠的原因是等待I/O，而 %iowait 升高则表明因等待I/O而休眠的进程数量更多了、或者进程因等待I/O而休眠的时间更长了。“ 听上去似乎很有道理，但是不对：

首先 %iowait 升高并不能证明等待I/O的进程数量增多了，也不能证明等待I/O的总时间增加了。为什么呢？看看下面两张图就明白了。

第一张图演示的是，在I/O完全一样的情况下，CPU忙闲状态的变化就能够影响 %iowait 的大小。下图我们看到，在CPU繁忙期间发生的I/O，无论有多少，%iowait 的值都是不受影响的（因为 %iowait 的第一个前提条件就是CPU必须空闲）；当CPU繁忙程度下降时，有一部分I/O落入了CPU空闲的时间段内，这就导致了 %iowait 升高。可见，I/O并没有变化，%iowait 却升高了，原因仅仅是CPU的空闲时间增加了。请记住，系统中有成百上千的进程数，任何一个进程都可以引起CPU和I/O的变化，因为 %iowait、%idle、%user、%system 等这些指标都是全局性的，并不是特指某个进程。

再往下看第二张图，它描述了另一种情形：假设CPU的繁忙状况保持不变的条件下，即使 %iowait 升高也不能说明I/O负载加重了。
如果2个I/O请求依次提交、使得整个时段内始终有I/O在进行，那么 %iowait 是100%；
如果3个I/O请求同时提交，因为系统有能力同时处理多个I/O，所以3个并发的I/O从开始到结束的时间与一个I/O一样，%iowait 的结果只有50%。
2个I/O使 %iowait 达到了100%，3个I/O的 %iowait 却只有50%，显然 %iowait 的高低与I/O的多少没有必然关系，而是与I/O的并发度相关。所以，仅凭 %iowait 的上升不能得出I/O负载增加 的结论。

这就是为什么说 %iowait 所含的信息量非常少的原因，它是一个非常模糊的指标，如果看到 %iowait 升高，还需检查I/O量有没有明显增加，avserv/avwait/avque等指标有没有明显增大，应用有没有感觉变慢，如果都没有，就没什么好担心的。