장애 때 필요한 로그를 바로 찾으려면? 로그 설정 가이드

장애가 난 요청을 트레이스 화면에서 찾아 trace_id로 로그를 검색했는데 결과가 비어 있습니다. 로그를 열어 보니 trace_id가 아예 찍혀 있지 않습니다. trace_id는 요청 하나가 여러 서비스를 거치는 동안 그대로 따라다니는 고유 번호입니다. APM이나 트레이싱 도구가 요청마다 trace_id를 생성하더라도, 로그 형식에 해당 값을 출력하도록 설정하지 않으면 로그에는 남지 않습니다. 장애 때 필요한 로그를 바로 찾으려면 로그 한 줄마다 trace_id가 출력되도록 로그 형식을 설정해야 합니다.

trace_id로 로그를 찾는 순서는 장애 때 필요한 로그만 찾는 법, trace_id 활용 가이드에 정리했습니다. 이 글은 APM이나 분산 추적 도구로 요청의 트레이스를 볼 수 있는 환경을 전제로, Java 서비스의 로그 설정을 다룹니다.

먼저 에러 로그 한 줄을 열어 trace_id 값이 있는지 확인합니다. Spring Boot 3.2 이상에서 Micrometer Tracing을 쓴다면 대개 이미 출력되고 있으니 확인만 하면 됩니다. OpenTelemetry Java 에이전트를 쓴다면 로그 패턴에 trace_id를 추가해야 합니다. 로그 패턴은 로그 한 줄의 출력 형식을 정하는 설정입니다. 아래에서는 trace_id가 로그에 출력되는 원리, 도구별 설정, 비동기 작업 로그에서만 값이 빠질 때의 해결 방법을 차례로 살펴봅니다.

‍

로그에 trace_id가 찍히는 원리

Java 서버는 보통 요청 하나를 스레드 하나에 맡겨 처리합니다. 스레드는 프로그램 안에서 작업 하나를 실행하는 흐름입니다. SLF4J, Logback, Log4j 같은 Java 로깅 라이브러리는 스레드마다 별도의 키·값 저장소를 제공합니다. 이 저장소를 MDC(Mapped Diagnostic Context)라고 부릅니다. 요청을 처리하는 스레드의 MDC에 trace_id를 저장해 두면, 그 스레드가 남기는 모든 로그에 같은 값을 출력할 수 있습니다.

MDC는 값을 저장만 합니다. 저장된 값을 로그 줄에 출력하는 일은 로그 패턴이 담당합니다. 따라서 MDC에 값이 있어도 로그 패턴에 그 키를 지정하지 않으면 로그에는 나타나지 않습니다. Logback에서는 %X{traceId}나 %X{trace_id}처럼 키 이름을 지정해 MDC 값을 출력합니다.

트레이싱 도구가 MDC에 trace_id를 저장하므로 관련 코드를 직접 작성할 필요는 없습니다. trace_id를 저장하는 방식은 크게 두 가지입니다. 첫째는 에이전트입니다. 에이전트는 애플리케이션과 함께 실행되며 요청 처리 과정을 기록하는 프로그램으로, OpenTelemetry Java 에이전트가 대표적입니다. 둘째는 트레이싱 라이브러리입니다. 프로젝트에 의존성으로 추가해 쓰는 외부 라이브러리로, Spring Boot에서 쓰는 Micrometer Tracing이 대표적입니다. 어느 방식이든 MDC 값을 출력하는 일은 로그 패턴이 담당합니다. 아래 표의 span_id는 요청 안의 작업마다 따로 붙는 번호입니다.

‍

표의 키 이름은 Java 기준 기본값입니다. OpenTelemetry Java 에이전트는 trace_id를, Micrometer Tracing은 traceId를 씁니다. 두 방식을 함께 쓰는 조직이라면 로그 검색 조건도 두 가지가 필요합니다.

‍

Spring Boot에서 로그에 trace_id 남기는 설정

Spring Boot 3.2부터는 Micrometer Tracing을 쓰면 기본 로그 패턴이 traceId와 spanId를 대괄호로 묶어 출력합니다. Micrometer Tracing은 요청이 시작되면 MDC에 traceId와 spanId를 저장하고, 요청이 끝나면 해당 값을 삭제합니다. OpenTelemetry와 함께 쓴다면 Spring Boot 3에서는 spring-boot-starter-actuator와 micrometer-tracing-bridge-otel을, Spring Boot 4에서는 spring-boot-starter-opentelemetry를 의존성으로 추가합니다.

출력 형식을 바꾸고 싶을 때만 application.properties에 다음 두 줄을 넣습니다.

logging.pattern.correlation=[${spring.application.name:},%X{traceId:-},%X{spanId:-}] 
logging.include-application-name=false

‍

