Helidon, Logging, and MDC

原文はこちら。
The original articles were written by Tomáš Langer (Consulting Member of Technical Staff at Oracle).
https://medium.com/helidon/helidon-logging-and-mdc-5de272cf085d

Helidonは利用する3rdパーティーの依存関係はできる限り最小限になるように設計されており、そのゴールを念頭に置き、元々はJVMの必須部分として依存関係を追加せず、Java Util Logging (JUL) を使うことにしていました。

しかしながらHelidon 2.2.0で、以下のロギングフレームワークとその機能をサポートすることにしました。

  • Java Util Logging (JUL) — すでにサポートしており、Helidonでの変更は不要
  • Simple Logging Facade for Java (SLF4J) — 複数のロギング実装(logback、Log4j、JUL)へ書き込むために利用可能なAPI
  • Log4j (version 2.x) — 幅広く利用されているロギングフレームワーク

Log4jとSLF4Jの追加により、Mapped Diagnostic Context (MDC) を提供できるようになりました。これは多数のリクエストをもらっていた機能で、これを使うことにより、利用者がstaticメソッドを使ってMDCに値を登録し、それを出力に書き込むことができます。この値は各メッセージや現在の利用者、もしくは類似のコンテキスト値のための確認したいトレースIDである可能性があります。

JULはMDCをそのままではサポートしないため、HelidonMdcと呼ばれるHelidon APIをhelidon-logging-commonモジュールに追加しました。

サポートされているロギングフレームワークのいずれかで動作する HelidonMdc を使用するか、 org.slf4j.MDC のようなロギングフレームワーク固有のクラスを使用するかを選択できます。Helidon はどちらの場合もスレッドの境界を越えた MDC の伝播を処理します。

Helidon MDCを利用するためには、以下の3個の設定が必要です。

  1. サポートされるロギングフレームワークのうちの一つの依存関係を追加する
  2. ロギングを構成して、その出力に情報を提供する
  3. コードでMDCを利用する

Java Util Logging (JUL)

Dependency

<dependency>
    <groupId>io.helidon.logging</groupId>
    <artifactId>helidon-logging-jul</artifactId>
</dependency>

Configuration

JULの場合、 HelidonConsoleHandler もしくは HelidonFormatter を使う必要があります。これらはこの構成で利用される SimpleFormatter を拡張しています。MDCの重要な部分は %X{name} です。これにより、MDCで利用可能な name プロパティが表示されます。

handlers=io.helidon.logging.jul.HelidonConsoleHandler
java.util.logging.SimpleFormatter.format=%1$tY.%1$tm.%1$td %1$tH:%1$tM:%1$tS %4$s %3$s !thread!: %5$s%6$s "%X{name}"%n
.level=INFO

Code

まずloggerインスタンスを取得します(Mainクラスであると想定します)。

import java.util.logging.Logger;
...
private static final Logger LOGGER = Logger.getLogger(Main.class.getName());

続いて、MDCに値を設定します。

import io.helidon.logging.common.HelidonMdc;
...
HelidonMdc.set("name", "some-name");

そして、何かをログ出力すると…

LOGGER.info("Log using MDC, name:");

想定される出力は以下のような感じになります。

2020.12.17 13:39:57 INFO Main Thread[main,5,main]: Log using MDC, name: “some-name”

Simple Logging Facade for Java (SLF4J)

Dependency

SLF4Jを使う場合、4個の依存関係を追加する必要があります。

  • Helidonロギング統合ライブラリ
  • SLF4J API
  • JUL-SLF4Jブリッジ(SLF4JでHelidonのメッセージを確認するために必要)
  • ロギング実装(このエントリではlogbackを選択)
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
</dependency>
<dependency>
    <groupId>io.helidon.logging</groupId>
    <artifactId>helidon-logging-slf4j</artifactId>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jul-to-slf4j</artifactId>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
</dependency>
Configuration

Logbackでは、構成オプションの一つとしてクラスパスにlogback.xmlがあることを期待しています。MDCの重要な部分は%X{name}です。これにより、MDCで利用可能な name プロパティが表示されます。

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

Code

まずloggerインスタンスを取得します(Mainクラスであると想定します)。

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
...
private static final Logger LOGGER = LoggerFactory.getLogger(Main.class);

