lombok | Casual Developers Note

SLF4JとLogbackによるJavaのロギング入門(SLF4J + Logback + Lombok)

アプリケーションにおいてロギング処理は無くてはならない必需品です。現在ではログは故障の解析はもちろんのこと、セキュリティチェックやユーザの行動分析など多岐に渡って利用されています。今回はJavaによるロギング方法として、SLF4JとLogback、Lombokを使った方法を紹介します。

はじめに

Javaのロギングは、一昔前はCommons-loggingとLog4jによる方法が一般的でしたが、現在ではSLF4J+Logbackに取って代わりました。ベースは全てLog4jなので、乗り換える人も特に苦はありません。今回は、SLF4J+Logbackによるロギング方法を紹介します。ついでに、Lombokで簡潔に記述してみましょう。

SLF4Jとは？

SLF4Jは、Javaのロギング用のファサードAPIです。一昔前のCommons-loggingに該当します。役割としては、ライブラリが使っているロギングの実装が異なっていた場合に、インターフェースを統一するためのものです。

Logbackとは？

Logbackは、Javaのロギングの実装です。一昔前のLog4Jに該当します。SLF4Jと一緒に使う前提で作られており、特徴としてはアダプタによるログの横取りにより、他のロギングライブラリを使っているライブラリとログ出力を統一できます。

Lombokとは？

Lombokとは、一般的なボイラープレートをアノテーションで省略できるようにするライブラリです。例えば、よく書くゲッターやセッターが必要な場面では、@Getterや@Setter、@Dataのアノテーションを書くだけで実現できます。そして、SLF4J用に@Slf4jのアノテーションが提供されているので、今回利用します。

SLF4JとLogbackによるロギング

前提

以下がインストールされている前提で進めます。

Java10
Maven3

細かいバージョンは「環境」を参照して下さい。

サンプルアプリケーションを作る

それでは、雛形を作りましょう。

$ mvn -B archetype:generate \
> -DarchetypeGroupId=org.apache.maven.archetypes \
> -DgroupId=com.example.project \
> -DartifactId=logging-sample-app   
$ cd logging-sample-app/
$ rm src/main/java/com/example/project/App.java
$ rm src/test/java/com/example/project/AppTest.java
$ touch src/main/java/com/example/project/Main.java
$ mkdir -p src/main/resources
$ touch src/main/resources/logback.xml
$ tree src/main/
src/main/
├── java
│   └── com
│       └── example
│           └── project
│               └── Main.java
└── resources
    └── logback.xml
$ tree
.
├── pom.xml
├── src
│   ├── main
│   │   ├── java
│   │   │   └── com
│   │   │       └── example
│   │   │           └── project
│   │   │               └── Main.java
│   │   └── resources
│   │       └── logback.xml
...

できました。

標準出力

それでは、標準出力にログを出力してみましょう。

pom.xml

<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/maven-v4_0_0.xsd">
  <modelVersion>4.0.0</modelVersion>

  <groupId>com.example.project</groupId>
  <artifactId>logging-sample-app</artifactId>
  <packaging>jar</packaging>
  <version>1.0-SNAPSHOT</version>
  <name>logging-sample-app</name>
  <url>http://maven.apache.org</url>

  <properties>
    <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
    <java.version>10</java.version>
    <logback.version>1.2.3</logback.version>
    <lombok-version>1.18.0</lombok-version>
  </properties>

  <dependencies>
    <dependency>
      <groupId>ch.qos.logback</groupId>
      <artifactId>logback-classic</artifactId>
      <version>${logback.version}</version>
    </dependency>

    <dependency>
      <groupId>org.projectlombok</groupId>
      <artifactId>lombok</artifactId>
      <version>${lombok-version}</version>
    </dependency>
  </dependencies>

  <build>
    <plugins>
      <plugin>
        <groupId>org.apache.maven.plugins</groupId>
        <artifactId>maven-compiler-plugin</artifactId>
        <version>3.7.0</version>
        <configuration>
          <target>${java.version}</target>
          <source>${java.version}</source>
          <release>${java.version}</release>
        </configuration>
      </plugin>
    </plugins>
  </build>

</project>

Main.java

package com.example.project;

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

public class Main {

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

  public static void main(String[] args) {
    log.info("{} starting...", "My logging process");

    log.trace("Tracing...");
    log.debug("Debugging...");
    log.warn("Warning...");
    log.error("Error handling...");

    log.info("{} done.", "My logging process");
  }

}

