[Spring] ThreadLocal로 싱글톤 패턴의 동시성 문제 해결

이 전 포스팅에서 파라미터 동기화로 하나의 HTTP 요청에 대해서 고유의 TraceId를 사용하도록 고쳐보았습니다.

동기화에는 성공했지만, 여전히 문제가 있었습니다.

1.  로그를 출력하는 모든 메소드에 TraceId 파라미터를 추가해주어야 하는 껄끄러움(확장, 유지보수에 대한 불편함)이 있었습니다.
2. 뿐만 아니라 각 계층에 try/catch문을 사용하게 되어 코드의 가독성까지 떨어졌어요.
3. 이 외에도 첫 요청에 대해서만 begin을 호출하고, 이어받은 계층에서는 beginSync를 실행하도록 설정해야 하기 때문에, 비슷한 기능에 코드의 확장까지 이루어져 좋은 코드라고 보기 어렵습니다.

이번에는 다른방법을 도입해보도록 합시다. 결론적으로 말하자면  ThreadLocal을 사용합니다.
 
하지만 처음부터 ThreadLocal을 도입하지 않고,

1. TraceId를 클래스 내에 인스턴스의 필드에 담아서 사용하는 필드 로그 추적기를 만들어 보고, 
2. 이 때 발생하는 문제를 확인해보고,
3. ThreadLocal을 적용시켜 발생한 문제를 해결해보도록 하겠습니다.

같은 기능을 하는 두 가지(Thread를 사용한 로그 추적기, ThreadLocal을 사용한 로그 추적기) 로그 추적기를 도입할 예정이므로, 먼저 프로토타입으로 인터페이스부터 작성하도록 합시다.

public interface LogTrace {

    TraceStatus begin(String msg);
    void end(TraceStatus status);
    void exception(TraceStatus status, Exception e);
}

• 이 전 로그추적기와 다르게, beginSync와 begin을 구분짓지 않고 begin 내부에서 첫 호출인지 검사할 예정

---

인스턴스의 필드에 동기화 - FieldLogTrace

@Slf4j
public class FieldLogTrace implements LogTrace {

    private static final String START_PREFIX = "-->";
    private static final String COMPLETE_PREFIX = "<--";
    private static final String EX_PREFIX = "<X-";

