さくらインターネットのアドベントカレンダー9日目として、サーバ屋らしく、運用に関するコマンドの使い方を紹介します。
サーバの負荷が高まってきたときに、vmstatやtopなどのコマンドで調査する事が出来ますが、I/O負荷をwa(iowait)によって判断する人も多いと思います。
ただ、結論から言うと、iowaitは正確にI/Oの負荷を表しているわけではありません。
これらを、実際に演習をしながら見ていきたいと思います。
iowaitとidle
iowaitとはあくまでも、CPUが空いているのにI/Oがボトルネックになっているプロセスを示しているだけで、CPUの利用率が高いときにはI/Oがボトルネックになっていてもiowaitが上がりません。
同様に勘違いされがちなのが、id(idle)はCPUの空きを示しているというものですが、idleは必ずしもCPUの空き時間を示しているものではありません。
us(user)がユーザプロセスでのCPU使用率、sy(system)がカーネルでのCPU使用率であり、userとsystemを足したものがいわゆるCPU使用率を示しています。
そして、user + system + idle + iowait は必ず100になります（ここではstの説明は省きます）。
例えば、userもsystemも0の状態、つまりCPU利用率が0%のときに、I/Oに大きな負荷がかかってiowaitが100になると、idleは0になります。CPU使用率が0%なのにidleは0になるのです。
CPUの空きをidleで確認していた場合には、CPU使用率は0%なのに、CPUの空きがない、つまりCPUが食いつぶされていると読み取ってしまいます。
逆に言うと、I/Oに大きな負荷がかかっていたとしても、CPU使用率が100%の場合には、iowaitは0のままです。
I/O負荷をiowaitで確認していた場合には、負荷が発生しているのに0としか読み取ることができず、I/Oが空いていると勘違いしてしまいます。
# vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
2 0 1004 290756 47660 441328 0 0 2 1 41 32 0 0 100 0 0
I/O負荷を発生させてみる
それでは、実際にI/Oに対して負荷を発生して見たいと思います。
以下のコマンドを実行すれば、キャッシュ無しで500MBのファイルを作成します。
別のセッションでvmstatを実行すると、書き込み中の各数値の変化が読み取れます。
# dd if=/dev/zero of=test bs=1M count=512 oflag=direct
# vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 1004 283272 51228 442416 0 0 0 0 59 48 0 0 100 0 0
0 1 1004 281440 51232 442480 0 0 80 137216 438 419 0 5 13 82 0
0 1 1004 281440 51240 442516 0 0 4 153600 446 446 0 4 0 96 0
0 1 1004 281440 51256 442568 0 0 16 153600 480 458 0 6 0 94 0
0 0 1004 282404 51256 442772 0 0 232 79872 270 272 0 2 46 52 0
0 0 1004 282404 51256 442796 0 0 0 0 56 42 0 0 100 0 0
この場合、I/Oウェイトは、82->96->94->52 と変化し、数値が大きくなっているので、I/Oに負荷がかかっているんだろうなということが推測できます。
ちなみに、procsのbが1になっていることが分かりますが、これはI/Oが原因で待ち状態になっているプロセスが一個あるということを示しています。
実際にpsを実行すると、STATがDになっていることが分かります。
# ps aux
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 12572 4.0 0.1 108984 1668 pts/0 D+ 14:18 0:00 dd if=/dev/zero of=test bs=1M count=512 oflag=direct
CPU負荷を発生させてみる
次に、CPU負荷を発生させてみましょう。
無駄にforループするperlスクリプトを作ったので、これをダウンロードして実行してみてください。
いまどきPerlで申し訳ないですが・・・。
# curl -O https://tanaka.sakura.ad.jp/loadtest.pl
# chmod +x loadtest.pl
ソースを見れば分かりますが、引数に指定された数の子プロセスを生成して、延々とループするだけのスクリプトです。
例えば、第1引数に4と指定して実行すれば、4つプロセスがCPUを使い尽くします。
# ./loadtest.pl 4
# vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 1004 274652 51388 450624 0 0 0 0 46 40 0 0 100 0 0
4 0 1004 273580 51388 450640 0 0 0 4 909 107 87 1 12 0 0
4 0 1004 273580 51388 450640 0 0 0 0 1047 117 100 0 0 0 0
4 0 1004 273580 51388 450640 0 0 0 0 1015 110 100 0 0 0 0
0 0 1004 274388 51388 450640 0 0 0 0 788 123 75 0 25 0 0
0 0 1004 274404 51388 450640 0 0 0 80 52 45 0 0 100 0 0
この場合、cpuのusが100になり、ユーザプロセスによってCPUが使い尽くされていることが分かります。
ちなみに、procsのrが4になっていることが分かりますが、これはCPUが原因で待ち状態になっているプロセスが4個あるということを示しています。
実際にpsを実行すると、STATがRになっていることが分かります。
# ps aux
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 12592 0.0 0.2 129668 2028 pts/0 S+ 14:26 0:00 /usr/bin/perl ./loadtest.pl 4
root 12593 20.3 0.0 129668 400 pts/0 R+ 14:26 0:00 /usr/bin/perl ./loadtest.pl 4
root 12594 20.3 0.0 129668 400 pts/0 R+ 14:26 0:00 /usr/bin/perl ./loadtest.pl 4
root 12595 20.3 0.0 129668 400 pts/0 R+ 14:26 0:00 /usr/bin/perl ./loadtest.pl 4
root 12596 20.3 0.0 129668 400 pts/0 R+ 14:26 0:00 /usr/bin/perl ./loadtest.pl 4
I/OとCPUの両方に負荷を発生させてみる
では、CPUとI/Oの両方に負荷を発生させてみましょう。
まず、CPUに負荷を発生させます。
# ./loadtest.pl 4
# vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 1004 274764 51396 450636 0 0 0 0 44 43 0 0 100 0 0
4 0 1004 273568 51396 450656 0 0 0 0 595 90 55 0 45 0 0
4 0 1004 273568 51396 450656 0 0 0 0 1022 114 100 0 0 0 0
vmstatによると、cpuのusが100になっていて、ユーザプロセスによってCPUが使い尽くされていることが分かります。
では、CPUに負荷を発生させたまま、ddを実行してI/Oに負荷をかけてみましょう。
直感的には、I/O負荷が高まるとcpuのwa、つまりiowaitの数値が上がりそうなものですが、loadtest.plを実行したままなのでusが100になっているなかで、どうなるでしょうか？
# dd if=/dev/zero of=test bs=1M count=512 oflag=direct
# vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
4 0 1004 268672 51500 451064 0 0 0 0 1016 110 100 0 0 0 0
4 1 1004 268036 51500 451040 0 0 0 27648 1145 196 98 2 0 0 0
4 1 1004 267540 51508 451088 0 0 8 89088 1269 266 100 0 0 0 0
4 1 1004 267048 51512 451168 0 0 0 92160 1224 243 100 0 0 0 0
4 1 1004 269172 51520 451056 0 0 0 92264 1283 264 100 0 0 0 0
5 1 1004 269188 51520 451064 0 0 0 89088 1251 235 100 0 0 0 0
4 1 1004 269188 51524 451072 0 0 0 94208 1235 231 100 0 0 0 0
4 0 1004 270444 51524 451072 0 0 0 39936 1125 177 100 0 0 0 0
4 0 1004 270444 51524 451072 0 0 0 0 1033 114 100 0 0 0 0
結論としては、I/Oに負荷がかかっているのに、iowaitが上がらないというものでした。
では、どのようにして負荷をみればいいのかということですが、vmstatの場合には、ioのbiとboがそれぞれデバイスへの書き込みと読み込みを示しており、上記の出力では、90MB/sec前後で6秒ほど書き込みが発生していることがわかります。
iostatをつかう
vmstatでI/Oの状況を確認できましたが、より詳しく見るためにはiostatコマンドを利用しましょう。
細かな解説は省きますが、以下のように実行すれば1秒ごとにI/Oの状態を表示してくれます。
コマンドがインストールされていない場合には、CentOSの場合は yum install sysstat を実行すればインストールされます。
以下ケースでは、%utilで示されるI/Oの利用率が、23.27% -> 44.90%と上がって行っていることが分かります。
# iostat -x 1
Linux 3.10.0-693.2.2.el7.x86_64 (tanaka) 2017年12月05日 _x86_64_ (1 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
99.01 0.00 0.99 0.00 0.00 0.00
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
vda 0.00 0.00 0.00 151.49 0.00 51706.93 682.67 0.70 4.61 0.00 4.61 1.54 23.27
avg-cpu: %user %nice %system %iowait %steal %idle
100.00 0.00 0.00 0.00 0.00 0.00
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
vda 0.00 0.00 0.00 270.00 0.00 92160.00 682.67 1.35 4.99 0.00 4.99 1.66 44.90
ということで、簡単ではありましたが、vmstatとiowaitについての紹介でした。