環境：Spring Boot 3.4.1

1.概要

プロジェクト開発において、各リクエストのログ情報を効果的に管理・追跡することは、デバッグや監視において非常に重要です。SLF4J（Simple Logging Facade for Java）は統一されたログ記録インターフェースを提供し、その中でもMDC（Mapped Diagnostic Context）は強力な機能の1つです。MDCを使用すると、ログ記録にコンテキスト情報を追加することができます。Spring BootでMDCを使用することで、各リクエストの全リンクトレーシング（フルチェーントレース）を実現することが可能です。

MDCはSLF4Jが提供するクラスであり、ユーザーのコンテキスト情報をMDC（マッピング診断コンテキスト）に格納できます。以下はMDCクラスのメソッドシグネチャです：

public class MDC {
    // 現在のスレッドコンテキスト（ThreadLocal）にキー/値を格納する
    public static void put(String key, String val);

    // 現在のスレッドコンテキストから指定されたキーの値を取得する
    public static String get(String key);

    // 現在のスレッドコンテキストから指定されたキーを削除する
    public static void remove(String key);

    // 現在のスレッドコンテキストのすべてのデータをクリアする
    public static void clear();
}

MDCクラスの詳細について知りたい場合は、該当するAPIドキュメントをご確認ください。

本記事では以下の側面からMDCについて紹介します。

1.クイックスタート
2.データベースを基盤とした完全なアプリケーションの実例
3.スレッド間の問題（例：@Asyncの使用）
4.一意の識別子traceIdの統一出力とクライアントへの返却
5.便利な内蔵フィルター

2. クイックスタート

使用方法は非常に簡単で、MDCの対応する静的メソッドを呼び出すだけです。以下に例を示します：

package com.jojo.boot.springbootmdc;

import org.junit.jupiter.api.Test;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.boot.test.context.SpringBootTest;

@SpringBootTest
class MDCTests {

    @Test
    void testMDC() {
        // ロガーの作成
        Logger logger = LoggerFactory.getLogger(MDCTest.class);

        // 現在のスレッドコンテキストにtraceXIdを格納
        MDC.put("traceXId", "xxxooo");

        // ログ出力（MDCのtraceXIdが含まれる）
        logger.info("ビジネス処理を実行中...");
        logger.info("ビジネス処理が完了しました");

        // 使用後、MDCのtraceXIdを削除
        MDC.remove("traceXId");
    }
    
}

次に、ログの設定（logback.xml）を行う必要があります。

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

    <statusListener class="ch.qos.logback.core.status.NopStatusListener" />

    <contextName>trace-mdc</contextName>

    <!-- ここでの traceXId は、MDC に格納するキーです。「%X{traceXId}」を使用して一意の識別子を取得します -->
    <property name="CONSOLE_LOG_PATTERN" value="%green(%d{yyyy-MM-dd HH:mm:ss}) traceId:「%red(%X{traceXId})」 %highlight(%-5level) [%yellow(%thread)] %logger Line:%-3L - %msg%n" />

    <include resource="org/springframework/boot/logging/logback/defaults.xml" />

    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />

    <springProfile name="default">
        <root level="INFO">
            <appender-ref ref="CONSOLE" />
        </root>
    </springProfile>

</configuration>

注意：ここでは %X パターンを使用しており、このパターンを通じてコンテキストに定義されたデータを出力します。

最後に、上記のプログラムを実行すると、以下のようなログ情報が表示されます。

ログには、設定した traceId が記録されており、これによって現在のビジネスロジック実行の各詳細を非常に明確に把握することができます。

次に、Spring-BootとJPAを組み合わせた包括的なケースを紹介します。

3. 総合的なケース

3.1 環境準備

まずは、基本的なデータベースクエリ操作を準備します。以下は、Spring-BootとJPAを使用したサンプルコードです。


spring:
  main:
    banner-mode: off
  datasource:
    driverClassName: org.postgresql.Driver
    url: jdbc:postgresql://localhost:5432/spring_boot_samples
    type: com.zaxxer.hikari.HikariDataSource
    hikari:
      username: postgres
      password: 123456
      connection-timeout: 30000
      read-only: off
      minimum-idle: 2
      maximum-pool-size: 10
      auto-commit: on
      max-lifetime: 600000
      idle-timeout: 300000
      connection-test-query: select 1
      validation-timeout: 1500
      schema: public
  jpa:
    open-in-view: off
    hibernate:
      ddl-auto: update
    show-sql: on

