예제 만들기, 프로젝트 생성 및 프로젝트 만들기V0, 로그 추적기 - 요구사항 분석, 로그 추적기 V1(프로토타입 개발 / 적용), 로그 추적기 V2(파라미터로 동기화 개발 / 적용)

출처 : 인프런 - 스프링 핵심 원리 - 고급편 (유료) / 김영한님  
유료 강의이므로 정리에 초점을 두고 코드는 일부만 인용

---

1. 프로젝트 생성 및 프로젝트 만들기

1) 프로젝트 생성

 

(1) Project

• Gradle
• Java 17
• Spring Boot 3.3.5

(2) Metadata

• Group - hello
• Artifact - advanced
• Packaging - Jar

(3) Dependencies

• Spring Web
• Lombok

2) 프로젝트 만들기V0

• 학습을 위한 간단한 예제로 상품을 주문하는 프로세스로 가정하고 일반적인 웹 애플리케이션에서 Controller -> service -> Repository로 이어지는 흐름을 최대한 단순하게 작성

(1) 리포지토리V0

• 상품 저장 시 1초정도의 소요시간이 걸리고, 상품 id가 ex로 넘어오면 IllegalStateException을 터트리도록 코드를 작성(다양한 예제를 위한 코드)
• Thread.sleep()를 캡슐화한 sleep()메서드로 1초정도의 소요시간을 부여

package hello.advanced.app.v0;

@Repository
@RequiredArgsConstructor
public class OrderRepositoryV0 {

    // 저장 로직 - 상품 저장시 1초의 시간이 걸리고 상품의Id가 ex로 들어오면 예외가 발생함
    public void save(String itemId) {
        if (itemId.equals("ex")) {
            throw new IllegalStateException("예외 발생");
        }
        sleep(1000);
    }

