LoginSignup
11

More than 5 years have passed since last update.

自作LoggerではLocationAwareLoggerを使おう

Posted at

はじめに

ログ出力に関するあるあるネタと解決策です。

Logbackでの「ロギング要求の生成元」の出力

Logbackでは、パターンレイアウトに以下の変換指定子を指定することで、「ロギング要求の生成元」の情報をログ出力に含めることができます1

変換指定子 (別名) 出力内容
C (class) 呼び出し元のクラス名(FQCN)   
M (method) 呼び出し元のメソッド名             
F (file) ソースコードファイル名      
L (line) ソースコードファイル中の行番号 
caller2 呼び出し元の位置情報             

本記事では、以下の設定をログ出力の例として使用します。
pattern要素の内容に注目してください。この設定により、クラス名やファイル名などをログに出力させることができます。デバッグが捗りますね。

logback.xml
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>[[%class.%method\(%file:%line\)]] %logger{0} - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="debug">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>
ログ出力例
[[com.example.demo.DemoLogApplication.main(DemoLogApplication.java:16)]] DemoLogApplication - hello

変換指定子の詳細はマニュアルをご参照ください。

【問題】自作Loggerクラスの場合

様々な事情によりSLF4JのLoggerを直接使わずに、自作のLoggerを定義する場合があります。
このとき、単純にSLF4JのLoggerに処理を委譲(いわゆるWrapper)すると、「ロギング要求の生成元」が全て自作Loggerになってしまいます。

MyWrongLogger.java
package com.example.demo;

import org.slf4j.LoggerFactory;
import org.slf4j.Marker;

public class MyWrongLogger {
  // 委譲先となるSLF4JのLogger
  private final org.slf4j.Logger logger;

  // コンストラクタは非公開
  private MyWrongLogger(org.slf4j.Logger logger) {
    this.logger = logger;
  }

  // ファクトリメソッド
  public static final MyWrongLogger getLogger(Class<?> clazz) {
    org.slf4j.Logger logger = LoggerFactory.getLogger(clazz);
    return new MyWrongLogger(logger);
  }

  // 以下、loggerへの委譲

  public boolean isTraceEnabled() {
    return logger.isTraceEnabled();
  }

  public void trace(String msg) {
    logger.trace(msg);
  }

  // (以下略)

}
DemoLogApplication.java
package com.example.demo;

public class DemoLogApplication {
  private static final MyWrongLogger WRONG_LOGGER = MyWrongLogger.getLogger(DemoLogApplication.class);

  public static void main(String[] args) {
    WRONG_LOGGER.info("hello");
    WRONG_LOGGER.info("hello {}", "xxx");
    WRONG_LOGGER.info("exception", new Exception("test"));
    WRONG_LOGGER.info("{} {} {} exception", 1, 2, 3, new Exception("test"));
  }
}
ログ出力例(「ロギング要求の生成元」がMyWrongLoggerになってしまっている)
[[com.example.demo.MyWrongLogger.info(MyWrongLogger.java:122)]] DemoLogApplication - hello
[[com.example.demo.MyWrongLogger.info(MyWrongLogger.java:126)]] DemoLogApplication - hello xxx
[[com.example.demo.MyWrongLogger.info(MyWrongLogger.java:138)]] DemoLogApplication - exception
java.lang.Exception: test
    at com.example.demo.DemoLogApplication.main(DemoLogApplication.java:11)
[[com.example.demo.MyWrongLogger.info(MyWrongLogger.java:134)]] DemoLogApplication - 1 2 3 exception
java.lang.Exception: test
    at com.example.demo.DemoLogApplication.main(DemoLogApplication.java:12)

確かに、実際にloggerのメソッドを呼び出しているのはMyWrongLoggerなのですが……
こんな残念なログ、たまにありますよね。

【解決策】LocationAwareLogger

SLF4JのLocationAwareLogger3を使うことで、この問題を解決できます。
LocationAwareLoggerlogメソッドでは、FQCNを指定することができます。

org.slf4j.spi.LocationAwareLogger
public void log(Marker marker, String fqcn, int level, String message, Object[] argArray, Throwable t);

LogbackのLogger4は、LocationAwareLoggerを実装しています。
つまり、ログ出力の実装にLogbackを使用している場合、LoggerFactoryから取得したLogger5LocationAwareLoggerにキャストすることができます。

以下がLocationAwareLoggerの使用例です。

MyLocationAwareLogger.java
package com.example.demo;

import static org.slf4j.spi.LocationAwareLogger.*;
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;

public class MyLocationAwareLogger {
  // Marker(今回は使用しない)
  private static final Marker MARKER = null;
  // このクラスのFQCN 
  private static final String FQCN = MyLocationAwareLogger.class.getName();

  // 委譲先となるSLF4JのLocationAwareLogger
  private final org.slf4j.spi.LocationAwareLogger logger;

  // コンストラクタは非公開
  private MyLocationAwareLogger(org.slf4j.spi.LocationAwareLogger logger) {
    this.logger = logger;
  }

