[Java] MDC와 스레드 로컬

MDC란?

MDC(Mapped Diagnostic Context)는 스레드 단위로 데이터를 읽고 쓸 수 있는 기능입니다. MDC를 사용하면 멀티 스레드 환경에서 각 스레드의 실행 컨텍스트를 구분할 수 있어서 모니터링시 추적에 용이합니다. 예를 들어 멀티 스레드 환경에서는 요청 순서대로 로그가 찍히지 않고, 로그가 섞여서 쌓이게 되므로 동일한 스레드의 컨텍스트를 추적하기 위해 MDC를 사용합니다. 스레드 로컬에 대해 알고 계시는 분들은 MDC와 스레드 로컬의 차이점이 무엇인지 궁금하실 수 있을 것 같습니다. 사실, MDC는 내부적으로 스레드 로컬을 사용하고 있어서 별도로 스레드 로컬을 선언할 필요없이 MDC를 바로 사용하면 됩니다.

// MDC 내부
public class MDC {

    static final String NULL_MDCA_URL = "http://www.slf4j.org/codes.html#null_MDCA";
    private static final String MDC_APAPTER_CANNOT_BE_NULL_MESSAGE = "MDCAdapter cannot be null. See also " + NULL_MDCA_URL;
    static final String NO_STATIC_MDC_BINDER_URL = "http://www.slf4j.org/codes.html#no_static_mdc_binder";
    static MDCAdapter mdcAdapter;
 
    ...

    public static void put(String key, String val) throws IllegalArgumentException {
        if (key == null) {
            throw new IllegalArgumentException("key parameter cannot be null");
        }
        if (mdcAdapter == null) {
            throw new IllegalStateException(MDC_APAPTER_CANNOT_BE_NULL_MESSAGE);
        }
        mdcAdapter.put(key, val); // MDCAdapter에게 실행 위임
    }

    ...

    public static String get(String key) throws IllegalArgumentException {
        if (key == null) {
            throw new IllegalArgumentException("key parameter cannot be null");
        }

        if (mdcAdapter == null) {
            throw new IllegalStateException(MDC_APAPTER_CANNOT_BE_NULL_MESSAGE);
        }
        return mdcAdapter.get(key); // MDCAdapter에게 실행 위임
    }
}

// MDCAdapter 구현체 중 하나인 LogbackMDCAdapter 내부
public class LogbackMDCAdapter implements MDCAdapter  {

    final ThreadLocal<Map<String, String>> readWriteThreadLocalMap = new ThreadLocal<Map<String, String>>();
    final ThreadLocal<Map<String, String>> readOnlyThreadLocalMap = new ThreadLocal<Map<String, String>>();
    private final ThreadLocalMapOfStacks threadLocalMapOfDeques = new ThreadLocalMapOfStacks();

    ...
}

스레드 로컬 대신 MDC를 사용하는 이유는?

스레드 로컬 대신 MDC를 사용하는 이유는 무엇일까요? MDC와 스레드 로컬은 모두 멀티 스레드 환경에서 유용하게 사용될 수 있습니다. 두 기술의 주된 목적은 각 스레드의 실행 컨텍스트를 관리하는 것이지만, 로깅 작업에는 MDC가 더 적합합니다. 

 

MDC는 로깅을 목적으로 설계되었기 때문에 로그 데이터에 추가적인 컨텍스트 데이터를 제공하는데 최적화 되어있습니다. 로깅시 스레드 로컬을 사용하면, 로그 메시지를 생성할 때 매번 스레드 로컬에서 데이터를 꺼내어 로그 메시지에 추가해야 합니다. 반면, MDC는 컨텍스트 데이터를 자동으로 로그 메시지에 포함시키므로, 개발자가 코드 상에서 매번 데이터를 추출하고 로그 메시지에 추가하는 번거로움을 줄일 수 있습니다.

 

MDC는 어떻게 이런 번거로움을 줄일 수 있었을까요? MDC는 로깅 시스템과 통합되어 있기 때문입니다. 따라서, 개발자가 직접 스레드 별로 로깅 컨텍스트를 관리할 필요가 없습니다. MDC에 데이터를 설정하면 로깅 라이브러리가 자동으로 해당 스레드의 로그 메시지에 MDC 데이터를 포함 시킵니다. 이는 매번 로그를 찍을 때 수동으로 컨텍스트 데이터를 추가해야하는 번거로움을 줄여줍니다. 

스레드 로컬과 MDC를 사용한 로깅 비교

스레드 로컬과 MDC를 사용한 로깅을 비교하기 위해 logback 라이브러리를 추가하고 로그 메시지를 설정하는 과정을 진행합니다. 예제에서는 순수 자바 애플리케이션에 logback과 slf4j를 사용해서 MDC를 사용하는 예제를 알아봅니다. 

로그백 의존성 추가

`logback-classic`을 의존성을 추가하면, `logback-core`와 `slf4j` 의존성도 함께 들어오기 때문에 별도로 추가하지 않아도 됩니다.

dependencies {
    ...
    api("ch.qos.logback:logback-classic:1.5.5")
}

logback-classic을 추가하면 logback-core, slf4j-api 의존성도 함께 추가됨

로그백 설정

`{project}/resources/logback.xml` 위치에 로그백 설정 파일을 만들어주세요.

 

MDC 특정 키의 값을 로그 메시지에 포함시키기