    // sleep 메서드 생성, Thread.sleep()를 사용
    private void sleep(int millis) {
        try {
            Thread.sleep(millis);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

 

(2) 서비스V0

• 단순히 OrderRepositoryV0을 사용하여 상품을 저장하는 Service
• 실무에서는 복잡한 비즈니스 로직이 서비스 계층에 포함됨

@Service
@RequiredArgsConstructor
public class OrderServiceV0 {

    private final OrderRepositoryV0 orderRepository;

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

 

(3) 컨트롤러V0

• @RestController로 API로 응답하는 컨트롤러를 생성
• @GetMapping으로 매핑된 주소의 요청파라미터로 들어온 itemId값을 받아서 OrderServiceV0의 orderItem()를 호출하고 정상 반환되면 응답메시지를 "OK"로 반환

@RestController
@RequiredArgsConstructor
public class OrderControllerV0 {

    private final OrderServiceV0 orderService;

    @GetMapping("/v0/request")
    public String request(String itemId) {
        orderService.orderItem(itemId);
        return "OK";
    }
}

 

(4) 실행결과

• 위 예제 코드들을 작성하고 매핑된 URL의 요청파라미터로 id값을 입력하면 정상적으로 OK 반환이 됨
• itemId=ex로 요청파라미터를 작성하면 500오류를 보내며, IDE의 콘솔창을 확인해보면 의도한대로 예외가 발생함

---

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

1) 요구사항

(1) 프로젝트 상황 예시

• 전체 소스 코드는 수 십만 라인이도 클래스도 수 백개 이상인 수 년간 운영중인 거대한 프로젝트에 로그 추적기를 만드는 요구사항을 맡아 프로젝트에 투입되었다고 가정
• 애플리케이션이 커지면서 모니터링과 운영이 중요해지는 단계인데 최근 자주 병목이 발생하고 있는데, 어떤 부분에서 병목이 발생하는지 어떤 부분에서 예외가 발생하는지를 로그를 통해 확인하는 것이 점점 중요해지고있는 상황이라고 가정
• 기존 개발자는 문제가 발생한 다음에 관련 부분을 어렵게 찾아 로그를 하나하나 직접 만들어서 남겼는데, 이부분을 로그를 미리 남겨두어 문제가 발생된 부분을 손쉽게 찾을 수 있도록 개선 및 자동화하는 것이 미션

(2) 요구사항

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

(3) 예시

정상 요청

[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: 예외 발생!

** 참고

• 실무에서는 모니터링 툴을 도입하여 많은 부분을 해결하지만 학습이 목적이기에 직접구현
• 실제로 가끔 모니터링 툴에서도 못잡는 경우도 있기에 로그를 세세하게 남겨두는 것이 좋을 수 있음

---

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

1) 프로토타입 개발 

(1) 접근 방안

• 애플리케이션의 모든 로직에 직접 로그를 남기는 단순한 방식보다 조금 더 효율적인 방법을 적용하여 로그 추적기를 개발
• 특히 트랜잭션ID와 깊이를 표현하는 방법은 기존 정보를 이어 받아야 하기 때문에 단순히 로그만 남긴다고 해결할 수 없음
• 로그 추적기를 위한 기반 데이터를 가지고 있는 TraceId와 TraceStatus클래스를 먼저 개발을 진행

(2) TraceId

• 로그 추적기는 트랜잭션ID와 깊이를 표현하는 방법이 필요하기에 id에는 UUID를 활용하여 트랜잭션ID를 저장하고, level에는 계층을 표현하도록 메서드를 활용하여 TraceId라는 개념을 생성
• 즉, TraceId에는 트랜잭션ID와 계층을 표현하는 level 정보를 가지고 있음
• UUID는 그냥 사용하면 너무 길어서 substring으로잘라 8자리만 사용하도록함(단순 로그를 구분하는 ID이기에 간혹 중복이 발생되어도 큰 문제가 없음)
• 최초의 계층은 0으로 설정되도록 하고 createNextId(), createPreviousId()를 만들어서 level의 값을 증감시켜 계층의 깊이를 표현
• isFirstLevel()메서드로 첫번째 레벨의 여부를 확인하는 메서드와 각 변수의 값을 꺼낼 수 있는 게터도 생성

package hello.advanced.trace;

public class TraceId {

    private String id;  // 트랜잭션ID
    private int level;  // 메서드 호출 계층 표현

    // 기본생성자를 호출하면 UUID를 생성하여 트랜잭션ID를 부여하고 level을 0으로 세팅
    public TraceId() {
        this.id = createId();
        this.level = 0;
    }

    // 내부에서만 사용하는 private 생성자
    private TraceId(String id, int level) {
        this.id = id;
        this.level = level;
    }

    private String createId() {
        // UUID가 너무 길어서 UUID의 8자리만 사용
        // 가끔 중복이 될 수 있겠지만 주문번호같은 특별한게 아닌 단순 로그의 ID이므로 이정도는 괜찮음
        return UUID.randomUUID().toString().substring(0, 8);
    }

    // 계층의 깊이를 표현 - level을 +1해서 깊은 계층을 표현
    public TraceId createNextId() {
        return new TraceId(id, level + 1);
    }

    // 계층의 깊이를 구현 - createNextId와 반대
    public TraceId createPreviousId() {
        return new TraceId(id, level - 1);
    }

    // level이 0인지 확인
    public boolean isFirstLevel() {
        return level == 0;
    }
    
    // 변수의 값을 꺼내는 게터 생성
    public String getId() {
        return id;
    }
    
    public int getLevel() {
        return level;
    }
}

 

(3) TraceStatus

• 로그의 상태정보를 나타내기 위한 클래스
• 방금 정의한 TraceId정보와 시작시간, 메시지의 정보가 있음
• 시작시간의 정보만 있으면 종료된 값은 계산하여 출력할 수 있고 메시지는 시작과 종료시에도 해당 메시지를 출력

package hello.advanced.trace;

public class TraceStatus {

    private TraceId traceId;
    private Long startTimeMs;   // 시작시간만 알면 종료시간은 구할 수 있음
    private String message;

    // 필드값을 초기화하는 생성자 및 필드의 값을 불러오는 게터 생성
}

 

(4) HelloTraceV1

• 실제 로그를 생성하고 처리하는 로그추적기 V1 버전 개발 - 아직 모든 요구사항을 만족하지못한 로그추적이임(버전업 하면서 기능을 하나씩 추가)
• @Component으로 싱글톤 사용을 위해 스프링 빈으로 등록하며 컴포넌트 스캔의 대상이 됨
• begin()메서드로 로그출력을 시작하면 로그 메시지를 파라미터로 받아서 시작 로그를 출력하고 응답 결과로 현재 로그의 상태를 반환
• end()메서드는 예외가 없는 정상 흐름에서 호출하여 로그를 정상 종료하고, 파라미터로 시작 로그의 상태를 전달받아서 실행 시간과 로그 메시지를 반환
• exception()메서드는 예외가 발생했을 때 호출하여 로그를 예외 상황으로 종료하고, 파라미터로 Exception정보를 추가로 받아서 로그로 출력하는 부분만 다르고 나머지는 end()와 동일한 정보를 출력함
• complete()메서드는 실제 end()와 exception()가 호출되어있을때 동작하는 메서드이므로 private으로 선언, 시작시간정보로 종료시간을 계산하고 Exception 전달 유무에 따라 if문으로 각 로그를 출력
• addSpace()메서드는 계층정보에 따라 prefix 정보를 출력하는 메서드로, 레벨이 깊어질수록 계층 구조를 표현하는 화살표가 더 많이 출력됨(예외에 따른 화살표 모양도 적용)

package hello.advanced.trace.hellotrace;

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

    // 예외가 발생하여 예외를 출력하는 메서드, end()의 동일한 정보에서 예외정보를 추가하여 반환
    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());
        }
    }

    // 계층 상태에 따라 prefix를 적용하는 코드
    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();
    }
}

