Advance I/Spring

22.09.19 :: 스프링 핵심 원리 - 고급편

kinggora 2022. 9. 19. 16:08

0. 강의 소개

스프링 핵심 디자인 패턴

  • 템플릿 메서드 패턴
  • 전략 패턴
  • 템플릿 콜백 패턴
  • 프록시 패턴
  • 데코레이터 패턴

동시성 문제와 쓰레드 로컬

  • 웹 애플리케이션
  • 멀티쓰레드
  • 동시성 문제

스프링 AOP

  • 개념, 용어정리
  • 프록시 - JDK 동적 프록시, CGLIB
  • 동작 원리
  • 실전 예제
  • 실무 주의 사항

기타

  • 스프링 컨테이너의 확장 포인트 - 빈 후처리기
  • 스프링 애플리케이션을 개발하는 다양한 실무 팁

1. 예제 만들기

로그 추적기 - 요구사항 분석

전체 소스 코드는 수 십만 라인이고, 클래스 수도 수 백개 이상인 프로젝트의 로그 추적기 만들기

애플리케이션이 커지면 모니터링과 운영이 중요해진다. 어떤 부분에서 병목이 발생하는지, 그리고 어떤 부분에서 예외가 발생하는지를 로그를 통해 확인해야 한다. 기존에는 개발자가 문제가 발생한 다음에 관련 부분을 어렵게 찾아서 로그를 하나하나 직접 만들어서 남겼다. 로그를 미리 남겨둔다면 이런 부분을 손쉽게 찾을 수 있을 것이다.

요구사항

  • 모든 PUBLIC 메서드의 호출과 응답 정보를 로그로 출력
  • 애플리케이션의 흐름을 변경하면 안됨: 로그를 남긴다고 해서 비즈니스 로직의 동작에 영향을 주면 안됨
  • 메서드 호출에 걸린 시간
  • 정상 흐름과 예외 흐름 구분: 예외 발생시 예외 정보가 남아야 함
  • 메서드 호출의 깊이 표현
  • HTTP 요청을 구분: HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야 함. [트랜잭션 ID] DB 트랜잭션이 아니고 하나의 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: 예외 발생!

로그 추적기 V1 - 프로토타입 개발

애플리케이션의 모든 로직에 직접 로그를 남겨도 되지만, 그것보다는 더 효율적인 개발 방법이 필요하다. 특히 트랜잭션ID와 깊이를 표현하는 방법은 기존 정보를 이어 받아야 하기 때문에 단순히 로그만 남긴다고 해결할 수 있는 것은 아니다.

TraceId 클래스

로그 추적기는 트랜잭션ID와 깊이를 표현하는 방법이 필요하다. 여기서는 트랜잭션ID와 깊이를 표현하는 level을 묶어서 TraceId 라는 개념을 만들었다.

TraceId 는 단순히 id (트랜잭션ID)와 level 정보를 함께 가지고 있다.

 

[796bccd9] OrderController.request() //트랜잭션ID:796bccd9, level:0
[796bccd9] |-->OrderService.orderItem() //트랜잭션ID:796bccd9, level:1
[796bccd9] | |-->OrderRepository.save()//트랜잭션ID:796bccd9, level:2

 

createNextId()

다음 TraceId 를 만든다. 예제 로그를 잘 보면 깊이가 증가해도 트랜잭션ID는 같다. 대신에 깊이가 하나 증가한다.

실행 코드: new TraceId(id, level + 1)

 

createPreviousId()

createNextId() 의 반대 역할을 한다. id 는 기존과 같고, level 은 하나 감소한다.

실행 코드: new TraceId(id, level - 1)

 

isFirstLevel()

첫 번째 레벨 여부를 편리하게 확인할 수 있는 메서드.

실행 코드: return level == 0

TraceStatus 클래스

로그의 상태 정보

TraceStatus 는 로그를 시작할 때의 상태 정보를 가지고 있다. 이 상태 정보는 로그를 종료할 때 사용된다.

 

[796bccd9] OrderController.request() //로그 시작
[796bccd9] OrderController.request() time=1016ms //로그 종료

 

필드

traceId : 내부에 트랜잭션ID와 level을 가지고 있다.

startTimeMs : 로그 시작시간이다. 로그 종료시 이 시작 시간을 기준으로 전체 수행 시간을 구할 수 있다.

message : 시작시 사용한 메시지이다. 로그 종료시에도 이 메시지를 출력한다.

HelloTraceV1 클래스

로그 메세지 생성

 

TraceStatus begin(String message)

  • 로그를 시작한다.
  • 로그 메시지를 파라미터로 받아서 시작 로그를 출력한다.
  • 응답 결과로 현재 로그의 상태인 TraceStatus 를 반환한다.

