[김영한 스프링 review] 스프링 핵심 원리 - 고급편 (1)

조갱·2024년 3월 24일
0

스프링 강의

목록 보기
12/16

* 이 포스팅에는 원래 강의에서 다루지 않는 팁이 1개 더 추가되어있습니다 ~!
* V3의 마지막 ~ ThreadLocal 사이를 확인해주세요. (bean scope)

스프링 핵심 원리 고급편에서 다루는 내용 요약

스프링의 3대 특징 중 하나인 AOP를 주로 다룬다.
김영한님의 강의 답게 밑바닥에서부터 직접 구현 -> 추가 개념 설명(개선) -> 스프링AOP 활용
까지의 플로우로 진행된다.

상세하게 배우는 내용으로는
1. ThreadLocal
2. AOP 와 관련된 디자인 패턴 (템플릿 메소드 패턴, 콜백 패턴, 프록시 패턴, 데코레이터 패턴)
3. 프록시의 개념과 동적 프록시 (JDK 동적 프록시, CGLIB)
4. 포인트컷, 어드바이스, 어드바이저와 Aspect 어노테이션
에 대한 내용을 다룬다.

AOP하면 나오는 대표적인 예제인 '공통 로그 찍기' 를 주제로 기본기를 쌓아나간다.

요구사항

  • 모든 PUBLIC 메서드의 호출과 응답 정보를 로그로 출력
  • 애플리케이션의 흐름을 변경하면 안됨
    • 로그를 남긴다고 해서 비즈니스 로직의 동작에 영향을 주면 안됨
  • 메서드 호출에 걸린 시간
  • 정상 흐름과 예외 흐름 구분
    • 예외 발생시 예외 정보가 남아야 함
  • 메서드 호출의 깊이 표현
  • HTTP 요청을 구분
    • HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야 함
    • 트랜잭션 ID (DB 트랜잭션X), 여기서는 하나의 HTTP 요청이 시작해서 끝날 때 까지를 하나의 트랜잭션이 라 함

예시

정상 요청
[796bccd9] OrderController.request()
[796bccd9] |-->OrderService.orderItem()
[796bccd9] | |-->OrderRepository.save()
[796bccd9] | |<--OrderRepository.save() time=1004ms
[796bccd9] |<--OrderService.orderItem() time=1014ms
[796bccd9] OrderController.request() time=1016ms

예외 발생
[b7119f27] OrderController.request()
[b7119f27] |-->OrderService.orderItem()
[b7119f27] | |-->OrderRepository.save()
[b7119f27] | |<X-OrderRepository.save() time=0ms
ex=java.lang.IllegalStateException: 예외 발생!
[b7119f27] |<X-OrderService.orderItem() time=10ms
ex=java.lang.IllegalStateException: 예외 발생!
[b7119f27] OrderController.request() time=11ms
ex=java.lang.IllegalStateException: 예외 발생!

v0 - 예제 Flow 개발

앞으로 개발할 기능의 뼈대를 개발해보자.
Controller -> Service -> Repository 순으로 호출한다.

별도로 로그를 찍지 않기 때문에, 단순히 Controller의 결과인 ok 가 반환된다.

클래스명은 Order~~~V{n} 으로 {n}은 0~5까지 버전을 올리며 개선해나간다.
예제를 따라할 예정이라면, 클래스 명에 주의하자.

Controller V0

@RestController
@RequiredArgsConstructor
public class OrderControllerV0 {
	private final OrderServiceV0 orderService;
	@GetMapping("/v0/request")
	public String request(String itemId) {
		orderService.orderItem(itemId);
		return "ok";
	}
}

Service V0

@Service
@RequiredArgsConstructor
public class OrderServiceV0 {
	private final OrderRepositoryV0 orderRepository;
	public void orderItem(String itemId) {
		orderRepository.save(itemId);
	}
}

Repository V0

@Repository
@RequiredArgsConstructor
public class OrderRepositoryV0 {
	public void save(String itemId) throws Exception {
		//저장 로직
		if (itemId.equals("ex")) {
			throw new IllegalStateException("예외 발생!");
		}
		Thread.sleep(1000); // 저장에는 1초가 소요되는 로직이 있다고 가정한다. 이후에 나오는 모든 Sleep도 로직에 소요되는 시간이라고 가정.
	}
}

