Spring Boot에서 Logback과 MDC로 요청 흐름 추적하기

 

들어가며

애플리케이션을 추적하기 위해 로그는 필수다.

로그의 중요성은 모든 개발자가 알고 있다. 장애가 발생했을 때 가장 먼저 확인하는 것도 결국 로그다.

 

하지만 막상 프로젝트를 들여다보면, 로그는 그저 ‘출력’에만 그치는 경우가 많다. 요청의 시작과 끝이 연결되지 않고, 어떤 로그가 어떤 흐름에서 발생했는지 한눈에 파악하기 어렵다. 로그는 많지만, 정작 추적은 쉽지 않은 상태다.

 

특히 웹 애플리케이션처럼 동시 요청이 많은 환경에서는 단순한 메시지 출력만으로는 부족하다. 같은 시점에 여러 요청이 뒤섞여 실행되기 때문에, 로그에 최소한의 맥락(Context)이 필요하다.

 

이번 글에서는 Spring Boot 환경에서 기본 로깅 구조를 정리하고, 로그에 맥락을 부여하는 방법을 단계적으로 살펴본다.

단순히 로그를 ‘찍는 것’을 넘어, 추적 가능한 로그를 만들기 위한 과정을 정리해본다.

 

 

Spring Boot에서 Logback으로 기본 로깅 구성하기

Spring Boot 기본 로깅 구조

• Spring Boot는 기본적으로 SLF4J + Logback 조합을 사용한다.
  • SLF4J : 로깅 추상화 인터페이스
  • Logback : 실제 로깅 구현체
• logback.xml vs logback-spring.xml
  • logback.xml
    • Spring 초기화 이전에 로딩된다.
    • Spring Environment, Profile 등을 사용할 수 있다.
  • logback-spring.xml
    • Spring 초기화 이후 로딩된다.
    • springProfile 사용 가능 → 환경별 로그 설정이 가능하다.

Logback 구성요소

Logback은 다음 3가지 요소로 구성된다.

Logger → Appender → Layout(Encoder)

• Logger
  • 로그 메시지를 생성한다.
  • 로그 레벨에 따라 출력 여부를 결정한다.
    • TRACE < DEBUG < INFO < WARN < ERROR
• Appender
  • 로그를 어디로 보낼지 결정한다.
    • ex. ConsoleAppender, FileAppender, RollingFileAppender 등등
• Layout / Encoder
  • 로그를 어떤 형식으로 출력할지 결정한다.
    • ex. Encoder → PatternLayoutEncoder, JsonEncoder 등등

Logback 설정

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- Spring Boot 기본 Logback 설정 -->
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>

    <!-- 로컬 환경 로그 설정 -->
    <springProfile name="local">
        <root level="DEBUG">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>

    <!-- 개발 환경 로그 설정 -->
    <springProfile name="dev">
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>

    <!-- 운영 환경 로그 설정 -->
    <springProfile name="prod">
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>
</configuration>

• Spring Boot에서 제공하는 기본 설정 파일
  • defaults.xml : 기본 property와 logger 정의
  • console-appender.xml : 기본 ConsoleAppender가 정의
  • 그 외 설정 파일 참고 : https://github.com/spring-projects/spring-boot/tree/v4.0.2/core/spring-boot/src/main/resources/org/springframework/boot/logging/logback
• Spring 환경별 로그 설정
  • springProfile의 name에 환경을 명시한다. 각 환경별로 로그 레벨, 로그 출력 방식을 정의할 수 있다.

로깅 사용 방법

@RequestMapping("/v1/users")
@RestController
public class UserController {
    private static final Logger log = LoggerFactory.getLogger(UserController.class);

    @GetMapping
    public ResponseEntity<String> test() {
        log.info("test");
        return ResponseEntity.ok("test");
    }
}

사용 방법은 간단하다. Logger를 가져와서 찍으려는 로그 레벨로 메시지를 작성하면 된다.

 

 

Lombok을 사용하면 @Slf4J 를 사용하여 더 간결하게 작성할 수 있다.

@Slf4j
@RequestMapping("/v1/users")
@RestController
public class UserController {

    @GetMapping
    public ResponseEntity<String> test() {
        log.info("test");
        return ResponseEntity.ok("test");
    }
}

파라미터화 로깅(Parameterized Logging)

logger.debug("value=" + value, value);

 

Java를 사용하면 문자열과 변수를 이어 붙이는 방법으로 로깅을 하게 되는 경우가 있다. 이렇게 로그를 찍을 경우, 로그가 실제로 출력되는지 여부와 관계없이 문자열을 생성한다. 만약 DEBUG 레벨 로그가 꺼져 있으면 불필요한 문자열을 생성하게 된다.

 

