티몬 연동셀이 외부 딜 연동 프로젝트에서 모든 요청과 응답을 로깅하려다 겪은 ThreadLocal 문제의 해결 과정이다. 한 요청에서 나온 여러 로그를 묶을 키를 파라미터로 넘기는 대신 ThreadLocal로 풀기로 했는데, 비동기 호출과 스레드풀 재사용이 겹치면서 문제가 연달아 튀어나왔다. 최종적으로 Runnable과 Callable을 래핑하고 beforeExecute에서 ThreadLocal을 다시 심는 구조로 마무리했다.
핵심 포인트- InheritableThreadLocal은 부모가 자식 스레드를 직접 생성할 때만 값을 물려준다.
- 스레드풀에서 꺼낸 스레드는 이미 자기 ThreadLocal을 갖고 있어 엉뚱한 부모의 값을 보게 된다.
- ThreadPoolExecutor의 beforeExecute 훅에서 ThreadLocal을 재선언하면 되지만 그 시점에는 부모의 값을 알 방법이 없다.
- 그래서 Runnable을 감싼 래퍼에 uuid를 실어 보내고 beforeExecute에서 꺼내 쓰는 구조로 풀었다.
- Callable은 submit 과정에서 FutureTask로 바뀌어 래퍼가 사라지므로 newTaskFor를 오버라이드해 FutureTask까지 확장해야 했다.
- 멀티스레드가 걸린 로직은 반드시 그 조건에서 테스트해야 한다는 것이 저자의 결론이다.
상세 정리- 요구사항: 외부 딜 연동에서 모든 요청과 응답을 기록하기로 했다. 요청과 응답은 결국 메서드 호출 파라미터와 리턴 값이다.
- 설계: 로깅이 필요한 메서드에 @Snapshot 어노테이션을 달고 AOP로 진입 시점에 파라미터를, joinPoint 실행 후에 결과를 얻어 기록한다.
- 성능 고려: 어노테이션 처리기에서 DB에 직접 쓰지 않고 메시지 큐에 로그 모델을 넣은 뒤 큐 리스너가 카우치베이스에 적재하도록 구상했다.
- 묶는 키의 필요성: 요청 하나가 여러 메서드를 호출하므로 로그가 여러 건 생기고, 이를 한 번에 조회하려면 같은 요청에서 나왔다는 마킹이 필요했다.
- 선택: 그 값을 메서드 파라미터로 계속 넘기면 간단히 끝나지만, 웹 요청이 스레드 기반이라는 점을 이용해 ThreadLocal로 풀기로 했다.
- 1차 실패: 특정 메서드에서 비동기로 다른 메서드를 호출하면 자식 스레드가 만들어져 ThreadLocal이 공유되지 않았다.
- 1차 조치: ThreadLocal을 확장한 InheritableThreadLocal로 바꾸자 자식 스레드에서도 값이 보였다.
- 2차 실패: 그런데 자식 메서드가 전혀 엉뚱한 부모의 값을 보는 현상이 나왔다.
- 원인: 비동기 메서드가 실제로는 부모가 새로 만든 스레드가 아니라 스레드풀에서 꺼내온 스레드였고, 풀의 목적이 재사용이라 ThreadLocal이 비워지지 않은 채 남아 있었다.
- 2차 조치 방향: ThreadPoolExecutor의 beforeExecute 훅을 구현하면 된다는 정보를 얻었고 주석에도 ThreadLocal 재선언 용도가 적혀 있었다.
- 3차 벽: beforeExecute에 진입한 시점의 Thread는 이미 풀에서 꺼낸 스레드라 부모가 가진 값을 가져올 방법이 애매했다.
- 3차 조치: 훅으로 전달되는 Runnable을 한 번 래핑하면서 생성자에서 현재 ThreadLocal 값을 uuid로 저장해 넘기고, 훅에서 그 uuid를 꺼내 ThreadLocal을 다시 세팅했다.
- 4차 문제: 커스텀 ExecutorService가 Callable도 받는데 Callable 실행 시 beforeExecute에 오는 것은 래퍼가 아니라 FutureTask였다.
- 원인 추적: AbstractExecutorService의 submit이 Callable을 RunnableFuture로 변환해 반환하기 때문이며, newTaskFor를 재정의하면 그 변환 지점을 잡을 수 있다.
- 최종 구조: FutureTask를 상속해 uuid를 담는 WrapFutureTask를 만들고, newTaskFor 오버라이드에서 WrapRunnable과 WrapCallable을 그것으로 감싼 뒤 beforeExecute에서 두 래퍼 타입 모두를 받아 ThreadLocal을 재설정한다.
- 재현 조건: 예제 코드에 스레드풀을 크게 늘리면 재현되지 않는다는 주석이 달려 있다. 풀이 넉넉하면 재사용이 덜 일어나기 때문이다.
- 원 문서 성격: 사내 메일 공유용으로 쓴 글을 그대로 공개한 것이며 예제 코드에 코드 스멜이 있다고 저자가 미리 밝힌다.
왜 읽나트레이스 ID나 MDC를 ThreadLocal로 옮기다 비동기와 스레드풀에서 값이 섞인 적이 있다면 래퍼와 beforeExecute 조합이 그 해법이다.