  // ファクトリメソッド
  public static MyLocationAwareLogger getLogger(Class<?> clazz) {
    org.slf4j.spi.LocationAwareLogger logger = (org.slf4j.spi.LocationAwareLogger) LoggerFactory.getLogger(clazz);
    return new MyLocationAwareLogger(logger);
  }

  //<<< isXxxEnabled >>>
  public boolean isTraceEnabled() { return logger.isTraceEnabled(); }
  public boolean isDebugEnabled() { return logger.isDebugEnabled(); }
  public boolean isInfoEnabled () { return logger.isInfoEnabled (); }
  public boolean isWarnEnabled () { return logger.isWarnEnabled (); }
  public boolean isErrorEnabled() { return logger.isErrorEnabled(); }
  //---

  //<<< log >>>
  // (String msg)
  public void trace(String msg)                         { logger.log(MARKER, FQCN, TRACE_INT, msg,    null,      null); }
  public void debug(String msg)                         { logger.log(MARKER, FQCN, DEBUG_INT, msg,    null,      null); }
  public void info (String msg)                         { logger.log(MARKER, FQCN, INFO_INT,  msg,    null,      null); }
  public void warn (String msg)                         { logger.log(MARKER, FQCN, WARN_INT,  msg,    null,      null); }
  public void error(String msg)                         { logger.log(MARKER, FQCN, ERROR_INT, msg,    null,      null); }
  // (String msg, Throwable t)
  public void trace(String msg,    Throwable t)         { logger.log(MARKER, FQCN, TRACE_INT, msg,    null,      t   ); }
  public void debug(String msg,    Throwable t)         { logger.log(MARKER, FQCN, DEBUG_INT, msg,    null,      t   ); }
  public void info (String msg,    Throwable t)         { logger.log(MARKER, FQCN, INFO_INT,  msg,    null,      t   ); }
  public void warn (String msg,    Throwable t)         { logger.log(MARKER, FQCN, WARN_INT,  msg,    null,      t   ); }
  public void error(String msg,    Throwable t)         { logger.log(MARKER, FQCN, ERROR_INT, msg,    null,      t   ); }
  // (String format, Object... arguments)
  public void trace(String format, Object... arguments) { logger.log(MARKER, FQCN, TRACE_INT, format, arguments, null); }
  public void debug(String format, Object... arguments) { logger.log(MARKER, FQCN, DEBUG_INT, format, arguments, null); }
  public void info (String format, Object... arguments) { logger.log(MARKER, FQCN, INFO_INT,  format, arguments, null); }
  public void warn (String format, Object... arguments) { logger.log(MARKER, FQCN, WARN_INT,  format, arguments, null); }
  public void error(String format, Object... arguments) { logger.log(MARKER, FQCN, ERROR_INT, format, arguments, null); }
  //---
}
DemoLogApplication.java
package com.example.demo;

public class DemoLogApplication {
  private static final MyLocationAwareLogger MY_LOGGER = MyLocationAwareLogger.getLogger(DemoLogApplication.class);

  public static void main(String[] args) {
    MY_LOGGER.info("hello");
    MY_LOGGER.info("hello {}", "xxx");
    MY_LOGGER.info("exception", new Exception("test"));
    MY_LOGGER.info("{} {} {} exception", 1, 2, 3, new Exception("test"));
  }
}
ログ出力例(正しい「ロギング要求の生成元」が出力されている)
[[com.example.demo.DemoLogApplication.main(DemoLogApplication.java:16)]] DemoLogApplication - hello
[[com.example.demo.DemoLogApplication.main(DemoLogApplication.java:17)]] DemoLogApplication - hello xxx
[[com.example.demo.DemoLogApplication.main(DemoLogApplication.java:18)]] DemoLogApplication - exception
java.lang.Exception: test
    at com.example.demo.DemoLogApplication.main(DemoLogApplication.java:18)
[[com.example.demo.DemoLogApplication.main(DemoLogApplication.java:19)]] DemoLogApplication - 1 2 3 exception
java.lang.Exception: test
    at com.example.demo.DemoLogApplication.main(DemoLogApplication.java:19)

おわりに

SLF4JのLoggerのメソッドを模倣するだけならば自作のLoggerは不要だと思います。
自作のLoggerを作るなら、ログ出力目的(監査ログや性能ログなど)別にメソッドを用意するなど、有意義なLoggerを作りましょう。
(本記事ではサンプルとして分かりやすくするために、あえてLoggerのメソッドを模倣しました。ご容赦ください)


  1. :warning:「ロギング要求の生成元」の取得は高コストな処理のため、実行速度を悪化させます。開発環境などに限定して使用するようにしましょう 

  2. 出力内容が特殊なため、本記事では取り扱いません 

  3. org.slf4j.spi.LocationAwareLogger 

  4. ch.qos.logback.classic.Logger 

  5. org.slf4j.Logger 

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
11