    private TraceId traceIdHolder; // 추가

이 전 로그 추적기와 달리 TraceId를 담을 traceHolder를 추가하였습니다. 이렇게 하게 되면 파라미터로 넘길 필요가 없어집니다.
아래에서 코드를 살펴보긴 하겠지만, 먼저 설명하자면 이렇습니다.

• 로그 추적기의 시작인 경우 새로운 TraceId를 생성,
• 그렇지 않은 경우 traceHolder에서 createNextId()로 동기화된 TraceId를 사용

FieldLogTrace.begin 

@Override
public TraceStatus begin(String message) {
    syncTraceId();
    TraceId traceId = traceIdHolder;
    Long startTimeMills = currentTimeMillis();
    log.info("[{}] {}{}", traceId.getId(), addSpace(START_PREFIX, traceId.getLevel()), message);
    return new TraceStatus(traceId, startTimeMills, message);
}

private void syncTraceId() {
    if (traceIdHolder == null) {
        traceIdHolder = new TraceId();
    } else {
        traceIdHolder = traceIdHolder.createNextId();
    }
}

위에서 했던 설명 그대로입니다. 중요한 부분은 synTraceId()입니다.
 
syncTraceId

• 로그 추적기의 시작인 경우 새로운 TraceId를 생성,
• 그렇지 않은 경우 traceHolder에서 createNextId()로 동기화된 TraceId를 사용

여기서 생성되거나 동기화된 TraceId를 사용함으로써 동기화 문제 뿐만 아니라 불필요한 코드확장 ( begin(), beginSync() 구분 ) 까지 해결했습니다.
 

FieldLogTrace - end, exception

public void end(TraceStatus status) {
    complete(status, null);
}

public void exception(TraceStatus status, Exception e) {
    complete(status, e);
}

이전과 동일하지만 complete 이후 처리가 조금 수정되었습니다.

private void complete(TraceStatus status, Exception e) {
    Long stopTimeMs = currentTimeMillis();
    long resultTimeMs = stopTimeMs - status.getStartTimeMs();
    TraceId traceId = status.getTraceId();

    if (e == null) {
        log.info("[{}] {}{} time={}ms", traceId.getId(),
                addSpace(COMPLETE_PREFIX, traceId.getLevel()), status.getMessage(),
                resultTimeMs);
    } else {
        log.info("[{}] {}{} time={}ms ex={}", traceId.getId(),
                addSpace(EX_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs,
                e.toString());
    }

    releaseTraceId();
}

private void releaseTraceId() {
    if (traceIdHolder.isFirstLevel()) {
        traceIdHolder = null; // 1 -> destroy
    } else {
        traceIdHolder = traceIdHolder.createPreviousId(); // 1 -> 2 -> 3(complete) -> 2 -> 1
    }
}

releaseTraceId()가 추가되었습니다.
 
releaseTraceId()

• 인스턴스 필드로 처리해주었기 때문에 요청이 끝나게 되면 이 전 계층에게 traceHolder에 현재 TraceId의 이전 값을 넘겨주어야 합니다. ( level을 하나 감소 ) 
• 만약 최초 호출(level=0)이면 내부에서 관리하는 traceId를 제거 
• syncTraceId()의 역로직

 
테스트 코드를 만들어 테스트 해보면 트랜잭션 ID도 일치, level을 통한 깊이 표현도 잘 되는 것을 확인할 수 있습니다.

---

로직에 도입 , 동시성 문제 확인

우선 위에서 만든 FieldLogTrace를 빈으로 등록해줍시다. 

왜 수동으로 등록했을까 ?
: 이 추적기 말고도 추후에 ThreadLocal을 사용한 로그 추적기도 구현할 예정인데 갈아 끼우기 쉽게 하기 위함.
/ 프로토타입이 선언되고 구현체가 여러 개라면 수동 빈으로 등록하는 것이 좋은 것 같다.

@Configuration
public class LogTraceConfig {
    @Bean
    public LogTrace logTrace() {
        return new ThreadLocalLogTrace();
    }
}

 
Controller, Service, Repository 쪽은 이 전 로그 추적기 (ver2)에서 추적기만 갈아끼워주면 되기 때문에 따로 코드를 언급하지 않겠습니다.

// private final HelloTraceV2 trace; 
private final LogTrace trace;

 
이제 HTTP 요청을 통해 테스트를 해보겠습니다.
 
http://localhost:8080/v3/request?itemId=3 

• 동시에 여러 사용자가 요청하면 여러 쓰레드가 동시에 애플리케이션 로직을 호출하게 됩니다. 
• 이를 테스트 해보기 위해 요청을 빠르게 여러번 보내봅시다.

트랜잭션 ID는 동일한데 Level도 이상합니다. 테스트 코드에서는 문제가 없었는데 뭐가 문제일까요.
 
이 문제는 동시성 문제입니다. 

동시성 문제

• 싱글톤 빈에서 발생하는 문제로, 여러 쓰레드가 하나의 싱글톤 빈에 동시에 접근하는 경우 발생합니다.

• 이처럼 1)여러 쓰레드가 동시에 같은 인스턴스의 필드 값을 변경하거나, 2)호출이 처리되는 도중 다른 호출이 요청될 때 같은 인스턴스의 필드값을 참조할 때 발생하는 문제를 동시성 문제라고 합니다.

• 이런 동시성 문제는 여러 쓰레드가 같은 인스턴스의 필드에 접근해야 하기 때문에 트래픽이 적은 상황에서는 확률상 잘 나타나지 않고, 트래픽이 점점 많아질 수 록 자주 발생합니다.
• 특히 스프링 빈 처럼 싱글톤 객체의 필드를 변경하며 사용할 때 이러한 동시성 문제를 조심해야 합니다.

 

---

ThreadLocal 도입하여 동시성 문제 해결 

