[Spring] 쓰레드 로컬 - ThreadLocal - 2

내가 공부한것을 올리며, 중요한 단원은 저 자신도 곱씹어 볼겸 상세히 기록하고 얕은부분들은 가겹게 포스팅 하겠습니다.

 

5. ThreadLocal - 소개

쓰레드 로컬은 해당 쓰레드만 접근할 수 있는 특별한 저장소를 말한다.

쉽게 이야기해서 물건 보관 창구를 떠올리면 된다.

여러 사람이 동일한 물건 보관 창구의 직원에게 물건을 전달하면, 직원은 사용자를 인식해서 사용자별로 확실하게 물건을 구분해준다.

 

쓰레드 로컬을 사용하면 각 Thread마다 별도의 내부 저장소를 제공한다.

따라서 같은 인스턴스의 쓰레드 로컬 필드에 접근해도 문제 없다.

 

출처 - 인프런 김영한 고급편

thread-A 가 userA 라는 값을 저장하면 쓰레드 로컬은 thread-A 전용 보관소에 데이터를 안전하게 보관한다.

 

출처 - 인프런 김영한 고급편

thread-B 가 userB 라는 값을 저장하면 쓰레드 로컬은 thread-B 전용 보관소에 데이터를 안전하게 보관한다.

 

쓰레드 로컬을 통해서 데이터를 조회할 경우:

thread-A 가 조회하면 쓰레드 로컬은 thread-A 전용 보관소에서 userA 데이터를 반환해준다.

thread-B 가 조회하면 쓰레드 로컬은 thread-B 전용 보관소에서 userB 데이터를 반환해준다.

 

6. ThreadLocal - 예제 코드

기존의 코드와 거의 동일하지만, ThreadLocal을 사용하도록 코드를 변경시켜보자!

@Slf4j
public class ThreadLocalService {

    private ThreadLocal<String> nameStore = new ThreadLocal<>();

    public String logic(String name) {
        log.info("저장 name={} -> nameStore={}", name, nameStore.get());
        nameStore.set(name);
        sleep(1000);
        log.info("조회 nameStore={}", nameStore.get());
        return nameStore.get();
    }

