HACK #20　使用fio进行I/O的基准测试

本节介绍使用fio进行模拟各种情况的I/O基准测试的操作方法。
I/O的基准测试中有无数需要考虑的因素。是I/O依次访问还是随机访问？是通过read/write的I/O？还是通过访问mmap的空间的I/O？是单一进程发出的I/O？还是多个进程同时发出的I/O？进程是受I/O限制还是受CPU限制？等等。
如果使用fio，就不需要每次都根据不同情况来编写用于性能评估的程序，就可以模拟这些情况的I/O。
安装fio
Fedora、Ubuntu等主流发布版中都备有fio的二进制文件包。请使用yum、apt等安装fio工具包。
这里按照Fedora 13中包含的fio版本1.36来进行说明。
想要使用最新版时，请先从下列网页下载fio的源代码，再进行安装。
程序页
http://freshmeat.net/projects/fio
Git仓库
git://git.kernel.org/pub/scm/linux/kernel/git/axboe/fio.git
基本执行方法
指定记载了I/O操作模式的设置文件，然后启动fio命令，这就是fio最基本的执行方法。大多数的项目可以不使用配置文件而通过命令行选项来指定。首先举出两种分别使用命令行选项的方法和配置文件的方法的简单例子，了解基本执行方法和命令行/设置文件的对应情况。
第一个示例执行的是下列操作。
进行10MB的顺序读入。
同时，其他进程随机进行5MB的写入。
使用read(2)和write(2)进行读写。
使用Direct I/O。
在fio命令行进行这些设置时的操作如下。在当前目录下会生成读写用的文件，因此要在可以写入的目录下执行。

$ fio --name=global --direct=1 --name=read --rw=read --size=10m --name=write --rw=randwrite --size=5m

与上述命令行选项具有相同意义的配置文件如下所示。

# cat fio_exam.fio[global]
direct=1[readjob]
size=10m
rw=read[writejob]
size=5m
rw=randwrite

使用这个配置文件执行fio命令如下。

$ fio simple_read.fio

命令行选项与配置文件的各项之间的关系非常明显。这里简单介绍配置文件的各项的意义。
以#开头的是注释（comment）。内容直到行尾都被忽略。
方括号表示[]作业（job）定义选项的开始。方括号内是作业的名称。作业可以任意命名。但是global这个名称是内部使用的。作业global是用来定义所有作业共同的设置项。
fio按照每个作业生成进程，生成的进程根据设置进行实际的I/O操作。因此，fio的配置文件中除了global选项以外，必须要定义多个作业。
global选项中设置了direct=1。将direct设置为1时，使用的就Direct I/O。未指定时，就等同于direct=0（经由一般页面缓存进行I/O）。
接下来定义名为readjob的作业。
readjob作业中使用size设置I/O操作的大小（字节数）。后缀m表示兆字节。后缀可以使用k、m、g、t、p。readjob作业的进程在进行了size所设置的大小的I/O后就会结束。
rw用来设置I/O模式。readjob作业中指定的是表示顺序读出的read。其他的将在下一节中介绍。
最后再定义一个名称为writejob的作业。
writejob作业将进行I/O的大小设置为5MB，I/O模式设置为随机写入（randwrite）。
按照这个设置执行fio时，首先会在当前目录下生成用于I/O的文件，进行同步处理，取消页面缓存。然后，生成与readjob作业相对应的进程和与writejob作业相对应的进程，进行各自设置的I/O操作。各作业在完成size所设置的字节数的I/O后，就会结束。所有作业结束后，结果就会显示在控制台上。
输出结果包括很多信息。这些内容将在下一节中详细介绍。
模拟实验的例子和输出的意义
现在已经掌握了基本执行方法，就可以尝试生成并执行模拟某种情况的配置文件，然后对输出进行分析。
先生成符合下列情况的配置文件。
在文件数据的基础上执行查询（query）并返回发出请求的进程有两个正在执行。每隔10毫秒接受查询的请求并执行，从接受请求到返回结果的演算过程花费5毫秒。
1个正在运行的进程，它用来将访问记录写入磁盘。记录每1秒通过direct I/O写入。通过AIO实现I/O复用（multiplexing）。
与此同时，执行文件系统备份处理。
模拟这种情况的配置文件以及其中使用的各种配置项的意义如表3-7所示。另外，模拟时间设置为执行30秒后结束。