2) 테스트

• HelloTraceV1의 begin, end, exception 메서드들의 테스트를 수행보면 정상적로그가 출력되는 것을 확인할 수 있음
• end의 경우 정상흐름으로 메시지와 실행 시간정보만 출력하고 exception의 경우 예외 정보까지 함께 출력함

** 참고

• 해당 강의는 테스트강의가아니기에 검증과정이 없고 결과를 콘솔로만 직접 확인하는 학습용 테스트로만 실행
• 실무에서는 항상 테스트 코드를 작성할 때 검증하는 과정이 필수이며 이렇게 응답값이 없는 경우를 자동으로 검증하려면 여러가지 테스트 기법이 필요함
• 지금까지 만든 로그 추적기가 어떻게 동작하는지 확실히 이해해야 다음단계로 넘어갈 수 있음

package hello.advanced.trace.hellotrace;

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("exception");
        trace.exception(status, new IllegalStateException());
    }
}


/* 각 메서드의 출력 결과
11:25:17.312 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV1 -- [5f784477] hello
11:25:17.312 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV1 -- [5f784477] hello time=0ms

11:23:48.784 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV1 -- [59626278] exception
11:23:48.786 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV1 -- [59626278] exception time=3ms ex=java.lang.IllegalStateException
*/

---

4. 로그 추적기 V1 - 적용

1) v0 -> v1복사

• 기존에 작성해둔 v0버전의 Controller, Service, Repository코드들을 복사하여 V1으로 이름을 변경
• @GetMapping의 매핑 정보를 /v1/request로 변경

2) v1 적용

(1) OrderControllerV1에 적용

