SpringBootのログ出力機能設計(Webアプリ編)

オフィスで働く女性 Spring Framework
オフィスで働く女性

Spring Framework上で共通ログ機能の設計を行ってみます。ログ出力といっても色々な機能が考えられますが、今回は以下の2つを考えます。
1.アプリケーション向けの共通ログ出力ユーティリティ
2.バックエンド側の共通ログ自動出力

環境前提

Spring Bootv3.5.6
Java21
ログ出力ライブラリSLF4J + Logback

アプリケーション向けの共通ログ出力ユーティリティ

提供機能

共通ログ項目を自動で出力する共通ログ出力ユーティリティを作成します。アプリケーション側では「業務固有メッセージ」だけを設定するだけで、その他の項目は基盤部品側で自動で出力するようにします。
「リクエストURL」などログ出力タイミングで情報が存在しないものは「N/A」を出力します。

項目名フォーマット内容項目設定元
タイムスタンプ%d{yyyy-MM-dd HH:mm:ss.SSS}ログ出力時刻Logback
ログレベル%-5levelINFO / DEBUG / ERROR などLogback
ログ出力元クラス名%logger{48}ログを出力したクラスの完全修飾名(48文字制限)Logback
スレッド名%threadスレッド名Logback
リクエストID%X{requestId}HTTPリクエスト単位の識別子。
X-Request-Idが付与されていればX-Request-Idを出力。存在しない場合は独自で以下のIDを生成し出力する。
uuid()+yyyymmddss。
基盤
リクエストURL%X{requestUri}リクエストURL基盤
HTTPメソッド%X{httpMethod}HTTPメソッド基盤
業務固有メッセージ%X{msg}業務固有ログアプリ

Logback設定

Logback設定(logback-spring.xml)でログフォーマットを定義します。

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

  <!-- 基本プロパティ -->
  <property name="APP_NAME" value="${APP_NAME:-${spring.application.name:-unknown-app}}"/>
  <property name="LOG_CHARSET" value="UTF-8"/>

  <!-- WEB 用パターン:
       - %msg 内の改行はスペースに置換して1行に整形
       - 例外の1行目を同一行に付与し、改行ののちに完全なスタックトレースを出力
       - %msgが未指定の場合は空文字が出力されます(ログ自体は出力される)
       - %exが未指定の場合は何も出力されません(ログ自体は出力される)
       - MDCからリクエストID・URI・HTTPメソッドを出力する(ラベルなし、ログ圧縮目的)
  -->
  <property name="PATTERN_WEB"
            value="[%d{yyyy-MM-dd'T'HH:mm:ss.SSS}] %-5level %logger{48} [%thread] %X{requestId:-N/A} %X{requestUri:-N/A} %X{httpMethod:-N/A} %replace(%msg){'[\r\n]+',' '} %ex{1}%n%ex"/>
  
  <!-- 外部FW用のシンプルなパターン -->
  <property name="PATTERN_FW"
            value="[%d{yyyy-MM-dd'T'HH:mm:ss.SSS}] %-5level %logger{48} [%thread] %msg%n"/>

  <!-- WEB 用コンソール -->
  <appender name="CONSOLE_WEB" class="ch.qos.logback.core.ConsoleAppender">
    <target>System.out</target>
    <encoder>
      <pattern>${PATTERN_WEB}</pattern>
      <charset>${LOG_CHARSET}</charset>
    </encoder>
  </appender>

  <!-- 外部FW用コンソール -->
  <appender name="CONSOLE_FW" class="ch.qos.logback.core.ConsoleAppender">
    <target>System.out</target>
    <encoder>
      <pattern>${PATTERN_FW}</pattern>
      <charset>${LOG_CHARSET}</charset>
    </encoder>
  </appender>

  <!-- ルートロガー(外部FWのログはCONSOLE_FWへ) -->
  <root level="WARN">
    <appender-ref ref="CONSOLE_FW"/>
  </root>

  <!-- com.example.demo配下のみCONSOLE_WEBに出力 -->
  <logger name="com.example.demo" level="INFO" additivity="false">
    <appender-ref ref="CONSOLE_WEB"/>
  </logger>

  <!-- 必要に応じて個別パッケージにも指定可 -->
  <logger name="com.example.demo.framework.controller" level="INFO" additivity="false">
    <appender-ref ref="CONSOLE_WEB"/>
  </logger>
  <logger name="com.example.demo.framework.service" level="INFO" additivity="false">
    <appender-ref ref="CONSOLE_WEB"/>
  </logger>
  <logger name="com.example.demo.framework.filter" level="INFO" additivity="false">
    <appender-ref ref="CONSOLE_WEB"/>
  </logger>
  <logger name="com.example.demo.framework.config" level="INFO" additivity="false">
    <appender-ref ref="CONSOLE_FW"/>
  </logger>

  <!-- ライブラリ系は冗長にならないよう抑制 -->
  <logger name="org.springframework" level="WARN"/>
  <logger name="org.hibernate" level="WARN"/>

  <!-- フレームワーク自体のログ -->
  <logger name="com.example.demo.framework" level="INFO"/>

  <!-- プロファイルごとの出力レベル -->
  <springProfile name="dev">
    <logger name="com.example.demo" level="INFO"/>
  </springProfile>

  <springProfile name="prod">
    <logger name="com.example.demo" level="INFO"/>
  </springProfile>

</configuration>
  • タイムスタンプ」、「ログレベル」、「ログ出力元クラス名」はこの設定だけでLogpackが自動で出力してくれます。
  • 今回はログの出力先をコンソールに設定
  • ルートロガーのレベルを「INFO」に設定し、全体としては「INFO」レベル以上のログのみ出力するように設定。

共通ログ出力ユーティリティ

アプリケーションから任意のメッセージを指定しログ出力を行うユーティリティクラスです。

package com.example.demo.framework.log;

import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.Objects;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.Supplier;

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

