怠惰系エンジニアのメモ帳

勉強した内容をメモしていきます。解説ブログではないので悪しからず。

SLF4J + Logbackでログ出力

SLF4J と Logback を使用したログ出力について調べたので、忘れないようにメモ。
普段の開発でログ出力は行っていますが、ログ出力のための基盤(ライブラリ)周りについては無知でしたので、 今回の勉強でチョットログ分かる程度にはなれたかなと思います。

Java本格入門を参考にさせていただいたので、特段目新しいことは書いてません。
間違った記載がありましたら、指摘していただけると幸いです。

今回の目標

SLF4J + LogbackGet Wildする。

参考

今回参考にさせていただいた書籍やサイトは以下。

SLF4Jとは

  • Simple Logging Facade For Java、略してSLF4J。
  • ロギング実装ではない。
  • 使用するロギングライブラリは、デプロイ時に指定できる。
    • クラスパス上に存在するロギングライブラリを探して、自動的に関連付けを行う。(賢い!)
  • 実装(ロギングライブラリ)と利用者(プログラマ)の間に入る、アダプタ的な役割。

Logbacklog4Jなどのロギングライブラリは単体でも使用できるが、 要件や性能の関係でロギングライブラリが変更になった場合に、ログ出力のコードを全て書き換える必要がでてくる。
それを回避するために、ロギングライブラリに依存しないコードを書く必要があり、それを実現するのがSLF4J。

Logbackとは

  • ロギングライブラリ。
  • Log4jの後継。
  • Log4jよりも性能的にいいらしい。

公式?サイトも和訳されており、英語できない自分にとっては嬉しい限り。

Logbackマニュアル

環境

準備

pom.xmlにSLF4JとLogbackの依存関係を追加。

<!-- https://mvnrepository.com/artifact/org.slf4j/slf4j-api -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>
</dependency>

<!-- https://mvnrepository.com/artifact/ch.qos.logback/logback-classic -->
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.1.7</version>
</dependency>

必要なもの

クラスパス上にlogback.xmlを作成する。
今回は main/resources 配下に作成しました。

<?xml version="1.0" encoding="UTF-8" ?>
<configuration>

    <!-- コンソール出力の定義 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%date [%thread] %-5level %logger{35} - %message%n</pattern>
        </encoder>
    </appender>

    <!-- ファイル出力の定義 -->
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/main.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>main_%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%thread] %-5level %logger{35} - %message%n</pattern>
        </encoder>
    </appender>

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

</configuration>

各タグや設定値は公式サイトを参照。

ログ出力のコード

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

public class Main {

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

    /** ログ出力するメッセージ */
    private static final String LOG_MESSAGE = "Get Wild!!";

    public static void main(String[] args) {
        logger.debug(LOG_MESSAGE);
        logger.info(LOG_MESSAGE);
        logger.warn(LOG_MESSAGE);
        logger.error(LOG_MESSAGE);
        logger.trace(LOG_MESSAGE);
    }
}

SLF4JのLoggerFactory#getLoggerを使用し、Loggerインスタンスを取得します。

SLF4JのLoggerクラスには、ログレベルに応じたメソッドが用意されています。
また、ログメッセージに変数を埋め込む場合にはプレースホルダを利用します。

logger.debug("message = " + hoge);  // debugレベルのログを出力しない場合でも、hoge.toString()が呼ばれて効率が悪い。
logger.debug("message = {}", hoge); // ログ出力時にのみ hoge.toString() が呼ばれるので、効率が良い。

実行結果

2017-06-15 21:01:46,741 [main] INFO  Main - Get Wild!!
2017-06-15 21:01:46,744 [main] WARN  Main - Get Wild!!
2017-06-15 21:01:46,744 [main] ERROR Main - Get Wild!!

今回の設定では、ログレベルをINFO以上にしているのでDebugとTraceログは出力されていません。
とりあえずGet WildできたのでOK。

疑問に思ったこと

Q. クラスパス上に複数のロギングライブラリを配置したらどうなる?
A. 警告が出るが、最初にクラスパスに追加されたライブラリが使用される。

試しに、log4jをクラスパスに追加してみたところ…

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/user/.m2/repository/ch/qos/logback/logback-classic/1.1.7/logback-classic-1.1.7.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/user/.m2/repository/org/apache/logging/log4j/log4j-slf4j-impl/2.8.2/log4j-slf4j-impl-2.8.2.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]
2017-06-15 21:01:46,741 [main] INFO  Main - Get Wild!!
2017-06-15 21:01:46,744 [main] WARN  Main - Get Wild!!
2017-06-15 21:01:46,744 [main] ERROR Main - Get Wild!!

複数のライブラリがバインドされていると警告されました。
ただ、実際に使用されたのはLogbackで、これはlog4jよりも先にLogbackをクラスパスに追加したからでした。(多分)
log4jを先に追加したら、log4jが使用されたので間違ってないかも)

まとめ

  • SLF4J を使用することで、ロギングライブラリに依存しないログ出力が可能。
  • 変数を埋め込む際は、プレースホルダを使用して効率よく。
  • 複数のロギングライブラリが存在する場合、最初にクラスパスに追加したライブラリが使用される。

今後調べること

  • 動的にロギングライブラリやログレベルを切り替える方法
  • ファイル出力時の圧縮設定とか