java.util.loggingとLog4Jのパフォーマンス比較

Java

今日ログの取り方についてちょっと調べてたんですが、ついでにLog4Jとjava.util.loggingのパフォーマンス比較をしてみました。
とりあえず下記のように、10000回ログを吐く簡単なコードを作りました。commons-loggingを使って実行時にLog4Jとjava.util.loggingのどちらを使用するか切り替えます。

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
public class TestLogging {
    private static Log log = LogFactory.getLog(TestLogging.class);
    public static void main(String[] args) {
        long l = System.currentTimeMillis();
        for(int i = 0 ; i < 10000 ; i++)
            log.fatal("なんでやねん");
        System.out.println("経過時間:" + (System.currentTimeMillis() - l) + "ms");
    }
}

java.util.loggingの設定ファイルがこちら。

.level = FINEST
handlers= java.util.logging.FileHandler
java.util.logging.FileHandler.pattern = D:/temp/jdk14.log
java.util.logging.FileHandler.append = true
java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter

Log4Jの設定ファイルがこちら。

log4j.rootCategory=DEBUG, A1
log4j.appender.A1=org.apache.log4j.FileAppender
log4j.appender.A1.File=d:/temp/log4j.log
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%d{yyyy/MM/dd HH:mm:ss} %C %M%n%p: %m%n

これでどちらも、

yyyy/MM/dd HH:mm:ss クラス名 メソッド名
レベル: 詳細メッセージ

という形式でログを取ることが出来ます。

この実行結果。まずLog4Jの場合。

経過時間:6400ms

次にjava.util.logging。

経過時間:2774ms

java.util.loggingの方が圧倒的に早い、という結果になりました。Log4Jの方が早いと思ってましたが……。ログのフォーマットを簡単に変更出来るなど、Log4Jにメリットがいろいろあることには変わりませんが、JSR47 vs. log4jをずっと前に読んで、パフォーマンスでも圧倒しているものだとばかり思ってました。
ちなみに、クラス名・メソッド名を出力しないように設定したところ、Log4Jでは721msに縮みました。java.util.loggingの方では2523msでほとんど変化無し。java.util.loggingはあらかじめクラス名を読み込んでいるのかな。
今回のデータでいうと、クラス名・メソッド名を出力させたい場合はjava.util.loggingを、その必要が無い場合はLog4Jを使ったほうが高速だという結果になりました。とりあえずcommons-logging使ってどちらにでも切り替えるようにしておくのがやはり無難ですね。
最後に、計測した環境は以下のとおりになります。

  • Windows2000SP4
  • SUN JDK1.4.2_03
  • CPU Pentium3 733MHz

何か計測方法に問題があったらツッコミいれてください。
【追記】Log4Jは1.2.8、Commons-Loggingは1.0.3を使用しました。