[Spring] Sl4fj MDC로 요청 구분하기
Slf4j MDC란?
Slf4j(Simple Logging Facade for Java)는 자바 로깅 라이브러리 인터페이스고,
MDC(Mapped Diagnostic Context)는 Sl4fj에서 제공하는 기능으로 Thread Local에 정보를 Map 형태로 저장할 수 있다.
Thread Local은 각 스레드가 따로 가지는 저장 공간이라고 생각하면 된다.
그러면 Thread Local에 값을 저장하면 되는거 아니야? 라고 할 수 있는데, Map으로 key-value를 관리하기에 더 다루기 편한 것도 있고
로깅 시스템과 통합돼있어서 다루기 편리하다. 필요에 따라 context를 복사해야할 때도 있는데, 이에 대한 기능도 제공해 간편하다.
이걸 왜 써야 하나요?
요청마다 타는 로직이 다를 수 있다. 그런데 이런 요청이 너무 많아진다면? 서버가 싱글 스레드로 도는게 아니라서 순식간에 로그가
뒤죽박죽 섞일 것이다. 이때 장애가 발생하면 어떤 로직을 탔는지 확인이 필요할 때 요청을 구분할 수 없기때문에 매우 곤란해진다.
그래서 로그를 봤을 때 어느 요청에 의한 로그인지 구분할 수 있어야 한다. 요청을 구분할 수 있는 정보를 스레드별로 관리하려고
Thread Local을 쓰는 거고, 동시에 로깅에 편리한 방법이 MDC를 사용하는 것이다.
MDC 적용하기
저장은 MDC.put(key, value), 조회는 MDC.get(key)를 쓰면 된다. (String만 가능)
MDC.put("hi", "hello")
val result = MDC.get("hi")
logger.info("result = $result") // "hello"
Servlet Filter
요청마다 UUID를 생성해 요청을 구분한다고 해보자. 그러면 Controller마다 UUID를 생성해서 MDC.put()을 호출해야 할까?
가능은 하지만 수정 범위가 너무 많고 실수할 여지도 많다. 그렇게 하지말고 Servlet Filter를 만들어 등록해주자.
@Component
class MdcFilter: Filter {
override fun init(filterConfig: FilterConfig?) {
super.init(filterConfig)
}
override fun doFilter(request: ServletRequest, response: ServletResponse, chain: FilterChain) {
val traceId = UUID.randomUUID().toString().substring(0, 6) // 요청을 구분할 UUID 앞 6자리
MDC.put("traceId", traceId) // 요청이 들어올 때마다 MDC에 저장해주자
chain.doFilter(request, response)
}
}
- 이렇게 하면 요청이 들어올 때마다
MdcFilter를 거치면서 요청을 구분할 수 있게 MDC에traceId를 저장함
MDC.get("traceId")도 로그에 직접 넣어주지 말고, logback-spring.xml 파일을 resources에 만들어주자.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>[%X{traceId:-NO TRACE ID}] %msg%n</pattern>
</encoder>
</appender>
<root>
<level value="INFO" />
<appender-ref ref="STDOUT" />
</root>
</configuration>
- pattern 태그를 보면,
%X{키 이름}을 적어주면 MDC에서{키 이름}으로 저장된 값을 알아서 등록해줌 - MDC에
{키 이름}으로 등록된 값이 없으면%X{키 이름:-기본값}으로기본값을 설정해줄 수 있음
그러면 로그에 MDC 정도를 직접 적어주지 않아도 같이 출력된다.
logger.info("hello")
>> [6f56cf] hello
6f56cf로 요청을 구분하면 된다!
스레드가 달라지면 MDC가 달라진다
같은 요청인데 다른 스레드를 사용하는 케이스가 뭐가 있을까?
EventListener에 @Async가 붙어서 새 스레드로 동작하는 경우가 있고, 다른 context의 코루틴에서 동작하는 경우가 있다.
커스텀 스레드풀 등록하기 (MDC를 곁들인)
AsyncConfigurer를 구현한 스레드풀 설정을 등록해놓으면, @Async처럼 새 스레드에서 동작하는 경우 등록한 스레드풀을 사용하게
만들 수 있다. 이때 스레드풀에 있는 스레드들도 같은 MDC를 품을 수 있도록 decorator를 적용해야한다.
class MdcTaskDecorator: TaskDecorator {
override fun decorate(runnable: Runnable): Runnable {
val context = MDC.getCopyOfContextMap() // MDC 복사
return Runnable {
MDC.setContextMap(context) // 새 스레드 MDC에 저장
runnable.run()
}
}
}
AsyncConfigurer를 구현한 설정 클래스 AsyncConfig도 만들어서 등록해주자.
@Configuration
@EnableAsync
class AsyncConfig : AsyncConfigurer {
@Bean
fun customTaskExecutor(): ThreadPoolTaskExecutor {
val taskExecutor = ThreadPoolTaskExecutor()
// ... 스레드풀 설정 생략
taskExecutor.setTaskDecorator(MdcDecorator()) // decorator 설정
taskExecutor.initialize()
return taskExecutor
}
override fun getAsyncExecutor(): Executor {
return customTaskExecutor()
}
}
다른 스레드에서 동작하는 코루틴
부모의 context를 물려받는 코루틴이라면 MDC가 유지돼서 괜찮다.
예) 파라미터가 없는 runBlocking, launch 등
하지만 withContext()를 사용해서 다른 스레드풀을 사용한다면?
launch로 코루틴은 생성할 건데 파라미터로 다른 스레드풀을 넣어준다면?
이때는 다른 스레드에서 동작하는거니까 MDC가 달라진다. 여기는 위에처럼 decorator 설정을 추가해주지 않아도 된다.
MDCContext()를 사용해서 간편하게 기존 MDC를 복사할 수 있다. CoroutineContext에 + 연산자 오버로딩이 된다!
아래처럼 설정해줄 수 있다.
suspend fun callInCoroutine() {
// [0995ec] hi from withContext
withContext(Dispatchers.IO + MDCContext()) {
logger.info("hi from withContext")
}
// [0995ec] hi from launch
coroutineScope {
launch(Dispatchers.IO + MDCContext()) {
logger.info("hi from launch")
}
}
// [NO TRACE ID] hi from launch in IO Dispatcher
coroutineScope {
launch(Dispatchers.IO) {
logger.info("hi from launch in IO Dispatcher")
}
}
}
launch(Dispatchers.IO)에서NO TRACE ID로 나온 이유는 Dispatchers.IO 스레드풀의 스레드는 기존 MDC가 없기 때문
댓글남기기