• HelloTraceV1을 주입, @Component 애노테이션을 가지고 있어서 컴포넌트 대상이 되며 자동으로 스프링 빈으로 등록됨
• 로그를 시작할 때 메시지 이름으로 컨트롤러 이름 + 메서드 이름을 입력하여 어떤 컨트롤러와 메서드가 호출되었는지 로그로 편리하게 확인할 수 있으나 지금은 수작업으로 해주어야 함
• try - catch문으로 예외가 발생하지 않았을 때와 발생했을때의 메서드를 각각 다르게 호출하여 처리해야하기에 코드가 깔끔하지가 않음
• 로그는 애플리케이션 흐름에 영향을 주면 안되기 때문에 예외가 발생했을 때는 return으로 정상흐름으로 바꾸는 것이 아니라 throw로 다시 예외를 던져서 예외가 사라지지 않도록 설정
• 실행후 Mapping된 정보로 정상흐름, 예외흐름 모두 테스트 해보면 로그로 잘 출력됨

package hello.advanced.app.v1;

@RestController
@RequiredArgsConstructor
public class OrderControllerV1 {

    private final OrderServiceV1 orderService;

    // HelloTraceV1 주입
    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;        // 예외를 꼭 다시 던져주어야 흐름을 바꾸지 않음
        }
    }
}

 

(2) OrderServiceV1에 적용

• Controller에 적용했던 동일한 try-catch를 orderRepository.save를 호출하는 oderItem()메서드에 적용
• trace.begin()메서드의 메시지는 OrderService.orderItem()으로 변경

@Service
@RequiredArgsConstructor
public class OrderServiceV1 {
    // ... 기존 코드 생략

    public void orderItem(String itemId) {
        // try - catch문에 orderRepository.save 및 메시지 수정
        TraceStatus status = null;
        try {
            status = trace.begin("OrderService.orderItem()");
            
    // ... 기존 코드 생략
    }
}

 

(3) OrderRepositoryV1에 적용

• save()메서드에서 수행하는 저장 로직을 동일한 try-catch 로직을 적용
• trace.begin()메서드의 메시지는 OrderRepository.save()로 변경

@Repository
@RequiredArgsConstructor
public class OrderRepositoryV1 {
    // ... 기존 코드 생략
    // save()의 로직에 try-catch문을 적용
    public void save(String itemId) {
        TraceStatus status = null;
        try {
            status = trace.begin("OrderRepository.save()");

            if (itemId.equals("ex")) {
                throw new IllegalStateException("예외 발생");
            }
            
    // ... 기존 코드 생략
}

 

(4) 실행

• 실행후 매핑된 URL로 정상 및 예외 흐름을 요청해보면 아래와같이 흐름 로그가 정상적으로 출력됨
• 요청 -> OrderController 시작로그 출력 -> OrderService 시작로그 출력 -> OrderRepository 시작 로그 출력 -> OrderRepository 코드 수행 후 로그 출력 -> OrderService 기능 수행 완료 후 로그 출력 -> OrderController 기능 수행 완료 후 로그 출력 -> 응답의 흐름으로 진행됨
• 직접 로그를 하나하나 남기는 것보다는 편리하게 여러가지 로그를 남길 수는 있게 되었으나 계층 구조와 같은트랜잭션ID를 남기는 기능도 아직 개발하지 않았음에도 로그를 남기기 위한 로그가 생각보다 복잡함

** 참고

• 현재는 level관련 기능과 동일 트랜잭션ID를 출력하는 기능은 개발하지 않았으므로 level 값이 항상 0이고, 트랜잭션ID가 동일한 HTTP 요청임에도 각각 다르게 출력됨

정상 흐름 로그 결과
[680c5576] OrderController.request()
[ce487d5a] OrderService.orderItem()
[d0872e96] OrderRepository.save()
[d0872e96] OrderRepository.save() time=1004ms
[ce487d5a] OrderService.orderItem() time=1005ms
[680c5576] OrderController.request() time=1005ms

예외 흐름 로그 결과
[e9a24843] OrderController.request()
[ca5f0ee2] OrderService.orderItem()
[a9c216d9] OrderRepository.save()
[a9c216d9] OrderRepository.save() time=1ms ex=java.lang.IllegalStateException: 예외 발생
[ca5f0ee2] OrderService.orderItem() time=2ms ex=java.lang.IllegalStateException: 예외 발생
[e9a24843] OrderController.request() time=3ms ex=java.lang.IllegalStateException: 예외 발생

---

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

1) 트랜잭션ID와 메서드 호출의 깊이를 표현

• 직전 로그의 깊이와 트랜잭션ID가 무엇인지 알아야 개발이 가능함
• 해당 기능을 개발하기 위한 가장 단순한 방법은 첫 로그에서 사용한 트랜잭션ID와 level을 다음 로그에 넘겨주면 되는데 현재 로그의 상태정보인 TraceId에 포함이 되어있으므로 TraceId를 다음 로그에 넘겨주면 됨

2) V2 개발 및 테스트

(1) HelloTraceV2 

• 기존 HelloTraceV2에서 파라미터로 TraceId를 받아서 createNextId()를 호출하는 beginSync()메서드를 추가
• createNextId()는 계층구조를 로그에 남기는 로직을 가지고 있음
• 처음 호출할 때는 기존의 begin메서드를 호출하고 두번째부터는 beginSync()메서드가 호출되도록 로직을 작성

public class HelloTraceV2 {
    // ... 기존 코드 동일
    // V2에 추가됨
    public TraceStatus beginSync(TraceId beforeTraceId, String message) {
        TraceId traceId = beforeTraceId.createNextId(); // TraceId를 생성하지않고 createNextId()를 호출
        Long startTimeMs = System.currentTimeMillis();
        log.info("[{}] {}{}", traceId.getId(), addSpace(START_PREFIX, traceId.getLevel()), message);
        return new TraceStatus(traceId, startTimeMs, message);
    }
    