logback 설정 파일에서 로그 메시지 포맷을 정의할 때, MDC 특정 키의 값을 포함시키려면 `%X{keyName}` 형식을 사용합니다. 여기서 keyName은 MDC에 저장된 키 이름을 의미합니다. 다음 로그백 설정을 잘 살펴보면 `%X{userId}`라는 표현식이 있습니다. 이 표현식은 MDC에 저장된 `userId` 키의 값을 로그 메시지에 자동으로 포함시키는 것을 의미합니다.

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{35} - [%X{userId}] %msg%n</pattern>
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

MDC의 전체 정보를 로그 메시지에 포함시키기

만약, MDC의 전체 데이터를 로그 메시지에 포함시키고자 할 때는, `%X` 또는 `%mdc`를 사용하여 MDC의 모든 Key-Value 쌍을 출력할 수 있습니다. 이 표현식은 MDC에 저장된 모든 Key-Value 쌍을 `{key1=value1, key2=value2, ...}` 형태로 로그 메시지에 포함시킵니다.

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

    <root level="debug">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

 

이 처럼 MDC를 사용할 때는 로그 설정 파일(여기서는 logback 설정 파일)에 MDC의 특정 키 값 또는 전체 MDC 데이터를 적절한 포맷으로 정의하여 로그 메시지에 자동으로 포함되도록 쉽게 만들 수 있습니다. MDC를 적절하게 사용하면 로그 데이터에 추가적인 컨텍스트를 제공할 수 있어 디버깅과 모니터링을 용이하게 만들어 줍니다.

스레드 로컬을 사용한 로깅

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

public class ThreadLocalExample {

    private static final Logger logger = LoggerFactory.getLogger(MDCExample.class);
    private static final ThreadLocal<String> userIdThreadLocal = new ThreadLocal<>();

    public static void main(String[] args) {
        new Thread(() -> {
            userIdThreadLocal.set("user123");
            simulateWork("Thread1");
            userIdThreadLocal.remove();
        }).start();

        new Thread(() -> {
            userIdThreadLocal.set("user456");
            simulateWork("Thread2");
            userIdThreadLocal.remove();
        }).start();
    }

    private static void simulateWork(String threadName) {
        // 스레드 로컬에서 사용자 ID 가져오기
        String userId = userIdThreadLocal.get();
        logger.info(threadName + ": Working for user " + userId);
    }
}

---

2024-04-14 17:03:36 [Thread-1] INFO  mdc.MDCExample - [] Thread2: Working for user >> user456
2024-04-14 17:03:36 [Thread-0] INFO  mdc.MDCExample - [] Thread1: Working for user >> user123

 

스레드 로컬을 사용하여 로그를 찍는 예제를 알아봅니다. 로그백 설정을 완료하고 로깅을 해보아도 로그백 설정의 `%X{userId}` 영역은 공란으로 노출되고, 스레드 로컬에서 꺼내온 userId만 데이터가 노출되는 것을 확인할 수 있습니다. 사실 어떻게보면 당연합니다. `%X`는 로깅이 발생한 Thread와 관련된 MDC를 출력하는 표현식이기 때문입니다. 이처럼 스레드 로컬을 사용하면 로깅에 필요한 데이터를 일일히(여기서는 userId) 꺼내서 로그를 찍을 때 로그 메시지에 매번 값을 붙여줘야하는 번거로움이 있습니다.

MDC를 사용한 로깅

package mdc;

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

public class MDCExample {
    private static final Logger logger = LoggerFactory.getLogger(MDCExample.class);

    public static void main(String[] args) {
        new Thread(() -> {
            MDC.put("userId", "user123");
            simulateWork("Thread1");
            MDC.clear();  // 사용 후 MDC를 정리
        }).start();

        new Thread(() -> {
            MDC.put("userId", "user456");
            simulateWork("Thread2");
            MDC.clear();  // 사용 후 MDC를 정리
        }).start();
    }

    private static void simulateWork(String threadName) {
        String userId = MDC.get("userId");
        // 로그 메시지에 자동으로 'userId'가 포함됩니다.
        logger.info("{}: Working for user >> {}", threadName, userId);
    }
}

---

2024-04-14 17:03:50 [Thread-1] INFO  mdc.MDCExample - [user456] Thread2: Working for user >> user456
2024-04-14 17:03:50 [Thread-0] INFO  mdc.MDCExample - [user123] Thread1: Working for user >> user123

 

다음으로 MDC를 사용하여 로그를 찍는 예제를 알아봅니다. MDC에 데이터를 넣고 로그를 찍어보니 로그백 설정에 맞춰 `[]` 영역에 userId가 노출된 것을 확인할 수 있습니다. 그리고 MDC에 저장된 userId 키에 해당하는 데이터를 꺼내서 로그 메시지에도 추가했습니다.스레드 로컬과 다른 점은 MDC에 저장된 데이터는 로그 포맷에 맞춰 로그 메시지에 자동으로 추가된다는 점입니다. 이를 통해서 로깅에 필요한 데이터를 컨텍스트 데이터를 손쉽게 추가할 수 있습니다.

마무리

MDC는 대부분의 로깅 라이브러리와 이미 통합되어 있기 때문에 개발자가 손쉽게 적용하여 사용할 수 있습니다. 오늘 알아본 내용을 통해 MDC를 사용하면 로그에 필요한 컨텍스트 데이터를 자동으로 추가할 수 있다는 장점이 있다는 것을 알게 되었습니다. 이러한 MDC 특징을 토대로, Spring Filter에서 매 요청 정보를 추적할 수 있도록 MDC에 요청 정보를 저장하고 각 요청 스레드에 대한 추적을 하는 방안에 대해서도 고려해볼 수 있습니다.

참고

https://logback.qos.ch/manual/layouts.html#mdc