[스프링 핵심원리 - 고급편 ] 쓰레드 로컬 - ThreadLocal

필드 동기화 - 개발

앞서 로그추적기를 만들면서 로그를 출력할 때 트랜잭션ID 와 level을 동기화 하는 문제가 있었다.
이 문제를 해결하기 위해 TraceId를 파라미터로 넘기도록 구현.

이렇게 해서 동기화는 성공했지만, 로그를 출력하는 모든 메서드에 TraceId 파라미터를 추가해야하는 문제가 발생.

TraceId를 파라미터로 넘기지 않고 이 문제를 해결 할 수 있는 방법은 없을까?

이런문제를 해결할 목적으로 새로운 로그 추적기를 만들어보자.
어제 프로토타입 버전이 아닌 정식 버전으로 제대로 개발
향후 다양한 구현체로 변경할 수 있도록 LogTrace인터페이스를 먼저만들고, 구현해보자

LogTrace.java

LogTrace인터페이스에는 로그 추적기를 위한 최소한의 기능인 begin(), end(), exception()를 정의한다.
이제파라미터를 넘기지 않고 TraceId를 동기화 할수 있는 FieldLogTrace 구현체를 만들자.

package study.advanced.trace.logtrace;

import study.advanced.trace.TraceStatus;

public interface LogTrace {

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

FieldLogTrace.java

package study.advanced.trace.logtrace;

import lombok.extern.slf4j.Slf4j;
import study.advanced.trace.TraceId;
import study.advanced.trace.TraceStatus;
import study.advanced.trace.hellotrace.HelloTraceV2;

@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 동기화, 동시성 이슈 발생 
	
	@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);
	}
	
	
	private void syncTraceId() {
		if(traceIdHolder == null) {
			traceIdHolder = new TraceId();
		}else {
			traceIdHolder = traceIdHolder.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.getStartITmeMs();
		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; //destroy
		}else {
			traceIdHolder = traceIdHolder.createPreviousId();
		}
		
	}


	private Object 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();
	}

}

FieldLogTrace는 기존에 만들었던 HelloTraceV2와 거의 같은 기능을 한다.
TraceId를 동기화 하는 부분만 파라미터를 사용하는 것에서 TraceId traceIdHolder 필드를 사용하도록 변경되었다.
이제 직전 로그의 TraceId는 파라미터로 전달되는 것이 아니라 FieldTrace의 필드인 traceIdHolder에 저장된다.

여기서 중요한 부분은 로그를 시작할 때 호출하는 syncTraceId()와 로그를 종료할 때 호출하는 releaseTraceId()이다.

• SyncTraceId()
  • TraceId() 를 새로만들거나 앞선 로그의 TraceId를 참고해서 동기화하고, level도 증가한다.
  • 최초 호출이면 TraceId를 새로 만든다.
  • 직전 로그가 있으면 해당 로그의 TraceId 를 참고해서 동기화하고, level도 하나 증가한다.
  • 결과를 traceIdHolder에 보관한다.
• releaseTraceId()
  • 메서드를 추가로 호출할 때는 level이 하나 증가해야 하지만, 메서드 호출이 끝나면 level이 하나 감소 해야한다.
  • releaseTraceId()는 level을 하나 감소한다.
  • 만약 최초 호출(level==0)이면 내부에서 관리하는 traceId를 제거한다.

---

FieldLogTraceTest.java

package study.advanced.trace.logtrace;

import org.junit.jupiter.api.Test;

import study.advanced.trace.TraceStatus;

public class FieldLogTraceTest {

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

FieldLogTraceTest.java

예외처리도 잘 나온다.!

@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());
	}

begin_end_level2() - 실행 결과
begin_exception_level2() - 실행 결과

실행결과를 보면 트랜잭션 ID도 동일하게 나오고, level을 통한 깊이도 잘 표현된다.
FieldLogTrace.traceIdHolder 필드를 사용해서 TraceId가 잘 동기화 되는 것을 확인할 수 있다.
이제 불필요하게 TraceId를 파라미터로 전달하지 않아도 되고, 애플리케이션의 메서드 파라미터로 변경하지 않아도된다.