Q7：JDK1.4 ロギングAPIとの速度差は？

debug レベルのログ出力を 10000 回繰り返し、Log4j とJDKロギングAPI で速度を比較しました。出力先はファイルで、出力フォーマットはJDK1.4 ロギングAPI の SimpleFormatter の出力をベースに（ログレベルのローカライズは無効に設定）以下の2種類で測定しました（Log4j の変換パターンで記述した場合）。

• パターンA
  <param name="ConversionPattern" value="%d{yyyy/MM/dd HH:mm:ss} %c %M %p: %m%n"/>
• パターンB（パターンAからメソッド名出力を削除）
  <param name="ConversionPattern" value="%d{yyyy/MM/dd HH:mm:ss} %c %p: %m%n"/>

それぞれのソースは以下のものです。

Log4j

import org.apache.log4j.Logger;

public class Log4jPerformanceTest {
    private static final Logger logger = 
        Logger.getLogger(Log4jPerformanceTest.class);
    private static final int ROOP_COUNT = 10000;

    public void printLog() {
        long before = System.currentTimeMillis();
        for (int i = 0; i < ROOP_COUNT; i++) {
            if (logger.isDebugEnabled()) {
                logger.debug("DEBUG message");
            }
        }
        long after = System.currentTimeMillis();
        System.out.println("Log4j Logging total time:" + (after - before) + "(ms)");
    }
}

JDK1.4

import java.util.logging.*;

public class JDKPerformanceTest {
    private static final Logger logger = 
        Logger.getLogger("logtest.performance.JDKPerformanceTest");
    private static final int ROOP_COUNT = 10000;

    public void printLog() {
        long before = System.currentTimeMillis();
        for (int i = 0; i < ROOP_COUNT; i++) {
            if (logger.isLoggable(Level.FINE)) {
                logger.fine("DEBUG message");
            }
        }
        long after = System.currentTimeMillis();
        System.out.println("JDK Logging total time:" + (after - before) + "(ms)");
    }
}

結果は以下のようになりました（単位：ms）。

パターンAでは JDK1.4 ロギングAPI の方が 2 倍以上早いという結果がでました。次にパターンBでコストのかかるメソッド出力をレイアウトから削除すると、ほぼ同じ時間がかかりました。JDK1.4 では行番号を出力することができませんが、こういった機能的な差がそのまま出力コストとして現れたのかもしれません。

結局、速度最優先で出力させる場合（パターンB）は、どちらを採用しても性能に差が無いということになります。より多くの情報をログに残す場合は JDK1.4 ロギングAPI の方が速度面で有利ですが、ソース修正が必要であることと（Log4j は設定ファイルで可能）、行番号出力やネスト化診断コンテキストのような機能が使えないことになります。ロギングライブラリの選択の際にはこれらを考慮するとよいでしょう。

最後に、パターンBの計測のために修正した JDK1.4 ロギングAPI のフォーマッタを以下に載せます。メソッド名だけでなくクラス名出力もコメントアウトし、その代わりにロガーを出力させていることに注意して下さい（これを行わなければパターンAと速度がほぼ同じになります）。

package logtest.performance;

import java.io.*;

import java.text.*;

import java.util.Date;
import java.util.logging.*;


public class MyFormatter extends Formatter {
    private final static String format = "{0,date} {0,time}";
    Date dat = new Date();
    private MessageFormat formatter;
    private Object[] args = new Object[1];
    private String lineSeparator = 
        (String) java.security.AccessController.doPrivileged(
        new sun.security.action.GetPropertyAction(
        "line.separator"));

    public synchronized String format(LogRecord record) {
        StringBuffer sb = new StringBuffer();

        // Minimize memory allocations here.
        dat.setTime(record.getMillis());
        args[0] = dat;

        StringBuffer text = new StringBuffer();

        if (formatter == null) {
            formatter = new MessageFormat(format);
        }

        formatter.format(args, text, null);
        sb.append(text);
        sb.append(" ");

                sb.append(record.getLoggerName());
        /*if (record.getSourceClassName() != null) {
            sb.append(record.getSourceClassName());
        } else {
            sb.append(record.getLoggerName());
        }*/

        /*if (record.getSourceMethodName() != null) {
            sb.append(" ");
            sb.append(record.getSourceMethodName());
        }*/
        //sb.append(lineSeparator);
        sb.append(" ");

        String message = formatMessage(record);

        //sb.append(record.getLevel().getLocalizedName());
        sb.append(record.getLevel());
        sb.append(": ");
        sb.append(message);
        sb.append(lineSeparator);

        if (record.getThrown() != null) {
            try {
                StringWriter sw = new StringWriter();
                PrintWriter pw = new PrintWriter(sw);
                record.getThrown().printStackTrace(pw);
                pw.close();
                sb.append(sw.toString());
            } catch (Exception ex) {
            }
        }

        return sb.toString();
    }
}

トップページへ戻る