読者です 読者をやめる 読者になる 読者になる

Disk I/O性能測定するときに活躍する道具たち

この記事はピョッコリンアドベントカレンダーのために書かれたものです。

サマリ

Disk(HDD/SSD/仮想ディスク等)のI/O性能を測定するのに 活躍するツールについて、簡単に使い方を説明する。

はじめに

Diskに限定せずとも、性能測定と言えば、 おおまかには、スループット(Diskに関して言えば、1秒あたりどれくらいのI/Oを処理できるか?)と レイテンシ(Diskに関して言えば、1個のI/Oを処理するのにどれくらい時間がかかったか?) の2つについて見ることになる。 特にLinuxに関しては、このあたりをよく使うような気がする(主観)。

  • fio:Diskに対してI/Oを発行してくれて、スループットやレイテンシを算出してくれるもの。
  • iostat:Diskごとにスループットなどの情報をリアルタイムで見せてくれるもの
  • blktrace:LinuxがDiskに対してどんなI/Oを出していたかの履歴(=トレース)を見せてくれるもの。

fioはスループットもレイテンシも算出してくれるので、基本的にはfioだけで事足りるのだけど、 本当にfioに指定したとおりにLinuxがI/Oを出しているのか、に関してはちゃんと確認する意義があるので、 iostatとblktraceを追加した。

以後、以下の環境を前提とするので、必要があれば適宜読み替えてほしい。

fio

fioのインストール

fioはメジャーなツールなので、こんな感じでaptでインストールできる。

$ sudo aptitude install fio

ソースからビルドしたい原理主義者は、作者様のgithubから落としてくると幸せになれる。 (ビルド前にlibaioを入れておくことを忘れなければ、さらに幸せになれる) github.com

手順としてはこんな感じ。

$ sudo aptitude install libaio1 libaio-dev
$ git clone git@github.com:axboe/fio.git
$ ./configure
$ make
$ sudo make install

使い方

コマンドとしてはこんな感じ。起動時に、どんなI/Oをかけるのかを記述した 設定ファイルを指定する。

$ fio -f script.fio --output output_filename # 場合によってはsudoが必要

fioはコマンド引数でもろもろ指定ができるんだけど、 後々の再利用を考えると、設定ファイルを逐一書いたほうがよいと思う。

設定ファイルの書き方

最小限ではないが、これだけ書けばI/Oをかけることができる。 細かいところはman fioを見るのがいちばん。 英語で書いてあるけど、割と簡単に読めると思う。

fioの設定ファイルは、全体で共通の[global]以下の設定と、 個別の[job]に分けられる。[global]予約語だけど、 [job]に関しては好きな名前を指定できる。もちろん、[job]複数個書くことができる。

[global]                                
ioengine=libaio    # I/Oを発行するのにlibaioを使う。性能測るときは
                   # とりあえずlibaioを指定しておけばよいと思う。
blocksize=4KB      # 1回のI/Oの転送長
blockalign=4KB     # I/Oのアラインメント。
                   # I/O先のアドレスが4KB刻みになる。
kb_base=1024       # K=1000かK=1024かわからなくなるので、
                   # 書いておくと親切。defaultは1024。
filesize=1-1GB     # I/Oをかけるアドレス範囲の指定。
                   # この設定だと、各ファイルそれぞれについて、
                   # 1-1GBの範囲にI/Oをかける(1始まりなので注意)。
direct=1           # Disk I/O性能を測るので、Linuxのキャッシュを
                   # 素通りするようにする。
ioscheduler=noop   # Disk I/O性能を測るので、Linuxに何も考えず
                   # I/Oしてもらうようにする。

[job]
rw=randread        # I/Oの種別。[global]で指定したアドレス範囲から
                   # ランダムに選んでリードする。                                       
filename=/dev/sdc:/dev/sdd:/dev/sde 
                   # どのファイルにI/Oをかけるかを指定。
                   # : で複数指定できる。
                   # 見ての通り、別にファイルでなくともよい。
ramp_time=30       # I/Oかけはじめの、性能測定はしない時間。
                   # I/Oかけはじめは安定しないこともあるので、
                   # 少し時間を置くほうがよいこともある。
