문제 상황 — 요청 단위 추적 불가능
일반적인 동기 구조에서는 하나의 요청이 하나의 스레드에서 순차 실행되므로,
요청 단위로 로그가 자연스럽게 분리된다. 따라서, 별도의 로그 컨텍스트 관리가 필요하지 않다.
하지만 현재 시스템은 코루틴 기반 Job 단위로 동작하며,
하나의 요청이 여러 스레드를 오가며 실행되기에 아래와 같은 문제가 발생했다.
- 동일 요청의 로그가 순서 없이 뒤섞여 추적이 어려움
- 하나의 요청 로그가 여러 스레드에서 분산 출력됨
- 서로 다른 요청이 동일 스레드 풀을 공유하면서 로그가 혼재됨
즉, 스레드 단위 로그만으로는 요청 단위 추적이 불가능 하였다.
문제 해결책 — MDC 도입 ?
이 문제를 해결하기 위해, 요
청마다
requestId, userId 같은 식별 값을 로그에 함께 기록하도록 MDC를 도입해보았다. MDC는 스레드 단위로 동작하는 key-value 형태의 컨텍스트 저장소로, 해당 스레드에서 발생하는 모든 로그에 동일한 메타 정보를 자동으로 포함시킨다. 이를 통해 로그를 요청 단위로 묶어 추적할 수 있다.
- 요청마다 고유 컨텍스트 부여
- 로그를 요청 단위로 그룹화 가능
- 사용자/트랜잭션 단위 추적 가능
내부적으로 MDC는 ThreadLocal 기반으로 동작하며, 각 스레드는 독립적인 컨텍스트를 가진다.
그러나, 코루틴에서는 여전히 요청 추적이 불가능
문제는 MDC가 ThreadLocal 기반이라는 점이다.
코루틴 환경에서는 하나의 요청이 여러 스레드를 오가며 실행되기 때문에,
- 실행 스레드 변경 시 MDC 값이 유실되거나
- 서로 다른 요청의 MDC가 같은 스레드에서 섞이는 문제
가 발생하며 MDC만으로는 일관성을 보장할 수 없었다.
Controller 구간에서는 request_id(5aee21a3)가 존재하지만,
이후 Service(비동기 구간)에서는 실행 컨텍스트가 끊겨 request_id가 비어 있다.
MDCContext (kotlinx-coroutines-slf4j 라이브러리)
이 문제를 해결하기 위해 Kotlin에서 제공하는
MDCContext를 적용했다.MDCContext는 코루틴 단위로 MDC 컨텍스트를 유지하며,
스레드가 변경될 때마다 ThreadLocal MDC를 자동으로 동기화해준다.
- 코루틴 생성 시 현재 속한 스레드의 MDC 상태를 복사하여 contextMap에 보관
- 보관 중이던 contextMap을 현재 실행 중인 스레드에 주입
- 기존에 스레드가 갖고 있던 원래 상태(oldState)를 반환하여 나중에 복구할 수 있도록 함
- 코루틴이 suspend되거나 완료 시 기존 MDC 상태 복원
- 스레드 풀의 다른 작업에 로그 컨텍스트가 오염되지 않도록 방지 (MDC.clear())
MDCContext는 코루틴 컨텍스트에 MDC 값을 포함시켜, 하위 코루틴들에도 자동으로 MDC가 전파되도록 설계 되어 있다. (부모 코루틴과 그 내부에서 생성된 모든 자식 코루틴은 동일한 MDC 컨텍스트를 공유)
요청 컨텍스트 전달 방식 — 프록시 서버 → Filter
MDC는 요청 단위로 설정되고 종료 시 정리되어야 하므로,
요청의 시작부터 끝까지 전체 흐름을 감싸는 위치에서 컨텍스트를 주입할 필요가 있다.
이에 따라 요청 진입 시점에서 request_id를 생성 & MDC에 저장하는 Filter 기반 구조를 적용했다. (Filter와 Interceptor 모두 MDC 설정이 가능하지만, Interceptor는 Controller 전/후 범위에 한정되기 때문에 요청 전체를 일관되게 관리하기 어려움)
코루틴이 여러 스레드에서 실행되더라도,
요청 시작부터 종료까지 동일한 request_id, user_id가 유지되었다.
값 | 역할 |
request_id | 로그 상관관계 추적 |
user_id | 어떤 사용자의 요청인지 식별 |
trace_id | 요청의 전체 실행 흐름 추적 |
실제 사용 예시
시나리오: 유저 1번이 "모임 상세 조회가 안 된다"고 신고가 들어왔다.
1. user_id 기반 로그 필터링
특정 사용자의 id를 검색했을 때,
해당 사용자가 어떤 요청을 했는지 한 눈에 보이게 대시보드를 구축하였다.
로그를 통해 별도 DB 조회 없이 대응이 가능하며, 두 로그의 차이점은 다음과 같다.
- GlobalExeptionHandler : 서비스 내부에서 발생한 예외 자체를 기록, 스택 트레이스 포함
- MdcFilter : 요청이 끝났을 때 남기는 요청 단위 요약 로그
두 로그를 함께 봐야하는 이유는 실패한 요청이 왜 실패했고, 얼마나 걸렸는지를 알 수 있기 때문이다.
2. traceId 기반 전체 호출 흐름 확인
traceId를 통해서는 요청 전체의 실행 흐름을 확인할 수 있다. 
상단에 해당 api의 총 처리 시간부터 각 레이어의 소요 시간이 표시된다.
또한 DB 쿼리와 쿼리 실행 속도, 응답 속도 등 모든 정보를 확인할 수 있다.
포인트는 특정 구간의 병목 식별이 가능하다는 점이다. 위의 경우 DB 연결 획득 및 상위 레이어 처리 구간에서 전체 요청 687.2ms 중 620ms가 소요되었음을 확인할 수 있었다.
이를 통해, 로그만으로 장애 원인 식별이 가능했고 빠른 대응이 가능해진다.
