spring boot/actuator in spring boot

spring boot 3.x + actuator 파헤치기. 11. about metrics endpoint ( Timer )

Hello World Study 2023. 4. 14. 09:31

https://youtu.be/aqkb1SHBNIc

https://youtu.be/LywjP3UDTcM

 

마지막으로 다룰 metric type 으로 timer 가 있습니다.

 

이름 그대로 시간을 측정하는 metric 입니다.

 

timer 등록

우선 다른 metric type과 동일하게 builder 를 이용해서 timer 를 만든 후 meterRegistry 에 등록해줍니다. 

아래처럼 my.timer 라고 파라미터값을 넣었으므로 actuator 에서는 my.timer 가 path에 들어가게 됩니다.

timer 의 경우 시간값을 측정하고 싶은 곳에 timer 로 감싸서 구현을 해야합니다. 그래서 반드시 Timer 를 bean 으로 등록해둬야 합니다.

@Configuration
@RequiredArgsConstructor
public class TimerConfig {

    private final MeterRegistry meterRegistry;

    @Bean
    public Timer myTimer() {
        Timer myTimer = Timer
                .builder("my.timer")
                .register(meterRegistry);
        return myTimer;
    }
}

 

timer 적용

아래처럼 controller 내의 특정 메서드의 수행 시간을 timer metric 을 이용해서 측정해봤습니다.

위에서 만든 Timer bean을 생성자 주입으로 받았습니다. @Qualifier("myTimer")는 넣지 않아도 오류가 나지 않으나, timer 를 개인적으로 더 추가해서 테스트 하는 분들이 있을듯 하여 Timer 타입의 bean이 2개 이상 있어도 오류가 나지 않게 미리 @Qualifier 를 추가해두었습니다.

timer 로 측정하고 싶은 코드를 Timer.record() 메서드 내에 넣어주면 됩니다.

@RestController
@Slf4j
@RequestMapping("/api")
@RequiredArgsConstructor
public class TimerController {

    @Qualifier("myTimer")  // 없어도 오류는 없으나 Timer 타입 bean이 추가되면 오류나므로 예방차원에서 추가.
    private final Timer myTimer;
    
    @GetMapping("/timer")
    public String timer() {
        myTimer.record(() -> {
            try {
                Thread.sleep(3000);
            } catch (InterruptedException e) {
                throw new RuntimeException(e);
            }
        });
        return "ok";
    }

}

위 코드에서는 3초 정도 걸리는 코드가 있다는 가정하여 sleep 3초를 넣어두었습니다.

 

timer test

잘 동작하는지 테스트를 해봅시다. 아래처럼 위 method 가 실행되도록 http request 를 보냅니다. sleep 3초가 되어 있어서 응답되는데 3초가 걸립니다. 이후 http://127.0.0.1:8080/actuator/metrics/my.timer 으로 접속을 하면 횟수, 누적 수행시간, 최대 수행시간 항목이 나오는걸 알 수 있습니다. 

아래 테스트에서는 총 2번 rest api를 호출했으므로 count : 2 로 나오고, 누적 시간(TOTAL_TIME)은 3+3=6. 6초 가 나옵니다. 호출될때마다 3초 sleep을 두었으므로 MAX 값은 3초가 나옵니다.

 

timer debugging

위 timer 는 어떤식으로 동작하길래 Timer.record() 메서드의 파라미터에 Runnable 을 넣어줘야 할까요?

아래처럼 record() 메서드에 디버그 포인트를 걸고 내부 코드를 따라가보니

Runnable 실행 전후에 시간을 알아낸후 그걸 계산해서 수행시간을 측정하는걸 알 수있습니다. 보통 시간측정할때 흔히 사용하는 방법을 동일하게 쓰고 있네요. :)

 

Timer.Sample

지금까지 알아본 방법은 Timer.record() 메서드의 파라미터에 Runnable을 넣어주는 방식이었습니다. 이 방식으로 대부분 해결되나, 좀 복잡한 로직에서 Timer 를 사용하고 싶다면 Timer.Sample 을 이용하는것도 좋은 방식입니다.

아래 가이드처럼 명시적으로 timer start 를 해서 시작값을 객체에 저장한 후, 중단하고 싶은 곳에서 stop()을 호출하는 방식입니다. 

https://micrometer.io/docs/concepts#_storing_start_state_in_timer_sample

위 방식대로 아래처럼 my.timer2 에 대해 Timer.Sample 을 사용해봤습니다. 결과는 동일하니 테스트 결과는 skip 합니다.

    @GetMapping("/timer2")
    public String timer2() {

        Timer.Sample sample = Timer.start(meterRegistry);

        internal();

        sample.stop(meterRegistry.timer("my.timer2"));
        return "ok";
    }

    private void internal() {

        try {
            Thread.sleep(3000);
        } catch (InterruptedException e) {
            throw new RuntimeException(e);
        }
    }

 

@Timed

위 Timer.Sample 예제를 보니 timer 측정하고 싶은 코드 앞 뒤에 start와 stop 메서드를 호출하는 패턴입니다. 많이 익숙한 패턴이지요? AOP를 적용하기 좋은 모양입니다.

micrometer 라이브러리에서는 AOP를 활용한 @Timed 라는 어노테이션을 제공하며 이를 통해 쉽게 timer 를 적용할 수 있습니다.

 