/**
 * Webアプリケーション向け共通ログ出力ユーティリティ。
 *
 * <p>目的
 * <ul>
 *   <li>アプリケーションの各クラスから一貫したログ出力を簡素に行うための軽量ラッパーを提供します。</li>
 *   <li>SLF4J に委譲しつつ、遅延評価(Supplier)とパラメータ化ログの利便性を提供します。</li>
 * </ul>
 *
 * <p>主要仕様
 * <ul>
 *   <li>{@link #getLogger(Class)} は指定クラスに紐づく WebLogger インスタンスを返します。呼び出し側は
 *       {@code private static final WebLogger log = WebLogger.getLogger(MyClass.class);} の形で保持することを推奨します。</li>
 *   <li>パラメータ化ログ("{}")と遅延評価(Supplier)をサポートします。Supplier 版は該当レベルが有効な場合にのみ評価されます。</li>
 *   <li>引数 {@code clazz} が {@code null} の場合、ログ出力のフォーマットを統一するために内部 Logger として
 *       {@code WebLogger.class} の Logger を使用し、エラーメッセージ(初回のみ)を SLF4J 経由で出力します(EMITTED フラグで一度だけ出力)。</li>
 *   <li>MDC の操作や追加コンテキストの注入はこのクラスでは行いません。必要なら別ユーティリティを利用してください。</li>
 *   <li>WARN / ERROR の単純版(String 引数)は常に出力する方針です(内部での二重判定は行いません)。</li>
 * </ul>
 *
 * <p>フェールセーフ動作(clazz が null の場合)
 * <ol>
 *   <li>{@code WebLogger.class} の Logger を内部的に使ってエラーログを出します(ログ出力フォーマットは他のクラスと統一されます)。</li>
 *   <li>このエラーログは同一 JVM 起動中に一度だけ出力されます(過剰なノイズを防ぐため)。</li>
 *   <li>以降返される WebLogger インスタンスは通常モード(WebLogger.class に紐づく Logger)で動作します。</li>
 * </ol>
 *
 * <p>スレッド安全性: インスタンスは不変(immutable)であり、複数スレッドから安全に再利用可能です。
 *
 * <p>利用例
 * <pre>{@code
 * public class MyController {
 *     private static final WebLogger log = WebLogger.getLogger(MyController.class);
 *
 *     public void handle() {
 *         log.info("処理開始");
 *         
 *         //引数の遅延評価ありのログ出力。DEBUGレベルが無効の場合はexpensiveToString()自体が実行されない。
 *         //引数を組み立てるための処理が重い場合はこちらの呼び出し方法を推奨。
 *         log.debug(() -> expensiveToString());
 *
 *         try {
 *             // 処理本体
 *         } catch (Exception e) {
 *             // 例外オブジェクトを指定してログ出力(%msg と %ex に出力される)
 *             log.error("致命的な例外が発生しました", e);
 *         }
 *     }
 * }
 * }</pre>
 */
public final class WebLogger {

    private static final String FALLBACK_MSG =
            "[WebLogger] getLogger called with null clazz — using WebLogger.class as fallback logger. "
            + "Please initialize loggers using WebLogger.getLogger(YourClass.class).";

    // Ensure we emit fallback error only once to avoid spamming logs
    private static final AtomicBoolean FALLBACK_EMITTED = new AtomicBoolean(false);

    private final Logger logger;

    private WebLogger(Logger logger) {
        this.logger = Objects.requireNonNull(logger, "logger must not be null");
    }

    /**
     * 指定されたクラスに紐づく WebLogger インスタンスを返します。
     *
     * <p>仕様:
     * <ul>
     *   <li>clazz が非 null の場合、{@code LoggerFactory.getLogger(clazz)} を内部で使用します。</li>
     *   <li>clazz が null の場合、{@code LoggerFactory.getLogger(WebLogger.class)} を内部で使用し、
     *       一度だけエラーログ(指定ミスの通知)を出力します。</li>
     * </ul>
     *
     * @param clazz ロガー名として使うクラス(null 可)
     * @return WebLogger インスタンス(null 指定時は WebLogger.class に紐づくインスタンスを返す)
     */
    public static WebLogger getLogger(Class<?> clazz) {
        if (clazz == null) {
            Logger fallback = LoggerFactory.getLogger(WebLogger.class);
            emitFallbackErrorOnce(fallback);
            return new WebLogger(fallback);
        }
        return new WebLogger(LoggerFactory.getLogger(clazz));
    }

    private static void emitFallbackErrorOnce(Logger fallback) {
        if (FALLBACK_EMITTED.compareAndSet(false, true)) {
            // Build a helpful stack trace message to assist debugging, but log via SLF4J so format is unified
            StringWriter sw = new StringWriter();
            new Exception("WebLogger.getLogger(null) initialization trace").printStackTrace(new PrintWriter(sw));
            String trace = sw.toString();
            // Use error so it is always visible under the project's error policy
            fallback.error(FALLBACK_MSG + "\n" + trace);
        }
    }

    /* --- isEnabled --- */
    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(); }

    /* --- TRACE --- */
    public void trace(String msg) { if (logger.isTraceEnabled()) logger.trace(msg); }
    public void trace(String format, Object... args) { if (logger.isTraceEnabled()) logger.trace(format, args); }
    public void trace(Supplier<String> msgSupplier) { if (logger.isTraceEnabled() && msgSupplier != null) logger.trace(msgSupplier.get()); }
    public void trace(String msg, Throwable t) { if (logger.isTraceEnabled()) logger.trace(msg, t); }

    /* --- DEBUG --- */
    public void debug(String msg) { if (logger.isDebugEnabled()) logger.debug(msg); }
    public void debug(String format, Object... args) { if (logger.isDebugEnabled()) logger.debug(format, args); }
    public void debug(Supplier<String> msgSupplier) { if (logger.isDebugEnabled() && msgSupplier != null) logger.debug(msgSupplier.get()); }
    public void debug(String msg, Throwable t) { if (logger.isDebugEnabled()) logger.debug(msg, t); }

    /* --- INFO --- */
    public void info(String msg) { if (logger.isInfoEnabled()) logger.info(msg); }
    public void info(String format, Object... args) { if (logger.isInfoEnabled()) logger.info(format, args); }
    public void info(Supplier<String> msgSupplier) { if (logger.isInfoEnabled() && msgSupplier != null) logger.info(msgSupplier.get()); }
    public void info(String msg, Throwable t) { if (logger.isInfoEnabled()) logger.info(msg, t); }

    /* --- WARN --- */
    public void warn(String msg) { logger.warn(msg); }
    public void warn(String format, Object... args) { if (logger.isWarnEnabled()) logger.warn(format, args); }
    public void warn(Supplier<String> msgSupplier) { if (logger.isWarnEnabled() && msgSupplier != null) logger.warn(msgSupplier.get()); }
    public void warn(String msg, Throwable t) { logger.warn(msg, t); }

    /* --- ERROR --- */
    public void error(String msg) { logger.error(msg); }
    public void error(String format, Object... args) { if (logger.isErrorEnabled()) logger.error(format, args); }
    public void error(Supplier<String> msgSupplier) { if (logger.isErrorEnabled() && msgSupplier != null) logger.error(msgSupplier.get()); }
    public void error(String msg, Throwable t) { logger.error(msg, t); }
    public void error(Supplier<String> msgSupplier, Throwable t) { if (logger.isErrorEnabled() && msgSupplier != null) logger.error(msgSupplier.get(), t); }
}

ログ出力ユーティリティを利用したログ出力サンプル

import com.example.demo.framework.log.WebLogger;
import org.springframework.stereotype.Service;

@Service
public class UserService {

    private static final WebLogger log = WebLogger.getLogger(UserService.class);

