"メッセージ" というログメッセージを次のアペンダによって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倍遅くなる結果となりました。出力内容や動作環境によって結果は異なるのでケースバイケースですが、ログの出力回数を半分に減らすよりも変換パターン記号を見直した方が効果がある場合が多いはずです。