Counter metric ( https://semtul79.tistory.com/18 참조 ) 에서 @Counted 라는 어노테이션을 통해 쉽게 counter metrics 을 적용할 수 있다고 했으며, 이를 위해 CountedAspect 타입의 bean을 등록해야 했습니다.

동일하게 Timer metric 에서 @Timed 라는 어노테이션을 적용하려면 TimedAspect 타입의 bean을 아래처럼 등록해줘야 합니다. AOP를 적용하려면  @Aspect 와 @Around 가 사용되어야 하는데 TimedAspect 클래스 내부에 관련 코드가 있습니다. 그래서 반드시 bean으로 등록해줘야 합니다. @Counted 어노테이션 설명시에도 동일한 내용을 언급했습니다. :)

@Configuration
public class TimedConfiguration {
    @Bean
    public TimedAspect timedAspect(MeterRegistry meterRegistry) {
        return new TimedAspect(meterRegistry);
    }
}

 

rest controller 에 아래처럼 특정 메서드 위에 @Timed 어노테이션을 사용했습니다. 

    @Timed("my.timer3")
    @GetMapping("/timer3/{sleepSeconds}")
    public String timer3(@PathVariable("sleepSeconds") int sleepSeconds) throws InterruptedException {
        Thread.sleep(sleepSeconds);
        return "ok";
    }

이후 위 메서드가 실행되도록 http request 를 날린 후 http://127.0.0.1:8080/actuator/metrics/my.timer3 에 접속하면 아래처럼 timer metric 정보를 볼 수 있습니다. 

 

AOP를 이용하고 있으므로 일반적인 AOP의 제약사항이 그대로 적용됩니다. 즉 아래처럼 클래스 내부의 메서드들끼리 호출될 경우 AOP가 적용되지 않기에 결론적으로 my.timer4 는 동작하지 않습니다.

    @Timed("my.timer3")
    @GetMapping("/timer3/{sleepSeconds}")
    public String timer3(@PathVariable("sleepSeconds") int sleepSeconds) throws InterruptedException {
        Thread.sleep(sleepSeconds);
        internal();  
        return "ok";
    }


    @Timed("my.timer4")
    private void internal() {

        try {
            Thread.sleep(3000);
        } catch (InterruptedException e) {
            throw new RuntimeException(e);
        }
    }

 

FunctionTimer

Counter metric 파트에서 자체 counter 관리 bean 이 있다면, 이를 재활용하기 위해 FunctionCounter 라는 클래스를 이용하면 된다고 배웠습니다. ( 가물가물 하시나요? ㅡ.ㅡ+ )

 

timer 도 동일하게 FunctionTimer 가 있으며 사용 패턴은 동일합니다.

 

아래처럼 자체적으로 시간을 관리하는 bean 이 있다고 가정하겠습니다. 테스트 용도이니, 현재 시간값을 count, 누적 시간 으로 지정했습니다. 실무에서는 특정 메서드 호출횟수와 소요시간 등을 직접 계산하는 로직이 들어가야 합니다.

@Service
public class MyTimerManager {

    public long getCount() {
        return System.currentTimeMillis();
    }

    public long getTotalTime() {
        return System.currentTimeMillis() * 2;
    }
}

timer 를 등록하기 위해 아래처럼 FunctionTimer 타입의 bean을 생성하며, 이때 위에서 만든 bean을 주입받아서 사용하면 됩니다.

@Configuration
public class FunctionTimerConfig {

    @Bean
    FunctionTimer myFunctionTimer(MeterRegistry meterRegistry, MyTimerManager myTimerManager) {
        FunctionTimer functionTimer = FunctionTimer.builder("my.timer5.latency", myTimerManager,
                        m -> {
                            return m.getCount();
                        },
                        m -> {
                            return m.getTotalTime();
                        },
                        TimeUnit.SECONDS)
                .register(meterRegistry);

        return functionTimer;
    }
}

builder 메서드의 파라미터는 아래와 같습니다. 다소 복잡하나, 횟수와 누적시간을 가져오는 메서드를 지정해주고, 누적시간값의 단위 즉 초, 분, 시 등을 지정해주면 됩니다. 아쉽게도 FunctionTimer 의 경우 max 값은 지원되지 않는 것으로 보입니다.

 

FunctionTimer 의 경우 spring boot 시작시점에 meterRegistry에 등록되기에 http://127.0.0.1:8080/actuator/metrics/my.timer5.latency 로 접속하면 바로 값을 얻을 수 있습니다. 

 

MeterBinder

위에서는 FunctionTimer 자체를 bean 으로 등록했는데, MeterBinder 를 통해 등록도 가능합니다. 

FunctionTimer 에서 사용된 코드 거의 그대로 사용하면서 FunctionTimer 가 아닌 MeterBinder 가 bean으로 등록되다보니 그에 맞게 bindTo() 메서드 문법에 맞게 구현해야 하는 차이가 있을 뿐 동작은 동일합니다.

@Configuration
public class TimerConfigWithMeterBinder {

    @Bean
    public MeterBinder myTimerWithMeterBinder(MyTimerManager myTimerManager) {
        return new MeterBinder() {
            @Override
            public void bindTo(MeterRegistry registry) {
                FunctionTimer functionTimer = FunctionTimer.builder("my.timerWithMeterBinder.latency", myTimerManager,
                                m -> {
                                    return m.getCount();
                                },
                                m -> {
                                    return m.getTotalTime();
                                },
                                TimeUnit.SECONDS)
                        .register(registry);
            }
        };
    }
}

 

 

여기서 사용된 소스코드는 아래에서 확인할 수 있습니다.

 

https://github.com/ChunGeun-Yu/spring-actuator-study/tree/timerMetrics

 


길고긴 metric 파트도 이제 끝났습니다. 깔딱고개 끝났으니 남은부분 금방 끝내시죠