# server_sim.fio[global]
directory=/mnt/sdb
runtime=30
time_based[query]
size=100m
rw=randread
ioengine=mmap
thinktime=10k
thinktime_spin=5k
filename=query.dat
numjobs=2[log]
size=10m
rw=randrw
ioengine=libaio
iodepth=32
thinktime=1m
thinktime_blocks=2
blocksize=1k,4k
direct=1[backup]
size=100m
rw=randrw
thinktime=1k

表3-7　fio的配置项

然后实际执行，并详细查看输出结果。

$ fio server_sim.fioquery: (g=0): rw=randread, bs=4K-4K/4K-4K, ioengine=mmap, iodepth=1
query: (g=0): rw=randread, bs=4K-4K/4K-4K, ioengine=mmap, iodepth=1
log: (g=0): rw=randrw, bs=1K-1K/4K-4K, ioengine=libaio, iodepth=32
backup: (g=0): rw=randrw, bs=4K-4K/4K-4K, ioengine=sync, iodepth=1
Starting 4 processes
query: Laying out IO file(s) (1 file(s) / 100MB)
log: Laying out IO file(s) (1 file(s) / 10MB)
backup: Laying out IO file(s) (1 file(s) / 100MB)query: (groupid=0, jobs=1): err= 0: pid=3158read : io=6,740KB, bw=225KB/s, iops=56, runt= 30006msecclat (usec): min=6, max=124K, avg=7553.49, stdev=5995.06bw (KB/s) : min=  162, max=  254, per=25.31%, avg=225.24, stdev=15.52cpu          : usr=28.83%, sys=0.24%, ctx=3544, majf=1639, minf=75IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%issued r/w: total=1685/0, short=0/0lat (usec): 10=2.67%, 20=0.06%, 500=0.18%, 750=0.65%, 1000=0.36%lat (msec): 2=1.54%, 4=15.73%, 10=58.16%, 20=17.69%, 50=2.79%lat (msec): 100=0.12%, 250=0.06%query: (groupid=0, jobs=1): err= 0: pid=3159read : io=6,772KB, bw=226KB/s, iops=56, runt= 30008msecclat (usec): min=6, max=128K, avg=7470.76, stdev=6163.17bw (KB/s) : min=  181, max=  260, per=25.45%, avg=226.47, stdev=14.27cpu          : usr=28.99%, sys=0.20%, ctx=3622, majf=1630, minf=88IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%issued r/w: total=1693/0, short=0/0lat (usec): 10=3.66%, 20=0.06%, 500=0.35%, 750=0.77%, 1000=0.06%lat (msec): 2=1.24%, 4=16.42%, 10=55.64%, 20=19.31%, 50=2.30%lat (msec): 100=0.12%, 250=0.06%log: (groupid=0, jobs=1): err= 0: pid=3160read : io=39,936B, bw=1,311B/s, iops=1, runt= 30449msecslat (usec): min=8, max=63, avg=27.92, stdev=19.38clat (msec): min=36, max=16,815, avg=10042.82, stdev=5584.03bw (KB/s) : min=    0, max=    1, per=0.01%, avg= 0.06, stdev= 0.24write: io=197KB, bw=6,625B/s, iops=1, runt= 30449msecslat (usec): min=10, max=89, avg=33.40, stdev=22.97clat (msec): min=33, max=16,778, avg=11045.30, stdev=5371.05bw (KB/s) : min=    0, max=    7, per=0.56%, avg= 2.62, stdev= 2.59cpu          : usr=0.00%, sys=0.01%, ctx=31, majf=0, minf=21IO depths    : 1=1.1%, 2=2.2%, 4=4.5%, 8=9.0%, 16=18.0%, 32=65.2%, >=64=0.0%submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%complete  : 0=0.0%, 4=98.3%, 8=0.0%, 16=0.0%, 32=1.7%, 64=0.0%, >=64=0.0%issued r/w: total=39/50, short=0/0lat (msec): 50=2.25%, 2000=4.49%, >=2000=93.26%backup: (groupid=0, jobs=1): err= 0: pid=3161read : io=13,556KB, bw=452KB/s, iops=112, runt= 30005msecclat (usec): min=419, max=104K, avg=6669.29, stdev=4584.93bw (KB/s) : min=  341, max=  525, per=50.82%, avg=452.29, stdev=40.41write: io=14,072KB, bw=469KB/s, iops=117, runt= 30005msecclat (usec): min=10, max=98,704, avg=79.48, stdev=2190.03bw (KB/s) : min=  321, max=  632, per=100.32%, avg=469.52, stdev=72.87cpu          : usr=0.38%, sys=0.74%, ctx=10302, majf=0, minf=28IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%issued r/w: total=3389/3518, short=0/0lat (usec): 20=38.63%, 50=12.25%, 500=0.51%, 750=0.61%, 1000=0.04%lat (msec): 2=1.61%, 4=9.64%, 10=28.99%, 20=7.37%, 50=0.25%lat (msec): 100=0.10%, 250=0.01%Run status group 0 (all jobs):READ: io=27,107KB, aggrb=890KB/s, minb=1KB/s, maxb=462KB/s, mint=30005msec, maxt=30449msecWRITE: io=14,269KB, aggrb=468KB/s, minb=6KB/s, maxb=480KB/s, mint=30005msec, maxt=30449msecDisk stats (read/write):sdb: ios=6698/2302, merge=0/26478, ticks=48982/1143531, in_queue=1207586, util=93.27%

