S-JIS[2007-11-17/2007-11-23] 変更履歴

Java デバッグログ出力メソッド削除

Javaのデバッグログの出力用メソッドを実行時に(あるいは事前に)削除するライブラリー(ツール/エージェント)です。
詳細はJavadoc参照。
このライブラリーはJavassistを使わせてもらっています。また、JDK1.5以降でないと動きません。

dbglogrm.jar(48.8kB)[/2007-11-23]


製作の経緯

C言語/C++でデバッグログを出力するには、#defineを用いて、デバッグビルドとリリースビルドでログ出力関数の有無を制御するのが常套手段かと思います。

/* C言語での例 */
#ifdef DEBUG	…デバッグモードかどうか
#define	TRACE(msg)	0
#else
#define	TRACE(msg)	printf(msg)
#endif

	TRACE("デバッグ出力\n");

そして、C言語/C++からJavaに移ってきた人は、Javaに#defineが無いことにショックを受けると思います。←それは自分だけか^^;
無くてもなんとかなるのでJavaの仕様からはあえて削ったのでしょうが、デバッグログ出力に関してはやはり不便です。

Javaでの以下のようなログ出力のコーディングは効率が悪いことで有名で、悪名の高さ抜群です。

	log.debug("デバッグ出力:" + map); //Mapの場合、暗黙にMap#toString()が呼ばれる。そしてMap内の全データが出力対象に…!

実際に出力するかどうかの判断はdebugメソッド内で行われますが、debug()への引数を生成する為の文字列結合は最終的な出力の有無に関わらず必ず実行されるからです。出力されない場合の文字列結合は全くの無駄で不要なのに、Javaでは単なる文字列結合でもかなりの高負荷です。これがさらにMapのtoString()だったりすると、目の前が暗くなって背筋が寒くなります…!

という訳で、Javaの場合は、以下のようにif文でくくることが推奨されます。

	if (log.isDebugEnabled()) {
		log.debug("デバッグ出力:" + map);
	}

これであれば、出力の判断が先に行われ、出力しない場合に無駄な文字列操作が行われることはありません。
文字列結合に比べれば、判断メソッドを呼び出すくらいのことは全然大した負荷じゃありません

しかし、ひとつのログ出力でもコーディングが3行に亘ってしまうので、見た目がくどくなってしまいます。
ソースの生産性・メンテナンスの観点からは、書きやすい事・読みやすい事も重要です

そこで、最近(ちょっと昔から?)流行りのバイトコードを直接いじる方法(アスペクト指向?)でログ出力メソッドを削除できないかなーと思いました。
みんな考えることは同じだろうから、噂のAspectJとかで出来るのではないかと思ったのですが、インターネットでほんのちょっぴり調べた限りでは、AspectJで各メソッドの先頭と末尾にトレース用のメソッドを埋め込んだりするのは簡単に出来るようでしたが、ログ出力メソッドを消すようなものは見当たりませんでした。ちゃんと探せば絶対あるような気はするんですが

それじゃ自分でやってみっぺーと、Javassistを使ってみることにしました。
バイトコードをいじるライブラリーは他にもあるようですが、JavassistはJavaソースの形で修正できるので敷居がまだ低いと思ったのです。
で、Javassistでログ出力メソッド呼び出しを削除するものを作ってみたところ、比較的簡単に出来ました
が、喜びも束の間。
これはバイトコードレベルのメソッド呼び出しのみを消すだけでした。つまり、そのメソッドの引数の演算は残ってしまうのです。

	log.debug("デバッグ出力:" + map);
			↓ log.debug()だけ消える
	String dummy = "デバッグ出力:" + map.toString(); …意味的にはこんな感じになる

これじゃ意味が無ーい!
調べてみた感じでは、メソッドの引数まで含めた削除方法は、Javassistには用意されていないようでした。

もしかすると、バイトコードレベルでは「arg = "デバッグ出力:" + map; log.debug(arg);」という感じ(演算とメソッド呼び出しが別)になってしまっており、“メソッドの引数に使うかどうか”という情報が残っていないのか、とも考えました。
が、jadで逆コンパイルしてみると、ちゃんとメソッドの引数の演算もメソッドの括弧内に出るんですよね。
(ローカル変数に一旦入れて その変数をメソッドの引数にすると、ちゃんとそういう形で逆コンパイルされますし)

どうもJavaのコンパイルは、最適化というものがされないようです。ほとんどソースを単純にバイトコードに置き換えているだけって感じです。
逆に言うと、メソッドの引数は常にスタックに積むのみであり、ローカル変数に変更されることも無いわけです。
なので、メソッドの引数分をスタックにPUSHしている範囲がメソッドの呼び出しに直接使われている部分だと判断できそうです。
試しにその範囲を全て削除(NOPに置換)してみたところ、見事に全て消えたのでした!