    // ... 기존 코드 동일
}

 

(2) 테스트 및 결과

• 기존의 HelloTraceV1테스트에서 beginSync()메서드만 추가하는 테스트를 생성
• 계층 구조를 표현해야하기에 begin먼저 호출하고, beginSync()를 나중에 호출
• end를 호출할 때는 나중에 호출된 beginSync()메서드 연산 결과의 정보가 담긴 status2를 먼저 입력하고 마지막에 status1을 입력하여 호출
• begin_exception()도 동일하게 적용하면 계층 구조가 표현된 로그가 찍힘

class HelloTraceV2Test {

    // 정상 종료 테스트
    @Test
    void begin_end() {
        HelloTraceV2 trace = new HelloTraceV2();
        TraceStatus status1 = trace.begin("hello1");  // begin 테스트
        TraceStatus status2 = trace.beginSync(status1.getTraceId(), "hello2"); // beginSync 테스트
        trace.end(status2);     // beginSync 먼저 종료
        trace.end(status1);
    }

    // 예외 발생 테스트
    @Test
    void begin_exception() {
        HelloTraceV2 trace = new HelloTraceV2();
        TraceStatus status1 = trace.begin("exception1");
        TraceStatus status2 = trace.beginSync(status1.getTraceId(), "exception2");
        trace.exception(status2, new IllegalStateException());
        trace.exception(status1, new IllegalStateException());
    }
}

/* 실행 결과 로그
13:55:22.839 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [f4208450] hello1
13:55:22.839 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [f4208450] |-->hello2
13:55:22.839 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [f4208450] |<--hello2 time=0ms
13:55:22.839 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [f4208450] hello1 time=0ms

13:55:22.831 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [61e95cd5] exception1
13:55:22.833 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [61e95cd5] |-->exception2
13:55:22.833 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [61e95cd5] |<X-exception2 time=0ms ex=java.lang.IllegalStateException
13:55:22.833 [Test worker] INFO hello.advanced.trace.hellotrace.HelloTraceV2 -- [61e95cd5] exception1 time=3ms ex=java.lang.IllegalStateException

*/

---

6. 로그 추적기 V2 - 적용

1) v1 -> v2복사

