스프링 리액터 로깅과 체크포인트
로깅
리액터의 동작을 보다 자세히 보고 싶다면 다음과 같이 log() 메서드를 사용한다. 아래 코드를 보자.
Flux.just(1, 2, 4, 5, 6)
.log()
.map(x -> x * 2)
.subscribe(x -> logger.info("next: {}", x));
"reactor.Flux.Array.1"이라는 로거가 출력한 로그 메시지는 Flux.just()가 생성한 시퀀스의 동작을 로그로 남긴 것이다. 로그를 보면 시퀀스가 request() 신호를 받은 시점, next 신호(onNext(2) 등)나 complete 신호(onComplete())를 발생한 시점을 확인할 수 있다.
로그 레벨은 INFO인데 로그 레벨을 변경하고 싶다면 다음과 같이 log() 메서드를 사용하면 된다.
Flux.just(1, 2, 4, 5, 6)
.log(null, Level.FINE) // java.util.logging.Level 타입
.subscribe(x -> logger.info("next: {}", x));
두 번째 인자로 자바 로깅의 Level.FINE을 주었다. SLF4j를 사용할 경우 리액터는 자바의 FINE 레벨을 SLF4j의 DEBUG 레벨로 기록한다. 따라서 위 코드를 실행하면 다음과 같이 DEBUG 레벨로 로그를 남기는 것을 확인할 수 있다.
08:50:30.098 [main] DEBUG reactor.Flux.Array.1 - | onSubscribe([Synchronous Fuseable] FluxArray.ArraySubscription)
08:50:30.101 [main] DEBUG reactor.Flux.Array.1 - | request(unbounded)
08:50:30.102 [main] DEBUG reactor.Flux.Array.1 - | onNext(1)
08:50:30.102 [main] INFO logging.LoggingTest - next: 1
08:50:30.102 [main] DEBUG reactor.Flux.Array.1 - | onNext(2)
08:50:30.102 [main] INFO logging.LoggingTest - next: 2
다음과 같이 특정 로거를 이용하도록 지정할 수도 있다.
Flux.just(1, 2, 4, 5, 6)
.log("MYLOG") // 또는 log("MYLOG", Level.INFO)
.subscribe(x -> logger.info("next: {}", x));
위 코드를 실행하면 다음과 같이 지정한 로거를 이용해서 로그를 남긴다.
08:51:55.180 [main] INFO MYLOG - | onSubscribe([Synchronous Fuseable] FluxArray.ArraySubscription)
08:51:55.184 [main] INFO MYLOG - | request(unbounded)
08:51:55.184 [main] INFO MYLOG - | onNext(1)
08:51:55.184 [main] INFO logging.LoggingTest - next: 1
08:51:55.184 [main] INFO MYLOG - | onNext(2)
08:51:55.184 [main] INFO logging.LoggingTest - next: 2
08:51:55.184 [main] INFO MYLOG - | onNext(4)
체크포인트
시퀀스가 신호를 발생하는 과정에서 익셉션이 발생하면 어떻게 될까? 시퀀스가 여러 단게를 거쳐 변환한다면 어떤 시점에 익셉션이 발생했는지 단번에 찾기 힘들 수도 있다. 이럴 때 도움이 되는 것이 체크포인트이다. 다음은 체크포인트 사용 예이다.
Flux.just(1, 2, 4, -1, 5, 6)
.map(x -> x + 1)
.checkpoint("MAP1")
.map(x -> 10 / x) // 원본 데이터가 -1인 경우 x는 0이 되어 익셉션이 발생
.checkpoint("MAP2")
.subscribe(
x -> System.out.println("next: " + x),
err -> err.printStackTrace());
관련글