LogbackやSLF4Jの簡単な調査 #Java

概要

logbackは三つのモジュールに分割されています(logback-core、logback-classic、logback-access)
クラスLoggerFactoryのstaticメソッドgetLoggerに完全修飾名(パッケージ名+クラス名)を指定することでクラスごとにログを管理できます。以下のソースコードで言うと、完全修飾名は"chapters.introduction.HelloWorld"ってやつです。

package chapters.introduction;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class HelloWorld {

  public static void main(String[] args) {

    Logger logger = LoggerFactory.getLogger("chapters.introduction.HelloWorld");
    logger.debug("Hello world.");

  }
}

ロガーの取得について、例えば次のような場合は常に同じインスタンスを返します。xとyは、完全に同じオブジェクトを参照します。

Logger x = LoggerFactory.getLogger("wombat"); 
Logger y = LoggerFactory.getLogger("wombat");

一度ロガーのインスタンスを設定すれば、わざわざ参照を渡さなくても、コード中のどこででも同じインスタンスを取得することができます。
ロガーの名前にそれが置かれたクラスの完全名を付けることは、一般的に最も良い方法であるということが共通認識になっているらしいです。

レベル

ロガーにはレベルを割り当てることができます。
利用できるレベル(TRACE、DEBUG、INFO、WARNおよびERROR)はch.qos.logback.classic.Levelクラスに定義されています。
レベルはTRACE < DEBUG < INFO < WARN < ERRORとなっています。
レベルの割り当てられていないロガーは、直近の祖先に割り当てられたレベルを継承します。
最終的に全てのロガーがレベルを継承できるように、ルートロガーには必ずレベルが割り当てられています(デフォルトではDEBUGになっています)。

例1

ロガー名	割り当てられたレベル	有効レベル
ルートロガー	DEBUG	DEBUG
X	なし	DEBUG
X.Y	なし	DEBUG
X.Y.Z	なし	DEBUG

上記の例1では、ルートロガーにだけレベルが割り当てられています。レベルはDEBUGで、他の全てのロガーに継承されています。

例2

ロガー名	割り当てられたレベル	有効レベル
ルートロガー	ERROR	ERROR
X	INFO	INFO
X.Y	DEBUG	DEBUG
X.Y.Z	WARN	WARN

上記の例2では、すべてのロガーにレベルが割り当てられています。レベルの継承は何も仕事をしていません。

例3

ロガー名	割り当てられたレベル	有効レベル
ルートロガー	DEBUG	DEBUG
X	INFO	INFO
X.Y	なし	INFO
X.Y.Z	ERROR	ERROR

上記の例3では、ルートロガーにDEBUG、XにINFO、X.Y.ZにERRORが割り当てられています。X.Yは親であるXからレベルを継承しています。

例4

ロガー名	割り当てられたレベル	有効レベル
ルートロガー	DEBUG	DEBUG
X	INFO	INFO
X.Y	なし	INFO
X.Y.Z	なし	INFO

上記の例4では、ルートロガーにDEBUG、XにINFOが割り当てられています。X.YおよびX.Y.Zは、最も近い親からレベルを継承しています。

クラスLoggerには印字メソッドとしてtrace, debug, info, warn, errorがあります。
印字メソッドはロギング要求のレベルを決定するものです。
例えば、Lがロガーのインスタンスだとすると、式L.info("..")はINFOレベルのロギングであることになります。
ロギング要求は、そのロガーの有効レベル以上である場合に有効となります。
そうでなければ、ロギング要求は無効になります。
前述のように、レベルが割り当てられていないロガーは最も近い祖先から継承します。
このルールは次のように要約できます。

基本的な選択ルール
有効レベルqのロガーに発行されたレベルpのログ要求は、p>=qを満たす場合有効になる。

選択ルールのソースコードによる例

import ch.qos.logback.classic.Level;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
....

// "com.foo"という名前のロガーを取得します。
// ロガーのインスタンスはレベルを設定するために ch.qos.logback.classic.Logger とします。
ch.qos.logback.classic.Logger logger = 
        (ch.qos.logback.classic.Logger) LoggerFactory.getLogger("com.foo");
// レベルにINFOを設定します。setLevel() メソッドは logback のロガーにしかありません。
logger.setLevel(Level.INFO);

Logger barlogger = LoggerFactory.getLogger("com.foo.Bar");

