Eclipseをプロファイラとして活用する：Eclipse徹底活用（6）（1/2 ページ）

[的場聡弘, 岡本隆史，NTTデータ]

　Eclipseを用い、Javaアプリケーションの性能向上のためのプロファイル情報を取得することができます。今回は、EclipseとEclipse Profilerプラグインを用いて実際にJavaアプリケーションのプロファイル情報を取得し、ボトルネックを見つけ出す方法を説明します。また、その部分をチューニングし、性能が向上する様子を紹介しましょう。

Eclipseでプロファイラを実現する

　Javaアプリケーションを開発しリリースするに当たって、性能のチューニングは欠かすことができません。性能の悪いアプリケーションは、その利用者にとってはストレスの要因となります。また、Webアプリケーションのように複数のスレッドが並行して動作するようなケースでは、それぞれのスレッドのほんの少しの性能劣化が、システム全体の性能を指数関数的に下げる要因にもなります。性能劣化の要因の多くは、アプリケーションの作り方にあるといっても過言ではないでしょう。

　これらの問題を分析するツールとして、プロファイラというジャンルの商用製品が提供されています。しかし、これから紹介するEclipseとEclipse Profileプラグインの組み合わせを使えば、高価な商用製品を使わずとも、これらの分析を無料で行うことができるようになります。

　チューニング作業を進めるに当たっては、「80：20の法則」、すなわち、「プログラムの実行時間の80％はプログラムコードの20％が占める」という経験則がよく引き合いに出されます。

　この記事で述べる「プロファイリング」とは、その20％を特定すること、つまり、システム全体の実行時間の中で、多くのCPU時間を占めている部分を特定する、という作業のことをいいます。その部分に注力し、さまざまなテクニックを駆使して性能を向上させることで、システム全体の性能を効果的に向上させることができます。ボトルネックをうまく見つけ出して修正することができれば、アプリケーションの性能を劇的に向上させることができるかもしれません。

　なお本稿では、以下のソフトウェア環境で動作確認を行っています。これ以外の組み合わせでは動作に支障が出ることがありますので、お手元のバージョンをご確認ください。

ソフトウェア	バージョン
OS	Windows XP
JDK	1.4.2
Eclipse	2.1.1
国際化プラグイン	2.1.x Translations
Profilerプラグイン	0.5.28
Lombozプラグイン	2.1_02
Apache Tomcat	4.1.24

Eclipse profilerプラグインとは

　Eclipse profilerプラグイン（eclipsecolorerプロジェクト）とは、Eclipse上でプロファイリングを行うためのプラグインです。同様の機能を持つプラグインとして、jMechanic（http://jmechanic.sourceforge.net/）やExtensible Java Profiler（http://ejp.sourceforge.net/）などもあります。

　『Java Platform Performance』（注）によれば、プロファイリングとは、以下を明らかにする作業です。

1. 呼び出される回数の多いメソッドはどれか
2. 処理に時間がかかっているメソッドはどれか
3. どのメソッドがそのメソッドを呼んでいるのか
4. どのメソッドがメモリをたくさん使っているか

　プロファイラを使うと、これらを容易に特定できます。Eclipse profilerは、Eclipseという統合開発環境の上で作業を行えるため、特定したメソッドをその場で修正でき、その後続けてプロファイルの取得を行えるので、いま行った改善がどれくらい効果があったかをすぐに知ることができます。

　なお、発見したボトルネックをどのように改善すればよいかについては、とてもこの記事に書ききれませんので、後述する参考文献をご覧ください。

注：日本語訳が、ピアソン・エデュケーションより『Javaプラットフォームパフォーマンス』」として出版されています。

■プラグインの入手／インストール／設定

　Eclipse colorerプロジェクトのページからプラグインを入手します。「Downloads」というリンクをクリックして、プラグインのzipファイルを入手しましょう。執筆時の最新版は0.5.28です。ru.nlmk.eclipse.plugins.profiler_0.5.28.zipという名前のファイルを入手してください。

　入手したら展開し、展開されたフォルダをEclipseのpluginsフォルダに格納します。また、Windowsの場合は、そのフォルダに含まれているProfilerDLL.dllというファイルを、使用しているJREのbinフォルダにコピーしておきます。Linuxの場合は、nativeフォルダにあるファイルを展開するとlibProfilerDLL.soというファイルが現れますので、これを実行パスの通ったフォルダに置いておきます。その後、Eclipseを再起動することで導入は完了です。

