レイテンシ最大のプロセスを特定するLatencyTOP
特定タスクの実行に生じるレイテンシの大きさは、システム上で実行中のその他のタスク、接続されたネットワークの回線状況、ネットワーク上の各種サーバが発揮可能なパフォーマンスなどの要因で左右される。こうした、各自のシステム上で実行するアプリケーションに何がレイテンシをもたらしているかを特定するために利用できるのが LatencyTOP というツールであり、これはコマンドライン操作ツールとカーネル用パッチのセットという構成になっている。
多少煩わしいことに、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オプションを付けて実行させると、ブロックIOに関するデバッグレベルメッセージがいくつか表示されるようになっている。
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、ファイルシステム、検索ソリューションを中心としたコンサルティング業に従事している。
