じゃじゃ馬ならし

 

管理に使える便利なツール

はじめに

J2SE 5.0 には管理用やデバッグで使える jmap などのツールが付属していました。ところが、これらのツールは Windows では使えなかったのです。

それがやっと Java SE 6 で、Windows でも使えるようになったのです。そこで、あらためてここで紹介しましょう。取りあげるのは

の 3 つのツールです。

また、もう 1 つ便利なツールが加わりました。それが jhat です。これもいっしょに紹介します。

jinfo

jmap は Java VM の構成情報を参照、設定するためのツールです。

とりあえず試してみましょう。題材は OutOfMemoryError のハンドリングで使用した OutOfMemorySample です。

jinfo の引数は引数はターゲットとなる Java VM の PID です(リモートで動作している Java VM に接続することもできます)。

$ jps
2697 Jps
2683 OutOfMemorySample
$ jinfo 2683
Attaching to process ID 2683, please wait...
Debugger attached successfully.
Client compiler detected.
JVM version is 1.6.0-b105
Java System Properties:

java.runtime.name = Java(TM) SE Runtime Environment
sun.boot.library.path = /usr/java/jdk1.6.0/jre/lib/i386
java.vm.version = 1.6.0-b105
java.vm.vendor = Sun Microsystems Inc.
java.vendor.url = http://java.sun.com/
      <<省略>>
sun.cpu.endian = little
sun.desktop = gnome
sun.cpu.isalist =

VM Flags:

$

さて、jinfo の出力を見てみましょう。

はじめに Java VM にアタッチするというメッセージが出力されています。まぁ、これはどうでもよくて、次からが重要な部分です。

次の Java System Properties: は Java VM のシステムプロパティを表示しています。System#getProperties メソッドや System#getProperty メソッドで取得できるプロパティと同じものです。

そして、最後の行に VM Flags: という出力があります。ここには Java VM の起動オプションが出力されます。しかし、ここでは何も指定しなかったので、起動オプションは出力されていません。

jinfo をオプションナシで実行すると、このようにシステムプロパティと起動オプションが表示されます。別々に表示させたいときは、システムプロパティの場合 -sysprops オプション、起動オプションは -flags オプションを指定して jinfo を起動します。

ところで、これは Linux で実行したのですが、それにはわけがあります。なんと、Windows では起動オプションなしで jinfo を起動することがサポートされていないのです。

その他にも、-sysprops と -flags が使用できません。

jinfo が使えるようになったのはいいのですが、こんなところに制限があるとは... 次のバージョンアップで使えるようになるといいですね。

さて、Java VM の起動オプションが見られるようになったので、これを後から変更することを考えてみましょう。ただし、すべての起動オプションが変更できるわけではないようです。-XX ではじまる起動オプション、たとえば -XX:+PrintGC のようなものは後から設定できるようです。

設定を行なう場合は -flag の後に起動オプションをつづけて記述します。これは Windows でもできるのでやってみましょう。

C:\temp>jps
3760 Jps
4040 OutOfMemorySample
 
C:\temp>jinfo -flag PrintGC 4040
-XX:-PrintGC
 
C:\temp>jinfo -flag +PrintGC 4040
 
C:\temp>

PrintGC は -XX:+PrintGC で GC の情報を出力し、-XX:-PrintGC で出力しなくなります。

jinfo では単に -flag PrintGC と指定すると、現在の設定を表示します。もし、+ か - を指定したときは -XX: の部分を抜かして指定します。

上記のように実行すれば、GC の情報が出力されるはずです。

逆に GC の情報出力を止めたいときは、-flag -PrintGC で止まります。

これとおなじことは jconsole でもできるのですが、GUI が使えないときには jinfo が重宝します。

 

jmap

jmap はヒープダンプをおこなうためのツールです。

使い方は

C:\temp>jmap
Usage:
    jmap -dump: <pid>
      (to connect to running process and dump java heap)

    dump-options:
      format=b     binary default
      file=<file>  dump heap to <file>

    Example:       jmap -dump:format=b,file=heap.bin <pid>

 

今のところはフォーマットはバイナリしかないようなので、Example のようにするしかないのですが... ^^;;

使う場合は jps などで PID を調べてからつかうことになります。たとえば、前述の OutOfMemorySample クラスのヒープダンプを取ってみましょう。

C:\temp>jps
888 Jps
3176 OutOfMemorySample

C:\temp>jmap -dump:format=b,file=heap.map 3176
Dumping heap to C:\temp\heap.map
...
Heap dump file created
 
C:\temp>

 

ヒープダンプはバイナリなので、そのまま見るのは難しいので、ヒープダンプ解析用のツールを利用しましょう。

実をいうと、jmap は Solaris/Linux の JDK では Tiger でも使用できました。やっと、Mustang になって、Windows でも使えるようになりました。

ところが、Tiger の時の使い方とずいぶん違っているようです。今後、ビルドのバージョンがあがってくると、また変化する可能性があります。

なにはともあれ、Windows でも使えるようになったということで。

 

jstack

ヒープではなくて、スレッドダンプなので、おまけにしました。

JVM を実行しているときに、 Ctrl+Break でスレッドダンプすることはご存知の方が多いと思います。

でも、Ctrl+Break を押せない場合もありますよね。たとえば、PC や WS がサーバルームに隔離されているときなどは、物理的にキーボードがなかったりするので、Ctrl+Break を押すことができません。

そんなときには jstack を使いましょう。

Solaris/Linux の JDK には Tiger のときから jstack が添付されていたのですが、Windows にはありませんでした。

Mustang になって、やっとこのツールが使えるようになりました。

使い方は引数にターゲットとなる JVM の PID を指定するだけです。