設定が完了した後、次は Repository、Service、Controller などの基本的なクラスを定義します。


package com.jojo.boot.springbootmdc.entity;

import jakarta.persistence.Entity;
import jakarta.persistence.Id;
import jakarta.persistence.Table;

@Entity
@Table(name = "t_person")
public class Person {

    @Id
    private Integer id;
    private String name ;
    private Integer age ;

    public String getName() {
        return name;
    }

    public void setName(String name) {
        this.name = name;
    }

    public Integer getId() {
        return id;
    }

    public void setId(Integer id) {
        this.id = id;
    }

    public Integer getAge() {
        return age;
    }

    public void setAge(Integer age) {
        this.age = age;
    }

}

PersonRepositoryの定義では、何もメソッドを定義する必要はありません。


package com.jojo.boot.springbootmdc.repository;

import com.jojo.boot.springbootmdc.entity.Person;
import org.springframework.data.jpa.repository.JpaRepository;

public interface PersonRepository   extends JpaRepository<Person, Integer> {}

PersonService の定義では、ここでIDに基づいて検索するメソッドを1つ定義します。


package com.jojo.boot.springbootmdc.service;

import com.jojo.boot.springbootmdc.entity.Person;
import com.jojo.boot.springbootmdc.repository.PersonRepository;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Service;

@Service
public class PersonService {

    // ロガーのインスタンスを作成
    private final Logger logger = LoggerFactory.getLogger(getClass());
    private final PersonRepository personRepository;

    // コンストラクタでリポジトリを初期化
    public PersonService(PersonRepository personRepository) {
        this.personRepository = personRepository;
    }

    // IDでPerson情報を検索するメソッド
    public Person findById(Integer id) {
        logger.info("ID【{}】の情報を取得する準備をしています", id);
        return this.personRepository.findById(id).orElse(null);
    }
}

最後に、Controller インターフェースを定義します。


package com.jojo.boot.springbootmdc.controller;

import com.jojo.boot.springbootmdc.entity.Person;
import com.jojo.boot.springbootmdc.service.PersonService;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@RequestMapping("persons")
public class PersonController {

    private final PersonService personService ;
    public PersonController(PersonService personService) {
        this.personService = personService ;
    }

    @GetMapping("{id}")
    public Person queryPerson(@PathVariable Integer id) {
        return this.personService.findById(id) ;
    }
    
}

以上で基本的な操作の準備が整いました。まずはインターフェースをテストしてみましょう。

この時点では、私たちのログには特別なマークはありません。

ログは私たちの設定に従って出力されていますが、これがどのリクエストの呼び出しなのか区別することができません。そこで、次にこれを改善していきます。

3.2 フィルタの定義

リクエスト処理全体で一意の識別子を記録するために、フィルタ（Filter）を利用してこの識別子を初期化して設定することができます。フィルタを使用する理由は、リクエスト処理の開始段階で一意の識別子をMDC（Mapped Diagnostic Context）に保存し、リクエスト処理が終了した後に MDC をクリアすることで、各リクエストのログ記録が一貫したコンテキスト情報を含むように保証できるためです。


package com.jojo.boot.springbootmdc.filter;

import io.micrometer.common.lang.NonNullApi;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.apache.commons.lang3.RandomStringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.core.Ordered;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.OncePerRequestFilter;

import java.io.IOException;

@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
@NonNullApi
public class HttpRequestFilter extends OncePerRequestFilter {

    private final Logger logger = LoggerFactory.getLogger(getClass()) ;
    public static final String TRACE_KEY = "traceId" ;

    @Override
    public void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)  throws IOException, ServletException {
        String traceId = request.getHeader("x-trace-id") ;
        // 呼び出し元が traceId を渡さなかった場合、自動生成する
        if (!StringUtils.hasLength(traceId)) {
            traceId =  RandomStringUtils.secure().nextAlphanumeric(32).replace("-", "").toUpperCase() ;
        }
        // 現在のリクエストの traceId を MDC に保存する
        MDC.put(TRACE_KEY,traceId);
        logger.info("リクエスト: {}", request.getServletPath());
        try {
            chain.doFilter(request, response);
        } finally {
            // 処理終了後に MDC から traceId を削除する
            MDC.remove(TRACE_KEY);
        }
    }

}