    private void sleep(int millis) {
        try {
            Thread.sleep(millis);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

 

- ThreadLocal 사용법
값 저장: ThreadLocal.set(xxx)

값 조회: ThreadLocal.get()
값 제거: ThreadLocal.remove()

 

실제로 동작하는 흐름을 테스트 해보자

@Slf4j
public class ThreadLocalServiceTest {

    ThreadLocalService service = new ThreadLocalService();

    @Test
    void field() {
        log.info("main start");

        Runnable userA = () -> {
            service.logic("userA");
        };
        Runnable userB = () -> {
            service.logic("userB");
        };

        Thread threadA = new Thread(userA);
        threadA.setName("thread-A");
        Thread threadB = new Thread(userB);
        threadB.setName("thread-B");

        threadA.start(); // A실행
        sleep(2000);
        threadB.start();
        sleep(3000); // 메인 쓰레드 종료 대기

        log.info("main exit");
    }

    private void sleep(int millis) {
        try {
            Thread.sleep(millis);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

 이전에 위에서 진행했던 코드와 거의 동일하다, 변경된 점은 ThreadLocalService를 사용하는 부분일 뿐이다.

 

실행결과를 살펴보자, 각각 2초, 0.2초를 sleep한 경우이다.

이전과 달리 Thread마다 개별 저장소가 있기 때문에, 각자 자신의 것을 출력하고 있다!

동시성 문제가 해결되었다! 

 

7. 쓰레드 로컬 동기화 - 개발

우리의 애플리케이션에 ThreadLocal을 적용시켜보자!

@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-";

    // ThreadLocal로 변경
    private ThreadLocal<TraceId> traceIdHolder = new ThreadLocal<>();

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

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

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

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

    private void complete(TraceStatus status, Exception e) {
        Long stopTimeMs = System.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() {
        TraceId traceId = traceIdHolder.get();
        if(traceId.isFirstLevel()) {
            traceIdHolder.remove();
        } else {
            traceIdHolder.set(traceId.createPreviousId());
        }
    }

    private static String addSpace(String prefix, int level) {
        StringBuilder sb = new StringBuilder();
        for (int i = 0; i < level; i++) {
            sb.append((i == level - 1) ? "|" + prefix : "|   ");
        }
        return sb.toString();
    }
}

ThreadLocal을 통해 LogTrace를 개선하였다.

 

추가로 쓰레드 로컬을 모두 사용하고 나면 꼭 ThreadLocal.remove() 를 호출해서 쓰레드 로컬에 저장된 값을 제거해주어야 한다.

만약 제거해주지 않는다면, 메모리 누수가 발생할수도 있다.

 

이전과 동일한 테스트로 실행결과를 살펴보자.

class ThreadLocalLogTraceTest {

    ThreadLocalLogTrace trace = new ThreadLocalLogTrace();

    @Test
    public void begin_end_level2() {
        TraceStatus status1 = trace.begin("hello1");
        TraceStatus status2 = trace.begin("hello2");
        trace.end(status2);
        trace.end(status1);
    }

    @Test
    void begin_exception_level2() {
        TraceStatus status1 = trace.begin("hello");
        TraceStatus status2 = trace.begin("hello2");
        trace.exception(status2, new IllegalStateException());
        trace.exception(status1, new IllegalStateException());
    }
}

정상적으로 다음과 같이 출력된다.

 

8. 쓰레드 로컬 동기화 - 적용

이전까지 동시성 문제가 있는 FieldLogTrace 대신에 문제를 해결한 ThreadLocalLogTrace 를 스프링 빈으로 등록하자.

@Configuration
public class LogTraceConfig {

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

다음 URI로 정상 요청을 연속해서 1초안에 2번 보내보자!

http://localhost:8080/v3/request?itemId=hello

 

실행 결과는 다음과 같다.

각각의 로그를 분리하여 확인해보면 다음과 같다.

[nio-8080-exec-3] [8fbdec22] OrderController.request()
[nio-8080-exec-3] [8fbdec22] |-->OrderService.orderItem()
[nio-8080-exec-3] [8fbdec22] |   |-->OrderRepository.save()
[nio-8080-exec-3] [8fbdec22] |   |<--OrderRepository.save() time=1002ms
[nio-8080-exec-3] [8fbdec22] |<--OrderService.orderItem() time=1002ms
[nio-8080-exec-3] [8fbdec22] OrderController.request() time=1003ms

[nio-8080-exec-4] [9d489286] OrderController.request()
[nio-8080-exec-4] [9d489286] |-->OrderService.orderItem()
[nio-8080-exec-4] [9d489286] |   |-->OrderRepository.save()
[nio-8080-exec-4] [9d489286] |   |<--OrderRepository.save() time=1005ms
[nio-8080-exec-4] [9d489286] |<--OrderService.orderItem() time=1006ms
[nio-8080-exec-4] [9d489286] OrderController.request() time=1007ms

로그를 직접 분리해서 확인해보면 각각의 쓰레드 nio-8080-exec-3 , nio-8080-exec-4 별로 로그가 정확하게 나누어 진 것을 확인할 수 있다.

 

9. 쓰레드 로컬 - 주의사항

Thread Local의 값을 사용 후 제거하지 않으면, WAS(톰캣)처럼 Thread Pool을 사용하는 경우에 심각한 문제가 발생할 수 있다.

 

다음 그림을 통해 확인해보자

 

▶ 사용자A 저장 요청

출처 - 인프런 김영한 고급편

1. 사용자가 저장 HTTP를 요청했다.

2. 사전에 생성된 Thread Pool에서 Thread를 하나 조회 한다.

3. 사용자의 작업을 처리하기 위해 Thread-A 가 할당되었다.

4. Thread-A 는 사용자A 의 데이터를 Thread Local에 저장한다.

5. Thread Local의 Thread-A 전용 보관소에 사용자A 데이터를 보관한다.

 

▶ 사용자A 저장 요청 종료

출처 - 인프런 김영한 고급편

사용자의 저장 요청 처리가 끝나면서 WAS는 Thread-A를 Thread Pool에 반환한다.

이때 Thread-A가 완전하게 소멸되는 것 이 아니다, Thread Pool 내부에 살아있다.

따라서 쓰레드 로컬의 thread-A 전용 보관소에 사용자A 데이터도 함께 살아있게 된다.

 

▶ 사용자B 조회 요청 (문제가 발생하는 상황)

출처 - 인프런 김영한 고급편

1. 사용자B가 조회를 위한 새로운 HTTP 요청을 한다.
2. WAS는 쓰레드 풀에서 쓰레드를 하나 조회한다.
3. 우연하게 쓰레드 thread-A 가 할당되었다.
4. 이번에는 조회하는 요청이다. thread-A 는 쓰레드 로컬에서 데이터를 조회한다.

5. 쓰레드 로컬은 thread-A 전용 보관소에 있는 사용자A 값을 반환한다.
6. 결과적으로 사용자A 값이 반환된다.
7. 사용자B는 사용자A의 정보를 조회하게 되는 문제가 발생한다.

 

이런 문제를 예방하려면 사용자A의 요청이 끝날 때 쓰레드 로컬의 값을 ThreadLocal.remove() 를 통해서 꼭 제거해야 한다.