    public void registerUser(String userName) {
        log.info("ユーザー登録処理開始");

        try {
            // 事前チェック
            if (userName == null || userName.isBlank()) {
                log.warn("ユーザー名が未入力のため、登録処理をスキップ");
                return;
            }

            // 登録処理
            boolean success = saveToDatabase(userName);

            if (success) {
                log.info("ユーザー登録成功: {}", userName);
            } else {
                log.error("ユーザー登録失敗: DB登録エラー");
            }

        } catch (Exception e) {
            log.error("ユーザー登録中に予期せぬ例外が発生", e);
        }
    }

    private boolean saveToDatabase(String userName) {
        return true;
    }
}
  • WebLoggerはクラスフィールドとしてstatic finalで保持
  • メッセージと変数埋め込みはパラメータ化({})を使う
  • 例外はlog.error("msg", e)形式で渡すことで%msg%exに展開されログ出力される
import com.example.service.UserService;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class UserController {

    private final UserService service;

    public UserController(UserService service) {
        this.service = service;
    }

    @GetMapping("/logtest")
    public String testLogging() {
        service.registerUser("taro");
        return "ログ出力テスト完了";
    }
}

SpringBootアプリケーションを起動し、「http://localhost:8080/logtest」へアクセスしテスト用コントローラを実行してみましょう。以下のようなログがコンソールに出力されればOKです。

[2025-10-30T00:28:00.244] INFO  com.example.demo.framework.service.UserService [http-nio-8080-exec-1] [N/A] ユーザー登録処理開始 
[2025-10-30T00:28:00.244] INFO  com.example.demo.framework.service.UserService [http-nio-8080-exec-1] [N/A] ユーザー登録成功: taro 

非同期処理への対応(@Asyncの場合)

1リクエスト内で非同期処理を行った場合、MDCは子スレッドに引き継がれません。そのため何もしないと「リクエストID」、「セッションID」が空になってしまいます。非同期処理の実行方法によって対応方法は変わりますが、ここでは「@Async」を利用した場合にSpringのTaskDecoratorを利用してMDCを引き継ぐ方法を記載します。

Spring の TaskDecorator は、@Asyncなどの非同期処理において実行されるタスク(Runnable)をラップして、実行前後に追加の処理を挿入するためのインタフェースです。

MDCの引き継ぎ処理(TaskDecorator)

import org.slf4j.MDC;
import org.springframework.core.task.TaskDecorator;

import java.util.Map;

/**
 * <h2>MDC伝搬用TaskDecorator</h2>
 * <p>
 * 非同期実行時(SpringのTaskExecutor等)において、
 * 親スレッド(呼び出し元)のMDC(Mapped Diagnostic Context)コンテキストを
 * 子スレッド(実際にRunnableが実行されるスレッド)へ安全に伝搬します。
 * </p>
 *
 * <h3>主な用途</h3>
 * <ul>
 *   <li>主にSpringの{@code @Async}等で利用されるTaskExecutorにセットし、
 *       非同期タスク実行時にリクエストID等のMDC情報を伝搬する用途</li>
 *   <li>ログ出力時にリクエスト単位の識別子やユーザー情報等のトレーサビリティ確保</li>
 * </ul>
 *
 * <h3>動作仕様</h3>
 * <ol>
 *   <li>{@link #decorate(Runnable)}が呼ばれた時点で、親スレッドのMDCコンテキスト(Map)をコピー</li>
 *   <li>戻り値のRunnableでは、run()実行直前にMDCをセットし、実行後(例外時も含む)に必ずMDCをclear</li>
 *   <li>MDCが未設定(null)の場合、子スレッドではMDC.clear()のみ実施</li>
 * </ol>
 *
 * <h3>注意点・適用されないケース</h3>
 * <ul>
 *   <li>このTaskDecoratorは、<b>Spring管理下のTaskExecutor</b>に対してのみ有効です。
 *     <ul>
 *       <li>たとえば、{@code @Async}アノテーションによる非同期実行や、
 *           {@code ThreadPoolTaskExecutor}等にセットした場合のみMDCが伝搬されます。</li>
 *     </ul>
 *   </li>
 *   <li>以下のようなケースでは<b>MDC伝搬はされません</b>ので注意してください:
 *     <ul>
 *       <li>自前で生成した{@code ExecutorService}や{@code new Thread()}等、Spring管理外のスレッド/Executorを利用した場合</li>
 *       <li>Java標準の{@code Executors.newFixedThreadPool()}等で作成したExecutorを直接利用した場合</li>
 *       <li>{@code @Async}でexecutor名を明示的に変え、TaskDecorator未設定のExecutorを利用する場合</li>
 *       <li>Spring Batch、WebFlux、Reactive Streamsなど、TaskDecorator非対応の非同期実行フレームワーク</li>
 *       <li>ApplicationEventPublisher等の非同期イベント処理(別途対策が必要)</li>
 *     </ul>
 *   </li>
 *   <li>MDC自体はスレッドローカル(ThreadLocal)管理のため、<b>巨大な値や重いオブジェクトを入れない</b>こと</li>
 * </ul>
 *
 */
public class MdcTaskDecorator implements TaskDecorator {

    /**
     * 親スレッドのMDCコンテキストを子スレッドに伝搬するためのRunnableを生成します。
     *
     * @param runnable 元の非同期タスク
     * @return MDCコンテキストが伝搬されたRunnable
     */
    @Override
    public Runnable decorate(Runnable runnable) {
        // 親スレッドのMDCコンテキスト(Map<String, String>)を取得(nullの場合もあり)
        Map<String, String> contextMap = MDC.getCopyOfContextMap();

        return () -> {
            if (contextMap != null) {
                // 子スレッドに親のMDCコンテキストをセット
                MDC.setContextMap(contextMap);
            }
            try {
                // 元のRunnableを実行
                runnable.run();
            } finally {
                // 子スレッドでMDCをクリア(リーク防止)
                MDC.clear();
            }
        };
    }
}

ラップしたTaskDecoratorの登録

package com.example.demo.framework.config;

import org.springframework.beans.factory.annotation.Value;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.scheduling.annotation.EnableAsync;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

import com.example.demo.framework.log.MdcTaskDecorator;

/**
 * 非同期処理(@Async)を有効化し、MDC伝搬対応のスレッドプールを提供する設定クラスです。
 *
 * <ul>
 *   <li>コアスレッド数(corePoolSize)は外部プロパティから読み込みます。(環境により切り替え)<br>
 *     設定プロパティ名:<b>async.executor.corePoolSize</b><br>
 *   <li>最大スレッド数(maxPoolSize): プールが一時的に増加できるスレッドの最大数。デフォルト値はInteger.MAX_VALUEです。</li>
 *   <li>タスクキューの最大数(queueCapacity): スレッドが足りない場合にタスクを一時的に保持するキューの容量。デフォルト値はInteger.MAX_VALUEです。</li>
 *   <li>MDC伝搬: ログのトレース情報等を非同期スレッドにも引き継ぐための仕組みです。</li>
 * </ul>
 *
 * <p>
 * <b>【具体例】</b><br>
 * コアスレッド数: 10, 最大スレッド数: 50, キューサイズ: 1000 の場合の挙動は以下の通りです。<br>
 * <ol>
 *   <li>同時に10件まではスレッド(コア)で即実行される。</li>
 *   <li>11件目~1,010件目まではキューに蓄積され、順次実行される。</li>
 *   <li>1,011件目~1,050件目までは、(キューが満杯なので)スレッド数をコア超えで最大50まで増やして実行される。</li>
 *   <li>1,051件目以降はRejectedExecutionException(デフォルト動作)となり、タスクが拒否される。</li>
 * </ol>
 * </p>
 */