runtime=60         # I/Oをかけて、性能測定をする時間。
time_based=1       # filesize分I/Oかけても、runtimeが経過するまで
                   # I/Oをかけ続ける。
numjobs=6          # いくつのプロセスでI/Oするかを指定。
                   # thread=1とすると、forkではなく
                   # pthreadを使ってくれる。
group_reporting=1  # プロセスごとに結果を報告するのではなく、
                   # ジョブごとにまとめて報告する。
iodepth=1          # I/Oの多重度。概して多重で出したほうが性能が上がる。

得られる結果

上記をtest.fioとして保存して、RAM Disk相手にfioを実行してみる。 I/O中はこんな感じで表示される。

$ sudo fio -f test.fio --output test.result             
Jobs: 6 (f=18): [r(6)] [60.0% done] [1137MB/0KB/0KB /s] [291K/0/0 iops] [eta 00m:36s] 

test.resultの中身はこんな感じ。 注意すべきはレイテンシがslat、clat、latの3つあること。 それぞれは以下のとおり。

  • slat:fioがI/O発行して、Linuxがコマンド発行までにかかっている時間。
  • clat:コマンド発行から応答を受け取るまでにかかった時間(単にディスクのレイテンシを見るだけならここだけ見ればよいかも)。
  • lat:全体。
read_test: (g=0): rw=randread, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=1
(略)
read_test: (groupid=0, jobs=6): err= 0: pid=8858: Sun Dec 13 22:27:14 2015                             
  read : io=67192MB, bw=1119.9MB/s, iops=286680, runt= 60001msec                                       
    slat (usec): min=4, max=11476, avg=16.24, stdev=13.23                                              
    clat (usec): min=0, max=10280, avg= 2.26, stdev= 8.96                                              
     lat (usec): min=11, max=10293, avg=18.94, stdev=14.98                                             
    clat percentiles (usec):                                                                           
     |  1.00th=[    0],  5.00th=[    0], 10.00th=[    0], 20.00th=[    1],                             
     | 30.00th=[    1], 40.00th=[    1], 50.00th=[    1], 60.00th=[    1],                             
     | 70.00th=[    1], 80.00th=[    1], 90.00th=[   12], 95.00th=[   13],                             
     | 99.00th=[   15], 99.50th=[   15], 99.90th=[   18], 99.95th=[   20],                             
     | 99.99th=[   47]                                                                                 
    bw (KB  /s): min=    0, max=228328, per=16.54%, avg=189615.16, stdev=19299.85                      
    lat (usec) : 2=88.03%, 4=0.33%, 10=0.02%, 20=11.56%, 50=0.05%                                      
    lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%                                
    lat (msec) : 2=0.01%, 4=0.01%, 10=0.01%, 20=0.01%                                                  
  cpu          : usr=12.58%, sys=37.56%, ctx=17215603, majf=0, minf=8                                  
  IO depths    : 1=150.9%, 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    : total=r=17201111/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0                         
     latency   : target=0, window=0, percentile=100.00%, depth=1                                       
                                                                                                       
Run status group 0 (all jobs):                                                                         
   READ: io=67192MB, aggrb=1119.9MB/s, minb=1119.9MB/s, maxb=1119.9MB/s, mint=60001msec, maxt=60001msec
                                                                                                       
Disk stats (read/write):                                                                               
  sdc: ios=8650516/0, merge=0/0, ticks=102172/0, in_queue=103080, util=61.34%                          
  sdd: ios=8650522/0, merge=0/0, ticks=104708/0, in_queue=103800, util=62.18%                          
  sde: ios=8650522/0, merge=0/0, ticks=101136/0, in_queue=101780, util=60.36%                          

iostat

fioはおおよそのスループットを表示してくれるわけだけど、いかんせんざっくりすぎるので、 iostatを使って、もう少し細かく見てみる。

iostatの入手

何も考えずにaptでinstallする。

$ sudo aptitude install sysstat

iostatの使い方

1秒間隔で表示させておけば困ることはないはず。

$ iostat -x 1 sdc sdd sde

得られる結果

