Q3:変換パターン記号による速度差は?

"メッセージ" というログメッセージを次のアペンダによって1万回ファイルへ出力し、その出力にかかる時間を計測します。

<appender name="FILE" class="org.apache.log4j.RollingFileAppender">
  <param name="File"   value="log/info.log" />
  <param name="Append" value="false" />                
  <layout class="org.apache.log4j.PatternLayout">
    <param name="ConversionPattern" value="%m%n"/>
  </layout>       
</appender>

ConversionPattern の value 属性値の先頭に各変換パターン記号を加え(例えば"%c %m%n")、それぞれのログ出力時間を計測します。

結果は以下のようになりました。

変換パターン記号 説明 出力内容 時間(ms)
%c ログを出力したロガー名 sample.Sample message 188
%d ログが出力された日時 2008-02-13 14:43:57,120 message 219
%p ログレベル INFO message 188
%t ログを生成したスレッドの名前 main message 187
%C クラス名 sample.Sample message 1172
%F ソースファイル名 Sample.java message 1125
%l 出力位置の情報 sample.Sample.main(Sample.java:14) message 1156
%L 行番号 14 message 1140
%M メソッド名 main message 1172

大文字の変換パターン記号や %l を使用すると、約6倍遅くなる結果となりました。出力内容や動作環境によって結果は異なるのでケースバイケースですが、ログの出力回数を半分に減らすよりも変換パターン記号を見直した方が効果がある場合が多いはずです。


トップページへ戻る