@Configuration
@EnableAsync // 非同期処理を有効化
public class AsyncConfig {

    /**
     * 非同期処理用のThreadPoolTaskExecutorを生成します。
     *
     * <p>
     * コアスレッド数(corePoolSize)は外部プロパティ
     * <b>async.executor.corePoolSize</b> で切り替え可能です。
     * </p>
     *
     * @param corePoolSize スレッドプールのコアスレッド数(外部プロパティで環境ごとに切り替え)
     * @return 非同期タスク実行用のスレッドプールExecutor
     */
    @Bean(name = "asyncTaskExecutor")
    ThreadPoolTaskExecutor taskExecutor(
            @Value("${async.executor.corePoolSize:8}") int corePoolSize 
    ) {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();

        // コアスレッド数(corePoolSize)は外部プロパティで設定
        executor.setCorePoolSize(corePoolSize);
        
        // 最大スレッド数。
        // タスクが多く、キューも満杯になった場合に最大どこまでスレッド数を増やすかの上限です。
        // デフォルト値はInteger.MAX_VALUE。
        // executor.setMaxPoolSize(50);

        // タスクキューの最大数。
        // スレッドが足りず即時実行できないタスクを一時的にためておくキューの容量です。
        // デフォルト値はInteger.MAX_VALUE。
        // executor.setQueueCapacity(1000);

        // スレッド名の接頭辞を設定(スレッドダンプやログで識別しやすくするため)
        executor.setThreadNamePrefix("AsyncTask-");

        // MDCの伝搬を有効化(親スレッドのログコンテキストを非同期タスクにも引き継ぐ)
        executor.setTaskDecorator(new MdcTaskDecorator());

        // シャットダウン時に、現在実行中のタスクが完了するまで待機する
        executor.setWaitForTasksToCompleteOnShutdown(true);

        // シャットダウン時の待機最大秒数(30秒まで待機し、未完了タスクは強制終了)
        executor.setAwaitTerminationSeconds(30);

        // スレッドプールの初期化(明示的に呼び出し。Spring管理下なら自動でも呼ばれる)
        executor.initialize();

        return executor;
    }
}

TaskDecoratorの登録に加えて「@EnableAsync」を付与し、非同期処理を有効化しています。非同期処理を有効化しておかないと見た目上は動作していても、非同期処理が同一スレッド上で動いているだけ・・という事もあるので注意してください。

ThreadPoolTaskExecutor設定用のプロパティファイル

ThreadPoolTaskExecutorのコアスレッド数(corePoolSize)は、CPUコア数に応じて変更することを想定しているため外部ファイル化します。

# このファイルは共通設定です。
# 個別の環境ごとの設定は application-dev.yml や application-prod.yml で上書きできます。
spring:
  application:
    name: demo  # アプリケーション名(全環境共通で利用)
  profiles:
    active: prod  # デフォルトは本番プロファイル(prod)を有効化
async:
  executor:
    # 非同期タスク実行用スレッドプールのコアスレッド数
    # (@Async等で非同期実行されるタスクが同時並行で動作できる最小数)
    # 開発環境では本番より負荷が小さいことを想定し、4に設定
    corePoolSize: 4
async:
  executor:
    # 非同期タスク実行用スレッドプールのコアスレッド数
    # (@Async等で非同期実行されるタスクが同時並行で動作できる最小数)
    # 本番環境ではサーバスペックに合わせて8に設定
    corePoolSize: 8

非同期処理のログ出力サンプル

@Asyncの非同期処理でもMDCが引き継がれることを確認するログ出力サンプルです。

import java.util.UUID;

import org.slf4j.MDC;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

import com.example.demo.framework.log.WebLogger;
import com.example.demo.framework.service.AsyncService;

@RestController
public class AsyncController {

    @Autowired
    private AsyncService asyncService;
    
    private static final WebLogger log = WebLogger.getLogger(AsyncController.class);

    @GetMapping("/asynclog")
    public String asynclog() {
        // リクエストごとにtraceIdを生成してMDCにセット
        String traceId = UUID.randomUUID().toString();
        MDC.put("traceId", traceId);

        // 親スレッド側ログ
        String msg = "親スレッド: traceId=" + MDC.get("traceId");
        log.info(msg);

        // 非同期メソッド呼び出し
        asyncService.helloAsync();

        // 応答(レスポンス)
        return "Asyncログ出力テスト完了";
    }
}
import org.slf4j.MDC;
import org.springframework.scheduling.annotation.Async;
import org.springframework.stereotype.Service;

import com.example.demo.framework.log.WebLogger;

@Service
public class AsyncService {
    private static final WebLogger log = WebLogger.getLogger(AsyncService.class);

    @Async
    public void helloAsync() {
        String msg = "子スレッド: traceId=" + MDC.get("traceId");
        log.info(msg);
    }
}

共通ログ項目のMDC設定

ここまででログを出力する基盤が出来ました。次にリクエストIDやリクエストURLなどの共通ログ項目を基盤側で自動でMDCに設定する機能を実装していきます。MDCに設定することでアプリケーションの独自ログ出力時や、基盤側のService実行前後などでログ出力した際に共通ログ項目が自動で出力されるようになります。

MDC操作ユーティリティ、定数

MDCのクリアなど、MDCコンテキストを操作するためのユーティリティと定数クラスを用意します。

package com.example.demo.framework.log;

import java.text.SimpleDateFormat;
import java.util.Collections;
import java.util.Date;
import java.util.Map;
import java.util.UUID;
import java.util.concurrent.Callable;

import org.slf4j.MDC;

/**
 * MDCコンテキスト操作のための共通ユーティリティクラス。
 * <p>
 * 主な用途:
 * <ul>
 *   <li>現在のMDCコンテキストの取得・復元</li>
 *   <li>MDCの明示的なクリア</li>
 *   <li>スレッド間(非同期)でのMDC伝搬支援</li>
 *   <li>asyncMethod(非同期処理識別子)のMDCセット</li>
 *   <li>リクエストIDの生成</li>
 * </ul>
 */
public final class MdcContextUtil {

    private MdcContextUtil() {
        // インスタンス化防止
    }

    /**
     * システム独自のリクエストID(UUID + 日付(yyyyMMddHHmmss))を生成します。
     * 例: c8551cd1-4f93-47c3-bb6b-4eb63e99fdcb_20251101020719
     *
     * @return 独自リクエストID
     */
    public static String generateCustomRequestId() {
        String uuid = UUID.randomUUID().toString();
        String ymdhms = new SimpleDateFormat("yyyyMMddHHmmss").format(new Date());
        return uuid + "_" + ymdhms;
    }  
    
