低負荷なのにCPU使用率が100％？：事例に学ぶWebシステム開発のワンポイント（7）

本連載では、現場でのエンジニアの経験から得られた、アプリケーション・サーバをベースとしたWebシステム開発における注意点やヒントについて解説する。巷のドキュメントではなかなか得られない貴重なノウハウが散りばめられている。読者の問題解決や今後システムを開発する際の参考として大いに活用していただきたい。（編集局）

» 2002年12月11日 00時00分公開

[田中秀彦，（株）NTTデータ]

この記事は会員限定です。会員登録（無料）すると全てご覧いただけます。

今回のワンポイント

アプリケーション・サーバ上でアプリケーションを稼働中に、大きな負荷がかかっていないにもかかわらず、CPUの使用率が100％になってしまうときがある。こんなときに役立つのは、スレッドダンプだ。スレッドダンプは、実行中のスレッドスタックを取得できるため、そのとき何が起きているのかを解析するには最適である。スレッドダンプの結果、原因は、java.ioパッケージ内のクラスの使い方による問題であることが判明した。これは、一般にも多く作成されているであろうダウンロードやアップロード処理で見掛けるコードの一部でもある。今回は、トラブル発生時の原因究明に役立つスレッドダンプの解説と、問題の原因となったjava.ioパッケージの使い方が引き起こす、非常に特定しにくい事象について紹介する。

低負荷なのに、CPU使用率100％

　アプリケーションに大きな負荷をかけていないのに、突然CPU使用率が100％に達してしまうという事象が発生した。貴重なCPUリソースを使うということで大きな問題となりすぐに調査を開始した。

　高負荷な状態では、CPU使用率が慢性的に100％になることがある。低負荷な状態でも、処理が重ければ一時的にCPU使用率が100％となることがある。しかし今回は、ほとんど負荷をかけていない状態で突然CPU使用率が100％になり、それ以降100％の状態が継続するという特徴があった。CPU使用率には、ユーザーモードとシステムモード（カーネルモード）があるが、この場合ユーザーモードの使用率が100％であるという特徴もあった。

原因は無限ループ？

　一般に、ユーザーモードが100％という現象は無限ループ状態で起こる。例えば、以下のようなJSPのコードを作成し、実行してみれば分かる。JSPで記述しているが、JavaアプリケーションやCなどほかのプログラミング言語でも同様である。なお、CPU使用率の確認は、UNIX環境ではvmstatやsarコマンドで、Windows環境ではタスクマネージャやパフォーマンスモニタなどで調べられる。

<% 

                while (true) ; 

            %>

　今回の場合も事象から判断して無限ループを疑った。しかし、実際にはどのリクエストで無限ループが発生しているのか特定できず、ソースコードチェックを行うにも膨大な時間と労力を費やすことが考えられた。

そのとき何が起きていたのか？

　さて、こんなときに行うとよいのはJavaのスレッドダンプである。スレッドダンプは、動作中のスレッドスタックをスナップショットとして取得することができる。そのため、ある状態において内部（スレッド）で何が起きているのかを把握するには最適である。スレッドダンプの取得方法は、実行中のJava VMのプロセスに、特定のシグナル（SIGQUIT）を送ればよい。具体的には、以下のように行う（UNIX環境の例）。


# ps -ef \| grep java	JavaのプロセスIDを確認
# kill -3 <上記で得られたPID>	SIGQUITシグナルを送る

　実行すると標準出力にスレッドダンプの結果が表示される。ただし、WebLogic Serverなどのアプリケーション・サーバの場合、運用状態では標準出力を監視することは難しいため、アプリケーション・サーバを起動するシェルスクリプトで標準出力をリダイレクトしておくとよい（併せて標準エラー出力もリダイレクトするとよい）。これにより、いつでもスレッドダンプの結果をファイルから確認できる。

　以下は、WebLogic Serverの起動スクリプトの一部抜粋である。WebLogic以外でも同様に、javaコマンド発行時にリダイレクトすれば問題ない。この例ではstdout.outのファイルに結果が出力される。赤い囲みの部分がリダイレクトの記述だ。

　アプリケーション・サーバの場合、通常複数のスレッドが動作しているため、いくつかのスレッドのダンプが表示される。そのため、具体的にどのスレッドが問題となっているかは、それぞれのスレッドの状態を詳しく見ていけば特定することができる。

真相は闇の中？