결과

ok

v1 (1) - 로그 추적기 기능 개발

기존 어플리케이션 로직을 손대기 전에,
로그추적기 핵심 기능을 먼저 개발해보자.

TraceId

로그 추적기를 위한 데이터(트랜잭션 id, depth)를 저장한다.
이후 로그의 상태정보를 관리하는 TraceStatus 클래스에서 참조한다.

public class TraceId {
	private String id; // 트랜잭션 id
	private int level; // 호출 깊이를 표현하기 위한 변수

	public TraceId() {
		this.id = createId();
		this.level = 0;
	}

	private TraceId(String id, int level) {
		this.id = id;
		this.level = level;
	}

	private String createId() {
    	// UUID는 유일한 랜덤값이다. 길이가 매우 길기 때문에, 앞 8글자만 사용한다.
		return UUID.randomUUID().toString().substring(0, 8);
	}
 
	public TraceId createNextId() { return new TraceId(id, level + 1); }
	public TraceId createPreviousId() { return new TraceId(id, level - 1); }
	public boolean isFirstLevel() { return level == 0; }
	public String getId() { return id; }
	public int getLevel() { return level; }
}

TraceStatus

로그의 상태정보를 관리한다.
이전에 정의한 TraceId를 통해 현재 로그의 id/depth를 관리한다.
트랜잭션이 종료될 때, {종료시각} - startTimeMs 를 통해 소요시간을 계산한다.

public class TraceStatus {
	private TraceId traceId;
	private Long startTimeMs;
	private String message;

	public TraceStatus(TraceId traceId, Long startTimeMs, String message) {
		this.traceId = traceId;
		this.startTimeMs = startTimeMs;
		this.message = message;
	}

	public Long getStartTimeMs() { return startTimeMs; }
	public String getMessage() { return message; }
	public TraceId getTraceId() { return traceId; }
}

HelloTrace V1

실제 로그 추적기의 로직이다.
외부로 노출 해야하는 컨셉은 단순히 [시작 / 종료] 2가지 기능이지만,
정상종료와 예외종료에 따른 동작 방식이 다르기 때문에
외부(public)로 노출되는 기능은 [시작 / 정상종료 / 예외종료] 3가지 로 나누며,
내부(private) 은 종료기능 1개만 개발하여 정상/예외 케이스를 커버한다.

@Slf4j
@Component
public class HelloTraceV1 {
	private static final String START_PREFIX = "-->";
	private static final String COMPLETE_PREFIX = "<--";
	private static final String EX_PREFIX = "<X-";

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

		return new TraceStatus(traceId, startTimeMs, message);
	}

	public void end(TraceStatus status) { complete(status, 	null); }
	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());
		}
	}
    
	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();
	}
}

v1 (2) - 프로토타입 개발

이전에 로그추적기 적용을 위한 TraceId, TraceStatus, HelloTraceV1 를 개발했다.
이제 기존 어플리케이션에 적용하여 로그를 찍어보자.

클래스명의 postfix가 V1으로 바뀌었음에 유의하자.

Controller V1

@RestController
@RequiredArgsConstructor
public class OrderControllerV1 {
	private final OrderServiceV1 orderService;
	private final HelloTraceV1 trace;

	@GetMapping("/v1/request")
	public String request(String itemId) {
		TraceStatus status = null;
		try {
			status = trace.begin("OrderController.request()");
			orderService.orderItem(itemId);
			trace.end(status);
			return "ok";
		} catch (Exception e) {
			trace.exception(status, e);
			throw e; //예외를 꼭 다시 던져주어야 한다.
		}
	}
}

Service V1

@Service
@RequiredArgsConstructor
public class OrderServiceV1 {
	private final OrderRepositoryV1 orderRepository;
	private final HelloTraceV1 trace;

	public void orderItem(String itemId) {
		TraceStatus status = null;
		try {
			status = trace.begin("OrderService.orderItem()");
			orderRepository.save(itemId);
			trace.end(status);
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}
}

Repository V1

@Repository
@RequiredArgsConstructor
public class OrderRepositoryV1 {
	private final HelloTraceV1 trace;

