第6回　Eclipseがプロファイラに変身!

　Javaアプリケーションの性能向上を目指して、プロファイル情報を取得する、といった作業も、Eclipse上で行えます。この文書では、Eclipseと Profilerプラグインを用いてJavaアプリケーションのプロファイル情報を取得し、ボトルネックを見つけ出す方法を説明します。また、その部分をチューニングし、性能が向上する様子をなぞっていきます。

　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.27
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プロジェクトのページhttp://sourceforge.net/projects/eclipsecolorer/からプラグインを入手します。 「Downloads」というリンクをクリックして、プラグインのzipファイルを入手しましょう。執筆時の最新版は0.5.27です。ru.nlmk.eclipse.plugins.profiler_0.5.27.zip という名前のファイルを入手してください 。

　入手したら展開し、含まれる ru.nlmk....という名前の3つのフォルダを 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>メソッド（コンストラクタ）が193,147回呼び出され、実行時間の合計は 3,823[msec]、プロセス全体の53.54%を消費していることがわかります。1回の実行にかかっている時間は0.02[msec]とわずかですが、このメソッドをチューニングして 0.01[msec]だけを削減したとしても、全体の実行時間の26%にあたる2.1秒程度を削減できることになります。

画面3　thread 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>の実行回数を193,147回から3回に減らすことができました。その結果、searchByZip()の総実行時間は 7,501[msec]から 3,075[msec]へ、4.5秒も削減することができました。

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

Tomcat上のWebアプリケーションをプロファイリングする

　Eclipse profilerプラグインでは、別のプロセスに接続してプロファイル情報を取得することが可能になっています。この方法を用いて、TomcatやJBossのようなWebアプリケーションのプロファイルを取得することが可能となります。

■ターゲットプロセスを用意する

　まず、ターゲットとなるtomcatプロセスを用意します。前回までの記事でLombozプラグインを使っていますので、ここではそれを利用し、Lombozプラグインによる起動構成を複製して、プロファイリングのリモートターゲットとなる起動構成を作成していきましょう。

　Lombozプラグインを使って、ターゲットプロジェクトを以下のように作りました。

画面6　ターゲットとなるJ2EEプロジェクト

　ここでいったん Lomboz を用いてTomcatサーバを起動すると、起動構成に 「プロジェクト名 - ApacheTomcatv410」といったエントリが追加されます。起動したサーバは今は使わないので終了しておきます。

画面7　Lombozでいったん起動する

　メニューから[実行(R)]→[実行(N)...]を選択して起動構成ダイアログを表示させ、いま追加された起動構成エントリを右クリックし、[重複]を選んで複製を作り、適切な名前を設定します。新たに作成されたエントリの[引数]タブの[VM 引き数]に、以下の文字列を追加します。

　

-XrunProfilerDLL:1 -D__PROFILER_USE_PACKAGE_FILTER=1 -D__PROFILER_TIMING_METHOD=1 -D__PROFILER_PACKAGE_FILTER=__M__sun.;__M__com.sun.;__M__java.; __M__javax.;__M__org.apache.

　また、プロファイラが利用する以下の4つのjarファイルを、tomcatのbinディレクトリ（C:\tomcat\bin など）にコピーしておきます（注）。

• ru.nlmk.eclipse.plugins.profiler.ui\profiler_trace.jar
• ru.nlmk.eclipse.plugins.profiler.io\profiler_io.jar
• ru.nlmk.eclipse.plugins.profiler.io\jakarta-regexp.jar
• ru.nlmk.eclipse.plugins.profiler.io\commons-lang.jar

注：起動構成の「クラスパス」-「ブートストラップクラス」に追加する方法はなぜかうまくいきません……。

　設定後は以下のようになります。

画面8　プロファイル取得用の起動構成

　ここまで設定したら、[実行]をクリックしてプロセスを起動しておきましょう（注）。次からの手順で、ここで起動したプロセスに接続してプロファイル情報を収集します。

注：リモートターゲットプロセスは、ポート6743を使用します。このポートを使っている別のプロセスが存在する場合には、うまく起動できませんので、そのプロセスを終了しておく必要があります。

コラム：ターゲットとなるtomcatプロセスをコマンドラインから起動したい場合
catalina.batの set JPDA=の次の行に、set JAVA_OPTS=に続けて上記のVM引き数（追加部分）を指定することで、プロファイリングのリモートターゲットとして起動することができるようになります。このとき、libProfilerDLL.dllファイル(または libProfileDLL.so ) を tomcatを実行しているJREのbinフォルダにコピーしておく必要があります。プラグインのマニュアルに具体的な方法が紹介してありますので、必要に応じて参照してください。

■リモートターゲットに接続する

　次に、いま作成したリモートターゲットに接続するための、リモートプロファイラの起動構成を作成します。

　まず、メニューの[実行]→[実行...]を選び、起動構成ダイアログを表示します。左ペインの[Remote Profiler]を選択し、その下の「新規」をクリックします。この起動構成には、[Profiler client]とでも名前をつけておきましょう。プロジェクト欄に、ターゲットプロセスが属しているプロジェクトを指定し、Host欄には tomcatプロセスが動作しているホストを指定します。同じマシンの場合は、「127.0.0.1」を指定しておけばよいでしょう。

