id:torutk:20100704 で、ポストロギングAPIとして候補に挙げた一つがBTraceです。が、知名度がいまひとつなせいか、使い方の情報が少ないので、とっかかりでひっかかると挫折してしまいます。
入手と設定
まず、BTraceのホームページから、バイナリ一式をダウンロードします。
- 上記URLのページを開き、左側メニューの"Documents & Files"をクリックします。
- ダウンロード一覧から、"releases"フォルダのリンクをクリックします。
- 現時点で一番新しそうな"release-1.1"フォルダのリンクをクリックします。
- btrace-bin.zipまたはbtrace-bin.tar.gzをクリックしダウンロードします。
- ダウンロードしたファイルを適切なディレクトリに展開します。
環境設定としては、Java（JDK）のあるパスを環境変数JAVA_HOMEにセットしている必要があります。コマンドで実行するときの利便性から、btraceを展開した中にあるbinディレクトリを環境変数PATHに登録するといいかもしれません。
最初のサンプル
btraceにおけるHello worldは、JDK付属のデモプログラム Java2Demo を動かし、そこにBTraceでトレーススクリプトをつなげてトレースログを出すというもののようです。
BTraceのトレーススクリプトの記述
トレーススクリプトはJavaで記述します。が、コンパイルしなくても動きます（btrace実行時にコンパイルされる）。コンパイルした方がエラーチェックが早くわかるのでよいかと思いますが、簡単なものならコンパイルの手間がなく使えるので、便利な機能です。
import com.sun.btrace.annotations.*; import static com.sun.btrace.BTraceUtils.*; @BTrace public class TraceMethods { @OnMethod(clazz="/javax\\.swing\\..*/", method="/.*/") public static void m() { print(strcat("entered ", name(probeClass()))); println(strcat(".", probeMethod())); } }
javax.swing.で始まるパッケージのクラスについて、名前は問わずメソッドが呼ばれたときにメッセージを出力するものです。
ここで、Java2Demoを実行します。
C:\Java\jdk1.6.0\demo\jfc\Java2D> java -jar Java2Demo.jar
特に何も指定せず普通に実行しています。
jpsコマンドを使って、上で起動したJava2Demoプログラムの実行IDを調べます。
C:\work> jps 1234 jar 2345 Jps
1つ目のjarという名前がJava2Demoのようです。ここで表示されるIDを覚えます。
btrace.batコマンドで、トレースを実施します。
C:\work> C:\Java\btrace-1.1.3\bin\btrace.bat" 1234 TraceMethods.java entered javax.swing.JComponent.repaint entered javax.swing.RepaintManager.currentManager entered javax.swing.RepaintManager.currentManager entered javax.swing.RepaintManager.currentManager entered javax.swing.RepaintManager.addDirtyRegion entered javax.swing.RepaintManager.getDelegate ：（大量に出力が続く）
次の一歩
btraceを展開した中に、ドキュメントとサンプルが入っています。docs\userguide.htmlを見るとよいでしょう。
以下、試していないのですが、サンプルのメモです
引数の値をログに出したい
ドキュメントに含まれるサンプルの１つAWTEventTracer.javaによると、
@OnMethod(clazz="java.awt.EventQueue", method="dispatchEvent") public static void onevent(@Self EventQueue queue, AWTEvent event) { if (event instanceof FocusEvent) { println(event); println(); } }
とあります。java.awt.EventQueueのdispatchEventメソッドのシグニチャは
protected void dispatchEvent(AWTEvent event)
となっているので、トレースメソッドの第一引数はインスタンス自身、第二引数にトレース対象メソッドの最初の引数がくるようです。これなら簡単ですね。
例外発生をログしたい
例外クラスがnewされるところをログするサンプルOnThrow.javaがあります。
@OnMethod(clazz="java.lang.Throwable",method="<init>") public static void onthrow(@Self Throwable self) { currentException = self; }
メソッド名に"
@OnMethod(clazz="java.lang.Throwable",method="<init>") public static void onthrow1(@Self Throwable self, String s, Throwable cause) { currentException = self; }
このサンプルでは、コンストラクタが呼ばれたときにそのインスタンスを記録しておき、コンストラクタからreturnするところでログを出しています。
@OnMethod(clazz="java.lang.Throwable", method="<init>", location=@Location(Kind.RETURN)) public static void onthrowreturn() { if (currentException != null) { jstack(currentException); println("====================="); currentException = null; } }
問題解決
WindowsでJavaやBTraceが空白を含むパスにあるとき
btrace.batが空白を含むパスを正しく処理できないのでエラーになりました。
Windows Vistaや7なら、シンボリックリンクを使い、Windows XPであればジャンクションを使って空白を含まないパスを作るとよいと思います。
Windows 7で、cygwin上で実行したJavaプログラムは、コマンドプロンプト上でjpsコマンドを実行してもIDが見えない
C:\Users\<ユーザ名>\AppData\Local\Temp\hsperfdata_<ユーザ名>\を見ると、コマンドプロンプトからJavaプログラムを実行したときには、そのプログラムのIDがファイルとして書かれますが、cygwin~実行したときには書かれません。
jpsコマンドは、環境変数TEMPの指すディレクトリの下にあるhsperfdata_<ユーザ名>ディレクトリの下にあるファイルを見て一覧を返しますが、cygwinでは環境変数TEMPは設定されていないので、別な場所を参照しているものと思われます。
とりあえず、cygwin上で環境変数TEMPをコマンドプロンプトと同じ場所に設定すれば、この問題は回避できます。
$ export TEMP=/cygdrive/c/Users/torutk/AppData/Local/Temp $
と、cygwin形式の指定でOKでした。