これをまとめてみたのが当ライブラリーです。

ちなみに、Javassistでコードを修正するには、ExprEditorを継承したクラスを作り、その中の該当editメソッドをオーバーライドするのが通常の方法なのですが。今回はedit呼び出しの範囲を超えたコードを変更したかったので、doitメソッド自体をオーバーライドしてしまいました。…doit()のコメントを見ると、オーバーライドするなって書いてあるんですけどね(汗)


注意

自分で試しに使ってみる分には動いていますが、常に安全かどうかは全く保証できません。
Javaはクラスのロード時にバイトコードのチェックをしているそうなので、変な変換になったらそこでエラーが出て止まるはずであり、変なコードのまま実行されることは まず無いと思いますが。


動作環境

JDK1.5以降でないと使えません。
また、Javassistを使っているので、dbglogrm.jarの他にjavassist.jarが実行時に必要です。 自分が使ったのはjavassist3.6ですが、javassist3.1以降(アノテーションに対応している)で動くのではないかと思います。


概要

当ライブラリーでは、デバッグログの出力用メソッドかどうかを判断する為にアノテーションを使っています。(だからJDK1.5以降用。アノテーションを使うのをやめればJDK1.4でも使えるはずです。その場合は判断方法をメソッド名に変えたりしないといけないでしょうが)
したがって、デバッグログの出力クラスの各メソッド定義にアノテーションを付ける必要があります。

デバッグログを管理するクラスの例:

import jp.hishidama.debuglogrm.DebugLevel;
import jp.hishidama.debuglogrm.DebugLogWriteMethod;

public class DebugLog {

	@DebugLogWriteMethod(DebugLevel.DEBUG)
	public void writeLogD(String msg) {
		System.out.println("[D]" + msg);
	}

	@DebugLogWriteMethod(DebugLevel.INFO)
	public void writeLogI(String msg) {
		System.out.println("[I]" + msg);
	}

	@DebugLogWriteMethod(DebugLevel.ERROR)
	public void writeLogE(String msg) {
		System.out.println("[E]" + msg);
	}

	@DebugLogWriteMethod(DebugLevel.ERROR)
	public void writeLogE(String msg, Throwable e) {
		System.out.println("[E]" + msg + ": " + e);
	}
}

ちなみに、レベルはFATAL・ERROR・WARNING・INFO・VERBOSE・DEBUG・TRACEです。
Log4JやJakarta Commons Loggingのレベル(FATAL・ERROR・WARN・INFO・DEBUG・TRACE)とantのレベル(error・warning・info・verbose・debug)の合体です(爆)
多めに用意しておいて、使いたいレベルだけ使えばいいかなーと^^;
でもFINE・FINER・FINESTは除外。全部先頭1文字がFなので、FATALと区別つかなくて困るから。

もうひとつ、ログ出力を使用したいクラス(そのクラス内のログ出力メソッドの削除を行う)にもアノテーションを付ける仕様にしました。
別にそんなの無しで全クラスを対象にすることは可能ですが、アノテーションを明示的に付けることにより、デバッグログ削除という変なライブラリー:)の対象である事が意識できるようにする目的で こうしています。

デバッグログ出力を使用するクラスの例:

import jp.hishidama.debuglogrm.UseDebugLog;

@UseDebugLog
public class Sample {

	private static DebugLog dbgLog = new DebugLog();

	public static void main(String[] args) {
		dbgLog.writeLogI("start");
		try {
			int n = 0;
			for (int i = 1; i <= 100; i++) {
				n += i;
				dbgLog.writeLogD(i + ":" + n);
			}
			dbgLog.writeLogI("結果:" + n);

		} catch(Exceptoin e) {
			dbgLog.writeLogE("何かエラー", e);
		}
		dbgLog.writeLogI("end");
	}
}

後述の方法を用いてERROR・INFOレベルのメソッドだけ残すと、DEBUGレベルのメソッド(writeLogD())の呼び出しが削除されます。

↓イメージとしてはこういう感じになる

〜
			for (int i = 1; i <= 100; i++) {
				n += i;
			}
〜

デバッグログ出力を削除したクラスファイルを作る例

まずは試験用に、デバッグログ出力メソッドを削除したclassファイルを作るクラスを用意しました。
これをjadなりで逆コンパイルすれば、どのように変化したかが分かるということです。