次に、logback.xml で設定を行います。


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

    <statusListener class="ch.qos.logback.core.status.NopStatusListener" />

    <contextName>trace-mdc</contextName>

    <!-- ここでの traceXId は、MDC に格納するキーです。「%X{traceXId}」を使用して一意の識別子を取得します -->
    <property name="CONSOLE_LOG_PATTERN" value="%green(%d{HH:mm:ss}) traceId:[%red(%X{traceId})] %highlight(%-5level) [%yellow(%thread)] %logger Line:%-3L - %msg%n" />

    <include resource="org/springframework/boot/logging/logback/defaults.xml" />

    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />

    <springProfile name="default">
        <root level="INFO">
            <appender-ref ref="CONSOLE" />
        </root>
    </springProfile>

</configuration>

同様に、%X パターンを使用して現在のコンテキストの traceId を出力しました。

フィルタと上記のログ設定が整ったので、再度 /persons/1 インターフェースにアクセスします。

現在、リクエストの呼び出しプロセスが非常に明確に表示されており、問題のトラブルシューティングが非常に便利になりました。

しかし、まだ解決する必要がある以下の問題があります：

クロススレッドの問題
MDC の内部実装は ThreadLocal を使用しているため、スレッドをカスタムで作成してタスクを実行したり、@Async を使用して非同期タスクを実行した場合、ログに traceId を取得できなくなります。
traceId をクライアントに出力する方法
場合によっては、各リクエストの traceId をクライアントに返したいことがあります。問題をトラブルシューティングする際に、ユーザーが対応する traceId を提供して検索を行えるようにするためです。

次に、これら 2 つの問題を解決していきます。

3.3 クロススレッドの問題

まず、問題を再現するために非同期タスクを起動します。以下のコードを Service と Controller にそれぞれ追加します。


// PersonService
@Async
public void task() {  
  // 非同期タスクを実行
  logger.info("非同期タスクを実行します");
}

//java

// PersonController
@GetMapping("/task")
public String task() {
  this.personService.task();  
  return "success";
}

注意：@EnableAsync を使用して非同期タスク機能を有効にすることを忘れないでください。

このように設定した後、/persons/task インターフェースにアクセスしてみましょう。

非同期タスク内で出力されるログの traceId が空になっています。

この問題を解決するためには、カスタムのスレッドプールと関連するいくつかのコアクラスを作成する必要があります。


package com.jojo.boot.springbootmdc.config;

import org.springframework.context.annotation.Configuration;
import org.springframework.lang.NonNull;
import org.springframework.scheduling.annotation.AsyncConfigurer;
import org.springframework.scheduling.annotation.EnableAsync;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
import java.util.concurrent.Executor;
import java.util.concurrent.ThreadPoolExecutor;

@Configuration
@EnableAsync
public class WebAsyncConfigurer implements AsyncConfigurer {

    @Override
    public @NonNull Executor getAsyncExecutor() {
        var executor = new ThreadPoolTaskExecutor();
        var core = Runtime.getRuntime().availableProcessors();
        executor.setCorePoolSize(core);
        executor.setMaxPoolSize(core);
        executor.setQueueCapacity(1000);
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        executor.setTaskDecorator(new WebTaskDecorator());
        executor.initialize();
        return executor;
    }

}

ここでは、AsyncConfigurer インターフェースを実装して、スレッドプールオブジェクトを構成します。

注意：ここでは、タスクデコレーターをカスタムで作成しています。これにより、タスクを実行する前にスレッドでいくつかの初期化処理を行うことができます。


package com.jojo.boot.springbootmdc.config;

import io.micrometer.common.lang.NonNullApi;
import org.slf4j.MDC;
import org.springframework.core.task.TaskDecorator;

import java.util.Objects;

@NonNullApi
public class WebTaskDecorator implements TaskDecorator {