第一部分输出的是已执行进程的信息，分别输出了名称、I/O模式、块的大小等设置。有两个query是因为指定为numjob=2，所以要执行两个进程。
接下来第一行为query的两个段落是query作业两个进程的结果，其后显示的分别是log作业和backup作业的结果。下面对比各部分的内容，看一下各输出表示的意义。
从read:和write:开始的3行或4行表示的是关于读入和写入的数据量、平均带宽、延迟。平均带宽是将总数据量除以作业执行时间得出的值，因此在thinktime较长的作业中值较低。clat（completion latency）的行为延迟，是作业进程开始向内核发出I/O请要到完成为止的时间，即从调出read(2)等直到返回的时间。log作业由于使用的是AIO，因此多输出一个slat（submitting latency）延迟。这表示I/O发出要求滞留在作业进程内部的queue时间。
从query作业的延迟来看，平均花费7.5毫秒左右，最多花费130毫秒左右。10毫秒的查询间隔中大部分时间都耗费在等待I/O上。log作业中出现了最长16秒的延迟。这时应当重新设计系统，分散I/O负载。
小贴士：clat在read(2)或Direct I/O的write(2)中I/O实际花费的时间，而在常用的经由页面缓存的write(2)中只是将数据存放到页面缓存所需的时间。上例中backup作业的write就相当于这种情况，因此其值平均为79微秒，比其他情况短得多。
I/O depths的行表示通过AIO实现复用的I/O数与时间之间的关系。例如，log作业的IO depths中的“8=9.0%，16=18.0%”，就表示9~16个I/O同时执行的时间相当于所有执行时间的18.0%。由于I/O复用只存在于AIO的情况下，因此在log以外的作业都是“1=100%”。
从log作业的IO depths可以看出，65.2%的时间都达到复用上限值附近的19~32。这也显示I/O负载仍然过高。
最后两个段落是关于所有进程总共的统计值。输出所有I/O的数据量的合计结果等。
小结
本节使用fio进行实际使用情况的I/O模拟实验，介绍了输出的结果。fio有非常多的选项，可以进行更加精确和详细的设置，由于数量庞大，这里无法一一列举。源代码包含的文档和man中有详细的记载，但都是英文。参考这些内容并熟练使用I/O操作，I/O基准测试就能成为强有力的工具。
—Munehiro IKEDA