>cd 〜\classes
>java -cp 〜\dbglogrm.jar;〜\javassist.jar;. jp.hishidama.debuglogrm.DebugRemoveExperiment -level=EI Sample.class
出力レベル:ERROR,INFO
in : Sample.class
out: Sample.dbgrm.class

「-level」に、デバッグログ出力を行うレベルを指定します。レベルを表す単語の先頭1文字(例:FATALならF)を組み合わせて指定します。(EIならERRORとINFOレベルだけ出力する)

また、クラスパスに、デバッグ出力メソッド(@DebugLogWriteMethodを付けているメソッド)を定義しているクラスのパスを入れておく必要があります。[2007-11-18]

ちなみに、言葉としては「メソッドを削除」と言っていますが、実際にはNOP(無処理)に置き換えているだけなので、ファイルサイズは変わりませんJavassistの方でNOPを削除する機能を用意してくれると嬉しいんだけどな〜(笑)


antで変換する例

デバッグログ出力メソッドの削除を行うantのタスクを用意しました。[2007-11-18]

copyタスクを元にしているので、普通にコンパイルしたclassesディレクトリ内のclassファイルを別ディレクトリへ(変換しつつ)コピーするイメージです。

build.xml

<?xml version="1.0" encoding="Shift_JIS"?>
<project name="debuglog_remove" default="debuglog_rm" basedir="..">
	<property name="fr_dir" location="classes" />
	<property name="to_dir" location="classes_rm" />

	<typedef name="dbglogrm" classname="jp.hishidama.debuglogrm.DebugRemoveTask" />

	<target name="debuglog_rm">
		<dbglogrm todir="${to_dir}" classpath="${fr_dir}">
			<fileset dir="${fr_dir}" includes="**/*.class" />
		</dbglogrm>
	</target>
</project>

このbuild.xmlを実行するantコマンド自体のクラスパスに、dbglogrm.jarとjavassist.jarを含める必要があります。
環境変数CLASSPATHに追加しておくか、-libオプションを指定します。

>cd 〜\bin 	build.xmlがあるディレクトリ。binと同じ場所にclassesがある前提
>ant -lib "〜\dbglogrm.jar;〜\javassist.jar"

Eclipseの場合は、build.xmlの実行の構成の「クラスパス」に追加します。


パラメータ

属性 説明 必須
todir 変換したクラスファイルを格納するディレクトリーを指定する。 Yes
classpath
classpathref
デバッグログ出力メソッドを実装しているクラスのパスを指定する。
ant自体のクラスパスに指定されていれば不要。のはずなのだが、Eclipse以外では上手くいかない…
No

ネストする要素として指定されるパラメータ

fileset

変換元のクラスファイルを指定する。

classpath
classpathref

属性のclasspathと同様。


クラスローダーを使って変換する例

ClassLoaderを使って、ロードされるクラス内のデバッグログ出力メソッドを実行時に削除する例です。

>java -cp 〜\dbglogrm.jar;〜\javassist.jar -Djava.system.class.loader=jp.hishidama.debuglogrm.DebugRemoveClassLoader -Ddebuglog.level=EI Sample

※クラスローダーが本当にこんな実装でいいのか自信が無いので、premain()を使う方法の方が良いような気が…


premain()を使って変換する例

premainメソッドを使って、ロードされるクラス内のデバッグログ出力メソッドを実行時に削除する例です。

>java -cp 〜\javassist.jar -javaagent:〜\dbglogrm.jar=EI Sample

dbglogrm.jarのマニフェストでPremain-ClassJasTransferPremainを指定し、その中でDebugRemoveTransferをバイトコード変換モジュールとして登録するようにしています。


変更履歴

更新日 変更内容
2007-11-21 デバッグログ出力メソッドを呼び出す際の引数に三項演算子が入っていると上手く変換できなかった。これに対応したつもり
“ログ出力メソッドがstaticで、第1引数に三項演算子を使っている場合”以外は、これで大丈夫だと思う。
削除範囲はスタック位置(使用量)で判断しているのだが、三項演算子では真と偽で別々のスタック位置に計算してしまっていた(IFによるジャンプ先のスタック位置を考慮していなかった為)。
また、下から順に目的のスタック位置になるまで遡り、見つかった時点で削除開始位置と認識するので、第1引数の三項演算子の真偽の片方をスタックに積んでいる箇所を開始位置と誤認してしまう。
staticメソッド以外では暗黙の第1引数thisがスタックに積まれるので、スタック位置を間違うことが無い。はず。
2007-11-23 Javadocコメントを付け忘れているメソッドがあったので書いただけ。でもprotectedメソッドだから生成したJavadocには無関係だし(爆)

自作ソフトへ戻る / 技術メモへ行く
メールの送信先:ひしだま