IO Accounting 機能で I/O 負荷の高いプロセスを特定

来源：互联网发布：fanuc数控系统编程编辑：程序博客网时间：2024/06/16 07:27

原文地址

随分久々の Linux ネタです。以前にロードアベレージに関する考察などの記事も書きましたが、多くのサーバーサイドエンジニアはサーバ負荷と日々戦っていることかと思います。過去多くの場合、負荷の原因特定はおおよそ下記のような手順で分析をしていたことかと思います。※詳しい手順は別エントリとして記載予定。

top をみて上位に張り付いているプロセスを確認しつつ CPU or I/O のどちらが原因か判別
ps を使ってプロセスの状態を確認して(T),(D)の状態から CPU or I/O のどちらが原因か判別
vmstat で procs の r, b の数、swap の si, so の状態、I/O の bi, bo の状態を確認
iostat を使って disk の read/write の状態をさらに詳しく確認
sar を使って os の状態をさらに詳しく確認
おおよその原因特定から設定を見直したりチューニング作業を実施

過去の経験上では CPU 負荷の場合は原因特定に至り、プログラムの実装見直しなどで対処可能な場合が多いのですが、ディスク I/O が原因の時には明確な原因特定に至らず手探りでチューニングするパターンが多いように思います。

そんなもやもや感を一気に解消してくれるのが kernel 2.16.20 以降で実装された IO Accounting 機能です。プロセス毎の I/O に関する統計情報が /proc/[pid]/io に出力されるようになっています。その情報を分析していけば、どのプロセスで原因で iowait を発生させているかを判別することが可能となります。

例としとうちの自宅サーバの top で上に張り付いているプロセスの IO 統計情報を見てみましょう。

top - 17:51:14 up 41 days, 10:54,  1 user,  load average: 0.63, 0.56, 0.42Tasks: 234 total,   2 running, 231 sleeping,   0 stopped,   1 zombieCpu(s): 16.9%us,  2.0%sy,  0.0%ni, 80.6%id,  0.0%wa,  0.2%hi,  0.3%si,  0.0%stMem:   4048980k total,  3965488k used,    83492k free,    53504k buffersSwap:  8388600k total,    45528k used,  8343072k free,  2275580k cached  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                     26664 drk       20   0  179m  87m 4412 S 31.7  2.2 709:24.43 gungho                                                                      18370 apache    20   0  146m  16m 2588 S  2.0  0.4   1:51.41 AmazonSimilarit                                                             18338 apache    20   0 51580 6876  912 S  1.3  0.2   1:22.47 lighttpd                                                                    20943 apache    20   0  163m  23m 2940 S  1.0  0.6   0:34.28 xml2json.fcgi                                                                2904 root      20   0  308m  67m  64m S  0.7  1.7 357:45.97 ttserver                                                                    24808 apache    20   0 14880 1252  872 R  0.7  0.0   0:00.09 top                                                                             1 root      20   0  4032  724  584 S  0.0  0.0   0:02.66 init                                                                            2 root      15  -5     0    0    0 S  0.0  0.0   0:00.00 kthreadd

crawler の gungho が CPU 消費で張り付いているのがわかります。まあ例としては不適切ですが、とりあえず IO Accounting 情報をみてみましょう。

[user01@srv01 2904]$ cat /proc/26664/iorchar: 5003188894wchar: 67923618syscr: 3404355syscw: 224322read_bytes: 3633152write_bytes: 144248832cancelled_write_bytes: 59867136

それぞれのパラメータの意味は以下の通りです。

rchar, wchar はシステムコール read, write の実行 byte 数
syscr, syscw はシステムコール read, write の実行回数
read_bytes はプロセスにより HDD 等のブロックデバイスからファイルキャッシュへのデータロードの byte 数
write_bytes はプロセスによりファイルキャッシュのデータの dirty フラグが立った byte 数
cancelled_write_bytes は write_bytes のうちブロックデバイスに write される前に、別のデータによってデータが書き換えられ、実際には write されなかった byte 数

これらの値が総じて高ければ I/O に負荷をかけているプロセスだと言えるでしょう。もっともある１つのプロセスを見ただけでは比較ができないので判別は難しいので、Tokyo Tyrant のプロセスの情報をみてみましょう。基本的にストレージにひたすらアクセスをしているプロセスなので、総じて値が高いと推測できます。

[user01@srv01 2904]$ cat /proc/2904/iorchar: 237416348388wchar: 76469372829syscr: 97349737syscw: 84108222read_bytes: 179451441152write_bytes: 101826129920cancelled_write_bytes: 0