if(logger.isDebugEnabled()) { 
  logger.debug("value=", value);
}

그래서 대안으로 DEBUG 레벨 로그가 켜져 있는지 isDebugEnabled() 를 통해 확인하고 로그를 찍을 수 있다.

공식 문서에서는 이 오버헤드(조건 검사 → 로깅)는 매우 작다고 했지만, 개인적인 생각으로 로깅인데 비즈니스 로직처럼 if문 안에 있어 미관상(?) 좋지 않아 보였다.

 

logger.debug("value={}". v); 

파라미터화 로깅을 사용하면 실제 DEBUG 로그가 활성화된 경우에만 문자열을 생성하므로 성능과 가독성을 모두 만족할 수 있다.

 

 

MDC로 요청 단위 Context 부여하기

MDC(Mapped Diagnostic Context)?

• ThreadLocal 기반의 Logging Context
• 로그에 맥락을 추가할 수 있게 해주는 도구. 컨텍스트 정보를 MDC에 저장하여 사용할 수 있다.

MDC는 스레드 단위로 데이터를 관리하기 때문에, 스레드를 재사용하는 Spring 서버 환경에서는 MDC에 잘못된 정보가 남아 있을 수 있어 데이터 관리가 중요하다.

공식 문서에서는 Filter를 사용하라고 적혀 있는데, Filter를 사용하면 처리 시작시 정보를 저장하고, 처리 종료시 해당 정보를 제거할 수 있다. Spring에서는 OncePerRequestFilter 라는 HTTP 요청당 1번 실행을 보장하는 Filter가 있으므로 이걸 사용하면 된다.

OncePerRequestFilter로 traceId 생성

@Component
public class RequestLoggingFilter extends OncePerRequestFilter {

    public static final String TRACE_ID = "traceId";

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        String traceId = generateTraceId();

        try {
            MDC.put(TRACE_ID, traceId);
            filterChain.doFilter(request, response);
        } finally {
            MDC.remove(TRACE_ID);
        }
    }

    private String generateTraceId() {
        return UUID.randomUUID().toString().replace("-", "");
    }
}

• String traceId = generateTraceId();
  • 요청 시 구분되는 traceId라는 식별자를 추가한다.
• MDC.put(TRACE_ID, traceId);
  • 요청이 실행되기 전 traceId를 MDC에 저장한다.
• MDC.remove(TRACE_ID);
  • 요청이 끝나면 traceId를 제거한다.
  • finally를 사용해야 요청 시 예외가 발생하더라도 traceId를 안전하게 지울 수 있다.

로그 패턴에 traceId 추가하기

 

MDC에 traceId를 넣었으니 로깅시 traceId가 기본으로 출력되게 하고 싶으면 로그 패턴에 traceId를 추가해야 한다.

 

기존 ConsoleAppender는 CONSOLE_LOG_PATTERN 에 로그 패턴이 이미 정의되어 있다. 패턴을 수정하려면 CONSOLE_LOG_PATTERN을 재정의해야 한다.

 

console-appender.xml를 보면 CONSOLE의 경우 로그 패턴을 CONSOLE_LOG_PATTERN 에 정의하고 있다.

 <property name="CONSOLE_LOG_PATTERN" value="%d{HH:mm:ss.SSS} [%thread] [%-5level] [%X{traceId}] %logger{36} -%kvp- %msg%n"/>

• %X{traceId}
  • MDC에 저장된 traceId 출력

 

이제 모든 로그에 자동으로 traceId가 포함된다.

문제 : 비동기 처리 시 traceId가 사라진다.

앞에서 MDC를 통해 traceId를 로그에 포함시켰다.

하지만 비동기 처리를 적용하면 예상치 못한 문제가 발생한다.

 

@Slf4j
@RequiredArgsConstructor
@RequestMapping("/v1/users")
@RestController
public class UserController {
    private final UserQueryService userQueryService;

    @GetMapping("/async")
    public ResponseEntity<List<User>> getUsersAsync() {
        log.info("GET /v1/users/async");
        return ResponseEntity.ok(userQueryService.getUsersAsync().join());
    }
}

 

@Slf4j
@RequiredArgsConstructor
@Service
public class UserQueryService {

    @Async("applicationTaskExecutor")
    public CompletableFuture<List<User>> getUsersAsync() {
        log.info("getUsersAsync");
        try {
            List<User> users = List.of(User.of("김모모", "momo@test.com"), User.of("강노노", "nono@test.com"));
            return CompletableFuture.completedFuture(users);
        } catch (Exception e) {
            return CompletableFuture.failedFuture(e);
        }
    }
}