Javaアプリケーションをプロファイリングする

　早速、Eclipseを使って、ボトルネックを特定する様子を見ていきましょう。ここではプロファイリングするターゲットとして、ZipCode.javaという簡単なプログラムを用います。日本郵政公社が提供している郵便番号データ（CSV）を基に、引数で指定された郵便番号から住所を検索する、という処理を実装したものです。このクラスを試験するため、JUnitのテストケース（ZipCodeTest.java）を記述してあります。

　テストケースのZipCodeTest#main(String[])をJavaアプリケーションとみなし、[実行]→[次を実行]→[Profiler]を用いて起動してみましょう（画面1）。

画面1　プロファイリングの取得を開始する

　するとプロファイリングが有効な状態で起動し、Profilerパースペクティブに切り替わります。右上にThread、Instances、Heapビューが。右下にPackages、Classes、Methods、Thread methods、Thread call tree、Inverted thread call tree、Thread call graph、Sitesビューが用意され、プロファイルデータをいろいろな角度から見ることができます。

画面2　Packages、Classes、Methodsビュー（配置は変更してあります）

　Packages、Classes、Methodsビューは、いま実行しているプロセスのプロファイル情報を、それぞれの単位で集計して表示したものです。どれも同じ情報を表示しているのですが、表のカラムヘッダをクリックするとソートできますので、ボトルネックとなっている対象をそれぞれの単位で抽出することができるわけです。「Calls」がメソッドの実行回数、「Total Time」が、そのメソッドの開始から終了までの実行時間の合計（別のメソッドを呼び出して実行している時間を含む）、「Time」がそのメソッドの正味の実行時間の合計（別メソッドの実行時間を除いたもの）を表しています。

　画面2では、ZipCodeクラスの<init>メソッド（コンストラクタ）が19万3147回呼び出され、実行時間の合計は 3823[msec]、プロセス全体の53.54％を消費していることが分かります。1回の実行にかかっている時間は0.02[msec]とわずかですが、このメソッドをチューニングして 0.01[msec]だけを削減したとしても、全体の実行時間の26％にあたる2.1秒程度を削減できることになります。

画面3　thread Call tree、Inverted thread call tree、thread call graphビュー

　Threadsビューでスレッドをどれか選択すると、特定のスレッドに注目して分析できます。例えばmainスレッドを選択してみましょう。「Thread call tree」ビューは、「このメソッドはどのメソッドを呼び出したか」を示しています。先ほどの分析では ZipCodeのコンストラクタは全体の53.54%を占めていましたが、その中の32.96%についてはtest9071801()を呼び出した延長である、ということが分かります。「Inverted thread call tree」ビューは、逆に「このメソッドはどのメソッドから呼び出されたか」を示しています。ZipCodeのコンストラクタが実行された時間を100%としたとき、そのうちの63.41%はtest9071801()からの呼び出しである、ということが分かります。

　これらをグラフィカルに表示したものが、「Thread call graph」ビューです。実行時間の多いものが、より赤い色で表示され、また呼び出し回数の多いパスが、より太い線で表示されています。このパスをダブルクリックすると、エディタ上でソースの該当行にマークが付きます（画面4）。

画面4　太いパスをダブルクリックすると、呼び出し回数が多い場所にマークが付く

　ああっ！この呼び出しは小さなwhileループの中です。しかも、作成したZipCodeインスタンスは、直後のif文で判定するのに使った後、すぐに放棄しています。コンストラクタのコードの一部をここに持ってくることで、<init>の無益な呼び出しを削れそうですね。

画面5　ソースを修正して実行した様子

　コードを修正（注）して再測定したところ、<init>の実行回数を19万3147回から3回に減らすことができました。その結果、searchByZip()の総実行時間は7501[msec]から3075[msec]へ、4.5秒も削減することができました。

注：例ではソースコード中に数値定数を埋め込んでありますが、説明の都合によるものです。品質を考慮すれば、とてもお勧めできるコードではありません。いや、そもそもこんなコードを書いていてはいけません。もっと効率的な設計や速いアルゴリズムは山ほどあります。