    @Override
    public Runnable decorate(Runnable runnable) {
        // メインスレッドからコンテキストデータを取得
        var contextMap = MDC.getCopyOfContextMap();
        return () -> {
            try {
                if (Objects.nonNull(contextMap)) {
                    // サブスレッドが実行される前に、現在のサブスレッドのコンテキストにデータを設定
                    MDC.setContextMap(contextMap);
                } else {
                    MDC.clear();
                }
                runnable.run();
            } finally {
                MDC.clear();
            }
        };
    }

}

上記のように定義した後、再度上記のインターフェースにアクセスしてみましょう。

これで、非同期タスク内でも traceId を正しくログに出力できるようになります。

3.4 traceIdをクライアントに出力する

もしtraceIdをクライアントに出力したい場合、カスタムのResponseBodyAdviceを使用してレスポンスデータを書き換えることができます。


package com.jojo.boot.springbootmdc.config;

import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.jojo.boot.springbootmdc.filter.HttpRequestFilter;
import io.micrometer.common.lang.NonNullApi;
import org.slf4j.MDC;
import org.springframework.core.MethodParameter;
import org.springframework.http.MediaType;
import org.springframework.http.ResponseEntity;
import org.springframework.http.converter.HttpMessageConverter;
import org.springframework.http.server.ServerHttpRequest;
import org.springframework.http.server.ServerHttpResponse;
import org.springframework.web.bind.annotation.RestControllerAdvice;
import org.springframework.web.servlet.mvc.method.annotation.ResponseBodyAdvice;

@NonNullApi
@RestControllerAdvice
public class WebResponseBodyAdvice implements ResponseBodyAdvice<Object> {

    private final ObjectMapper objectMapper;

    public WebResponseBodyAdvice(ObjectMapper objectMapper) {
        this.objectMapper = objectMapper;
    }

    @Override
    public boolean supports(MethodParameter returnType, Class<? extends HttpMessageConverter<?>> converterType) {
        return !returnType.getParameterType().equals(R.class)  ;
    }

    @Override  public Object beforeBodyWrite(Object body, MethodParameter returnType,
                                             MediaType selectedContentType,
                                             Class<? extends HttpMessageConverter<?>> selectedConverterType,
                                             ServerHttpRequest request,
                                             ServerHttpResponse response) {
        if (body instanceof String) {
            try {
                return this.objectMapper.writeValueAsString(R.success(response, MDC.get(HttpRequestFilter.TRACE_KEY))) ;
            } catch (JsonProcessingException e) {
                throw new RuntimeException(e);
            }
        }
        if (body instanceof ResponseEntity<?> entity) {
            return R.success(entity.getBody(), MDC.get(HttpRequestFilter.TRACE_KEY)) ;
        }
        return R.success(body, MDC.get(HttpRequestFilter.TRACE_KEY));
    }

}

最後に、上記の /persons/1 インターフェースをテストすることができます。

成功に traceId をクライアントに出力しました。

3.5 実用的なフィルタ

logback は MDC 用の実用的なフィルタである MDCInsertingServletFilter を提供しています。このフィルタは、現在のコンテキストに以下のデータを設定します。

次に、Spring Beanの方法でこのフィルタを登録します。

package com.jojo.boot.springbootmdc.config;

import ch.qos.logback.classic.helpers.MDCInsertingServletFilter;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration

public class BeanConfig {

    @Bean
    MDCInsertingServletFilter mdcInsertingServletFilter() {
        return new MDCInsertingServletFilter();
    }
    
}

ログ設定の XML ファイルでは、%X モードを使用して設定することができます。


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

    <statusListener class="ch.qos.logback.core.status.NopStatusListener" />

    <contextName>trace-mdc</contextName>

    <!-- ここでの traceXId は、MDC に格納するキーです。「%X{traceXId}」を使用して一意の識別子を取得します -->
    <property name="CONSOLE_LOG_PATTERN" value="%green(%d{HH:mm:ss}) traceId:[%red(%X{traceId})] %X{req.remoteHost} %X{req.requestURI} %highlight(%-5level) [%yellow(%thread)] %logger Line:%-3L - %msg%n" />

    <include resource="org/springframework/boot/logging/logback/defaults.xml" />

    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />

    <springProfile name="default">
        <root level="INFO">
            <appender-ref ref="CONSOLE" />
        </root>
    </springProfile>

</configuration>

最後に、インターフェースにアクセスすると、ログの出力は次のようになります：