SLF4Jとlogback

仕事で触る機会があったので色々試してみる。

プロジェクト作成

mavenプロジェクトを適当に作って、pom.xmlに必要最低限を記入。 (mavenが使えない場合は、本家サイトから必要なライブラリをダウンロード)

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
  xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
  <modelVersion>4.0.0</modelVersion>
  <groupId>logback</groupId>
  <artifactId>logback</artifactId>
  <version>0.0.1-SNAPSHOT</version>
  <dependencies>
    <dependency>
      <groupId>ch.qos.logback</groupId>
      <artifactId>logback-classic</artifactId>
      <version>1.1.2</version>
    </dependency>
  </dependencies>
</project>

依存性を解決した後は、本家サイトを参考にとりあえずコーディング

とりあえずのコーディング

http://logback.qos.ch/manual/configuration.html

package main.java;

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

public class Logtest {

  final static Logger logger = LoggerFactory.getLogger(Logtest.class);

  public static void main(String[] args) {
    logger.info("Entering application.");

    LogtestSub logTestSub = new LogtestSub();
    logTestSub.doIt();
    logger.info("Exiting application.");
  }

}

package main.java;

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

public class LogtestSub {

  static final Logger logger = LoggerFactory.getLogger(LogtestSub.class);

  public void doIt() {
    logger.debug("I'm LogtestSub Did it again!");
  }

}

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <root level="debug">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

いざ動作確認

コンソールログ

11:55:25.898 [main] INFO main.java.Logtest - Entering application.
11:55:25.901 [main] DEBUG main.java.LogtestSub - I'm LogtestSub Did it again!
11:55:25.901 [main] INFO main.java.Logtest - Exiting application.

ほほぅ。

appenderを追加してログファイルを出力してみる。

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>log/test.log</file>
    <append>true</append>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <root level="debug">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE" />
  </root>
</configuration>

いざ動作確認

ログファイル

13:02:48.731 [main] INFO  main.java.Logtest - Entering application.
13:02:48.734 [main] DEBUG main.java.LogtestSub - I'm LogtestSub Did it again!
13:02:48.734 [main] INFO  main.java.Logtest - Exiting application.

ほほほぅ。

個別のロガーを設定してみる。

package main.java;

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

public class LogtestOrigName {

  static final Logger logger = LoggerFactory.getLogger("HOGE");

  public void doIt() {
    logger.debug("I'm LogtestOrigName Did it again!");
  }

}

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>log/test.log</file>
    <append>true</append>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <appender name="FILE2" class="ch.qos.logback.core.FileAppender">
    <file>log/test2.log</file>
    <append>true</append>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <root level="debug">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE" />
  </root>

  <logger name="HOGE" additivity="false">
    <level value="debug" />
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE2" />
  </logger>
</configuration>

コンソールログ

13:14:07.558 [main] INFO main.java.Logtest - Entering application.
13:14:07.560 [main] DEBUG main.java.LogtestSub - I'm LogtestSub Did it again!
13:14:07.560 [main] INFO main.java.Logtest - Exiting application.
13:14:07.561 [main] DEBUG HOGE - I'm LogtestOrigName Did it again!
13:14:07.561 [main] INFO main.java.Logtest - Exiting application.

ログファイル１

13:14:07.558 [main] INFO main.java.Logtest - Entering application.
13:14:07.560 [main] DEBUG main.java.LogtestSub - I'm LogtestSub Did it again!
13:14:07.560 [main] INFO main.java.Logtest - Exiting application.
13:14:07.561 [main] INFO main.java.Logtest - Exiting application.

ログファイル２

13:14:07.561 [main] DEBUG HOGE - I'm LogtestOrigName Did it again!

ほほほほぅ。

ちなみにのadditivityをtrueにすると、 rootの対象として扱われてしまうため、少々鬱陶しいことになる。

コンソールログ

13:15:00.894 [main] INFO main.java.Logtest - Entering application.
13:15:00.897 [main] DEBUG main.java.LogtestSub - I'm LogtestSub Did it again!
13:15:00.897 [main] INFO main.java.Logtest - Exiting application.
13:15:00.897 [main] DEBUG HOGE - I'm LogtestOrigName Did it again!
13:15:00.897 [main] DEBUG HOGE - I'm LogtestOrigName Did it again!
13:15:00.897 [main] INFO main.java.Logtest - Exiting application.

こんな感じでlogger(HOGE)とrootのロガー同士で重複が発生する様子。

パッケージを指定してロガーを作成する。

package main.java.child;

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

public class LogtestChild1 {

  static final Logger logger = LoggerFactory.getLogger(LogtestChild1.class);

  public void doIt() {
    logger.debug("I'm LogtestChild1 Did it again!");
  }

}

package main.java.child;

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

public class LogtestChild2 {

  static final Logger logger = LoggerFactory.getLogger(LogtestChild2.class);

  public void doIt() {
    logger.debug("I'm LogtestChild2 Did it again!");
  }

}

package main.java.child;

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

public class LogtestChild3 {

  static final Logger logger = LoggerFactory.getLogger(LogtestChild3.class);

  public void doIt() {
    logger.debug("I'm LogtestChild3 Did it again!");
  }

}

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>log/test.log</file>
    <append>true</append>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <appender name="FILE2" class="ch.qos.logback.core.FileAppender">
    <file>log/test2.log</file>
    <append>true</append>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <appender name="FILE3" class="ch.qos.logback.core.FileAppender">
    <file>log/test3.log</file>
    <append>true</append>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <root level="debug">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE" />
  </root>

  <logger name="HOGE" additivity="false">
    <level value="debug" />
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE2" />
  </logger>

  <logger name="main.java.child" additivity="false">
    <level value="debug" />
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE3" />
  </logger>
</configuration>

コンソールログ

13:19:05.605 [main] INFO main.java.Logtest - Entering application.
13:19:05.608 [main] DEBUG main.java.LogtestSub - I'm LogtestSub Did it again!
13:19:05.609 [main] INFO main.java.Logtest - Exiting application.
13:19:05.609 [main] DEBUG HOGE - I'm LogtestOrigName Did it again!
13:19:05.609 [main] INFO main.java.Logtest - Exiting application.
13:19:05.609 [main] DEBUG main.java.child.LogtestChild1 - I'm LogtestChild1 Did it again!
13:19:05.609 [main] INFO main.java.Logtest - Exiting application.
13:19:05.610 [main] DEBUG main.java.child.LogtestChild2 - I'm LogtestChild2 Did it again!
13:19:05.610 [main] INFO main.java.Logtest - Exiting application.
13:19:05.610 [main] DEBUG main.java.child.LogtestChild3 - I'm LogtestChild3 Did it again!
13:19:05.610 [main] INFO main.java.Logtest - Exiting application.

ログファイル３（１，２は割愛）

13:19:05.609 [main] DEBUG main.java.child.LogtestChild1 - I'm LogtestChild1 Did it again!
13:19:05.610 [main] DEBUG main.java.child.LogtestChild2 - I'm LogtestChild2 Did it again!
13:19:05.610 [main] DEBUG main.java.child.LogtestChild3 - I'm LogtestChild3 Did it again!

ほほほほほぅ。

とりあえず基本的なことが知れたのでここまででいいや。