    /**
     * 指定されたクラス・メソッド名情報から MdcKeyNames.ASYNC_METHOD をMDCに明示的にセットします。
     *
     * @param clazz クラス
     * @param methodName メソッド名
     */
    public static void putAsyncMethod(Class<?> clazz, String methodName) {
        if (clazz == null || methodName == null) {
            throw new IllegalArgumentException("clazz/methodName must not be null");
        }
        MDC.put(MdcKeyNames.ASYNC_METHOD, clazz.getName() + "." + methodName);
    }

    /**
     * 現在のMDCコンテキストを取得します。
     * @return MDC内容(変更不可Map)。MDCが空の場合は空Mapを返す。
     */
    public static Map<String, String> capture() {
        Map<String, String> context = MDC.getCopyOfContextMap();
        return context != null ? context : Collections.emptyMap();
    }

    /**
     * 指定したMDCコンテキストを現在のスレッドに復元します。
     * 既存のMDC内容はクリアされます。
     * @param context 復元するMDCコンテキスト(nullの場合はMDCをクリアのみ)
     */
    public static void restore(Map<String, String> context) {
        MDC.clear();
        if (context != null) {
            MDC.setContextMap(context);
        }
    }

    /**
     * MDCを全クリアします。明示的な終了処理等に利用してください。
     */
    public static void clear() {
        MDC.clear();
    }

    /**
     * 指定されたRunnableを、呼び出し元のMDCコンテキストごとラップします。
     * スレッドが切り替わる非同期処理で利用してください。
     * @param task ラップするRunnable
     * @return MDCコンテキストを伝搬するRunnable
     */
    public static Runnable wrapWithMdcContext(Runnable task) {
        Map<String, String> context = capture();
        return () -> {
            restore(context);
            try {
                task.run();
            } finally {
                clear();
            }
        };
    }

    /**
     * 指定されたCallableを、呼び出し元のMDCコンテキストごとラップします。
     * @param task ラップするCallable
     * @param <T> 戻り値の型
     * @return MDCコンテキストを伝搬するCallable
     */
    public static <T> Callable<T> wrapWithMdcContext(Callable<T> task) {
        Map<String, String> context = capture();
        return () -> {
            restore(context);
            try {
                return task.call();
            } finally {
                clear();
            }
        };
    }
}

MDC設定キー用の定数クラス。

package com.example.demo.framework.log;

/**
 * MDCキー名を一元管理する定数クラス。
 * 必要に応じて追加してください。
 */
public final class MdcKeyNames {
    private MdcKeyNames() {}

    public static final String REQUEST_ID = "requestId";
    public static final String REQUEST_URI = "requestUri";
    public static final String HTTP_METHOD = "httpMethod";
    public static final String ASYNC_METHOD = "asyncMethod"; // 非同期処理の識別子用キー
    // 必要に応じて追加
}

MDC設定初期化用フィルター

MDCにログ共通項目を設定するフィルターを作成します。

package com.example.demo.framework.filter;

import java.io.IOException;

import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.web.filter.OncePerRequestFilter;

import com.example.demo.framework.log.MdcContextUtil;
import com.example.demo.framework.log.MdcKeyNames;

/**
 * <h2>LoggingInitializeFilter</h2>
 * <p>
 * HTTPリクエスト単位でMDCに共通情報(リクエストID、リクエストURI、HTTPメソッド)を自動設定するフィルタです。<br>
 * ・リクエストIDはUUIDと日付(yyyyMMddss)を結合し、システム独自で毎リクエストごとに生成します。<br>
 * ・外部からのX-Request-Id等のヘッダー値は一切使用しません。<br>
 * ・リクエスト処理後はMDCの内容を完全にクリアします。<br>
 * ・OncePerRequestFilterを継承することで、1リクエストにつき1回のみ実行されることが保証されます。<br>
 * </p>
 */
public class LoggingInitializeFilter extends OncePerRequestFilter {

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

    /**
     * 1リクエストにつき1回のみ呼び出され、MDCへの共通情報設定・クリアを行う。
     *
     * @param request     HTTPリクエスト
     * @param filterChain フィルタチェーン
     * @throws ServletException
     * @throws IOException
     */
    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
            throws ServletException, IOException {
    	
        try {
	        	String requestId = request.getHeader("X-Request-Id");
	        	if (requestId == null || requestId.isEmpty()) {
	            // システム独自のリクエストID発番(UUID+日付(yyyyMMddss))
	        	    requestId = MdcContextUtil.generateCustomRequestId();
	        	}
	        	MDC.put(MdcKeyNames.REQUEST_ID, requestId);

            // MDCにリクエストID、URI、HTTPメソッドを格納
            MDC.put(MdcKeyNames.REQUEST_ID, requestId);
            MDC.put(MdcKeyNames.REQUEST_URI, request.getRequestURI());
            MDC.put(MdcKeyNames.HTTP_METHOD, request.getMethod());

            // チェーン継続
            filterChain.doFilter(request, response);

        } finally {
            // 全てのリクエスト終了時にMDCを完全クリア
            MdcContextUtil.clear();
        }
    }
}

上記のLoggingInitializeFilterを実行順序付きで登録するためにConfigクラスを作成します。「@Component」で登録した場合、フィルタの実行順序は制御出来ません。@Orderを利用すると実行順序指定は可能ですが、今後共通フィルタが増えることを想定し、一元管理するためにフィルタの登録クラスを作成します。

package com.example.demo.framework.filter;

import java.io.IOException;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.UUID;

import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.web.filter.OncePerRequestFilter;

import com.example.demo.framework.log.MdcContextUtil;
import com.example.demo.framework.log.MdcKeyNames;

/**
 * <h2>LoggingInitializeFilter</h2>
 * <p>
 * HTTPリクエスト単位でMDCに共通情報(リクエストID、リクエストURI、HTTPメソッド)を自動設定するフィルタです。<br>
 * ・リクエストIDはUUIDと日付(yyyyMMddss)を結合し、システム独自で毎リクエストごとに生成します。<br>
 * ・外部からのX-Request-Id等のヘッダー値は一切使用しません。<br>
 * ・リクエスト処理後はMDCの内容を完全にクリアします。<br>
 * ・OncePerRequestFilterを継承することで、1リクエストにつき1回のみ実行されることが保証されます。<br>
 * </p>
 */
public class LoggingInitializeFilter extends OncePerRequestFilter {

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

