4 분 소요

 인프런 스프링 핵심 원리 - 고급편을 학습하고 정리한 내용 입니다.

쓰레드 로컬 동기화 - 개발

FieldLogTrace에서 발생했던 동시성 문제를 ThreadLocal로 해결해 보자.

TraceId traceIdHolder 필드를 쓰레드 로컬을 사용하도록 ThreadLocal traceIdHolder로 변경하면 된다.

필드 대신 쓰레드 로컬을 사용해서 데이터를 동기화 하는 ThreadLocalLogTrace를 새로 만들자.

ThreadLocalLogTrace

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70

@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 TraceId traceIdHolder; // traceId 동기화, 동시성 이슈 발생..  
    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();  
    }  
}

1
2

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

traceIdHolder가 필드에서 ThreadLocal로 변경되었다. 따라서 값을 저장할 때는 set(..)을 사용하고, 값을 조회할 때는 get()을 사용한다

1
2
3
4
5
6
7
8

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

먼저 traceIdHolder에서 traceId를 가져와서 set()을 사용해서 세팅을 한다.

값이 있다면 다음 Level을 세팅하기 위해 createNextId()를 사용한다.

1
2
3
4
5
6
7
8

private void releaseTraceId() {  
	TraceId traceId = traceIdHolder.get();  
	if (traceId.isFirstLevel()) {  
		traceIdHolder.remove(); // 파괴  
	} else {  
		traceIdHolder.set(traceId.createPreviousId()); // 레벨 감소  
	}  
}

로그 레벨이 감소 할 때도 마찬가지 이다.

하지만 이제 마지막 즉 처음 로그 레벨일 때는 traceIdHolder.remove()를 사용해 삭제 시켜줘야 한다.

ThreadLocal.remove()

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

쉽게 이야기해서 다음의 마지막 로그를 출력하고 나면 쓰레드 로컬의 값을 제거해야 한다.

1
2
3
4

[3f902f0b] hello1 
[3f902f0b] |-->hello2 
[3f902f0b] |<--hello2 time=2ms 
[3f902f0b] hello1 time=6ms //end() -> releaseTraceId() -> level==0, ThreadLocal.remove() 호출

여기 서는 releaseTraceId()를 통해 level이 점점 낮아져서 2→1→0이 되면 로그를 처음 호출한 부분으로 돌아온 것이다.

따라서 이 경우 연관된 로그 출력이 끝난 것이다. 이제 더 이상 TraceId 값을 추적하지 않아도 된다.

그래서 traceId.isFirstLevel()(level==0)인 경우 ThreadLocal.remove()를 호출해서 쓰레드 로컬에 저장된 값을 제거해준다.

코드에 문제가 없는지 간단한 테스트를 만들어서 확인해보자.

ThreadLocalLogTraceTest

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

class ThreadLocalLogTraceTest {  
  
    ThreadLocalLogTrace trace = new  ThreadLocalLogTrace();  
  
    @Test  
    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("hello1");  
        TraceStatus status2 = trace.begin("hello2");  
  
        trace.exception(status2, new IllegalStateException());  
        trace.exception(status1, new IllegalStateException());  
    }  
}

잘 된다.

이제 멀티쓰레드 상황에서 문제가 없는지는 애플리케이션에 ThreadLocalLogTrace를 적용해서 확인해보자.

쓰레드 로컬 동기화 - 적용

자 이제 기존 로직들을 크게 바꿀 필요 없이 LogTraceConfig만 잘 수정해 주면 된다.

hello.advanced.LogTraceConfig

1
2
3
4
5
6
7
8
9
10

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

이렇게 컨트롤러나 사용하는 곳에서 인터페이스로 주입을 받기 때문에 bean에서 구현체만 잘 바꿔주면 변경이 된다.

이제 정상적으로 쓰레드 별로 나누어 진 걸 볼 수 있다.

쓰레드 로컬 - 주의 사항

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

다음 예시를 통해서 알아보자.

사용자A 저장 요청

  1. 사용자A가 저장 HTTP를 요청했다.
  2. WAS는 쓰레드 풀에서 쓰레드를 하나 조회한다.
  3. 쓰레드 thread-A 가 할당되었다.
  4. thread-A는 사용자A의 데이터를 쓰레드 로컬에 저장한다.
  5. 쓰레드 로컬의 thread-A 전용 보관소에 사용자A 데이터를 보관한다.

사용자A 저장 요청 종료

  1. 사용자A의 HTTP 응답이 끝난다.
  2. WAS는 사용이 끝난 thread-A를 쓰레드 풀에 반환한다. 쓰레드를 생성하는 비용은 비싸기 때문에 쓰레드를 제거하지 않고, 보통 쓰레드 풀을 통해서 쓰레드를 재사용한다.
  3. thread-A는 쓰레드풀에 아직 살아있다. 따라서 쓰레드 로컬의 thread-A 전용 보관소에 사용자A 데이터도 함께 살아있게 된다.

사용자B 조회 요청

  1. 사용자B가 조회를 위한 새로운 HTTP 요청을 한다.
  2. WAS는 쓰레드 풀에서 쓰레드를 하나 조회한다.
  3. 쓰레드 thread-A가 할당되었다. (물론 다른 쓰레드가 할당될 수 도 있다.)
  4. 이번에는 조회하는 요청이다. thread-A는 쓰레드 로컬에서 데이터를 조회한다.
  5. 쓰레드 로컬은 thread-A전용 보관소에 있는 사용자A 값을 반환한다.
  6. 결과적으로 사용자A값이 반환 된다.
  7. 사용자B는 사용자A의 정보를 조회하게 된다.

결과적으로 사용자B는 사용자A의 데이터를 확인하게 되는 심각한 문제가 발생하게 된다.

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

쓰레드 로컬을 사용할 때는 이 부분을 꼭! 기억하자

댓글남기기

참고