스프링부트 3.x 에서 트레이싱 기능 추가하기

스프링부트 3.x부터 Spring cloud sleuth로 트레이싱 기능을 추가할 수 없게 되었습니다.
마이그레이션 가이드

https://github.com/micrometer-metrics/tracing/wiki/Spring-Cloud-Sleuth-3.1-Migration-Guide

Spring Cloud Sleuth 3.1 Migration Guide

앞으로는 Micrometer 의 brave 의존성을 추가해 트레이싱 기능을 사용할 수 있습니다.

 

적용해 볼 환경은 아래와 같습니다.

Spring boot 3.1.3

java 17

 

먼저 micrometer 의 brave 의존성을 추가해 줍니다.

zipkin 은 사용하지 않아 제외해 주었습니다. 사용하시는 분들은 exclude를 제거해 주세요.

implementation("io.micrometer:micrometer-tracing-bridge-brave") {
    exclude group: "io.zipkin.reporter2"
}

 

traceId 및 spanId를 확인할 수 있도록 로그 패턴을 변경해 줍니다.

저는 logback xml 파일에서 설정하였습니다.

[%-5level] %d{yyyy-MM-dd HH:mm:ss} [%thread] %replace([%X{traceId}, %X{spanId}]){'\[, \]',''}[%logger{0}:%line] - %msg%n

 

%replace 부분을 쓰지 않으면 traceId, spanId 가 없을 때 빈 값이 보이게 됩니다.
ex) 2024-04-07T14:14:20.632+09:00 [INFO ] 2024-04-07 14:14:20 [restartedMain] [, ] [OptionalLiveReloadServer:59] - LiveReload server is running on port 35729

 

여러 가지 상황을 테스트해보기 위해 아래와 같은 컨트롤러 서비스를 만듭니다.

AsyncConfig.java

@EnableAsync
@Configuration
public class AsyncConfig {
}

 

@EnableAsync를 통해 @Async 기능을 활성화해줍니다.

 

TracingService.java

import lombok.extern.slf4j.Slf4j;
import org.springframework.scheduling.annotation.Async;
import org.springframework.stereotype.Service;

@Slf4j
@Service
public class TracingService {

    public void print() {
        log.info("기존 스레드를 입니다.");
    }
    @Async
    public void asyncPrint() {
        log.info("@Async 에 의한 스레드 입니다.");
    }
}

 

3가지 케이스에 대한 테스트를 진행하기 위해 메서드를 추가합니다.

1. 기본 호출 print() 

2. @Async 어노테이션을 통한 비동기 호출 asyncPrint()

3. Executors를 통한 비동기 호출 executorsPrint()

 

TracingController.java

import com.infitry.laboratory.service.tracing.TracingService;
import lombok.RequiredArgsConstructor;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@RequiredArgsConstructor
@RequestMapping("/tracing")
public class TracingController {

	private final Executor executor;
    private final TracingService tracingService;

    @GetMapping("/test")
    public void testTracing() {
        tracingService.print();
        executor.execute(() -> log.info("executors 에 의한 스레드입니다."));
        tracingService.asyncPrint();
    }
}

 

각 메서드를 호출하도록 작성합니다.

 

이제 테스트로 컨트롤러를 호출합니다.

[INFO ] 2024-04-07 14:36:26 [http-nio-8080-exec-1] [661230da8761fca64322fbb40c3b2848, 4322fbb40c3b2848][TracingService:14] - 기존 스레드를 입니다.
[INFO ] 2024-04-07 14:36:26 [pool-5-thread-1] [TracingService:23] - executors 에 의한 스레드입니다.
[INFO ] 2024-04-07 14:36:26 [task-1] [TracingService:18] - @Async 에 의한 스레드 입니다.

 

예상했던 결과는 3가지 케이스 모두 traceId, spanId 가 생기길 기대하였습니다.

그런데 기본 호출에 대해서만 생성되었습니다. [661230da8761fca64322fbb40c3b2848, 4322fbb40c3b2848]

문서를 확인해 보니 비동기 스레드에 대해 tracing 기능을 사용하려면 별도로 커스터마이징이 필요합니다.

https://github.com/micrometer-metrics/tracing/wiki/Spring-Cloud-Sleuth-3.1-Migration-Guide#async-instrumentation

Spring Cloud Sleuth 3.1 Migration Guide

 

동일하게 적용하기 위해 기존 AsyncConfig 다음과 같이 수정합니다.

* 위 예시코드에서 ContextSnapshotFactory 인터페이스는 스프링부트 3.1.3 이상부터 존재하는 것 같네요.

import io.micrometer.context.ContextExecutorService;
import io.micrometer.context.ContextScheduledExecutorService;
import io.micrometer.context.ContextSnapshot;
import io.micrometer.context.ContextSnapshotFactory;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.core.task.SimpleAsyncTaskExecutor;
import org.springframework.scheduling.annotation.AsyncConfigurer;
import org.springframework.scheduling.annotation.EnableAsync;
import org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler;
import org.springframework.web.servlet.config.annotation.AsyncSupportConfigurer;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

import java.util.concurrent.*;

@EnableAsync
@Configuration(proxyBeanMethods = false)
public class AsyncConfig implements AsyncConfigurer, WebMvcConfigurer {

    @Override
    public Executor getAsyncExecutor() {
        return ContextExecutorService.wrap(Executors.newCachedThreadPool(), ContextSnapshot::captureAll);
    }

    @Override
    public void configureAsyncSupport(AsyncSupportConfigurer configurer) {
        configurer.setTaskExecutor(new SimpleAsyncTaskExecutor(r -> new Thread(ContextSnapshotFactory.builder().build().captureAll().wrap(r))));
    }

    @Bean
    public ThreadPoolTaskScheduler taskExecutor() {
        var threadPoolTaskScheduler = new ThreadPoolTaskScheduler() {
            @Override
            public ScheduledExecutorService getScheduledExecutor() throws IllegalStateException {
                return ContextScheduledExecutorService.wrap(super.getScheduledExecutor());
            }
        };
        threadPoolTaskScheduler.initialize();
        return threadPoolTaskScheduler;
    }
}

 

수정 후 다시 실행해 봅니다.

[INFO ] 2024-04-07 15:02:35 [http-nio-8080-exec-1] [661236fbbd55bf9f47bf8c35a9b5fb44, 47bf8c35a9b5fb44][TracingService:14] - 기존 스레드를 입니다.
[INFO ] 2024-04-07 15:02:35 [taskExecutor-1] [661236fbbd55bf9f47bf8c35a9b5fb44, 47bf8c35a9b5fb44][TracingController:24] - executors 에 의한 스레드입니다.
[INFO ] 2024-04-07 15:02:35 [pool-5-thread-1] [661236fbbd55bf9f47bf8c35a9b5fb44, 47bf8c35a9b5fb44][TracingService:18] - @Async 에 의한 스레드 입니다.

 

다음과 같이 스레드명은 모두 다르나 (http-nio-8080-exec-1, taskExecutor-1, poo-5-thread-1)
traceId, spanId(661236fbbd55bf9f47bf8c35a9b5fb44, 47bf8c35a9b5fb44) 는 모두 같아 비동기 호출이 존재하더라도 해당 요청을 추적 할 수 있게 되었습니다.

 

아직 sleuth 에서 micrometer 로 프로젝트가 이동한지 얼마되지 않아 불편한 점이 많은 것 같습니다. (async wrap 등..)

정확한 부분은 조금 더 여러가지 상황에서 테스트 해봐야 알 수 있을 것 같습니다.