    /**
     * 1リクエストにつき1回のみ呼び出され、MDCへの共通情報設定・クリアを行う。
     *
     * @param request     HTTPリクエスト
     * @param filterChain フィルタチェーン
     * @throws ServletException
     * @throws IOException
     */
    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
            throws ServletException, IOException {
    	
        try {
	        	String requestId = request.getHeader("X-Request-Id");
	        	System.out.println("X-Request-Id Header: " + requestId);
	        	if (requestId == null || requestId.isEmpty()) {
	            // システム独自のリクエストID発番(UUID+日付(yyyyMMddss))
	        	    requestId = generateCustomRequestId();
	        	}
	        	MDC.put(MdcKeyNames.REQUEST_ID, requestId);

            // MDCにリクエストID、URI、HTTPメソッドを格納
            MDC.put(MdcKeyNames.REQUEST_ID, requestId);
            MDC.put(MdcKeyNames.REQUEST_URI, request.getRequestURI());
            MDC.put(MdcKeyNames.HTTP_METHOD, request.getMethod());

            // チェーン継続
            filterChain.doFilter(request, response);

        } finally {
            // 全てのリクエスト終了時にMDCを完全クリア
            MdcContextUtil.clear();
        }
    }

    /**
     * システム独自のリクエストID(UUID + 日付(yyyyMMddHHmmss))を生成します。
     * 例: c8551cd1-4f93-47c3-bb6b-4eb63e99fdcb_20251101020719
     *
     * @return 独自リクエストID
     */
    private String generateCustomRequestId() {
        String uuid = UUID.randomUUID().toString();
        String ymdhms = new SimpleDateFormat("yyyyMMddHHmmss").format(new Date());
        return uuid + "_" + ymdhms;
    }
}

バックエンド側の共通ログ自動出力

バックエンド側で以下のタイミングで自動で開始、終了ログを出力するようにします。開始終了ログの紐づけが可能なよう、独自のリクエストIDを発行しログに含めます。
・Controller実行前後
・Service実行前後
・Async実行前後
・WebClient実行前後

ログには共通ログ項目に加え、呼び出しクラス名とメソッド名を出力します。
入力パラメータ、HTTPヘッダ情報は個人情報やセキュリティ情報が含まれるためログ出力はしていません。

加えてAsyncの場合はパフォーマンスも見れるように処理時間もログ出力します。
WebClientの場合はリクエストURL、HTTPメソッドもログ出力します。

Controller実行前後のログ出力

AOPを利用しすべてのControllerの実行前後でログを出力します。パラメータには個人情報や機微情報が含まれるため出力しません。

package com.example.demo.framework.log;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.*;
import org.springframework.stereotype.Component;

/**
 * <h2>ControllerLoggingAspect</h2>
 * <p>
 * 全てのControllerクラスのpublicメソッド実行前後にログを出力するAOPアスペクトです。<br>
 * 実行開始・終了・例外発生時に、独自のWebLoggerインスタンスを介してログを記録します。<br>
 * ※個人情報・機微情報保護のため、メソッド引数(パラメータ)はログ出力しません。<br>
 * </p>
 */
@Aspect
@Component
public class ControllerLoggingAspect {

    /**
     * このアスペクト専用のWebLoggerインスタンス。
     */
    private static final WebLogger log = WebLogger.getLogger(ControllerLoggingAspect.class);

    /**
     * Controllerの全publicメソッドをポイントカット。
     * RestController, Controllerアノテーションが付与されたクラスを対象とする。
     */
    @Pointcut("within(@org.springframework.web.bind.annotation.RestController *) || within(@org.springframework.stereotype.Controller *)")
    public void controllerMethods() {}

    /**
     * Controllerメソッド実行前にログ出力(引数は出力しない)。
     *
     * @param joinPoint ジョインポイント
     */
    @Before("controllerMethods()")
    public void beforeController(JoinPoint joinPoint) {
        log.info("【START】{}.{}",
            joinPoint.getSignature().getDeclaringTypeName(),
            joinPoint.getSignature().getName());
    }

    /**
     * Controllerメソッド実行後(正常終了時)にログ出力。
     *
     * @param joinPoint ジョインポイント
     * @param result    戻り値
     */
    @AfterReturning(pointcut = "controllerMethods()", returning = "result")
    public void afterReturningController(JoinPoint joinPoint, Object result) {
        log.info("【END】{}.{}",
            joinPoint.getSignature().getDeclaringTypeName(),
            joinPoint.getSignature().getName());
    }

    /**
     * Controllerメソッド実行中に例外発生時、エラーログ出力。
     *
     * @param joinPoint ジョインポイント
     * @param ex        例外
     */
    @AfterThrowing(pointcut = "controllerMethods()", throwing = "ex")
    public void afterThrowingController(JoinPoint joinPoint, Throwable ex) {
        log.error("【EXCEPTION】{}.{} ex={}",
            joinPoint.getSignature().getDeclaringTypeName(),
            joinPoint.getSignature().getName(),
            ex.toString(), ex);
    }
}

Service実行前後のログ出力

ServiceもControllerと同じように実行前後でログを出力します。

package com.example.demo.framework.log;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;

/**
 * <h2>ServiceLoggingAspect</h2>
 * <p>
 * 全てのServiceクラスのpublicメソッド実行前後にログを出力するAOPアスペクトです。<br>
 * 実行開始・終了・例外発生時に、独自のWebLoggerインスタンスを介してログを記録します。<br>
 * ※個人情報・機微情報保護のため、メソッド引数(パラメータ)はログ出力しません。<br>
 * </p>
 */
@Aspect
@Component
public class ServiceLoggingAspect {

    /**
     * このアスペクト専用のWebLoggerインスタンス。
     */
    private static final WebLogger log = WebLogger.getLogger(ServiceLoggingAspect.class);

    /**
     * Serviceの全publicメソッドをポイントカット。
     * Serviceアノテーションが付与されたクラスを対象とする。
     */
    @Pointcut("within(@org.springframework.stereotype.Service *)")
    public void serviceMethods() {}

    /**
     * Serviceメソッド実行前にログ出力(引数は出力しない)。
     *
     * @param joinPoint ジョインポイント
     */
    @Before("serviceMethods()")
    public void beforeService(JoinPoint joinPoint) {
        log.info("【START】{}.{}",
            joinPoint.getSignature().getDeclaringTypeName(),
            joinPoint.getSignature().getName());
    }

    /**
     * Serviceメソッド実行後(正常終了時)にログ出力。
     *
     * @param joinPoint ジョインポイント
     * @param result    戻り値
     */
    @AfterReturning(pointcut = "serviceMethods()", returning = "result")
    public void afterReturningService(JoinPoint joinPoint, Object result) {
        log.info("【END】{}.{}",
            joinPoint.getSignature().getDeclaringTypeName(),
            joinPoint.getSignature().getName());
    }

    /**
     * Serviceメソッド実行中に例外発生時、エラーログ出力。
     *
     * @param joinPoint ジョインポイント
     * @param ex        例外
     */
    @AfterThrowing(pointcut = "serviceMethods()", throwing = "ex")
    public void afterThrowingService(JoinPoint joinPoint, Throwable ex) {
        log.error("【EXCEPTION】{}.{} ex={}",
            joinPoint.getSignature().getDeclaringTypeName(),
            joinPoint.getSignature().getName(),
            ex.toString(), ex);
    }
}