C:\temp>jps
1204 OutOfMemorySample
2924 Jps
 
C:\temp>jstack 2924 > threaddump.txt
 
C:\temp>

 

リダイレクトをしておかないと、そのままコンソールにスレッドダンプが流れていってしまいます。ここではthreaddump.txt に出力しています。

threaddump.txt がどうなっているかというと...

2005-10-26 03:03:53
Full thread dump Java HotSpot(TM) Client VM (1.6.0-ea-b57 mixed mode, sharing):
 
"DestroyJavaVM" prio=6 tid=0x00036800 nid=0x670 waiting on condition [0x00000000..0x0007fb24]
   java.lang.Thread.State: RUNNABLE
 
"Timer-0" prio=6 tid=0x02db7a00 nid=0x4f4 in Object.wait() [0x0326f000..0x0326fd94]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x22e7dd08> (a java.util.TaskQueue)
	at java.util.TimerThread.mainLoop(Unknown Source)
	- locked <0x22e7dd08> (a java.util.TaskQueue)
	at java.util.TimerThread.run(Unknown Source)
 
"AWT-EventQueue-0" prio=6 tid=0x02d41100 nid=0x83c in Object.wait() [0x0311f000..0x0311fa14]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x22e7dda0> (a java.awt.EventQueue)
	at java.lang.Object.wait(Object.java:484)
	at java.awt.EventQueue.getNextEvent(Unknown Source)
	- locked <0x22e7dda0> (a java.awt.EventQueue)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForFilter(Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.run(Unknown Source)
 
"AWT-Windows" daemon prio=6 tid=0x02d3d400 nid=0xef8 runnable [0x0303f000..0x0303fa94]
   java.lang.Thread.State: RUNNABLE
	at sun.awt.windows.WToolkit.eventLoop(Native Method)
	at sun.awt.windows.WToolkit.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
 
     ... 以下、省略 ...

 

すべてのスレッドのスタックトレースが出力されています。

なにはともあれ、このようなツールが充実してきて、JVM の外側からでも JVM の状態を知ることができるというのはいいですね。

今後、ソフトウェアの管理がより重要となってくると思うのですが、ここで紹介したツール群は管理にも非常に役だつでしょう。

 

hat

java コマンドには標準でプロファイラが付属されているのをご存知ですか?

-agentlib:hprof というオプションでプロファイラが動作します (以前は -Xrunhprof だったのですが、Tiger のときに変更されました。-Xrunhprof でも動きますが)。

たとえば、さきほどの OutOfMemorySample クラスを -agentlib:hprof をつけて実行してみましょう。実際には 10 秒だけ実行して、停止させました。

アプリケーションを終了させると、デフォルトだと java.hprof.txt というファイルが生成されます。ここにプロファイルの情報が出力されます。

ところが、たった 10 秒だけ実行したとしても、そのファイルのサイズは 3.6MB。いくら有用な情報が詰まっていたとしても、これでは見るのも苦痛です。

そこで登場するのが hat (heap analysis tool) です。

もともと、hat は Advanced Programming for Java 2 Platform という本の中のサンプルとして登場しました。それが、java.net で開発されるようになり、Mustang でコアの中に取りいれられることになったという経緯があります。

これに伴って、JDK でのコマンド名は jhat に変更されています。

それでは、jhat を使ってみましょう。

 

jhat を使ってみる

jhat を使うには、hprof が出力するファイルをバイナリ形式にしなくてはなりません。そのために hprof のオプションとして format=b を付加します。

C:\temp>java -agentlib:hprof=format=b OutOfMemorySample photo

 

アプリケーションを終了すると、デフォルトでは java.hprof というファイルが出力されます (オプションで変更することもできます)。

その後、jhat を起動させます。引数には hprof が出力したファイルを指定します。

C:\temp>jhat java.hprof
Dump file created Mon Oct 24 02:09:00 JST 2005
Snapshot read, resolving...
Resolving 18765 objects...
Chasing references, expect 3 dots...
Eliminating duplicate references...
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

 

メッセージを読んでみると、ポート 7000 番で HTTP サーバを起動したと出ています。

Web ブラウザで localhost:7000 を見てみると。

アプリケーションを終了すると、デフォルトでは java.hprof というファイルが出力されます (オプションで変更することも

これはこれでいいのですが、問題はこのオプションをつけないと jconsole で見ても何も情報が得られないということです。

jhat

一番上にクラス名の一覧があります。これをクリックすると親クラスの情報やクラスローダ、自分が保持しているインスタンスへの参照の一覧などを見ることができます。

また、トップページに戻って、[Show heap histogram] をクリックしてみましょう。そうすると、ヒープのサイズもしくはインスタンスの個数でソートされた、クラスの一覧を見ることができます。

これを時間を変化させてみて見ましょう。

OutOfMemorySample の場合 int[] のサイズが非常に大きくなっていることがわかります。そこで、この int[] をクリックしてみると、int[] の情報を見ることができます。

int[] はどこかのオブジェクトの中で使われているはずなので、[References summary by Type] をクリックしてみます。

これで時間の長い短いで比べてみると sun.awt.image.DataBufferInt クラスからの参照数が増加していることが分かります。

jhat

DataBufferInt をクリックしていくと結局 BufferedImage クラスがこれをもっていることが分かります。ということはイメージのためにヒープの使用量が増えていることが分かります。

こういうのは、使ってみるのが一番。

最近は Eclipse の TPTP や NetBeans Profiler など無償で使えるプロファイラもありますが、JDK に標準でついているというのはとてもお手軽。

ぜひ、一度使ってみてください。

 

(Nov. 2005)

(改訂 Feb. 2007) OutOfMemoryError の解説と独立させ、jinfo の解説を追加