レイテンシ最大のプロセスを特定するLatencyTOP：Linux Hacks

システムを効率化するには、ボトルネックを改善するのが第一歩となる。各自のシステム上で実行するアプリケーションに何がレイテンシをもたらしているかを特定するLatencyTOPは、ボトルネックの改善に大きく寄与する。

[Ben Martin，SourceForge.JP Magazine]

　特定タスクの実行に生じるレイテンシの大きさは、システム上で実行中のそのほかのタスク、接続されたネットワークの回線状況、ネットワーク上の各種サーバが発揮可能なパフォーマンスなどの要因で左右される。各自のシステム上で実行するアプリケーションに何がレイテンシをもたらしているかを特定するために利用できるのがLatencyTOPというツールであり、コマンドライン操作ツールとカーネル用パッチのセットという構成になっている。

　多少煩わしいことに、LatencyTOPプロジェクトは発足して間もないこともあり、その利用に当たっては、各自のカーネルにパッチを当てなくてはならない状況に遭遇するかもしれない。いずれにせよアプリケーション本体およびカーネルパッチは、LatencyTOPのダウンロードページから入手できるようになっている。

　各自が使用中のディストリビューションにてカーネルの再コンパイルが必要であるかの判定は、後記の実行例のように、ビルドしたlatencytopコマンドを実行してみるのが一番簡単である。ただしLatencyTOPの実行にはroot権限が必要となる。なお2.6.25.10-86.fc9.i686以降のカーネルで動作するFedora 9システムの場合、カーネルのパッチ当てや再起動をすることなく、そのままの状態でLatencyTOPが実行できるので、yumを介してlatencytopパッケージをインストールするだけでいい。そのほか、Ubuntu Hardy用のLatencyTOPパッケージは用意されていないが、openSUSE 11についてはコミュニティーの有志の手により1-Click Install用のLatencyTOPファイルが幾つか作成されている。

$ tar xzvf /.../latencytop-0.4.tar.gz
$ cd ./latencytop*
$ make
$ ./latencytop
Please enable the CONFIG_LATENCYTOP configuration in your kernel.
Exiting...
# sudo ./latencytop
   LatencyTOP version 0.4       （C） 2008 Intel Corporation


Cause                                                Maximum     Percentage
opening cdrom device                                8.7 msec         33.5 %
Executing raw SCSI command                          7.6 msec         38.0 %
Waiting for event （poll）                            3.9 msec          5.0 %
SCSI cdrom ioctl                                    3.7 msec          5.7 %
Waiting for event （select）                          3.6 msec         17.1 %
Waiting for TTY to finish sending                   1.5 msec          0.5 %
Userspace lock contention                           0.2 msec          0.2 %
...

　パッチ処理が必要な場合は、後記に示したコマンド操作による新規カーネルのコンパイルとインストールおよび、システムの再起動をしなければならない。なおカーネルのビルドを行う前には、CONFIG_LATENCYTOP=yオプションを有効化しておく必要がある。すべてが問題なく進行した場合、更新後のカーネル下での再起動が終了すると、/proc/sys/kernel/latencytopファイルが作成されているはずだ。

$ tar xjf  /.../linux-2.6.26.2.tar.bz2
$ cd ./linux-2.6.26.2
$ cat /.../latencytop.patch | patch -p1
$ make menuconfig
$ make bzImage modules
...

　latencytopの基本的な使用法は、コマンドラインオプションを何も付けずに実行させることである。これによりLatencyTOPがcursesインタフェースで起動し、システム上でレイテンシ最大のプロセスにかんする情報が、画面上で定期的に更新される。-dオプションをつけて実行させると、LatencyTOPはその起動時にレイテンシが最大であったものを一覧して処理を終了する。同様に--blockオプションをつけて実行すると、ブロックI/Oにかんするデバッグレベルメッセージが幾つか表示される。

　cursesモードのLatencyTOPが受け付けるキー入力では、大文字と小文字は区別されない。例えばRキーを押すと、画面表示のリセット、全プロセスを対象としたレイテンシ情報の更新、レイテンシが最大であるプロセスの特定と詳細情報の表示が行われる。LatencyTOP画面の下端には、水平方向にプロセス名が一覧されているが、これらはシステムで動作中のプロセスの一部であり、ユーザーはこの中から関心のあるプロセスを任意に選択できる。そのためのキー操作は、X、B、Cのいずれかのキーを押すと、プロセスID（PID）が1つ繰り上がり、Z、A、Dのいずれかのキーを押すとPIDが1つ繰り下がるというものだ。キーボード入力イベントの判定コードがどのような仕様なのかは不明だが、PIDの繰り上げと繰り下げは上下左右の矢印キーでも行える。いずれにせよ画面上で反転表示されているものが、現在選択中のプロセスである。なおLatencyTOPの終了操作にはQキーが割り当てられている。