void end(TraceStatus status)

  • 로그를 정상 종료한다.
  • 파라미터로 시작 로그의 상태( TraceStatus )를 전달 받는다. 이 값을 활용해서 실행 시간을 계산하고, 종료시에도 시작할 때와 동일한 로그 메시지를 출력할 수 있다.
  • 정상 흐름에서 호출한다.

void exception(TraceStatus status, Exception e)

  • 로그를 예외 상황으로 종료한다.
  • TraceStatus , Exception 정보를 함께 전달 받아서 실행시간, 예외 정보를 포함한 결과 로그를 출력한다.
  • 예외가 발생했을 때 호출한다.

HelloTraceV1 는 아직 모든 요구사항을 만족하지는 못한다. 이후에 기능을 하나씩 추가할 예정이다.

로그 추적기 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; //로그 때문에 오류 흐름이 정상 흐름으로 바뀌면 안됨
        }
    }
}

 

단순하게 trace.begin() , trace.end() 코드 두 줄만 적용하면 될 줄 알았지만, 실상은 그렇지 않다.

  • 비지니스 로직 실행 중 exception 이 발생하면 trace.end() 가 실행되지 않는다. try-catch 문을 추가하여 trace.exception() 으로 예외 처리를 해주어야 한다.
  • begin() 의 결과 값으로 받은 TraceStatus status 값을 end() , exception() 에 넘겨야 한다. 결국 try-catch 블록 모두에서 이 값을 사용하므로 상위에 TraceStatus status 코드를 선언해야 한다. 
  • throw e : 예외를 꼭 다시 던져주어야 한다. catch 블록에서 예외를 먹어버리고, 이후에 정상 흐름으로 동작한다. 로그는 애플리케이션에 흐름에 영향을 주면 안된다. 로그 때문에 예외가 사라지면 안된다.

남은 요구사항

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

남은 기능은 직전 로그의 깊이와 트랜잭션 ID가 무엇인지 알아야 할 수 있는 일이다.

현재 로그의 상태 정보인 트랜잭션ID 와 level 이 다음으로 전달되어야 한다.

정리하면 로그에 대한 문맥( Context ) 정보가 필요하다.

로그 추적기 V2 - 파라미터로 동기화 개발

트랜잭션ID와 메서드 호출의 깊이를 표현하는 하는 가장 단순한 방법은 첫 로그에서 사용한 트랜잭션ID 와 level 을 다음 로그에 넘겨주면 된다. 현재 로그의 상태 정보인 트랜잭션ID 와 level 은 TraceId 에 포함되어 있다. 따라서 TraceId 를 다음 로그에 넘겨주자.

HelloTraceV2 클래스

beginSync(beforeTraceId, message)

beforeTraceId 에서 createNextId() 를 통해 다음 TraceId(id, level+1) 를 구한다.

로그 추적기 V2 - 적용

메서드 호출의 깊이를 표현하고, HTTP 요청도 구분해보자.

이렇게 하려면 처음 로그를 남기는 OrderController.request() 에서 로그를 남길 때 어떤 깊이와 어떤 트랜잭션 ID를 사용했는지 다음 차례인 OrderService.orderItem() 에서 로그를 남기는 시점에 알아야한다.

결국 현재 로그의 상태 정보인 트랜잭션ID 와 level 이 다음으로 전달되어야 한다. 이 정보는 TraceStatus.traceId 에 담겨있다. 따라서 traceId 를 컨트롤러에서 서비스를 호출할 때 넘겨주면 된다.

 

 

V2 컨트롤러 코드

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

 

V2 서비스 코드

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

 

리포지토리 코드에도 적용하면 모든 요구사항을 만족한다.

정리

남은 문제

HTTP 요청을 구분하고 깊이를 표현하기 위해서 TraceId 동기화가 필요하다.

TraceId 의 동기화를 위해서 관련 메서드의 모든 파라미터를 수정해야 한다.

   -> 만약 인터페이스가 있다면 인터페이스까지 모두 고쳐야 하는 상황이다.

로그를 처음 시작할 때는 begin() 을 호출하고, 처음이 아닐때는 beginSync() 를 호출해야 한다.

  -> 만약에 컨트롤러를 통해서 서비스를 호출하는 것이 아니라, 다른 곳에서 서비스를 처음으로 호출하는 상황이라면 파리미터로 넘길 TraceId 가 없다.

 

HTTP 요청을 구분하고 깊이를 표현하기 위해서 TraceId 를 파라미터로 넘기는 것 말고 다른 대안은 없을까?