アプリケーションのパフォーマンス・チューニングなどで使用するツールといえば,まず第一にあげられるのがプロファイラです。最近は,EclipseのTPTPや,NetBeans Profilerなどフリーで使えるプロファイラが増えてきたので,使ってみたことがある方も増えてきていると思います。
意外に知られていないのですが,Java SEにも標準でプロファイラが付属しています。それがhprofです。
Java 2 SE 5.0からは「-agentlib:hprof」という起動オプションでhprofを起動できます(J2SE 1.4.までは「-Xrunhprof」)。使い方はヘルプ・オプションで表示できます。
C:\temp>java -agentlib:hprof=help HPROF: Heap and CPU Profiling Agent (JVMTI Demonstration Code) hprof usage: java -agentlib:hprof=[help]|[<option>=<value>, ...] Option Name and Value Description Default --------------------- ----------- ------- heap=dump|sites|all heap profiling all cpu=samples|times|old CPU usage off monitor=y|n monitor contention n format=a|b text(txt) or binary output a file=<file> write data to file java.hprof[{.txt}] net=<host>:<port> send data over a socket off depth=<size> stack trace depth 4 interval=<ms> sample interval in ms 10 cutoff=<value> output cutoff point 0.0001 lineno=y|n line number in traces? y thread=y|n thread in traces? n doe=y|n dump on exit? y msa=y|n Solaris micro state accounting n force=y|n force output to <file> y verbose=y|n print messages about dumps y Obsolete Options ---------------- gc_okay=y|n Examples -------- - Get sample cpu information every 20 millisec, with a stack depth of 3: java -agentlib:hprof=cpu=samples,interval=20,depth=3 classname - Get heap usage information based on the allocation sites: java -agentlib:hprof=heap=sites classname Notes ----- - The option format=b cannot be used with monitor=y. - The option format=b cannot be used with cpu=old|times. - Use of the -Xrunhprof interface can still be used, e.g. java -Xrunhprof:[help]|[<option>=<value>, ...] will behave exactly the same as: java -agentlib:hprof=[help]|[<option>=<value>, ...] Warnings -------- - This is demonstration code for the JVMTI interface and use of BCI, it is not an official product or formal part of the JDK. - The -Xrunhprof interface will be removed in a future release. - The option format=b is considered experimental, this format may change in a future release.
それでは,JDKに付属しているサンプルのJava2Demoを題材にプロファイルをしてみましょう。
Java2Demoを実行して,適当なところで終了させてください。すると,「Dumping Java heap ...」というメッセージが表示されて,プロファイル結果が出力されます。
C:\temp>java -agentlib:hprof -jar Java2Demo.jar Dumping Java heap ... allocation sites ... done. C:\temp>
デフォルトではプロファイル結果はjava.hprof.txtというファイルに出力されます(fileオプションを使えば,任意のファイル名を指定できます)。このファイルをエディタなどで開いてみてください。
java.hprof.txtに出力されるのはデフォルトではヒープの情報だけです。実行時間の出力を行うには「cpu=samples」などのオプションを指定します。
ヒープの情報はトレース(オブジェクトが生成された時のスタック・トレース),ダンプ,サイツ(アロケートされたオブジェクトの個数でソートされた表)の順番で出力されます。
例として,Java2Demoのプロファイル出力を見てみましょう。まずは意味がわかりやすいサイツから。
サイツはプロファイル出力の最下部に記述されています。
SITES BEGIN (ordered by live bytes) Sun Oct 22 09:40:44 2006 percent live alloc'ed stack class rank self accum bytes objs bytes objs trace name 1 16.40% 16.40% 1307872 31 2341888 41 306111 int[] 2 7.65% 24.06% 610288 1 610288 1 309184 int[] 3 6.78% 30.84% 540880 4 540880 4 305413 int[] 4 5.74% 36.58% 458000 6846 458000 6846 300000 char[] 5 3.89% 40.48% 310528 27 310528 27 305378 byte[] 6 2.05% 42.53% 163544 6799 163544 6799 300000 java.lang.String ~以下略~
サイツはアロケーションされた個所ごとにオブジェクトの個数をカウントしています。このため,rankの1番目から3番目にint[ ]が並んでいるように,同じオブジェクトでもサイツにリストアップされることがあります。
rankが1のint[ ]は現在使用されているサイズが1307872バイト,個数が31個です。トータルだとサイズが2341888バイト,個数が41個です。
このint[ ]はどこでアロケーションされているのでしょう。これを調べるには,stack traceの下に記述されている数字を使用します。int[ ]の場合は306111です。
アロケーションしている場所を示すのがトレースです。トレースにはすべて番号が付けられています。先ほどのint[ ]の306111というのがその番号に相当します。
TRACE 306111: java.awt.image.DataBufferInt.(DataBufferInt.java:41) java.awt.image.Raster.createPackedRaster(Raster.java:458) java.awt.image.DirectColorModel.createCompatibleWritableRaster(DirectColorModel.java:1015) java.awt.image.BufferedImage. (BufferedImage.java:312)
これを見ると,DataBufferIntオブジェクトの中でint[ ]がアロケーションされていることがわかります。DataBufferIntクラスはBufferedImageクラスでイメージを保持するために使用されるクラスです。つまりイメージが多く使われていることを示しているわけです。
オブジェクトのサイズなどを調べるのにはダンプを参照します。このときもトレースの番号が識別子になっています。
と,こうやって見ていけばいいのですが,如何せんファイルのサイズが大きすぎて扱いが大変です。ここで使用したJava2Demoでも,1分間程度の実行に対するプロファイル結果は14MBにも達してしまいました。
そこで,もう少しhprofを扱いやすくするために生まれたのが,JDK 6に添付されることになったjhatというツールです注。
プロファイル解析ツール jhat
jhatはもともとAdvanced Programming for the Java 2 Platformという本の中のサンプルとして作られました。そのときはHAT(Heap Analysis Tool)という名前でした。
その後,HATはjava.netで公開され,最終的にJDK 6に付属することになったのです。そして,他のツール同様に「j」が頭に付き,jhatという名前になりました。
それでは,さっそくjhatを使ってみましょう。
jhatを使うには,バイナリ形式のhprofの出力ファイルを使用します。デフォルトではテキスト形式になってしまうので,「format=b」を指定します。
C:\temp>java -agentlib:hprof=format=b -jar Java2Demo.jar Dumping Java heap ... allocation sites ... done. C:\temp>
「hprof=format=b」と記述するのはなんか変な感じですが,こういうものだと思ってください。デフォルトではhprofの出力ファイルはjava.hprofになります。jhatは,hrpofの出力ファイル名を引数にして起動します。
C:\temp>jhat java.hprof Reading from java.hprof... Dump file created Sun Oct 22 16:36:00 JST 2006 Snapshot read, resolving... Resolving 108592 objects... Chasing references, expect 21 dots..................... Eliminating duplicate references..................... Snapshot resolved. Started HTTP server on port 7000 Server is ready.
jhatはWebサーバーとして動作するので,Webブラウザで解析結果を見ることができます。デフォルトのポート番号は7000なので,「http://localhost:7000/」で参照します。ポート番号は-portオプションで変更できます。
図1 jhatの結果の閲覧 |
---|
「http://localhost:7000/」で閲覧できるのはクラスの一覧です。ただし,プラットフォームのクラスは含まれず,アプリケーションに含まれるクラスだけです。
クラスのリンクをたどると,クラスに関する情報を閲覧できます。この情報には参照関係も含まれており,閲覧しているクラスに至る参照,このクラスが参照しているクラスなどを確認できます。
トップページの最下部には,これら以外の情報に対するリンクがあります。例えば,「Show heap histogram」ではjava.hprof.txtのサイツのようなヒープ・ヒストグラムを見ることができます(図2)。ただし,サイツではアロケーションごとに分かれていたものが,ヒープ・ヒストグラムではまとめられています。
テーブルのカラム名をクリックすることで,ソートする項目を変更できます。デフォルトではトータル・サイズでソートされています。
同様にトップページ最下部にある「Show instance counts for all classes」から,インスタンスの一覧を見ることができます(図3)。
図3 インスタンスの一覧 |
---|
このinstanceのリンクをたどると,そのクラスのインスタンスの一覧を参照できます。例えば,Stringクラスのインスタンスを見てみましょう(図4)。このインスタンスのリンクでページを移動すると,そのインスタンスのフィールドの情報やスタック・トレースが表示されます(図5)。
図4 Stringインスタンスの一覧 |
---|
図5 Stringインスタンスの情報 |
このようにして,アプリケーションのプロファイル情報を参照できます。テキストだけなので,見にくい部分もありますが,それでもjava.hprof.txtを直接参照するよりは圧倒的に簡単です。
EclipseのTPTPやNetBeans Profilerを使ってもいいですが,全く準備なしで使用できるhprofとjhatの組み合わせも便利ですよ。
著者紹介 櫻庭祐一 横河電機 ネットワーク開発センタ所属。Java in the Box 主筆 今月の櫻庭 秋も深まりつつある今日この頃。櫻庭の住んでいる東京でもそろそろ紅葉の時期になってきました。 カエデ,ナナカマド,ツタ,サクラなど,それぞれの色で秋の景色を彩っています。櫻庭が好きなのはニシキギ。名前のとおり錦のように赤い葉っぱが特徴です。 家のそばを通っているイチョウ並木もだんだんと黄色くなり始めてきました。日当たりのいい場所ほど,黄葉がはやくはじまるようです。イチョウが黄色くなる頃といえば,ギンナン。おいしいですよね。 と,今月も最後は食べ物の話題になってしまうのでした。 |