[스프링 핵심 원리 - 고급편] #1 예제 만들기

[YONGHYNG]

예제 프로젝트 만들기

• 상품을 주문하는 프로세스 가정, 일반적인 웹 어플리케이션에서 Controller -> Service -> Repository로 이어지는 흐름

OrderRepositoryV0

package hello.advanced.app.v0;

import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Repository;

@Repository //컴포넌트 스캔 대상, 스프링 빈 자동 등록, DAO 역할
@RequiredArgsConstructor
public class OrderRepositoryV0 {

    public void save(String itemId) {
        //저장 로직
        if(itemId.equals("ex")) {
            throw new IllegalStateException("예외 발생!");  //메서드 호출이 적합하지 않을 떄 예외 발생하는 예외
        }
        sleep(1000); //1초 지연
    }

    private void sleep(int millis) {
        try {
            Thread.sleep(millis); //호출로 해당 시간 호출을 지연시킴
        } catch (InterruptedException e){
            e.printStackTrace();
        }
    }
}

OrderServiceV0

package hello.advanced.app.v0;

import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Service;

@Service//컴포넌트 스캔대상, 비즈니스 로직
@RequiredArgsConstructor
public class OrderServiceV0 {

    private final OrderRepositoryV0 orderRepository;

    public void orderItem(String itemId) {
        orderRepository.save(itemId);
    }
}

OrderControllerV0

package hello.advanced.app.v0;

import lombok.RequiredArgsConstructor;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController //컴포넌트 스캔과 스프링 Rest 컨트롤러로 인식
@RequiredArgsConstructor
public class OrderControllerV0 {

    private final OrderServiceV0 orderService;

    @GetMapping("/v0/request") //메서드는 HTTP 파라미터로 itemId 받음
    public String request(String itemId){
        orderService.orderItem(itemId);
        return "ok";
    }
}

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

미션

• 애플리케이션이 커지면 모니터링과 운영이 중요함
• 특히 병목이 발생하고 있어 어떤 부분에서 병복이 발생하는지와 예외가 발생 할 떄의 로그 확인이 점점 중요해 지고 있음
• 로그를 미리 남기면 이런 상황을 쉽게 대응, 즉 이 부분을 개선하고 자동화 하는 것이 미션

요구사항

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

예시

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

• 로그 추적기를 위한 기반 데이터를 가지고 있는 TraceId, TraceStatus 클래스 만들자

TraceId

package hello.advanced.trace;

import java.util.UUID;

public class TraceId {

    private String 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 0~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;
    }
}

TraceId 클래스

• 로그 추적기는 트랜잭션ID와 깊이를 표현하는 방법 필요
• 여기서 트랜잭션ID와 깊이를 표현하는 level을 묶어 TraceId 라는 개념 있음
• TraceId는 단순히 id(트랜잭션ID)와 level 정보를 함께 가짐

UUID

• TraceId를 처음 생성하면 createId()를 사용 UUID를 만듦
• UUID가 너무 길어 앞 8자리만 사용
• 여기서 만들어진 값을 트랜잭션 ID로 사용

createNextId()

• 다음 TraceId를 만듬, 예제 로그를 보면 깊이가 증가해도 트랜잭션 Id 같음, 깊이가 하나 증가함
  

createPreviousId()

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

isFirstLevel()

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

TraceStatus -- 로그의 상태 정보를 나타냄

package hello.advanced.trace;

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

    // Getter 메서드
    public Long getStartTimeMs() {
        return startTimeMs;
    }

    public String getMessage() {
        return message;
    }

    public TraceId getTraceId() {
        return traceId;
    }
}

• traceId: 내부에 트랜잭션 ID와 level을 가지고 있음
• startTimeMs: 로그 시작시간, 로그 종료시 이 시작 시간을 기준으로 시작-종료까지 전체 수행 시간을 구함
• message: 시작시 사용한 메시지이다. 이후 로그 종료시에도 이 메시지를 사용해서 출력

HelloTraceV1 -- 실제 로그 시작과 종료 가능, 로그를 출력하고 실행시간 측정 가능

package hello.advanced.trace.hellotrace;

import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;

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

complete(TraceStatus status, Exception e)

• end(), exception()의 요청 흐름을 한 곳에서 편리하게 처리, 실행 시간을 측정하고 로그 남김

String addSpace(String prefix, int level)

prefix: -->

• level 0: ``
• level 1: |-->
• level 2: | |-->
  prefix: <--
• level 0: ``
• level 1: |<--
• level 2: | |<--
  prefix: <X-
• level 0: ``
• level 1: |<X-
• level 2: | |<X-

테스트 작성

package hello.advanced.trace.hellotrace;

import hello.advanced.trace.TraceStatus;
import org.junit.jupiter.api.Test;

public class HelloTraceV1Test {

    @Test
    void begin_end() {
        HelloTraceV1 trace = new HelloTraceV1();
        TraceStatus status = trace.begin("hello");
        trace.end(status);
    }

    @Test
    void begin_exception() {
        HelloTraceV1 trace = new HelloTraceV1();
        TraceStatus status = trace.begin("hello");
        trace.exception(status, new IllegalStateException());
    }
}

begin_end() -- 실행 로그

[41bbb3b7] hello
[41bbb3b7] hello time=5ms

begin_exception() -- 실행 로그

[898a3def] hello
[898a3def] hello time=13ms ex=java.lang.IllegalStateException

[YuDeokRin]

수고하셨습니다! 정리를 용학님 스타일 대로 너무 잘 정리해주셨네요 ㅎㅎ