스프링 핵심 원리 - 고급편_쓰레드 로컬(필드 동기화 - 개발)

필드 동기화 - 개발

• 이전 예제에서 다음 로그 출력을 위해 TraceId를 파라미터로 넘기도록 구현했다.
• 동기화는 성공했지만, 모든 메서드에 파라미터를 추가해야 하는 문제가 발생
• 위 문제 해결 방법을 찾아보자.

LogTrace 인터페이스

먼저 프로토타입이 아닌 정식 버전으로 하기 때문에 인터페이스부터 생성해서 다양한 구현체에 대응할 수 있도록 해보자.

public interface LogTrace {
    TraceStatus begin(String message);
    void end(TraceStatus status);
    void exception(TraceStatus status, Exception e);
}

로그 추적기를 위한 최소한의 기능 begin(), end(), exception()만 추가했다.

FieldLogTrace

이제 파라미터를 넘기지 않고 TraceId 동기화 가능한 구현체를 만들어보자.

@Slf4j
public class FiledLogTrace 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 동기화, 동시성 이슈 발생

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

    }

    @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(); // end 에서 호출 되면 마지막이라는 뜻이기 때문에 traceHolder 제거함
    }

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

    private void releaseTraceId() {
        if (traceIdHolder.isFirstLevel()) {
            traceIdHolder = null; //traceHolder 제거
        } else {
            traceIdHolder = traceIdHolder.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();
    }
}

• 기존 HelloTraceV2와 거의 같은 기능
• TraceId를 동기화 하는 부분만 파라미터를 사용하는 것에서 TraceId traceIdHolder를 사용하도록 변경
• 레벨과 ID 관리는 파라미터를 통해 하는 것이 아니라 traceIdHolder에서 해줌
• 중요 > syncTraceId() releaseTraceId()
  • syncTraceId()
    • TraceId를 새로 만들거나 앞선 로그의 TraceId를 참고해서 동기화하고 레벨 증가 (traceHolder를 사용하여 가능)
  • releaseTraceId()
    • 메서드 종료 시 레벨 감소
    • 최초 호출한 메서드에서 end()를 호출하면 내부에서 관리하는 traceId를 제거한다.

테스트 코드

• 정상

[0a36dd87] hello1
[0a36dd87] |-->hello2
[0a36dd87] |<--hello2 time=0ms
[0a36dd87] hello1 time=7ms

• 예외

[23ed1960] hello
[23ed1960] |-->hello2
[23ed1960] |<X-hello2 time=0ms ex=java.lang.IllegalStateException
[23ed1960] hello time=1ms ex=java.lang.IllegalStateException

 

출처: 김영한 지식공유자의 스프링 핵심 원리 고급편