IBM Javaのメソッド・トレースを使ってみる

概要

IBM Javaにはメソッド・トレースという便利な機能が標準装備されています（※）。
メソッド・トレースを使うと、実行時に呼び出されたメソッドを時系列に確認することができます。使い方はとても簡単で、javaコマンドの実行時オプションでトレースしたいメソッドを指定するだけです(プロパティー・ファイルやJava APIによる指定も可能)。トレース対象メソッドの指定にはワイルドカードも使えます。

※IBM Knowledge Centerを見ると6.0.0～9.0.0の全バージョンのIBM Javaで利用できるようです。

使い方

さそく使ってみましょう。sampleパッケージの全クラスの全メソッドをトレース対象として、sample.HelloMTクラスを実行してみます。以下のように-Xtrace: ...で実行時オプションを指定します。

java -Xtrace:methods={sample/*},print=mt sample.HelloMT

実行するJavaプログラム（HelloMT.java）は以下のとおりです。

HelloMT.java

package sample;
public class HelloMT {
    private void say() {
        System.out.println("Hello Method Trace.");
        sayMore("Enjoy Method Trace!");
    }
    private void sayMore(String message) {
        System.out.println(message);
    }
    public static void main(String args[]) {
        HelloMT hello = new HelloMT();
        hello.say();
    }
}

実行結果は以下のとおり。メソッド・トレースはデフォルトで標準エラーに出力されます。

標準出力

Hello Method Trace.
Enjoy Method Trace!

標準エラー

12:15:33.618*0x2cb0500              mt.3        > sample/HelloMT.main([Ljava/lang/String;)V bytecode static method
12:15:33.618 0x2cb0500              mt.0        > sample/HelloMT.say()V bytecode method, this = 0xfff3b990
12:15:33.618 0x2cb0500              mt.0        > sample/HelloMT.sayMore(Ljava/lang/String;)V bytecode method, this = 0xfff3b990
12:15:33.618 0x2cb0500              mt.6        < sample/HelloMT.sayMore(Ljava/lang/String;)V bytecode method
12:15:33.618 0x2cb0500              mt.6        < sample/HelloMT.say()V bytecode method
12:15:33.618 0x2cb0500              mt.9        < sample/HelloMT.main([Ljava/lang/String;)V bytecode static method

-Xtrace:オプションの指定例

オプション（-Xtrace: ...）の詳細については参考リンクに挙げたIBM Javaのオンライン・マニュアルをご確認いただくこととして、いくつか実践的なオプション指定例をサンプルとして示します。

例1) トレース対象メソッドの条件を複数指定する
-Xtrace:methods={sample/*,test/*},print=mt
カンマで区切って複数の条件を指定できます。

例2) クラス名／メソッド名を限定したトレース条件指定
-Xtrace:methods={sample/HelloMT},print=mt
-Xtrace:methods={sample/HelloMT.say},print=mt
上段はsample.HelloMTクラスの全メソッドがトレース対象になります。
下段はsample.HelloMTクラスのsayメソッドのみがトレース対象となります。

例3) パラメーター情報も含めたトレース
-Xtrace:methods={com/ibm/sample/HelloMT.say*()},print=mt
メソッド指定の最後に()を付けるとパラメーター情報も含めてトレースできます。
引数がプリミティブの場合は値もトレースで確認できます。引数がオブジェクトの場合は、16進数のアドレスが出力されるので中身の値の確認まではできませんが、nullの場合はトレースにもarguments: (null)と出力されるので、問題判別の手がかりになります。

例4) トレース除外条件の指定
-Xtrace:methods={sample/*,!sample/HelloMT.sayMore},print=mt
!を先頭に記述するとトレース除外条件の指定になります。
上記サンプルの場合、除外指定を先に記述すると無効になってしまい、sayMoreメソッドもトレースに出力されてしまいますので記述の順序に注意が必要です。

例5) トレースをファイルに出力
-Xtrace:none,methods={sample/HelloMT},maximal=mt,output=C:\MTrace\mtrace1.out
noneを指定しないとデフォルト・トレース・ポイントとして大量のログが出力されるので要注意！
出力されたファイルはバイナリー形式なので参照するためにはフォーマットする必要があります。以下のようにIBM JavaのTraceFormatクラスを使ってフォーマットします。
C:\MTrace>java com.ibm.jvm.format.TraceFormat mtrace1.out
TraceFormatクラスの詳細は参考リンク（Running the trace formatter）をご確認ください。

Java APIによるメソッド・トレースの開始／終了制御

上記（例1～例5）で示したメソッド・トレースは、JVMの起動から終了までの間、ずっとメソッド・トレースが有効になりますが、部分的にトレースを取りたい場合もあります。suspendオプションとTrace API(com.ibm.jvm.Traceクラス)を利用すれば、トレースの開始と終了を制御することができます。まず、以下のようにsuspendオプションを指定してトレースが一時停止した状態でJVMを起動します。

-Xtrace:methods={*},print=mt,suspend

そして、トレースを開始したい箇所でJavaプログラムからTrace.resume()をコールして、トレースを開始します。最後に、Trace.suspend()をコールして再びトレースを一時停止状態に戻します。下記HelloMT2.javaがそのサンプルです。

HelloMT2.java

package sample;
import com.ibm.jvm.Trace;

public class HelloMT2 {
    private void say() {
        System.out.println("Hello Method Trace.");
        sayMore("Enjoy Method Trace!");
    }
    private void sayMore(String message) {
        System.out.println(message);
    }
    public static void main(String args[]) {
        HelloMT2 hello = new HelloMT2();
        Trace.resume();
        hello.say();
        Trace.suspend();
    }
}

以上です。

参考リンク

IBM SDK, Java Technology Edition, Version 8
IBM Javaオンライン・マニュアルです。
https://www.ibm.com/support/knowledgecenter/SSYKE2_8.0.0/welcome/welcome_javasdk_version.html

Using method trace
IBM Javaオンライン・マニュアルのメソッド・トレースのトップページです。
https://www.ibm.com/support/knowledgecenter/SSYKE2_8.0.0/com.ibm.java.lnx.80.doc/diag/tools/method_trace.html

Controlling the trace
IBM Javaオンライン・マニュアルのメソッド・トレースのトップページです。
https://www.ibm.com/support/knowledgecenter/SSYKE2_8.0.0/com.ibm.java.lnx.80.doc/diag/tools/trace_control.html

Detailed descriptions of trace options
メソッド・トレースのオプション詳細とシンタックスを解説したページです。
https://www.ibm.com/support/knowledgecenter/SSYKE2_8.0.0/com.ibm.java.lnx.80.doc/diag/tools/trace_options_detail.html

Using the Java API
Java API(com.ibm.jvm.Traceクラス)の使用方法を解説したページです。
https://www.ibm.com/support/knowledgecenter/SSYKE2_8.0.0/com.ibm.java.lnx.80.doc/diag/tools/trace_app_api.html

Running the trace formatter
トレースをファイルに出力した場合(上記 例5参照)に必要となるフォーマッター(com.ibm.jvm.format.TraceFormat)の使用方法を解説したページです。
https://www.ibm.com/support/knowledgecenter/SSYKE2_8.0.0/com.ibm.java.lnx.80.doc/diag/tools/trace_formatter.html

その他（注意事項等）

私が実際にはまったことをいくつか注意事項としてあげておきます。

Windows版 WebSphere Application Server Liberty Profile環境で使用する場合の注意事項

WebSphere Application Server Liberty Profile環境（以下WAS Liberty環境と記載）でメソッド・トレースを利用する場合は、jvm.optionsファイルにオプション-Xtrace:methods=...を記述しますが、Windows版のWAS Liberty環境では、オプションで除外対象を指定する場合に!記号を^（ハット記号）でエスケープする必要があります（WAS Libertyのサーバー起動コマンドがWindowsバッチファイルで実装されていることによる）。以下に記述例を示します。
-Xtrace:methods={sample/*,^!sample/Hello.set*},print=mt

Eclipse系IDE環境でcom.ibm.jvm.Traceにアクセスできない場合には

Eclipse系IDE環境でcom.ibm.jvm.Traceをimportしようとすると、アクセス制限によりエラーになり(注1)、コンパイルできないことがあります。
注1) エラーマーカーにマウスを当てると「アクセス制限: The type 'Trace' is not API(restriction on required library ...」というメッセージが確認できます。

以下の対応で回避できます（注2）。
注2) 説明中のスクリーンショットは、IBM Rational Application Developer V9.6.1での操作です。

プロジェクト・フォルダーを右クリックし、コンテキスト・メニューから以下を選択。
ビルド・パス(B)　＞　ビルド・パスの構成(C)

「Javaのビルド･パス」ダイアログが表示されるので、ライブラリー・タブ(L)を選択。
JREシステム・ライブラリーの三角のアイコンをクリックして展開し
展開されたセクションの一番上にあるアクセス・ルールを選択し、編集ボタンをクリック。

「型のアクセス・ルール」ダイアログが表示されるので、追加(A)ボタンをクリック。

「アクセス・ルールの追加」ダイアログが表示されるので、
　　　　- レゾリューション(S)プルダウンからアクセス可能を選択、
　　　　- ルール・パターン(R)にcom/ibm/jvm/**を入力して
OKボタンをクリック。

com/ibm/jvmがアクセス可能になったのを確認したら、OKボタンをクリックして、開いているダイアログを閉じてください。

これでJavaソースのimport文の左に表示されていたエラーマーカーが消えているはずです。