　そして、この構成で[実行]をクリックすれば、前節「ターゲットプロセスを起動する」で起動したリモートターゲットプロセスに接続してプロファイル情報を取得することができます。

画面9　リモートプロセスに接続するための起動構成

■プロファイル情報を取得している様子

　前節「リモートターゲットに接続する」およびその前の節「ターゲットプロセスを起動する」で、それぞれプロファイラ（クライアント）とターゲット（tomcat）を起動しています。ここで、Profilerパースペクティブに切り替えてみましょう。 左上の「デバッグ」ビューに、それぞれのプロセスが表示されているのがわかります。プロファイラプロセスをクリックすると、ターゲットプロセスのプロファイル情報が表示されます。
ブラウザから、 http://localhost:8080/zip/search.jsp というURLでアクセスし、検索したい郵便番号を入力して「Search!」をクリックすると、サーバ側処理が実行され、「郵便番号 [9071801] の 住所は 沖縄県 八重山郡与那国町 与那国 です。」のように結果が表示されます。

　このとき、待機していたスレッドが動きだしたことが記録され、「threads」ビューに「Thread-5」のような行が追加されています。この行をクリックしてスレッドの様子を見ると、jspから呼び出している「searchByZip」メソッドがどのように実行されたかを観察することができます（画面10）。

画面10　リモート接続でプロファイルを取得している様子

■フィルタを設定しよう

　前節ではJSPから呼び出しているクラスをプロファイリングすることはできたのですが、JSP自体のプロファイリングは行えていません。これは、さきの設定ではJSPをプロファイリングの対象としていないことが理由です。

　-D__PROFILER_PACKAGE_FILTER=で、__M__という接頭辞をつけたパッケージを並べた場合、そのパッケージを除外してプロファイリングします。また、__P__という接頭辞をつけたパッケージを含めると、そのパッケージをプロファイリング対象とします（注）。

　ターゲットであるtomcatの起動構成の、「VM引き数」を以下のように修正することで、JSPをコンパイルした結果のクラスもプロファイル対象に含めることができます。

-D__PROFILER_PACKAGE_FILTER=__M__sun.;__M__com.sun.;__M__java.; __M__javax.;__M__org.apache.

　

-D__PROFILER_PACKAGE_FILTER=__M__sun.;__M__com.sun.;__M__java.;__M__javax.; __P__org.apache.jsp.;__M__org.apache.;__P__jp.co.atmarkit.

画面11　__P__フィルタを使って org.apache.jspパッケージも対象に入れてみた

注： __P__ をひとつも指定していない場合は __M__にマッチしないクラスはすべてプロファイリング対象となりますが、__P__がひとつ以上ある場合は、前から順に検査していって、いずれかの__P__にマッチしたものだけがプロファイリングの対象となります。

コラム: JSPがコンパイルされたら、どのパッケージになる?

tomcatを用いている場合は、JSPがコンパイルされた結果、org.apache.jspというパッケージに含まれるクラスとなります。 webLogicの場合は ディフォルトでは jsp_servlet です（weblogic.xml で packagePrefix を再定義できます →資料)。JRun4では、無名パッケージになります。WebSphere はtomcatと同様にorg.apache.jspというパッケージになります。

まとめ

　 Eclipseとプラグインを用いた環境でプロファイリングを行う様子を駆け足でご紹介してきました。商用製品を用いることで、よりきめ細かいプロファイリングを行うことができますが、ある程度のところまではEclipseでも十分なプロファイリングが可能であるといえるでしょう。

　プロファイリング、およびその先にあるパフォーマンスチューニングは、とても奥の深い世界です。説明の都合上、小さなサンプルを用いて説明してきましたが、本来、パフォーマンスチューニングという作業は、ソースの一部分だけを修正するだけでは十分ではないことが多く、場合によってはアーキテクチャを変更する必要が生じることもあります。プロファイリングやチューニングの経験を積み、優れた設計と実装を行うことで、期待される性能を実現できるようになるはずです。

■関連資料

• Java Performance Tuning 邦訳
• J2EE パフォーマンスチューニング徹底解説 (Amazonで買う)
• Javaプラットフォームパフォーマンス [邦訳] (Amazonで買う)
• パフォーマンスに関するHints&Tips集 第1版 (EJBコンポーネントに関するコンソーシアム)
• hp-ux Javaパフォーマンスチューニング
• hp-ux performance tuning Java™ (techniques, tools, and tips)
• @IT連載「[連載] 事例に学ぶWebシステム開発のワンポイント」や「[連載] J2EEパフォーマンスチューニング」

■ボトルネック解析のためのそのほかのツール

ボトルネックを解析できる商用製品として、JProbe™やOptimizeIt®といったものがある。 ボトルネック解析、 メモリリークの抽出、 デッドロック/レースコンディションの抽出、 テストカバレッジの確認 といった作業を容易に行うことができるようになっている。

無料で利用できるツールでは以下など。

• Extensible Java Profiler http://ejp.sourceforge.net/
• PerfAnal (-Xrunhprofを使います)
• HP JMeter & JTune
• jmp - Java Memory Profiler
• jrat - the Java Runtime Analysis Toolkit

＠ITメールマガジン　新着情報やスタッフのコラムがメールで届きます（無料）