스프링 핵심 원리 - 고급편_로그 추적기(V2 적용)

로그 추적기 V2 - 적용

• 기존 V1을 복사하여 V2로 변경
  • 의존관계를 모두 변경해야함.
• 메서드 호출의 깊이와 HTTP 요청을 구분하려면 처음 남기는 Controlle에서 로그를 남길 때 어떤 깊이와 트랜잭션ID를 사용했는지 다음 차례인 Service에서 알아야 한다.
  • 즉, 현재 정보를 다음 메서드로 전달 시켜야 하는 것
  • 이 정보는 TraceStatus.traceId에 담겨 있기 때문에 traceId를 Controller에서 Service를 호출할 때 넘겨주면 된다.

코드

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

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

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

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

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

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

    private void sleep(int millis) {
        try {
            Thread.sleep(millis);
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

• 위 코드에서 주의할 점은 begin()에서는 괜찮지만, beginSync()를 호출하고 다음 메서드로 넘겨줄 때는 beginSync()를 호출하고 반환 받은 TraceStatus의 TraceId를 넘겨줘야 한다. 그래야 level이 증가하는 것을 확인할 수 있다.
  • save()는 파라미터로 전달 받은traceId를 사용해서trace.beginSync()` 를 실행한다.
  • beginSync() 는 내부에서 다음 traceId 를 생성하면서 트랜잭션ID는 유지하고 level 은 하나 증가시킨다.
  • beginSync() 는 이렇게 갱신된 traceId 로 새로운 TraceStatus 를 반환한다.
  • trace.end(status) 를 호출하면서 반환된 TraceStatus 를 전달한다.

로그

• 정상
• [8e9c5b3d] OrderController.request() [8e9c5b3d] |--->OrderService.orderItem() [8e9c5b3d] | |--->OrderRepository.save() [8e9c5b3d] | |<---OrderRepository.save() time=1003ms [8e9c5b3d] |<---OrderService.orderItem() time=1003ms [8e9c5b3d] OrderController.request() time=1005ms
• 예외
• [5c696c03] OrderController.request() [5c696c03] |--->OrderService.orderItem() [5c696c03] | |--->OrderRepository.save() [5c696c03] | |<X-OrderRepository.save() time=0ms ex=java.lang.IllegalStateException: 예외 발생 [5c696c03] |<X-OrderService.orderItem() time=1ms ex=java.lang.IllegalStateException: 예외 발생 [5c696c03] OrderController.request() time=1ms ex=java.lang.IllegalStateException: 예외 발생 Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: java.lang.IllegalStateException: 예외 발생] with root cause

java.lang.IllegalStateException: 예외 발생

~

정리

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

모든 요구사항 만족

남은 문제

• HTTP 요청을 구분하고 깊이 표현을 위해서는 TraceId가 필요한 상황
• TraceId의 동기화를 위해서는 관련 메서드의 모든 파라미터를 수정해야 함
  • 인터페이스가 있다면 인터페이스도 고쳐야 하는 상황
• 로그를 처음 시작할 때 begin()을 호출하고, 처음이 아닐 때는 beginSync()를 호출해야 한다.
  • 만약 컨트롤러를 통해 서비스를 호출하는 것이 아니라, 다른 곳에서 서비스를 처음으로 호출하는 상황이면 beginSync()에 파라미터로 넘길 TracdId가 없다.
    • 예를 들어 첫 시작이 로그를 남기지 않는 곳에서 호출하거나, 테스트 코드에서 호출하는 경우 문제 발생(테스트 코드에서 로그를 남길 이유가... 없어보임)

 

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