첫 줄은 애플리케이션 이름, trace_id, span_id를 대괄호 안에 쉼표로 이어 출력하는 형식입니다. 줄 끝의 공백 하나도 함께 복사합니다. 이 공백이 없으면 대괄호 바로 뒤에 로그를 남긴 클래스 이름이 붙어 출력됩니다. %X{traceId:-}에서 :- 뒤는 값이 없을 때 대신 출력할 기본값이며, 이 설정에서는 빈 문자열입니다. 둘째 줄은 Spring Boot가 기본 패턴에 따로 넣는 애플리케이션 이름을 끕니다. 이름이 두 번 출력되지 않게 하는 설정입니다.

‍

‍

설정을 적용한 뒤에는 HTTP 요청을 하나 보내 봅니다. 그 요청을 처리하며 남긴 로그에 traceId와 spanId가 있으면 설정이 적용된 것입니다. 서버를 켤 때 남는 로그처럼 요청과 관계없는 로그는 [order-api,,]처럼 값이 비어 있는 것이 정상입니다.

‍

OpenTelemetry Java 에이전트로 로그에 trace_id 남기는 설정

OpenTelemetry Java 에이전트는 코드를 고치지 않고 실행 명령에 옵션만 더하면 붙일 수 있습니다. 예를 들어 java -javaagent:opentelemetry-javaagent.jar -Dotel.service.name=order-api -jar order-api.jar처럼 실행합니다. otel.service.name은 트레이스 화면에 표시할 서비스 이름입니다.

에이전트는 로그가 남을 때마다 그 로그 줄에 딸린 MDC 값으로 trace_id와 span_id를 추가합니다. 이 키 이름은 Micrometer Tracing의 traceId, spanId와 다릅니다. 따라서 Logback 설정 파일의 pattern 항목에 에이전트의 키 이름을 지정해야 합니다. 설정 파일은 Spring Boot라면 logback-spring.xml, 그 밖에는 logback.xml입니다.

<pattern>%d{ISO8601} %-5level [%thread] trace_id=%X{trace_id} span_id=%X{span_id} %logger{36} - %msg%n</pattern>

‍

이 패턴을 적용하면 로그 줄마다 trace_id와 span_id가 출력됩니다. 이제 trace_id 하나로 요청 하나의 로그를 모두 찾을 수 있습니다.

‍

비동기 작업 로그에만 trace_id가 없을 때, 추적 정보 전달 설정

비동기 작업은 다른 스레드에 맡겨 따로 실행하는 작업입니다. 요청을 처리하던 흐름은 비동기 작업이 끝나기를 기다리지 않습니다. 알림 메일 발송이나 결제 후처리처럼 응답과 별개로 돌아가는 일이 대표적입니다. 일반 요청 로그에는 trace_id가 있는데 비동기 작업 로그에서만 빠진다면, 로그 패턴은 원인이 아닙니다. 요청 스레드의 추적 정보가 비동기 작업을 실행하는 스레드로 전달되는지 확인해야 합니다. 여러 서비스를 거치다 특정 서비스부터 trace_id 값이 바뀌는 문제는 장애 때 필요한 로그만 찾는 법, trace_id 활용 가이드에서 다뤘습니다.

앞에서 살펴본 것처럼 MDC는 스레드마다 독립적으로 관리됩니다. 따라서 MDC에 저장된 trace_id를 다른 스레드로 전달하려면 별도의 추적 정보 전달 기능이 필요합니다. Spring에서는 @EnableAsync로 비동기 실행을 켜고 메서드에 @Async를 붙이면, 그 메서드가 비동기 작업으로 실행됩니다. 이 작업은 스레드풀의 다른 스레드에서 처리될 수 있습니다. 스레드풀은 미리 만들어 둔 스레드 묶음입니다. 이때 trace_id, span_id 같은 추적 정보가 함께 전달되지 않으면 작업 스레드의 MDC는 비어 있습니다. 결국 그 스레드가 남긴 로그의 trace_id 칸도 빈칸으로 출력됩니다.

‍

‍

OpenTelemetry Java 에이전트는 작업을 다른 스레드로 넘길 때 추적 정보도 함께 전달합니다. 그래서 @Async 작업 로그에도 대개 별도 설정 없이 trace_id가 출력됩니다.

Micrometer Tracing을 쓴다면 추적 정보를 전달하는 설정을 직접 추가해야 합니다. 먼저 관련된 두 가지 요소의 역할을 알아 둡니다.

• TaskExecutor: Spring이 @Async 작업을 실행할 때 쓰는 스레드풀
• ContextPropagatingTaskDecorator: 요청 스레드의 추적 정보를 작업 스레드로 전달하는 데코레이터. TaskExecutor에 적용해 쓰며, Spring Boot 3.2부터 제공