Async実行前後のログ出力

package com.example.demo.framework.log;

import java.util.Map;

import org.slf4j.MDC;
import org.springframework.core.task.TaskDecorator;

/**
 * <h2>MDC伝搬用TaskDecorator</h2>
 * <p>
 * 非同期実行時(SpringのTaskExecutor等)において、
 * 親スレッド(呼び出し元)のMDC(Mapped Diagnostic Context)コンテキストを
 * 子スレッド(実際にRunnableが実行されるスレッド)へ安全に伝搬します。
 * </p>
 *
 * <h3>主な用途</h3>
 * <ul>
 *   <li>主にSpringの{@code @Async}等で利用されるTaskExecutorにセットし、
 *       非同期タスク実行時にリクエストID等のMDC情報を伝搬する用途</li>
 *   <li>ログ出力時にリクエスト単位の識別子やユーザー情報等のトレーサビリティ確保</li>
 * </ul>
 *
 * <h3>動作仕様</h3>
 * <ol>
 *   <li>{@link #decorate(Runnable)}が呼ばれた時点で、親スレッドのMDCコンテキスト(Map)をコピー</li>
 *   <li>戻り値のRunnableでは、run()実行直前にMDCをセットし、実行前に<b>開始ログ</b>、正常終了時に<b>終了ログ</b>、例外発生時に<b>例外ログ</b>を出力する</li>
 *   <li>実行後(例外時も含む)に必ずMDCを元の状態に戻す</li>
 *   <li>MDCが未設定(null)の場合、子スレッドではMDC.clear()のみ実施</li>
 * </ol>
 *
 * <h3>ログ出力内容</h3>
 * <ul>
 *   <li>【ASYNC START】非同期タスク実行開始(MDCでセットされていればクラス・メソッド名を含める)</li>
 *   <li>【ASYNC END】  非同期タスク実行正常終了(MDCでセットされていればクラス・メソッド名・経過時間を含める)</li>
 *   <li>【ASYNC EX】   非同期タスク実行中例外発生(MDCでセットされていればクラス・メソッド名・例外内容を含める)</li>
 * </ul>
 *
 * <h3>注意点・適用されないケース</h3>
 * <ul>
 *   <li>このTaskDecoratorは、<b>Spring管理下のTaskExecutor</b>に対してのみ有効です。
 *     <ul>
 *       <li>たとえば、{@code @Async}アノテーションによる非同期実行や、
 *           {@code ThreadPoolTaskExecutor}等にセットした場合のみMDCが伝搬されます。</li>
 *     </ul>
 *   </li>
 *   <li>以下のようなケースでは<b>MDC伝搬はされません</b>ので注意してください:
 *     <ul>
 *       <li>自前で生成した{@code ExecutorService}や{@code new Thread()}等、Spring管理外のスレッド/Executorを利用した場合</li>
 *       <li>Java標準の{@code Executors.newFixedThreadPool()}等で作成したExecutorを直接利用した場合</li>
 *       <li>{@code @Async}でexecutor名を明示的に変え、TaskDecorator未設定のExecutorを利用する場合</li>
 *       <li>Spring Batch、WebFlux、Reactive Streamsなど、TaskDecorator非対応の非同期実行フレームワーク</li>
 *       <li>ApplicationEventPublisher等の非同期イベント処理(別途対策が必要)</li>
 *     </ul>
 *   </li>
 *   <li>クラス名・メソッド名はMDCContextUtil#putAsyncMethodを利用し呼び出し側でセットしてください</li>
 * </ul>
 *
 */
public class MdcTaskDecorator implements TaskDecorator {

    private static final WebLogger log = WebLogger.getLogger(MdcTaskDecorator.class);

    /**
     * 親スレッドのMDCコンテキストを子スレッドに伝搬しつつ、
     * 実行開始時・終了時・例外発生時にログを出力します。
     *
     * クラス名・メソッド名は呼び出し側でMDCキー("asyncMethod"等)へセットしてください。
     * 
     * @param runnable 元の非同期タスク
     * @return MDCコンテキストが伝搬されたRunnable
     */
    @Override
    public Runnable decorate(Runnable runnable) {
        // 親スレッドのMDCコンテキスト(Map<String, String>)を取得(nullの場合もあり)
        final Map<String, String> contextMap = MDC.getCopyOfContextMap();

        return () -> {
            // 実行スレッドの既存MDCを保管
            final Map<String, String> previous = MDC.getCopyOfContextMap();
            try {
                if (contextMap != null) {
                    // 子スレッドに親のMDCコンテキストをセット
                    MDC.setContextMap(contextMap);
                } else {
                    MDC.clear();
                }

                // クラス名・メソッド名(MDCにセットされていれば付与)
                String asyncMethod = MDC.get("asyncMethod");
                if (asyncMethod != null && !asyncMethod.isEmpty()) {
                    log.info("【ASYNC START】thread={} method={}", Thread.currentThread().getName(), asyncMethod);
                } else {
                    log.info("【ASYNC START】thread={}", Thread.currentThread().getName());
                }

                final long start = System.currentTimeMillis();
                try {
                    runnable.run();
                    final long elapsed = System.currentTimeMillis() - start;
                    if (asyncMethod != null && !asyncMethod.isEmpty()) {
                        log.info("【ASYNC END】thread={} method={} elapsed={}ms", Thread.currentThread().getName(), asyncMethod, elapsed);
                    } else {
                        log.info("【ASYNC END】thread={} elapsed={}ms", Thread.currentThread().getName(), elapsed);
                    }
                } catch (Throwable t) {
                    if (asyncMethod != null && !asyncMethod.isEmpty()) {
                        log.error("【ASYNC EX】thread={} method={} ex={}", Thread.currentThread().getName(), asyncMethod, t.toString(), t);
                    } else {
                        log.error("【ASYNC EX】thread={} ex={}", Thread.currentThread().getName(), t.toString(), t);
                    }
                    throw t;
                }

            } finally {
                // 終了時にMDCを元の状態に戻す
                if (previous != null) {
                    MDC.setContextMap(previous);
                } else {
                    MDC.clear();
                }
            }
        };
    }
}

Asyncについては処理時間を見たいケースもあると考え、処理時間をログに追加しています。AsyncではServiceやControllerと異なり、単純には呼び出し元クラス名、メソッド名が取得出来ないため、次のように「MdcContextUtil.putAsyncMethod」を利用し、呼び出し側のアプリケーション側でセットする方針とします。

@RestController
public class AsyncController {

    @Autowired
    private AsyncService asyncService;
    
    private static final WebLogger log = WebLogger.getLogger(AsyncController.class);

    @GetMapping("/asynclog")
    public String asynclog() {

        // 非同期呼び出しするクラス名、メソッド名をMDCにセット
    		MdcContextUtil.putAsyncMethod(AsyncController.class, ".asynclog");
    	
        // 非同期メソッド呼び出し
        asyncService.helloAsync();

        // 応答(レスポンス)
        return "Asyncログ出力テスト完了";
    }
}