　LatencyTOPの操作法でわたしが感じた不満の1つは、特定プロセスのレイテンシ情報を追跡させたい場合に、ユーザーがRキーを押し続けないといけなくなることだ。例えばそうした目的で、レイテンシ情報をnミリ秒間隔にて自動更新させるというようなオプションが、どうしても見つからないのである。もっとも、システム上でレイテンシ最大のプロセス群の中から特定プロセスの動作状況を確認することが目的であれば、こうした不備は問題とならないかもしれない。その場合は、LatencyTOP上で目的のプロセスがピックアップされるまで、Rを何度か押せば済むはずだからだ。ところがわたしの場合、目的とするプロセスを矢印キーで選択したら、その後は当該プロセスのレイテンシ情報が定期的に更新される、という運用をしたいのである。

　後記の出力例は、ファイル名検索用のファイルシステムインデックスを作成するupdatedbコマンドについて出力されたレイテンシ情報である。このデータを取得したのは、updatedbによりXFSファイルシステムがスキャンされている途中であり、ここにはすべてのxfs_buf呼び出しのレイテンシ情報が一覧されている。なお末尾に表示されている行は、前述した矢印キーそのほかのキーボード操作で選択可能なPIDリストの抜粋である。

   LatencyTOP version 0.4       （C） 2008 Intel Corporation


Cause                                                Maximum     Percentage
xfs_buf_iowait xfs_buf_iostart xfs_buf_read_flags  76.3 msec         29.2 %
Walking directory tree                             56.8 msec          0.9 %
Reading directory content                          25.3 msec          1.0 %
Scheduler: waiting for cpu                         23.6 msec         24.6 %
xfs_buf_iowait xfs_buf_iostart xfs_buf_read_flags  20.7 msec         12.9 %
xfs_buf_lock _xfs_buf_find xfs_buf_get_flags xfs_b 19.1 msec          0.3 %
stat（） operation                                   18.1 msec          0.1 %
opening cdrom device                               10.1 msec          0.9 %
Executing raw SCSI command                          8.2 msec          0.9 %
...


Process updatedb （7799）                    Total: 1232.8 msec
Scheduler: waiting for cpu                         23.6 msec         94.2 %
Reading directory content                          15.8 msec          2.1 %
xfs_buf_iowait xfs_buf_iostart xfs_buf_read_flags  13.0 msec          3.2 %_do_buf xfs_da_read_buf xfs_da_node_lookup_int xfs
xfs_buf_iowait xfs_buf_iostart xfs_buf_read_flags   2.7 msec          0.6 %obp xfs_iread xfs_iget_core xfs_iget xfs_dir_looku
p_int xfs_lookup xfs_vn_lookup do_lookup


...


...  ssh  ...  updatedb ...  bash

　後記の出力例は、実行中のprelink -aプロセスにかんするものである。これを見ると、ここでのレイテンシ情報を取得した時点において、prelinkに関しては最適化を必要とするほどのレイテンシが生じていないことが分かる。この場合、レイテンシ最大のイベントはいずれもディスクIO関連のものとなっているが、そもそもprelinkで行われるメインの処理はIO呼び出しにかんする操作であり、そこでの処理完了を待機する関係上、これは想定内の結果としていいはずだ。なお、本稿を執筆する際に使用したシステムに関してのみ言うと、“waiting for cpu”と表示されたプロセスはいずれも10から40ミリ秒（msec）の範囲に収まっていたが、この範囲内での分布についてはかなりランダムに分散した状況となっていた。

Process prelink （7965）                     Total: 288.0 msec
...
Scheduler: waiting for cpu                         42.2 msec         30.0 %
Writing a page to disk                             18.2 msec         52.6 %
Walking directory tree                             17.9 msec         10.4 %
Pagecache sync readahead                           12.1 msec          4.2 %
EXT3: Waiting for journal access                    5.2 msec          1.8 %
Reading from a pipe                                 2.9 msec          1.0 %

　アプリケーションがスムースに実行されない場合、システムないしネットワークのどの部分が原因なのかを特定する上で、レイテンシ発生時にどのカーネル関数が呼び出されているか特定することが有用なケースがおうおうにして存在する。特に最近は、X11リソース用のxrestopおよび有名なPowerTOPツールなど、“top”ライクなツールが多数公開されている。そうしたツール群の中におけるLatencyTOPの位置づけについては、個々のシステムにおける最大のレイテンシ発生源を簡単に特定するためのツールという評価ができるはずだ。

Ben Martinは10年以上にわたってファイルシステムに取り組んでおり、博士課程の修了後、現在はlibferris、ファイルシステム、検索ソリューションを中心としたコンサルティング業に従事している。

原文へのリンク