이 데코레이터를 빈으로 하나만 등록하면 됩니다. 빈은 Spring이 관리하는 객체입니다. 등록한 데코레이터는 Spring Boot가 자동 구성한 TaskExecutor에 적용됩니다. Spring Boot 4.1부터는 빈을 만드는 대신 spring.task.execution.propagate-context=true 속성 하나로 같은 데코레이터를 등록할 수 있습니다.

@Configuration
class ContextPropagationConfiguration {

    @Bean
    ContextPropagatingTaskDecorator contextPropagatingTaskDecorator() {
        return new ContextPropagatingTaskDecorator();
    }
}

‍

이 빈을 등록하면 비동기 작업의 로그에도 요청과 같은 trace_id가 출력됩니다.

단, 설정 코드에서 new ThreadPoolTaskExecutor()로 TaskExecutor를 직접 만들었다면 등록한 빈이 자동으로 적용되지 않습니다. 이때는 executor.setTaskDecorator(new ContextPropagatingTaskDecorator());로 데코레이터를 직접 지정합니다.

‍

자주 묻는 질문

trace_id와 traceId, 로그 키 이름은 하나로 맞춰야 하나요

꼭 맞출 필요는 없지만, 하나로 맞추면 검색 조건 하나로 찾을 수 있습니다. 도구마다 기본 키 이름이 다릅니다.

‍

와탭 APM 에이전트는 로그에 trace_id 대신 트랜잭션 ID인 @txid를 붙입니다. 여러 서비스를 거친 요청에는 멀티 트랜잭션 ID인 @mtid도 붙일 수 있습니다. @mtid는 설정한 비율의 요청에만 발급되며, Java 에이전트의 기본값은 10%입니다. @mtid 지원 여부는 언어마다 다릅니다.

애플리케이션 설정을 바꾸기 어렵다면 로그 수집기나 파이프라인에서 필드 이름을 하나로 바꿔 저장하는 방법도 있습니다.

WebFlux에서 로그에 traceId가 안 찍히는 이유는 무엇인가요

WebFlux는 Reactor라는 비동기 처리 라이브러리를 씁니다. Reactor는 처리 도중 작업을 다른 스레드로 넘길 수 있는데, 기본 설정에서는 스레드별 저장소인 MDC가 함께 넘어가지 않습니다. Spring Boot 3.2 이상에서 Micrometer Tracing을 쓴다면 spring.reactor.context-propagation=auto로 Reactor의 자동 전파를 켭니다. 그러면 작업이 다른 스레드로 넘어가도 추적 정보가 함께 전달되어 로그에 trace_id가 출력됩니다. OpenTelemetry Java 에이전트는 Reactor에도 자동으로 추적 코드를 붙입니다. 그래서 대개 이 설정 없이도 trace_id가 출력됩니다.

‍

마치며

설정을 마쳤다면 운영 중인 서비스에서 비동기 작업을 거치는 HTTP 요청을 하나 보냅니다. 그리고 그 요청의 trace_id로 로그를 검색합니다. 다음 세 가지가 모두 맞으면 설정이 제대로 적용된 것입니다.

• 요청 로그: 요청을 처리한 로그에 trace_id가 출력되는가
• 비동기 작업 로그: 같은 trace_id로 비동기 작업의 로그도 검색되는가
• 스레드 이름: 두 로그 줄에 찍힌 스레드 이름이 서로 다른가. 이름이 같으면 같은 스레드에서 실행된 것이라 추적 정보 전달을 확인할 수 없습니다

OpenTelemetry 같은 트레이싱 도구 대신 APM 제품의 에이전트를 쓰는 서비스도 있습니다. 이 경우 에이전트가 부여한 식별값을 로그에 함께 기록하면, 로그와 해당 트랜잭션을 연결할 수 있습니다. 와탭 APM Java 에이전트는 요청 한 건의 처리를 트랜잭션이라 부르고, 트랜잭션마다 트랜잭션 ID인 txid를 부여합니다. 에이전트 설정 logsink_trace_enabled를 쓰면 txid를 로그에 함께 남길 수 있습니다. 그러면 와탭 로그 모니터링에서 로그 한 줄로 그 트랜잭션을 바로 열 수 있습니다. 설정 방법은 로그 모니터링 Java 설정 문서에 정리되어 있습니다.

‍

더 읽을거리

• 장애 때 필요한 로그만 찾는 법, trace_id 활용 가이드
• 로그 레벨 종류와 순서, ERROR WARN 차이와 구조화 로깅
• 로그 모니터링 Java 설정 (와탭 공식 문서)
• Tracing (Spring Boot Reference)
• Observability, Context Propagation (Spring Boot Reference)
• Logger MDC auto-instrumentation (OpenTelemetry Java 계측 문서)