夢とガラクタの集積場

落ちこぼれ三流エンジニアである管理人の夢想=『夢』と、潰えた夢=『ガラクタ』の集積場です。

ソースそのままでLog4jからSLF4J&Logbackに移行する方法

こんにちは。

意外に、どうやればいいか1か所にまとまっているサイトがなかったので、
まとめのためにロギングフレームワーク移行の手順を残しておきます。

1.新旧ロギングフレームワーク

ここでいう移行元、移行先のロギングフレームワークは下記です。

移行元:Log4j
移行先:SLF4J + Logback

SLF4J + Logbackの方がLog4jに比べて下記のような点で優れているようです。

1.ログ出力時のパフォーマンス向上
2.ログ設定を起動中に再読み込みする設定が可能
3.デバッグログ出力時、isDebugEnabledメソッドでの囲みが不要

そのため、とりあえずログ出力をLog4jから移行しようと考えました!
#今さらかよ、という突っ込みはご勘弁を^^;

・・・なのですが、既存のコードを修正するのは面倒ですし、
元々Log4jを用いてログ出力を行っているフレームワークを用いることができなくなります。

何かいい方法はないかとSLF4Jのページを漁っていたところ、
Bridging legacy APIsというまんまなページが見つかりました。
どうやら、「log4j-over-slf4j」なるものを使用するとLog4jのロガーで出力したログを
SLF4Jを介して出力が可能となるようです。

というわけで、実際にブリッジして出力が可能かを確認してみました。

2.移行対象となるソース

移行対象となるソース、設定ファイルは下記の通りです。

移行対象ソース
import java.net.URL;

import org.apache.log4j.Logger;
import org.apache.log4j.PropertyConfigurator;

public class Log4jPrintSample
{
    public static void main(String[] args) {
        //設定ファイルを読み込む
        ClassLoader cl = Log4jPrintSample.class.getClassLoader(); 
        URL url = cl.getResource("log4j.properties"); 
        PropertyConfigurator.configure(url);
        
        //Loggerを作成する。
        Logger logger = Logger.getLogger(Log4jPrintSample.class);

        logger.trace("It's trace log");
        logger.debug("It's debug log");
        logger.info("It's info log");
        logger.warn("It's warn log");
        logger.error("It's error log");
        logger.fatal("It's fatal log");
    }

}
設定ファイル(log4j.properties)
log4j.rootLogger=TRACE, A1

log4j.appender.A1=org.apache.log4j.ConsoleAppender

log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c %x - %m%n
実行時のコンソール
2012-11-24 00:34:38,644 [main] TRACE sample.Log4jPrintSample  - It's trace log
2012-11-24 00:34:38,645 [main] DEBUG sample.Log4jPrintSample  - It's debug log
2012-11-24 00:34:38,645 [main] INFO  sample.Log4jPrintSample  - It's info log
2012-11-24 00:34:38,645 [main] WARN  sample.Log4jPrintSample  - It's warn log
2012-11-24 00:34:38,645 [main] ERROR sample.Log4jPrintSample  - It's error log
2012-11-24 00:34:38,645 [main] FATAL sample.Log4jPrintSample  - It's fatal log

3.移行手順

では、移行を試してみましょう。移行のための手順は下記です。

1.下記のJarをクラスパスに追加
2.logback.xml(Logbackの設定ファイル)をクラスパスに追加

設定ファイル(logback.xml

<configuration>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <!-- encoders are assigned the type
         ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
    <encoder>
      <pattern>[logback] %d [%thread] %-5level - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="TRACE">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>
3.クラスパス上の読み込み順をlog4j-over-slf4j-1.7.2.jar→log4j-1.2.16.jarの順番にする。

実際にログを出力するクラスがlog4j-over-slf4jからロードされるようにします。

・・・これだけです。
尚、「log4j-1.2.16.jar」をクラスパスから取り除いていないのは、
元のソースで「PropertyConfigurator」を使用しており、
とりあえず初期化の処理を通すために必要となるからです。

実際、フレームワークの内部で特定のファイルを指定して
Log4jを初期化しているパターンもあります。
そのため、「log4j-1.2.16.jar」を削除して問題が発生しないかを確認して、
その上で削除を行う形になりますね。

1〜3の対応を行った後、再度テストプログラムを実行すると下記の結果となります。

Logback化後の実行時コンソール
[logback] 2012-11-24 00:54:45,611 [main] TRACE - It's trace log
[logback] 2012-11-24 00:54:45,615 [main] DEBUG - It's debug log
[logback] 2012-11-24 00:54:45,616 [main] INFO  - It's info log
[logback] 2012-11-24 00:54:45,616 [main] WARN  - It's warn log
[logback] 2012-11-24 00:54:45,616 [main] ERROR - It's error log
[logback] 2012-11-24 00:54:45,616 [main] ERROR - It's fatal log

Logbackを通してログ出力されているのがわかりますね。
また、LogbackにはFATALのレベルが存在しないため、
Log4j側でFATALレベルのログを出力するとERRORとして出力されることもわかりました。

ちなみに、この方式でLog4jでログ出力を行っている
ミドルのログもまとめてSLF4J&Logbackから出力することができます。

これで、Log4jで動作するプログラムを変更せずに
SLF4J + Logbackからログ出力させることが可能ということがわかりました。

4.よし、やった・・・?

と思っていたら、Blitz4jなる高パフォーマンスなロギングフレームワーク
Netflixからアナウンスされました

これも今度試しておかなければ!
・・・ええ、実は最後は本文と何の関係もないですね(^^;