@Configuration
@EnableAsync
public class AsyncConfig {

    @Bean(name = "applicationTaskExecutor")
    public Executor applicationTaskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();

        executor.setCorePoolSize(10);
        executor.setMaxPoolSize(30);
        executor.setQueueCapacity(100);
        executor.setThreadNamePrefix("async-exec");

        executor.initialize();
        return executor;
    }
}

 

 

 

비동기 메서드에서 로그를 찍어보면 traceId가 출력되지 않는다.

 

왜 traceId가 사라질까?

MDC는 ThreadLocal 기반이다. 즉, 요청을 처리하는 스레드에 MDC 값이 저장된다.

• 요청 스레드 → traceId 존재
• 비동기 스레드 → traceId 없음

ThreadLocal은 스레드 간에 공유되지 않기 때문에 스레드가 변경되는 순간 MDC는 비어있다

 

 

해결 방법 : 비동기 작업 시 MDC 전파하기

TaskDecorator를 이용한 MDC 전파

Spring에서는 TaskDecorator 를 제공한다. 이를 사용하면 비동기 실행 시 MDC를 복사해 전파할 수 있다.

Async 설정 추가

@Configuration
@EnableAsync
public class AsyncConfig {

    @Bean(name = "applicationTaskExecutor")
    public Executor applicationTaskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();

        executor.setCorePoolSize(10);
        executor.setMaxPoolSize(30);
        executor.setQueueCapacity(100);
        executor.setThreadNamePrefix("async-exec");
        executor.setTaskDecorator(mdcTaskDecorator());

        executor.initialize();
        return executor;
    }

    @Bean
    public TaskDecorator mdcTaskDecorator() {
        return runnable -> {
            Map<String, String> contextMap = MDC.getCopyOfContextMap();

            return () -> {
                if (contextMap != null) {
                    MDC.setContextMap(contextMap);
                }

                try {
                    runnable.run();
                } finally {
                    MDC.clear();
                }
            };
        };
    }
}

• 동작 원리
  1. 현재 스레드의 MDC 값을 복사한다.
  2. 새로운 비동기 스레드 시작 시 복사본을 설정한다.
  3. 작업 종료 후 MDC를 정리한다.

이제 비동기 환경에서도 traceId가 유지된다.

 

※ 스레드 별 traceId가 clear되는 시점
- 요청 스레드 → Filter에서 clear
- Async 스레드 → TaskDecorator에서 clear

 

하지만 이것도 완벽한 해결 방법은 아니다.

다음과 같은 한계가 존재한다.

• CompletableFuture 체이닝 시 추가 전파가 필요하다.
• RestTemplate, WebClient 호출 시 수동 전파 필요하다.
• MQ, 외부 시스템 연동 시 별도 처리가 필요하다.
• 직접 구현 시 관리 포인트가 증가한다.

단일 서비스 내부 비동기 처리에는 충분하지만 분산 환경에서는 한계가 있다. 

 

다음 단계 : 분산 트레이싱

• Micrometer Tracing (+ OpenTelemetry)
• Spring Cloud Sleuth (구)

이들은 HTTP, Async, WebClient, MQ 등 전반에 걸쳐 Context를 자동으로 전파한다. 여러 서비스에 걸친 요청을 하나의 trace로 연결해준다.

MSA 환경이라면 MDC를 직접 관리하기보다 트레이싱 라이브러리를 도입하는 것이 일반적이다.

 

정리

Spring Boot에서 기본 Logback 설정을 구성하고, MDC를 활용하여 요청 단위 traceId를 로그에 포함시켜 보았다. 이를 통해 단일 서버 내에서는 특정 요청의 흐름을 비교적 쉽게 추적할 수 있다.

하지만 ThreadLocal 기반의 MDC는 스레드가 변경되는 순간 깨진다. 비동기 처리 시 직접 전파해야 하며, 외부 호출까지 고려하면 관리 복잡도가 올라간다.

• 다른 서버를 호출하는 경우에는 traceId를 어떻게 전달해야 할까?
• MSA 환경처럼 여러 서비스가 연결된 구조에서는 로그를 어떻게 추적해야 할까?

이번 글이 단일 애플리케이션 수준에서 로그 맥락을 다뤘다면, 다음 단계는 분산 환경에서의 로그 추적 방법을 정리하려고 한다.

 

---

참고자료

• https://logback.qos.ch/documentation.html
• https://www.baeldung.com/logback
• https://docs.spring.io/spring-boot/reference/features/logging.html#features.logging.logback-extensions