	public void save(String itemId) throws Exception{
		TraceStatus status = null;
		try {
			status = trace.begin("OrderRepository.save()");
			//저장 로직
			if (itemId.equals("ex")) {
				throw new IllegalStateException("예외 발생!");
            }
			Thread.sleep(1000);
			trace.end(status);
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}
}

결과

정상 실행

[11111111] OrderController.request()
[22222222] OrderService.orderItem()
[33333333] OrderRepository.save()
[33333333] OrderRepository.save() time=1000ms
[22222222] OrderService.orderItem() time=1001ms
[11111111] OrderController.request() time=1001ms

예외

[5e110a14] OrderController.request()
[6bc1dcd2] OrderService.orderItem()
[48ddffd6] OrderRepository.save()
[48ddffd6] OrderRepository.save() time=0ms ex=java.lang.IllegalStateException: 예
외 발생!
[6bc1dcd2] OrderService.orderItem() time=6ms ex=java.lang.IllegalStateException:
예외 발생!
[5e110a14] OrderController.request() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!

V0 대비 V1에서는 단순하게 begin, end 를 호출하는 로직이 추가되었다.
* 참고로, 아직 depth를 표현하는 기능은 개발되지 않았다. 차차 개선해나가자.

V0 -> V1 diff 보기
위 diff를 보면 알겠지만, try-catch 로직으로 인해 벌써부터 수정점이 많이 생겼고 코드가 지저분해졌다.

남은 요구사항

  • 모든 PUBLIC 메서드의 호출과 응답 정보를 로그로 출력
  • 애플리케이션의 흐름을 변경하면 안됨
    • 로그를 남긴다고 해서 비즈니스 로직의 동작에 영향을 주면 안됨
  • 메서드 호출에 걸린 시간
  • 정상 흐름과 예외 흐름 구분
    • 예외 발생시 예외 정보가 남아야 함
  • 메서드 호출의 깊이 표현
  • HTTP 요청을 구분
    • HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야 함
    • 트랜잭션 ID (DB 트랜잭션X), 여기서는 하나의 HTTP 요청이 시작해서 끝날 때 까지를 하나의 트랜잭션이 라 함

v2 - 파라미터로 동기화 개발

남은 요구사항인 메소드 호출 깊이 표현http 요청 구분을 위해
(가장 간단하게) 현재 트랜잭션ID 와 level 을 다음 로그에 넘겨주자.

HelloTraceV2

이전 TraceId를 받아 depth를 1 추가하는 beginSync 만 추가됐다.

@Slf4j
@Component
public class HelloTraceV2 {
	private static final String START_PREFIX = "-->";
	private static final String COMPLETE_PREFIX = "<--";
	private static final String EX_PREFIX = "<X-";

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

	//V2에서 추가
	public TraceStatus beginSync(TraceId beforeTraceId, String message) {
		TraceId nextId = beforeTraceId.createNextId();
		Long startTimeMs = System.currentTimeMillis();
		log.info("[" + nextId.getId() + "] " + addSpace(START_PREFIX, nextId.getLevel()) + message);
		return new TraceStatus(nextId, startTimeMs, message);
	}

	public void end(TraceStatus status) { complete(status, null); }
	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("[" + traceId.getId() + "] " + addSpace(COMPLETE_PREFIX, traceId.getLevel()) + status.getMessage() + " time=" + resultTimeMs + "ms");
		} else {
			log.info("[" + traceId.getId() + "] " + addSpace(EX_PREFIX, traceId.getLevel()) + status.getMessage() + " time=" + resultTimeMs + "ms" + " ex=" + e);
		}
	}

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

Controller V2

@RestController
@RequiredArgsConstructor
public class OrderControllerV2 {
	private final OrderServiceV2 orderService;
	private final HelloTraceV2 trace;

	@GetMapping("/v2/request")
	public String request(String itemId) {
		TraceStatus status = null;
		try {
			status = trace.begin("OrderController.request()");
			orderService.orderItem(status.getTraceId(), itemId);
			trace.end(status);
			return "ok";
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
        }
	}
}

Service V2

@Service
@RequiredArgsConstructor
public class OrderServiceV2 {
	private final OrderRepositoryV2 orderRepository;
	private final HelloTraceV2 trace;