続いて、MDCに値を設定します(SLF4J MDCもしくはHelidonMdcを使用します)。

import org.slf4j.MDC;
...
MDC.put("name", "some-name");

そして、何かをログ出力すると…

LOGGER.info("Log using MDC, name:");

想定される出力は以下のような感じになります。

13:43:52.440 INFO  [main] Main - Log using MDC, name: some-name

SLF4JログでJULログ出力を確認するには、アプリケーションのメインクラスの最初のエントリとして以下の設定を追加してください。

import org.slf4j.bridge.SLF4JBridgeHandler;
...
SLF4JBridgeHandler.removeHandlersForRootLogger();
SLF4JBridgeHandler.install();

Log4j

Dependency

Log4Jを使う場合、4個の依存関係を追加する必要があります。

  • Helidonロギング統合ライブラリ
  • Log4j API
  • JUL-Log4jブリッジ(Log4jおよびLog4j coreでHelidonのメッセージを確認するために必要)
<dependency>
    <groupId>io.helidon.logging</groupId>
    <artifactId>helidon-logging-log4j</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-jul</artifactId>
</dependency>

Configuration

JVMで実行する場合、ファイルベースの構成を利用できます。再度言いますが、MDCの重要な部分は%X{name}です。これにより、MDCで利用可能な name プロパティが表示されます。

この例では、プログラミングで設定していますが、これはGraalVM Native Imageで(少なくともある程度)機能する唯一の方法だからです。

import org.apache.logging.log4j.core.appender.ConsoleAppender;
import org.apache.logging.log4j.core.config.Configurator;
import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory;
...
private static void configureLogging() {
    // configure log4j
    final var builder = ConfigurationBuilderFactory.newConfigurationBuilder();
    builder.setConfigurationName("root");
    builder.setStatusLevel(Level.INFO);
    final var appenderComponentBuilder = builder.newAppender("Stdout", "CONSOLE")
            .addAttribute("target", ConsoleAppender.Target.SYSTEM_OUT);
    appenderComponentBuilder.add(builder.newLayout("PatternLayout")
                                         .addAttribute("pattern", "%d{HH:mm:ss.SSS} %-5level [%t] %logger{36} - %msg "
                                                 + "\"%X{name}\"%n"));
    builder.add(appenderComponentBuilder);
    builder.add(builder.newRootLogger(Level.INFO)
                        .add(builder.newAppenderRef("Stdout")));
    Configurator.initialize(builder.build());
}

Code

まずloggerインスタンスを取得します(Mainクラスであると想定します)。

import org.apache.logging.log4j.Logger;
...
private static final Logger LOGGER = Logger.getLogger(Main.class);

続いて、MDCに値を設定します(Log4j MDCもしくはHelidonMdcを使用します)。

import org.apache.logging.log4j.ThreadContext;
...
ThreadContext.put("name", "some-name");

そして、何かをログ出力すると…

LOGGER.info("Log using MDC, name:");

想定される出力は以下のような感じになります。

13:56:48.429 INFO  [main] Main - Log using MDC, name: some-name

Log4jログでJULログ出力を確認するには、プロセス起動時、もしくはJULのロガーを取得する前にシステムプロパティを設定する必要があります(この方法はGraalVM Native Imageでは現時点では動作しません)。

java -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager Main

Samples

ロギング統合の利用方法を説明するためのサンプルプロジェクトは以下のHelidonリポジトリにあります。

helidon/examples/logging
https://github.com/oracle/helidon/tree/master/examples/logging

Summary

ロギング統合はアプリケーションのトラブルシューティングにとって重要です。お試しいただいて、原文のコメント欄にコメントを残す、GitHubのIssueを立てる、Slackチャネルに投稿する、などを通じて、改善点などのフィードバックをお寄せください。

コメントを残す

以下に詳細を記入するか、アイコンをクリックしてログインしてください。

WordPress.com ロゴ

WordPress.com アカウントを使ってコメントしています。 ログアウト /  変更 )

Twitter 画像

Twitter アカウントを使ってコメントしています。 ログアウト /  変更 )

Facebook の写真

Facebook アカウントを使ってコメントしています。 ログアウト /  変更 )

%s と連携中