こんな感じで毎秒表示してくれる。 よく使う前半部分に関しては、こんな感じ。

項目 意味
rrqm/s 1秒あたりにマージしたリードリクエストの回数
wrqm/s 1秒あたりにマージしたライトリクエストの回数
r/s 1秒あたりのリード回数
w/s 1秒あたりのライト回数
rkB/s 1秒あたりにリードしたデータ量
wkB/s 1秒あたりのライトしたデータ量
%util I/OリクエストにCPU時間をどれくらい使ったか?(100%=CPUが全力でI/Oを発行しまくっている)
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          12.31    0.00   64.45    0.00    0.00   23.24

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdc               0.00     0.00 96948.00    0.00 387796.00     0.00     8.00     1.08    0.01    0.01    0.00   0.01  60.00
sdd               0.00     0.00 96949.00    0.00 387796.00     0.00     8.00     1.15    0.01    0.01    0.00   0.01  64.40
sde               0.00     0.00 96949.00    0.00 387796.00     0.00     8.00     1.08    0.01    0.01    0.00   0.01  57.60

blktrace

測定をしたはよいが、芳しくない結果が得られたときに、一体何が起こっていたのかを 確認するためのトレース採取ツール。困ったときに覗くとよいと思う。

blktraceの入手

考える前にまずはaptを叩く。

$ sudo aptitude install blktrace

blktraceの使い方

I/O中に、デバイスを指定してトレースを取得する。 トレースはコア数分できる。

$ sudo blktrace -d /dev/sdc # Ctrl-Cでトレース採取終了
$ ls
sdc.blktrace.0  sdc.blktrace.2  sdc.blktrace.4  sdc.blktrace.6 
sdc.blktrace.1  sdc.blktrace.3  sdc.blktrace.5  sdc.blktrace.7  

得られる結果

得られたファイルはバイナリなので、blktraceとセットになっているblkparseというコマンドを使って、 読みやすい形に整形する。

$ blkparse -i sdc.blktrace.0 > sdc.blkparse.0

sdc.blkparse.0を覗いてみると、左から順に以下のようになっている(デフォルト設定なのでもちろん変えられる)。

  • デバイスのmajor番号, minor番号
  • CPUコア番号
  • シーケンス番号
  • トレース採取時からの経過時間(秒)
  • I/Oしていたプロセスのpid
  • コマンド状況を表すアルファベット(詳細はmanを参照のこと)
  • 処理を表すアルファベット(詳細はmanを参照のこと)
  • I/Oの先頭アドレス+オフセット
  • プロセス名
  8,32   0        1     0.000000000  9718  G   R 1839944 + 8 [fio]   
  8,32   0        2     0.000000383  9718  P   N [fio]               
  8,32   4        1     0.000000413  9717  G   R 1831472 + 8 [fio]   
  8,32   4        2     0.000000643  9717  P   N [fio]               
  8,32   0        3     0.000001059  9718  I   R 1839944 + 8 [fio]   
  8,32   0        4     0.000001355  9718  U   N [fio] 1             

CPUコア0だけ取り出したのが以下。 多重でI/Oかけていると、トレースが混迷を極めそうだ・・・

8,32   0        1     0.000000000  9718  G   R 1839944 + 8 [fio]
→ fioがI/Oの先頭アドレスを算出した
8,32   0        2     0.000000383  9718  P   N [fio]              
→ fioがカーネルに対してリードリクエストを発行するために
   コマンドをためておくキューに接続
8,32   0        3     0.000001059  9718  I   R 1839944 + 8 [fio]  
→ fioのリードリクエストがコマンドをためておくキューに、
  コマンドを追加
8,32   0        4     0.000001355  9718  U   N [fio] 1            
→ fioのリードリクエストがコマンドをためておくキューとの接続を解除
8,32   0        5     0.000001688  9718  D   R 1839944 + 8 [fio]
→ コマンド発行
8,32   0        6     0.000014064     3  C   R 1839944 + 8 [0]    
→ 応答が返ってきた

さいごに

以上、Disk I/Oの性能測定をするときに活躍する道具たちとその使い方でした。 使い方とか説明が間違っていたらごめんね!