	public void orderItem(TraceId traceId, String itemId) {
		TraceStatus status = null;
		try {
			status = trace.beginSync(traceId, "OrderService.orderItem()");
			orderRepository.save(status.getTraceId(), itemId);
			trace.end(status);
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}
}

Repository V2

@Repository
@RequiredArgsConstructor
public class OrderRepositoryV2 {
	private final HelloTraceV2 trace;

	public void save(TraceId traceId, String itemId) throws Exception {
		TraceStatus status = null;
		try {
			status = trace.beginSync(traceId, "OrderRepository.save()");
			//저장 로직
			if (itemId.equals("ex")) {
				throw new IllegalStateException("예외 발생!");
			}
			Thread.sleep(1000);
			trace.end(status);
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}
}

결과

정상 실행

[c80f5dbb] OrderController.request()
[c80f5dbb] |-->OrderService.orderItem()
[c80f5dbb] | |-->OrderRepository.save()
[c80f5dbb] | |<--OrderRepository.save() time=1005ms
[c80f5dbb] |<--OrderService.orderItem() time=1014ms
[c80f5dbb] OrderController.request() time=1017ms

오류

[ca867d59] OrderController.request()
[ca867d59] |-->OrderService.orderItem()
[ca867d59] | |-->OrderRepository.save()
[ca867d59] | |<X-OrderRepository.save() time=0ms
ex=java.lang.IllegalStateException: 예외 발생!
[ca867d59] |<X-OrderService.orderItem() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!
[ca867d59] OrderController.request() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!

V1 -> V2 diff 보기

이제 모든 요구사항을 만족했다.

하지만 아직 수정해야할 문제점이 많이 남았다.

  • TraceId 의 동기화를 위해서 관련 메서드의 모든 파라미터를 수정해야 한다.
    • 만약 인터페이스가 있다면 인터페이스까지 모두 고쳐야 하는 상황이다.
  • 호출 시점에 따라 호출하는 메소드가 다르다.
    • 최초 호출 : begin() 이후 호출 : beginSync()
    • 만약 컨트롤러가 아닌 다른 곳에서 서비스를 처음으로 호출하는 상황 이라면 파리미터로 넘길 TraceId 가 없다.

TraceId 를 파라미터로 넘기지 않는 다른 방법을 찾아보자.

v3 - 필드로 동기화 개발

HelloTraceV3

@Slf4j
@Component
public class HelloTraceV3 {
	private static final String START_PREFIX = "-->";
	private static final String COMPLETE_PREFIX = "<--";
	private static final String EX_PREFIX = "<X-";
	private TraceId traceIdHolder; //traceId 동기화, 동시성 이슈 발생

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

	public void end(TraceStatus status) { complete(status, null); }
	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 syncTraceId() {
		if (traceIdHolder == null) {
			traceIdHolder = new TraceId();
		} else {
			traceIdHolder = traceIdHolder.createNextId();
		}
	}

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

Controller V3

@RestController
@RequiredArgsConstructor
public class OrderControllerV3 {
	private final OrderServiceV3 orderService;
	private final HelloTraceV3 trace;

	@GetMapping("/v3/request")
	public String request(String itemId) {
		TraceStatus status = null;
		try {
			status = trace.begin("OrderController.request()");
			orderService.orderItem(itemId);
			trace.end(status);
			return "ok";
		} catch (Exception e) {
			trace.exception(status, e);
			throw e; //예외를 꼭 다시 던져주어야 한다.
		}
	}
}

Service V3

@Service
@RequiredArgsConstructor
public class OrderServiceV3 {
	private final OrderRepositoryV3 orderRepository;
	private final HelloTraceV3 trace;

	public void orderItem(String itemId) {
		TraceStatus status = null;
		try {
			status = trace.begin("OrderService.orderItem()");
			orderRepository.save(itemId);
			trace.end(status);
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}
}

Repository V3

@Repository
@RequiredArgsConstructor
public class OrderRepositoryV3 {
	private final HelloTraceV3 trace;