• 기존에 작성해둔 v0버전의 Controller, Service, Repository코드들을 복사하여 V1으로 이름을 변경
• @GetMapping의 매핑 정보를 /v2/request로 변경
• 코드 내부의 의존관계 클래스들을 v2로 모두 변경하고 로그추적기 버전도 HelloTraceV2를 사용하도록 변경

2) V2 적용

(1) 적용 방안

• 메서드의 호출의 깊이를 표현하고 HTTP 요청도 구분해야하기에 각 계층의 메서드에서 로그를 남길 때 어떤 깊이와 어떤 트랜잭션ID를 사용했는지 알아야함
• 즉, 트랜잭션ID와 level이 각 다음 계층의 코드로 전달되어야하므로 컨트롤러에서부터 TraceStatus.traceId를 넘겨주도록 전체 코드를 수정하면 됨

(2) OrderControllerV2에 적용

• orderItem()메서드를 호출 시 status.getTraceId()의 정보를 itemId와 함께 인수값으로 전달하여 호출
• 트랜잭션ID와 level정보가 OrderServiceV2의 orderItem()메서드로 전달되어 연산을 수행함

package hello.advanced.app.v2;

@RestController
@RequiredArgsConstructor
public class OrderControllerV2 {
    // ... 기존 코드 생략
    public String request(String itemId) {
        TraceStatus status = null;
        try {
            status = trace.begin("OrderController.request()");
            orderService.orderItem(status.getTraceId(), itemId);
            
    // ... 기존 코드 생략

}

 

(3) OrderServiceV2에 적용

• 첫 번째 계층이 아니므로 begin을 호출하는 것이 아니라 trace.beginSync를 traceId의 값을 인수로 입력하여 호출
• beginSync()메서드는 내부에서 트랜잭션ID는 유지하고 level만 하나 증가시키는 traceId를 생성하고 그 상태를 OrderRepositoryV2에 넘김
• orderRepository.save를 호출할때도 status.getTraceId()의 값을 인수로 전달하여 호출

public class OrderServiceV2 {
    // ... 기존 코드 생략

    public void orderItem(TraceId traceId, String itemId) {
        TraceStatus status = null;
        try {
            status = trace.beginSync(traceId,"OrderService.orderItem()");
            orderRepository.save(status.getTraceId(), itemId);
            
        // ... 기존 코드 생략
}

 

(4) OrderRepositoryV2에 적용

• 마찬가지로 begin()가 아닌 beginSync()를 사용하도록 코드를 변경하여 트랜잭션ID는 유지하고 level만 1 증가시키도록 변경

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

    public void save(TraceId traceId, String itemId) {
        TraceStatus status = null;
        try {
            status = trace.beginSync(traceId,"OrderRepository.save()");
            
    // ... 기존 코드 생략            
}

 

(5) 적용 및 실행

• 매핑된 url로 요청을 보내보면 test와 마찬가지로 계층구조가 표현된 로그를 확인할 수 있음
• 요구항을 모두 만족하는 로그 추적기가 개발됨

로그 출력 결과 일부

(6) 남은 문제

• HTTP 요청을 구분하고 깊이를 표현하기 위해서 TraceId 동기화가 필요하기에 이를 해결하기 위해 관련 메서드의 모든 파라미터를 수정하였음
• 관련 클래스파일이 100개가 있었다면 모든 클래스파일을 고쳐야하고 인터페이스가 있었다면 인터페이스까지 모두 고쳐야하는 상황임
• 또한 로그를 처음 시작할 때는 begin()을 호출하고 처음이 아닐때는 beginSync()를 호출하도록 구분해서 적용하도록 되어있어 만약 컨트롤러가 아니라 다른 곳에서 서비스를 처음으로 호출하는 상황이라면 파라미터로 넘길 TraceId가 없는 문제가 발생함