동시성 문제는 같은 인스턴스의 필드( 주로 싱글톤에서 자주 발생 )나 static 같은 공용 필드에 접근할 때 발생합니다.
값을 읽기만 하면 문제가 없지만, 값을 변경할 때 문제가 발생합니다. 
싱글톤 객체의 필드를 사용하면서 동시성 문제를 해결하기 위한 방법으로는 ThreadLocal을 사용하는 방법이 있습니다.
 

ThreadLocal이란?

• 해당 쓰레드만 접근할 수 있는 특별한 저장소입니다.
• 쓰레드 로컬을 사용하면 각 쓰레드마다 별도의 내부 저장소를 제공하므로, 같은 인스턴스의 쓰레드 로컬 필드에 접근해도 문제가 발생하지 않습니다.

ThreadLocal 사용법

• 값 저장 : ThreadLocal.set()
• 값 조회 : ThreadLocal.get()
• 값 제거 : ThreadLocal.remove() ( 주의 : 쓰레드가 종료되기 직전 반드시 호출되어야 함 ! )

ThreadLocalLogTrace 생성

@Slf4j
public class ThreadLocalLogTrace implements LogTrace{

    private static final String START_PREFIX = "-->";
    private static final String COMPLETE_PREFIX = "<--";
    private static final String EX_PREFIX = "<X-";

    private ThreadLocal<TraceId> traceIdHolder = new ThreadLocal<>(); // traceId 동기화, 동시성 이슈 X

• 필드 로그 추적기에서 인스턴스 필드를 사용한 것과 달리, ThreadLocal을 도입하였습니다.
• 참고로 ThreadLocal을 ThreadLocal<T> 이므로 어떤 타입이던지 들어올 수 있습니다.

 
그 외 변경점

@Override
public TraceStatus begin(String message) {
    syncTraceId();
    TraceId traceId = traceIdHolder.get();

private void syncTraceId() {
    TraceId traceId = traceIdHolder.get();
    if (traceId == null) {
        traceIdHolder.set(new TraceId());
    } else {
        traceIdHolder.set(traceId.createNextId());
    }
}

private void releaseTraceId() {
    TraceId traceId = traceIdHolder.get();
    if (traceId.isFirstLevel()) {
        traceIdHolder.remove();
    } else {
        traceIdHolder.set(traceId.createPreviousId());
    }
}

조회할 때에는 get(), 저장할 때에는 set()을 사용합니다. 주의해야 할 점은 아까 언급했듯이 쓰레드 종료 시점(traceId.isFirstLevel) 에는 remove()를 호출하여 쓰레드 로컬에 저장된 값을 제거해주어야 합니다.
 
테스트를 해보면

트랜잭션 아이디 구분 X

위 결과의 트랜잭션 아이디를 구분지어서 확인해보면 동시성 문제가 해결된 것을 확인할 수 있습니다.
 

ThreadLocal 사용 시 쓰레드 종료 시점에  remove()를 호출해주어야 하는 이유

쓰레드 로컬의 값을 사용 후 제거하지 않고 그냥 두면 WAS(톰캣)처럼 쓰레드 풀을 사용하는 경우에 심각한 문제가 발생할 수 있습니다.

CASE)

1. A라는 유저가 쓰레드 로컬에서 쓰레드를 사용해 값을 저장한 이후 remove()를 호출하지 않은 상황
2. B라는 유저가 같은 요청(값 조회라고 가정)을 함.
3. B 유저가 유저가 A가 사용했던 쓰레드를 할당받았음.
4. B는 A가 쓰레드 로컬에 지우지 않고 남겨둔 데이터를 받게 됨.

참고로 쓰레드는 종료시점에 쓰레드 풀에 다시 반환됩니다.

 
이 때 동시성 문제가 이전과 동일하게 발생하게 됩니다. 이러면 ThreadLocal을 도입한게 말짱 도루묵
 
쓰레드 로컬을 사용할 때는 반드시 반드시 꼭 종료시점에 remove()를 호출하도록 합시다.
 
<참고 자료>

스프링 핵심 원리 - 고급편 - 인프런 | 강의