logback.xml

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
      <pattern>%date [%thread] [%-5level] %logger{40} = %message%n</pattern>
    </encoder>
  </appender>

  <logger name="com.example" level="DEBUG"/>

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

実行してみましょう。

$ mvn clean install
$ mvn exec:java -Dexec.mainClass="com.example.project.Main"
...
2018-07-11 22:21:34,057 [com.example.project.Main.main()] [INFO ] com.example.project.Main = My logging process starting...
2018-07-11 22:21:34,060 [com.example.project.Main.main()] [DEBUG] com.example.project.Main = Debugging...
2018-07-11 22:21:34,061 [com.example.project.Main.main()] [WARN ] com.example.project.Main = Warning...
2018-07-11 22:21:34,061 [com.example.project.Main.main()] [ERROR] com.example.project.Main = Error handling...
2018-07-11 22:21:34,062 [com.example.project.Main.main()] [INFO ] com.example.project.Main = My logging process done.
...

エラーレベルをDEBUGにしたので、TRACE以外の全てのレベルのログが出力されました。

ファイル出力

次にファイルに出力してみましょう。アペンダーはRollingFileAppenderを、ポリシーはTimeBasedRollingPolicyを使います。詳しくは公式ドキュメントを参照して下さい。

logback.xml

<configuration>
  <property name="encoding" value="UTF-8"/>
  <property name="logPath" value="logs/"/>
  <property name="logFormat" value="%date [%thread] [%-5level] %logger{40} = %message%n"/>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
      <pattern>${logFormat}</pattern>
    </encoder>
  </appender>

  <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${logPath}app.log</file>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${logPath}app.%d{yyyy-MM-dd}.log</fileNamePattern>
      <maxHistory>30</maxHistory>
    </rollingPolicy>

    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
      <charset>${encoding}</charset>
      <pattern>${logFormat}</pattern>
      <outputPatternAsHeader>true</outputPatternAsHeader>
    </encoder>
  </appender>

  <logger name="com.example" level="DEBUG"/>

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

実行してみましょう。

$ mvn clean install
$ mvn exec:java -Dexec.mainClass="com.example.project.Main"
...
$ tree logs/
logs/
└── app.log
$ cat logs/app.log
#logback.classic pattern: %date [%thread] [%-5level] %logger{40} = %message%n
2018-07-11 22:21:34,057 [com.example.project.Main.main()] [INFO ] com.example.project.Main = My logging process starting...
2018-07-11 22:21:34,060 [com.example.project.Main.main()] [DEBUG] com.example.project.Main = Debugging...
2018-07-11 22:21:34,061 [com.example.project.Main.main()] [WARN ] com.example.project.Main = Warning...
2018-07-11 22:21:34,061 [com.example.project.Main.main()] [ERROR] com.example.project.Main = Error handling...
2018-07-11 22:21:34,062 [com.example.project.Main.main()] [INFO ] com.example.project.Main = My logging process done.

ファイルにログが出力されました。

Lombokによる記述の簡略化

すでにPOMでLombokを追加してあるので、Main.javaで使ってみましょう。

Main.java

@Slf4jを使うことで、ロガーの定義を省略できます。

package com.example.project;

import lombok.extern.slf4j.Slf4j;

@Slf4j
public class Main {

  public static void main(String[] args) {
    log.info("{} starting...", "My logging process");

    log.trace("Tracing...");
    log.debug("Debugging...");
    log.warn("Warning...");
    log.error("Error handling...");

    log.info("{} done.", "My logging process");
  }

}

実行してみましょう。

$ mvn clean install
$ mvn exec:java -Dexec.mainClass="com.example.project.Main"
...
2018-07-11 22:35:34,612 [com.example.project.Main.main()] [INFO ] com.example.project.Main = My logging process starting...
2018-07-11 22:35:34,616 [com.example.project.Main.main()] [DEBUG] com.example.project.Main = Debugging...
2018-07-11 22:35:34,617 [com.example.project.Main.main()] [WARN ] com.example.project.Main = Warning...
2018-07-11 22:35:34,617 [com.example.project.Main.main()] [ERROR] com.example.project.Main = Error handling...
2018-07-11 22:35:34,617 [com.example.project.Main.main()] [INFO ] com.example.project.Main = My logging process done.
...

問題なく動きますね。