結果は、先ほどとは比較にならないほどの IO 値が出力されました。
しかしながら iowait を発生させているかと言えば違います。値と負荷については、そのシステムの今の状態によりけりなので、総合的に意味を把握する必要があるのに変わりはありません。
ちなみに TokyoTyrant は HDD を使いつつも memcached に近いパフォーマンスを出すことで有名で、くわえて自宅サーバ環境ではストレージに SSD を用いているので IO で待たされることは全く経験しておりません。

さて本題に入ってきました。

IO Accounting の値を分析すれば負荷の原因特定に近づくことができるのですが、自前で /proc/[pid]/io を分析するには骨が折れます。そんなわけでツールを使います。それぞれデフォルトでは入っていない場合もありますので、入っていない場合はインストールから。

yum install sysstat yum install dstat

pidstat -d を実行すると、実行時の各プロセスの IO 統計情報を出力することができます。

[user01@srv01 2904]$ pidstat -dLinux 2.6.27.21-170.2.56.fc10.x86_64 (srv01)    2011年07月02日20時33分38秒       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command20時33分38秒         1     80.86     10.75      0.04  init20時33分38秒       255      0.00      0.01      0.00  kswapd020時33分38秒       331      0.00      0.00      0.00  lighttpd・・・・20時33分38秒      2951      0.00      0.34      0.00  perl20時33分38秒      2965    121.89      3.32      0.00  ttserver20時33分38秒      2986     26.85     21.88      0.64  crond20時33分38秒      3018      0.00      0.00      0.00  atd・・・・

dstat は更に便利です。dstat -M topbio -al を実行すると IO 統計情報で最も負荷をかけているプロセスを cpu, system などの情報を付加させて、だら見することが可能となります。

[user01@srv01 2904]$ dstat -M topbio -al----most-expensive---- ----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system-- ---load-avg---  block i/o process   |usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw | 1m   5m  15m ttserver    122k:3408B|  8   2  89   0   0   1| 281k  104k|   0     0 |  45B   58B|1285   921 | 0.9  0.8  0.6ttserver    364k:   0 | 11   2  86   0   0   0| 524k    0 |  34k  103k|   0     0 |1587  1022 | 0.9  0.8  0.6cronolog      0 :4096B|  4   1  93   0   0   0|   0   200k|  92k  108k|   0     0 |1156   761 | 0.8  0.8  0.6ttserver     20k:  56k| 11   2  87   0   0   0|  24k    0 |  55k  139k|   0     0 |1557  1008 | 0.8  0.8  0.6ttserver   8192B:  56k|  6   1  92   0   0   0|8192B    0 | 204k  142k|   0     0 |1500   917 | 0.8  0.8  0.6ttserver     12k:  16k|  8   3  89   0   1   1|  16k    0 | 256k  149k|   0     0 |1633   996 | 0.8  0.8  0.6ttserver     44k:4096B|  6   1  92   0   0   1|  44k    0 | 135k  148k|   0     0 |1443   963 | 0.8  0.8  0.6ttserver     12k:  16k|  9   2  88   0   1   1|  16k  328k| 222k   68k|   0     0 |1569   861 | 0.8  0.8  0.6ttserver    888k:  44k| 23   3  72   2   0   1|1844k    0 | 257k  181k|   0     0 |2691  1500 | 0.8  0.8  0.6ttserver     64k:4096B|  5   2  92   0   1   1|  64k    0 | 160k  134k|   0     0 |1432   887 | 0.8  0.8  0.6ttserver     40k:   0 |  5   2  92   0   0   1|  52k 4096B| 146k  131k|   0     0 |1423   859 | 0.8  0.8  0.6ttserver     36k:   0 |  7   3  89   0   0   0|  40k    0 | 214k  132k|   0     0 |1674  1061 | 0.8  0.8  0.6ttserver    108k:4096B|  4   1  91   3   0   0| 108k  440k|  75k  143k|   0     0 |1375   885 | 0.8  0.8  0.6AmazonSimil1088k:   0 | 11   2  86   1   0   1|1140k    0 | 178k  157k|   0     0 |1829  1138 | 0.8  0.8  0.6AmazonSimil 576k:   0 | 13   2  83   2   0   0|1392k    0 |  68k  107k|   0     0 |1676   989 | 0.8  0.8  0.6AmazonSimil 472k:   0 | 22   4  73   0   0   1|1056k    0 | 287k  155k|   0     0 |2471  1248 | 0.8  0.8  0.6ttserver     60k:   0 |  5   2  92   0   0   0|  60k    0 | 193k  176k|   0     0 |1817  1088 | 0.8  0.8  0.6

さて結論です。top などで IO 関連が原因でロードアベレージが高いと感じたら dstat を使いましょう。きっと今まで以上に原因の特定に近づくことができることでしょう。

dstat -M topbio -al

あとは経験と勘で・・・ｗ