// このロギング要求は有効です。WARN >= INFO
logger.warn("Low fuel level.");

// このロギング要求は無効です。DEBUG < INFO. 
logger.debug("Starting search for nearest gas station.");

// "com.foo.Bar" という名前のロガーは、"com.foo" ロガーからレベルを継承します。
// したがって、このロギング要求は有効です。INFO >= INFO. 
barlogger.info("Located nearest gas station.");

// このロギング要求は無効です。DEBUG < INFO.
barlogger.debug("Exiting gas station search");

つまり、ロギング要求(印字メソッド)のレベルがロガーの有効レベル(setLevelの引数で指定したレベル)よりも厳しいときにレベルが継承されます。

アペンダー

logbackでは、宛先(出力先)のことをアペンダーと呼びます。
現在利用できるアペンダー
- コンソール
- ファイル
- MySQLやPostgreSQLやOracleなどのデータベース
- JMS
- リモートSyslogデーモン
ロガーには一つ以上のアペンダーを割り当てることができます。
アペンダーにも継承があります。
指定されたロガーにアペンダーを割り当てるには、addAppenderメソッドを使います。

レイアウト

logbackでは出力のフォーマットはレイアウトと呼ぶ。
レイアウトにはPatternLayoutがある。
PatternLayoutはロギングイベントを受け取って文字列を返す。
PatternLayoutの変換パターン文字列はC言語のprintf()関数と非常によく似たもので、文字列リテラルと変換指定と呼ばれる書式制御式で構成される。以下、PatternLayoutの使用例

ソースコードが以下の場合

package chapters.layouts;

import org.slf4j.LoggerFactory;

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.ConsoleAppender;

public class PatternSample {

  static public void main(String[] args) throws Exception {
    Logger rootLogger = (Logger)LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
    LoggerContext loggerContext = rootLogger.getLoggerContext();
    // we are not interested in auto-configuration
    loggerContext.reset();

    PatternLayoutEncoder encoder = new PatternLayoutEncoder();
    encoder.setContext(loggerContext);
    encoder.setPattern("%-5level [%thread]: %message%n");
    encoder.start();

    ConsoleAppender<ILoggingEvent> appender = new ConsoleAppender<ILoggingEvent>();
    appender.setContext(loggerContext);
    appender.setEncoder(encoder);
    appender.start();

    rootLogger.addAppender(appender);

    rootLogger.debug("Message 1");
    rootLogger.warn("Message 2");
  }
}

コンソールには以下のような出力となります。

DEBUG [main]: Message 1
WARN  [main]: Message 2

レイアウトにはまだまだ色々あります -> http://logback.qos.ch/manual/layouts_ja.html

パラメータ化ロギング

パラメータ化ロギングはメッセージフォーマットに基づいた便利な方法
以下のように書いた場合

Object entry = new SomeObject(); 
logger.debug("The entry is {}.", entry);

ロギング要求が有効かどうかを判断した後にだけ、そして、それが有効な場合にだけ、ロガーはメッセージを書式化して、'{}' を entry の文字列表現で置き換えます。つまり、ロギング要求が無効な場合、このやり方だとパラメータ構築のコストが発生しません。

以下の二行からはまったく同じ出力が得られます。しかし、ロギング要求が無効な場合、二行目のやり方は一行目のやり方に比べて少なくとも30倍は優れているでしょう。

logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);

二つ置換場所を指定することもできます。たとえば、次のように書くことができます。

logger.debug("The new entry is {}. It replaces {}.", entry, oldEntry);

引数が三つ以上になる場合、Object[]でラップしなければなりません。たとえば、次のように書くことができます。

Object[] paramArray = {newVal, below, above};
logger.debug("Value {} was inserted between {} and {}.", paramArray);

余談

和訳マニュアル間違い杉ワロター

本家マニュアルには

However, in case of a disabled logging statement, the second variant will outperform the first variant by a factor of at least 30.

logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);

とあるけど
和訳マニュアルには

しかし、 ロギング要求が無効な場合、二行目のやり方は一行目のやり方に比べて少なくとも30倍は遅くなるでしょう。

logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);

とあるwww

outperformは「より優れている」の意味だから、本当は「30倍は優れているでしょう」なのにwww

参考URL

logback マニュアル [日本語]
The logback manual [英語]