　そこで、無限ループ状態になったところを見計らいスレッドダンプを取得してみた。その結果、問題となったのは、ダウンロード処理サーブレットのループ部分であることが特定できた。以下にそのサンプルコードを示す（スレッドダンプで取得できたのは以下のwhileループの部分である）。コード中の変数fileはダウンロードすべきファイル、変数lenは読み込み時のバッファサイズであり、このコードの前の処理で動的に決定されている。

 
            

            

            BufferedInputStream in = 

              new BufferedInputStream( new FileInputStream( file ) );

            byte[] buf = new byte[len]; 

            

            int i;

            while ( ( i = in.read( buf, 0, len ) ) != -1 ) {

              out.write( buf, 0, i) ;　//outはServletOutputStream

            }

                

                ・

                ・

                ・

　さて、上記のコードのどこに問題があるのだろうか？一見して何の変哲もないごく一般的なコードのように見える。実際に調査したときも、無限ループを疑う前に、そもそもファイル自体が大きすぎて処理が重くなるのでは？などを疑ってみた。しかし、その場合、I/O処理に伴うI/O待ちが発生するためユーザーモードのCPU使用率が100％ということにはならないはずである。さらに、いったんCPU使用率が100％になると、その後も継続するという傾向も、無限ループを生み出す何らかの問題がコードに潜んでいることを示唆していた。

InputStreamのreadメソッド

　結論からいうと、BufferedInputStreamのreadメソッドに渡している第3引数（len）が0の場合、whileループのところで無限ループしてしまうのである。それが今回の落とし穴である。

　ここで、BufferedInputStreamから使われる、FileInputStreamのreadメソッド（継承が行われているため実際にはInputStreamのreadメソッド）の実装をJavaのソースで確認してみよう。疑わしいときなどは、API仕様も含めJavaのソースを確認するような癖をつけるとよい。

　赤い囲みの中のコードに注目してほしい。readメソッドの引数であるlenが0の場合には、何も処理することなく0が返ってくる（JavaのAPI仕様にもその旨の記述がある）。しかし、呼び出し側のコードでは、返却値として0を想定していないため、無限ループとなってしまったのである。

　なお、readメソッドはI/O処理が行われるため期待されたサイズを読み出せないことがある。よって、読み出し不可能であることを示すreadメソッドの返り値-1をもって終了条件にすることはあるが、0まで終了条件にすることはあまりない。

　さて、問題の本質は、readメソッドに渡す読み出しサイズが、なぜ0になったかということである。これは読み出しサイズを動的に計算していることに起因しており、計算の関係上0になることがあったのである。このような事例はまれなのでは？と思われる方もいると思うが、ダウンロード処理やアップロード処理を作り込むシステムは意外に多く、実際このサンプルコードのように、バッファサイズ（読み込みや書き込みサイズ）を動的に計算する事例をいくつか見たことがある。また、無限ループに陥るケースとして、JavaのバグデータベースであるBug Paradeでも見掛けたこともあり、一度作成してしまうとなかなか発見しづらい問題の1つであることを物語っている。なぜこのような方式にするかというと、性能向上の効果を期待し、I/O回数を減らすため、バッファサイズをできるだけファイルサイズに近づけようとする努力があるからであろう。

バッファサイズは固定がよい

　上記のサンプルコードではFileInputStreamクラスのreadメソッドを例に取っているが、実はFileOutputStreamクラスのwriteメソッドにも同じことがいえる。さらに、Writer／Reader系クラスのread／writeメソッドも同様な実装であり注意が必要である。

　対策の1つは、バッファサイズが0にならないよう計算ロジックの見直しを行えばよい。しかし、実際に適用するのであれば、読み出しサイズを固定にすることを推奨する。性能的な観点では、I/Oサイズ（読み出しサイズや書き込みサイズ）にはそもそも限界がある。よって、I/O回数をできるだけ減らすようにと、バッファサイズをファイルサイズに近づけたからといって、効果も大きいとは限らない。

　また、もっと重要なことは、パフォーマンスへの影響である。通常、バッファオブジェクトは一時領域として毎回生成、消去するため、サイズが大きくなるとガベージ・コレクションへの影響が無視できない。このことからも、大きなサイズになり得る、動的なバッファサイズ決定はやめた方が無難である。併せて、バッファサイズを固定にする場合でも、小さな値の方がトータルとして良い結果を生み出す。