はじめに
ログ出力に関するあるあるネタと解決策です。
Logbackでの「ロギング要求の生成元」の出力
Logbackでは、パターンレイアウトに以下の変換指定子を指定することで、「ロギング要求の生成元」の情報をログ出力に含めることができます1。
変換指定子 (別名) | 出力内容 |
---|---|
C (class) | 呼び出し元のクラス名(FQCN) |
M (method) | 呼び出し元のメソッド名 |
F (file) | ソースコードファイル名 |
L (line) | ソースコードファイル中の行番号 |
caller2 | 呼び出し元の位置情報 |
本記事では、以下の設定をログ出力の例として使用します。
pattern
要素の内容に注目してください。この設定により、クラス名やファイル名などをログに出力させることができます。デバッグが捗りますね。
<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になってしまいます。
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);
}
// (以下略)
}
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"));
}
}
[[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のLocationAwareLogger
3を使うことで、この問題を解決できます。
LocationAwareLogger
のlog
メソッドでは、FQCNを指定することができます。
public void log(Marker marker, String fqcn, int level, String message, Object[] argArray, Throwable t);
LogbackのLogger
4は、LocationAwareLogger
を実装しています。
つまり、ログ出力の実装にLogbackを使用している場合、LoggerFactory
から取得したLogger
5をLocationAwareLogger
にキャストすることができます。
以下がLocationAwareLogger
の使用例です。
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); }
//---
}
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
のメソッドを模倣しました。ご容赦ください)