	public void save(String itemId) throws Exception {
		TraceStatus status = null;
		try {
			status = trace.begin("OrderRepository.save()");
			//저장 로직
			if (itemId.equals("ex")) {
				throw new IllegalStateException("예외 발생!");
			}
			Thread.sleep(1000);
			trace.end(status);
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}
}

결과

정상 실행

[f8477cfc] OrderController.request()
[f8477cfc] |-->OrderService.orderItem()
[f8477cfc] | |-->OrderRepository.save()
[f8477cfc] | |<--OrderRepository.save() time=1004ms
[f8477cfc] |<--OrderService.orderItem() time=1006ms
[f8477cfc] OrderController.request() time=1007ms

오류

[c426fcfc] OrderController.request()
[c426fcfc] |-->OrderService.orderItem()
[c426fcfc] | |-->OrderRepository.save()
[c426fcfc] | |<X-OrderRepository.save() time=0ms
ex=java.lang.IllegalStateException: 예외 발생!
[c426fcfc] |<X-OrderService.orderItem() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!
[c426fcfc] OrderController.request() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!

V2 -> V3 diff 보기

이제 beginSync는 사용하지 않는다.
HelloTrace 내에 있는 traceIdHolder 가 이전 로그 정보를 기억하고 있기 때문에
더이상 이전 로그 정보를 파라미터로 전달하지 않아도 된다.

하지만, V3 코드에는 치명적인 이슈가 존재하는데, 바로 동시성 이슈이다.
API를 빠르게 2번 호출해보자. 아마 기대햇던 것과 달리 트랜잭션id도 꼬이고 depth도 이상하게 출력될 것이다.

이는 HelloTrace가 싱글톤으로 1개의 객체만 생성되어 스프링에서 관리되는데
다른 요청과 동일한 traceIdHolder를 참조하기 때문이다.

이를 해결하기 위해서는 가장 간단하게는 HelloTrace의 BeanScope를 request 로 설정해도 된다. -> 그러면 요청마다 새로운 빈이 생성되어 traceIdHolder를 공유하지 않는다. (관련 포스팅)

동시성 이슈 해결, ThreadLocal

ThreadLocal은 각 스레드마다 고유한 저장소를 사용할 수 있는 방법이다.
이를 통해 위에서 얘기한 traceIdHolder를 공유하기 때문에 발생하는 이슈를 해결할 수 있다.

관련 포스팅 : Java의 ThreadLocal 개념, 사용법, 주의사항

HelloTrace - ThreadLocal

@Slf4j
@Component
public class HelloTraceV3 {
	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<>();

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

	public void end(TraceStatus status) { complete(status, null); }
	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 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();//destroy
		} 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();
	}
}

V3 -> V3 Thread Local Diff 보기

이제 동일한 API를 동시에 아무리 많이 날려도 로그가 정상적으로 출력된다.
매 Thread마다 고유한 저장공간이 생기기 때문이다.

주의해야할 점이 있는데, ThreadLocal은 Thread 마다 공간이 생기기 때문에
Thread를 사용하지 않는 Spring-Webflux (Netty) 에서는 사용할 수 없다.
사용한다고 컴파일 에러가 발생하진 않지만, 런타임에서 예상과 다르게 동작되니
절대 사용하지 말자!!!

+ ThreadLocal 사용 후에는 반드시 release 하는것도 잊지 말자.

마무리

지금까지 주어진 요구사항을 가지고, 개선하나가는 작업을 거쳐봤다.
주어진 요구사항은 만족했지만, 코드는 V0과 V3을 비교해보면 몹시 지저분해졌음을 알 수 있다.

전체적으로 보면, 공통적으로 로그를 찍기위해

TraceStatus status = null;
try {
    status = trace.begin("OrderRepository.save()");
    // 핵심 로직
    trace.end(status);
} catch (Exception e) {
    trace.exception(status, e);
    throw e;
}

위와 같은 코드가 들어갔음을 알 수 있다.

다음 시간에는 디자인 패턴을 통해 공통 횡단 관심사를 분리하는 실습을 해본다.

profile
A fast learner.

0개의 댓글