MDCクリア

MDCが確実にクリアされるようにリクエスト前後にMDCをクリアするフィルタを作成しておきます。

import java.io.IOException;

import jakarta.servlet.Filter;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.ServletRequest;
import jakarta.servlet.ServletResponse;

import org.slf4j.MDC;
import org.springframework.stereotype.Component;

/**
 * リクエスト毎にMDCを必ず初期化・クリアするフィルタ。
 */
@Component
public class MdcClearFilter implements Filter {
    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
            throws IOException, ServletException {
        try {
            MDC.clear();
            chain.doFilter(request, response);
        } finally {
            MDC.clear();
            System.out.println("MDC cleared by MdcClearFilter");
        }
    }
}

WebClientの実行前後のログ出力

pom.xmlに利用する以下のライブラリを追加します。

		<dependency>
		  <groupId>org.springframework.boot</groupId>
		  <artifactId>spring-boot-starter-webflux</artifactId>
		</dependency>

WebClientの実行前後にログ出力します。
ServiceとControllerのリクエストIDをセットできるのでは?

package com.example.demo.framework.config;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.reactive.function.client.ClientRequest;
import org.springframework.web.reactive.function.client.WebClient;

import com.example.demo.framework.log.MdcContextUtil;

/**
 * <h2>LoggingWebClientConfig</h2>
 * <p>
 * WebClientのリクエストにフィルターをチェインし、各通信ごとに独自リクエストID(UUID+日付)でログを詳細に出力する設定クラスです。
 *
 * <h3>ログ出力のタイミングと内容</h3>
 * <ul>
 *   <li><b>リクエスト送信直前(START):</b><br>
 *     <code>【WEBCLIENT START】requestId=[独自ID] method=[HTTPメソッド] url=[リクエストURL]</code>
 *     <ul>
 *       <li>requestId : UUID+日付の一意リクエストID(例: b2e08c34-1c37-4498-b550-548965a98c19_20251106083023)</li>
 *       <li>method : GET/POSTなど</li>
 *       <li>url : 外部APIのエンドポイントURL</li>
 *     </ul>
 *   </li>
 *   <li><b>正常レスポンス受信時(END):</b><br>
 *     <code>【WEBCLIENT END】requestId=[独自ID] status=[HTTPステータス]</code>
 *     <ul>
 *       <li>requestId : リクエストと同じ独自ID</li>
 *       <li>status : HTTPステータス(例: 200 OK, 404 Not Found, ...)</li>
 *     </ul>
 *   </li>
 *   <li><b>例外発生時(ERROR):</b><br>
 *     <code>【WEBCLIENT ERROR】requestId=[独自ID]. [例外型]: [例外メッセージ]</code>
 *     <ul>
 *       <li>requestId : リクエストと同じ独自ID</li>
 *       <li>例外型 : 例外のクラス名(WebClientResponseException等)</li>
 *       <li>例外メッセージ : エラー内容</li>
 *     </ul>
 *   </li>
 * </ul>
 *
 * <h3>設計方針・注意点</h3>
 * <ul>
 *   <li>入力パラメータ、HTTPリクエストヘッダーなど機微情報、秘匿情報はログに出力しません</li>
 * </ul>
 */
@Configuration
public class LoggingWebClientConfig {

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

    /** ClientRequest#attributesに格納する独自リクエストIDのキー */
    private static final String ATTR_KEY_REQUEST_ID = "KEY-WEBCLIENT-CUSTOMREQUESTID";

    /**
     * WebClient Bean定義(requestId付きロギング用フィルタチェイン)
     *
     * @return ロギング機能付きWebClientインスタンス
     */
    @Bean
    public WebClient webClient() {
        return WebClient.builder()
            // リクエスト直前フィルタ: requestId生成→attributes格納→開始ログ出力
            .filter((request, next) -> {
                // 独自リクエストID(UUID+日付)を新規生成
                String requestId = MdcContextUtil.generateCustomRequestId();

                // attributes(リクエスト属性)にrequestIdを格納した新しいClientRequestを生成
                ClientRequest newRequest = ClientRequest.from(request)
                        .attribute(ATTR_KEY_REQUEST_ID, requestId)
                        .build();

                // リクエスト開始ログ(method, URL, requestIdのみ出力。ヘッダー等は出力しない)
                log.info("【WEBCLIENT START】requestId={} method={} url={}", requestId, request.method(), request.url());

                // 次のフィルタ/実処理へ
                return next.exchange(newRequest);
            })
            // レスポンス/エラー時フィルタ: attributesからrequestId取得→終了/エラーログ出力
            .filter((request, next) ->
                next.exchange(request)
                    // 正常レスポンス時
                    .doOnNext(response -> {
                        // attributesからrequestIdを取得
                        String requestId = request.attribute(ATTR_KEY_REQUEST_ID)
                                .map(String.class::cast)
                                .orElse("N/A");
                        // レスポンス終了ログ(requestIdとステータスのみ)
                        log.info("【WEBCLIENT END】requestId={} status={}", requestId, response.statusCode());
                    })
                    // 例外発生時
                    .doOnError(ex -> {
                        // attributesからrequestIdを安全に取得
                        String requestId = request.attribute(ATTR_KEY_REQUEST_ID)
                                .map(String.class::cast)
                                .orElse("N/A");
                        // エラーログ(requestId、例外型、例外メッセージ。ヘッダー等は出力しない)
                        log.error("【WEBCLIENT ERROR】requestId={}. {}: {}", requestId, ex.getClass().getSimpleName(), ex.getMessage(), ex);
                    })
            )
            .build();
    }
}

WebClientのログ出力確認用テストアプリケーション

WebClientのログ出力を確認するためのサンプルアプリケーションです。

package com.example.demo.framework.controller;

import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.reactive.function.client.WebClient;

import reactor.core.publisher.Mono;

/**
 * <h2>WebClient のログ出力確認用コントローラ</h2>
 * <p>
 * GET /webclientlog にアクセスすると外部API(httpbin.org/get)へWebClientリクエストを送信。
 * ログにはLoggingWebClientConfigで設定されたrequestId付きログが出力される。
 * </p>
 */
@RestController
public class WebClientTestController {

    private final WebClient webClient;

    // DIでLoggingWebClientConfigのWebClient Beanを受け取る
    public WebClientTestController(WebClient webClient) {
        this.webClient = webClient;
    }

    @GetMapping("/webclientlog")
    public Mono<String> helloWorldApi() {
        // 外部APIへリクエスト(GET)し、結果のbody(JSON文字列)をそのまま返す
        return webClient.get()
                .uri("https://jsonplaceholder.typicode.com/todos/1")
                .retrieve()
                .bodyToMono(String.class);
    }
}

参考URL

以上

タイトルとURLをコピーしました