[리액티브 프로그래밍] Debugging

스프링으로 시작하는 리액티브 프로그래밍 책 정리

스프링으로 시작하는 리액티브 프로그래밍 | 황정식 - 교보문고

스프링으로 시작하는 리액티브 프로그래밍 | *리액티브 프로그래밍의 기본기를 확실하게 다진다*리액티브 프로그래밍은 적은 컴퓨팅 파워로 대량의 요청 트래픽을 효과적으로 처리할 수 있는

product.kyobobook.co.kr

Reactor에서의 디버깅 방법

✅ Reactor 디버깅의 어려움

동기식 또는 명령형 프로그래밍 방식은 Exception이 발생했을 때,

스택트레이스를 확인하거나, 예외 상황 발생이 예상되는 코드에 브레이크포인트를 걸어 문제가 발생한 원인을 단계적으로 찾아가면 된다.

반면에, Reactor는 대부분 비동기적으로 실행되고, 선언형 프로그래밍 방식으로 구성되므로 디버깅이 쉽지 않다.

-> 이러한 디버깅의 어려움을 최소화하기 위해 Reactor에서는 몇 가지 방법을 제공한다.

Debug Mode를 사용한 디버깅

✅ Hooks.onOperatorDebug()

@Slf4j
public class Example12_1 {
    public static Map<String, String> fruits = new HashMap<>();

    static {
        fruits.put("banana", "바나나");
        fruits.put("apple", "사과");
        fruits.put("pear", "배");
        fruits.put("grape", "포도");
    }

    public static void main(String[] args) throws InterruptedException {
        // Hooks.onOperatorDebug();

        Flux
                .fromArray(new String[]{"BANANAS", "APPLES", "PEARS", "MELONS"})
                .subscribeOn(Schedulers.boundedElastic())
                .publishOn(Schedulers.parallel())
                .map(String::toLowerCase)
                .map(fruit -> fruit.substring(0, fruit.length() - 1))
                .map(fruits::get)
                .map(translated -> "맛있는 " + translated)
                .subscribe(
                        log::info,
                        error -> log.error("# onError:", error));

        Thread.sleep(100L);
    }
}

Reactor에서의 디버그 모드는 Hooks.onOperatorDebug()를 통해 이루어진다.

일단 디버그 모드를 활성화 하지 않을 경우를 보기 위해, 해당 코드를 주석처리했다.

<결과>

15:30:27.775 [parallel-1] INFO - 맛있는 바나나
15:30:27.780 [parallel-1] INFO - 맛있는 사과
15:30:27.781 [parallel-1] INFO - 맛있는 배
15:30:27.796 [parallel-1] ERROR- # onError:
java.lang.NullPointerException: The mapper [chapter12.Example12_1$$Lambda$58/0x0000000800154040] returned a null value.
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:115)
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129)
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129)
	at reactor.core.publisher.FluxPublishOn$PublishOnSubscriber.runAsync(FluxPublishOn.java:440)
	at reactor.core.publisher.FluxPublishOn$PublishOnSubscriber.run(FluxPublishOn.java:527)
	at reactor.core.scheduler.WorkerTask.call(WorkerTask.java:84)
	at reactor.core.scheduler.WorkerTask.call(WorkerTask.java:37)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	...

NullPointerException이 발생했다.

스택트레이스만 놓고 봤을 때 map Operator에서 발생한 에러같은데, 실제 코드에는 map Operator가 여러 개 있기 때문에 어디에서 에러가 발생했는지 구체적으로 알기 힘들다.

이제 주석을 해제한 후 다시 코드를 실행시켜보자.

java.lang.NullPointerException: The mapper [chapter12.Example12_1$$Lambda$66/0x0000000800151040] returned a null value.
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:115)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.FluxMapFuseable] :
	reactor.core.publisher.Flux.map(Flux.java:6271)
	chapter12.Example12_1.main(Example12_1.java:35)
Error has been observed at the following site(s):
	*__Flux.map ⇢ at chapter12.Example12_1.main(Example12_1.java:35)
	|_ Flux.map ⇢ at chapter12.Example12_1.main(Example12_1.java:36)
Original Stack Trace:
		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:115)
		...

에러 메시지와 스택트레이스 사이에 새로운 내용들이 보인다.

추가된 내용은 Operator 체인상에서 에러가 발생한 지점을 정확히 가리키고 있으며, 에러가 시작된 지점부터 에러 전파 상태를 친절하게 표시해주고 있다.

-> map(fruits::get)에서 null을 리턴한다.

-> Flux.map()에서 null을 리턴하면 subscribe하는 시점에서 NullPointerException이 발생한다.

✅ Hooks.onOperatorDebug()의 단점

디버그 모드는 다음과 같이 애플리케이션 내에서 비용이 많이 드는 동작 과정을 거친다.

애플리케이션 내에 있는 모든 Operator의 스택트레이스를 캡처한다.
에러가 발생하면 캡처한 정보를 기반으로 에러가 발생한 Assembly의 스택트레이스를 원본 스택트레이스 중간에 끼워 넣는다.

-> 따라서 에러 원인을 추적하기 위해 처음부터 디버그 모드를 활성화하는 것은 권장하지 않는다.

Q: Assembly가 뭐지?

A: Operator에서 리턴하는 새로운 Mono 또는 Flux가 선언된 지점을 의미한다.

디버그 모드를 활성화하면 Operator의 Assembly 정보를 캡처하는데, 이중에서 에러가 발생한 Operator의 스택트레이스를 캡처한 Assembly 정보를 Traceback이라고 한다.

Traceback은 Suppressed Exception 형태로 원본 스택트레이스에 추가된다.

참고: https://gksdudrb922.tistory.com/324

[Java] Suppressed Exception

✅ Suppressed ExceptionSuppressed Exception은 throw되지만 무시되는 예외를 말한다.예를 들어, try-catch-finally 문에서 try문에서 예외가 발생했을 때, catch문에서 예외를 받아 throw한 상황에서,finally 문에서도

gksdudrb922.tistory.com

✅ ReactorDebugAgent

Reactor에서는 애플리케이션 내 모든 Operator 체인의 스택트레이스 캡처 비용을 지불하지 않고 디버깅 정보를 추가할 수 있도록 별도의 Java 에이전트를 제공한다.

만약 Spring WebFlux 기반의 애플리케이션을 사용한다면, build.gradle에 'io.projectreactor:reactor-tools'를 추가하면 ReactorDebugAgent를 활성화할 수 있다.

ReactorDebugAgent가 존재하고, spring.reactor.debug-agent.enabled=true면 애플리케이션 시작 시, ReactorDebugAgent.init()이 자동으로 호출되면서 ReactorDebugAgent가 활성화된다. (Spring Boot에서는 default 값이 true)

해당 값을 false로 하면 스프링 main 함수에 ReactorDebugAgent.init()을 명시적으로 넣어줘야 한다.

-> 성능이 중요한 운영 환경에서는 이러한 방식을 사용하면 적절하겠다.

✅ Intellij에서 Debug Mode

IntelliJ에서는 개발자가 Hooks.onOperatorDebug()를 직접 추가하지 않아도 디버그 모드를 활성화하는 방법을 제공한다.

Settings > Languages & Frameworks > Reactive Streams

Debugger > Enable Reactor Debug mode를 체크하면 다양한 옵션을 사용할 수 있다.

Detect automatically: 아래 두 옵션을 모두 동적으로 적용해주는 것으로 보인다.
Hooks.onOperatorDebug(): 개발자가 별도로 Hooks.onOperatorDebug()를 추가하지 않아도, Debug모드로 코드를 실행하면 Hooks.onOperatorDebug()를 추가한 것처럼 Traceback을 확인할 수 있다.
ReactorDebugAgent.init(): 'io.projectreactor:reactor-tools'이 추가된 상태에서, 프로젝트를 Debug 모드로 실행하면, ReactorDebugAgent.init()이 실행된 것처럼 Traceback을 확인할 수 있다.

checkpoint() Operator를 사용한 디버깅

✅ Traceback을 출력하는 방법

checkpoint() Operator를 사용하면 특정 Operator 체인 내의 스택트레이스만 캡처한다.

실제 에러가 발생한 assembly 지점 도는 에러가 전파된 assembly 지점의 traceback이 추가된다.

@Slf4j
public class Example12_2 {
    public static void main(String[] args) {
        Flux
            .just(2, 4, 6, 8)
            .zipWith(Flux.just(1, 2, 3, 0), (x, y) -> x/y)
            .map(num -> num + 2)
            .checkpoint()
            .subscribe(
                    data -> log.info("# onNext: {}", data),
                    error -> log.error("# onError:", error)
            );
    }
}

map() Operator 바로 다음 위치에 checkpoint()를 추가했다.

<결과>

20:43:30.382 [main] INFO - # onNext: 4
20:43:30.383 [main] INFO - # onNext: 4
20:43:30.383 [main] INFO - # onNext: 4
20:43:30.403 [main] ERROR- # onError:
java.lang.ArithmeticException: / by zero
	at chapter12.Example12_2.lambda$main$0(Example12_2.java:15)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.FluxMap] :
	reactor.core.publisher.Flux.checkpoint(Flux.java:3352)
	chapter12.Example12_2.main(Example12_2.java:17)
Error has been observed at the following site(s):
	*__checkpoint() ⇢ at chapter12.Example12_2.main(Example12_2.java:17) // 에러 탐지
Original Stack Trace:
		at chapter12.Example12_2.lambda$main$0(Example12_2.java:15)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:982)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:971)
		at reactor.core.publisher.FluxZip$ZipCoordinator.drain(FluxZip.java:738)
		at reactor.core.publisher.FluxZip$ZipInner.onSubscribe(FluxZip.java:888)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:53)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:59)
		at reactor.core.publisher.Flux.subscribe(Flux.java:8466)
		...

우선 ArithmeticException이 발생한 것을 알 수 있다.

그리고 checkpoint()에서 에러가 발견된 것을 볼 수 있는데, 아직은 에러가 어디서 발생했는지 알 수 없다.

왜냐하면 checkpoint()는 에러가 전파되는 경우에도 에러를 발견하기 때문에, checkpoint() 기준 Upstream 어디에서 에러가 발생했는지 알 수 없다.

checkpoint()를 하나 더 달아보자.

@Slf4j
public class Example12_3 {
    public static void main(String[] args) {
        Flux
            .just(2, 4, 6, 8)
            .zipWith(Flux.just(1, 2, 3, 0), (x, y) -> x/y)
            .checkpoint()
            .map(num -> num + 2)
            .checkpoint()
            .subscribe(
                    data -> log.info("# onNext: {}", data),
                    error -> log.error("# onError:", error)
            );
    }
}

<결과>

20:46:46.670 [main] INFO - # onNext: 4
20:46:46.671 [main] INFO - # onNext: 4
20:46:46.671 [main] INFO - # onNext: 4
20:46:46.691 [main] ERROR- # onError:
java.lang.ArithmeticException: / by zero
	at chapter12.Example12_3.lambda$main$0(Example12_3.java:15)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.FluxZip] :
	reactor.core.publisher.Flux.checkpoint(Flux.java:3352)
	chapter12.Example12_3.main(Example12_3.java:16)
Error has been observed at the following site(s):
	*__checkpoint() ⇢ at chapter12.Example12_3.main(Example12_3.java:16) // 에러 탐지
	|_ checkpoint() ⇢ at chapter12.Example12_3.main(Example12_3.java:18) // 에러 탐지
Original Stack Trace:
		at chapter12.Example12_3.lambda$main$0(Example12_3.java:15)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:982)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:971)
		at reactor.core.publisher.FluxZip$ZipCoordinator.drain(FluxZip.java:738)
		at reactor.core.publisher.FluxZip$ZipInner.onSubscribe(FluxZip.java:888)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:53)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:59)
		...

두 개의 checkpoint() 지점이 모두 에러와 관련이 있음을 알 수 있다.

즉, 첫 번째 checkpoint()의 Upstream에서부터 에러가 발생했다는 것인데, just()에는 특별한 처리 로직이 없기 때문에, 결국 zipWith()에서 에러가 발생해 Downstream으로 전파되었음을 알 수 있다.

✅ Traceback 출력 없이 식별자를 포함한 Description을 출력해서 에러 발생 지점을 예상하는 방법

checkpoint(description)을 사용하면, 에러 발생 시 Traceback을 생략하고 description을 출력한다.

@Slf4j
public class Example12_4 {
    public static void main(String[] args) {
        Flux
            .just(2, 4, 6, 8)
            .zipWith(Flux.just(1, 2, 3, 0), (x, y) -> x/y)
            .checkpoint("Example12_4.zipWith.checkpoint")
            .map(num -> num + 2)
            .checkpoint("Example12_4.map.checkpoint")
            .subscribe(
                    data -> log.info("# onNext: {}", data),
                    error -> log.error("# onError:", error)
            );
    }
}

<결과>

20:49:01.833 [main] INFO - # onNext: 4
20:49:01.835 [main] INFO - # onNext: 4
20:49:01.835 [main] INFO - # onNext: 4
20:49:01.852 [main] ERROR- # onError:
java.lang.ArithmeticException: / by zero
	at chapter12.Example12_4.lambda$main$0(Example12_4.java:16)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Error has been observed at the following site(s):
	*__checkpoint ⇢ Example12_4.zipWith.checkpoint // 에러 탐지
	|_ checkpoint ⇢ Example12_4.map.checkpoint // 에러 탐지
Original Stack Trace:
		at chapter12.Example12_4.lambda$main$0(Example12_4.java:16)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:982)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:971)
		at reactor.core.publisher.FluxZip$ZipCoordinator.drain(FluxZip.java:738)
		at reactor.core.publisher.FluxZip$ZipInner.onSubscribe(FluxZip.java:888)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:53)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:59)
		at reactor.core.publisher.Flux.subscribe(Flux.java:8466)
		...

checkpoint()의 파라미터로 입력한 description이 출력된 것을 확인할 수 있다.

✅ Traceback과 Description을 모두 출력하는 방법

checkpoint(description, forceStackTrace)를 사용하면 description과 Traceback을 모두 출력할 수 있다.

@Slf4j
public class Example12_5 {
    public static void main(String[] args) {
        Flux
            .just(2, 4, 6, 8)
            .zipWith(Flux.just(1, 2, 3, 0), (x, y) -> x/y)
            .checkpoint("Example12_4.zipWith.checkpoint", true)
            .map(num -> num + 2)
            .checkpoint("Example12_4.map.checkpoint", true)
            .subscribe(
                    data -> log.info("# onNext: {}", data),
                    error -> log.error("# onError:", error)
            );
    }
}

checkpoint()의 두 번째 파라미터 값을 'true'로 설정하면 에러 발생 시 description과 Traceback을 모두 출력할 수 있다.

<결과>

java.lang.ArithmeticException: / by zero
	at chapter12.Example12_5.lambda$main$0(Example12_5.java:16)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.FluxZip], described as [Example12_4.zipWith.checkpoint] :
	reactor.core.publisher.Flux.checkpoint(Flux.java:3417)
	chapter12.Example12_5.main(Example12_5.java:17)
Error has been observed at the following site(s):
	*__checkpoint(Example12_4.zipWith.checkpoint) ⇢ at chapter12.Example12_5.main(Example12_5.java:17) // 에러 탐지
	|_     checkpoint(Example12_4.map.checkpoint) ⇢ at chapter12.Example12_5.main(Example12_5.java:19) // 에러 탐지
Original Stack Trace:
		at chapter12.Example12_5.lambda$main$0(Example12_5.java:16)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:982)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:971)
		at reactor.core.publisher.FluxZip$ZipCoordinator.drain(FluxZip.java:738)
		at reactor.core.publisher.FluxZip$ZipInner.onSubscribe(FluxZip.java:888)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:53)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:59)
		at reactor.core.publisher.Flux.subscribe(Flux.java:8466)
		...

✅ 서로 다른 Operator 체인에서의 checkpoint() 활용

@Slf4j
public class Example12_6 {
    public static void main(String[] args) {
        Flux<Integer> source = Flux.just(2, 4, 6, 8);
        Flux<Integer> other = Flux.just(1, 2, 3, 0);

        Flux<Integer> multiplySource = divide(source, other).checkpoint();
        Flux<Integer> plusSource = plus(multiplySource).checkpoint();


        plusSource.subscribe(
                data -> log.info("# onNext: {}", data),
                error -> log.error("# onError:", error)
        );
    }

    private static Flux<Integer> divide(Flux<Integer> source, Flux<Integer> other) {
        return source.zipWith(other, (x, y) -> x/y);
    }

    private static Flux<Integer> plus(Flux<Integer> source) {
        return source.map(num -> num + 2);
    }
}

<결과>

java.lang.ArithmeticException: / by zero
	at chapter12.Example12_6.lambda$divide$2(Example12_6.java:26)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.FluxZip] :
	reactor.core.publisher.Flux.checkpoint(Flux.java:3352)
	chapter12.Example12_6.main(Example12_6.java:15)
Error has been observed at the following site(s):
	*__checkpoint() ⇢ at chapter12.Example12_6.main(Example12_6.java:15)
	|_ checkpoint() ⇢ at chapter12.Example12_6.main(Example12_6.java:16)
Original Stack Trace:
		at chapter12.Example12_6.lambda$divide$2(Example12_6.java:26)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:982)
		at reactor.core.publisher.FluxZip$PairwiseZipper.apply(FluxZip.java:971)
		at reactor.core.publisher.FluxZip$ZipCoordinator.drain(FluxZip.java:738)
		at reactor.core.publisher.FluxZip$ZipInner.onSubscribe(FluxZip.java:888)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:53)
		at reactor.core.publisher.FluxArray.subscribe(FluxArray.java:59)
		at reactor.core.publisher.Flux.subscribe(Flux.java:8466)
		...

이처럼 Operator 체인이 기능별로 여러 곳에 흩어져 있는 경우라면, 각각의 Operator 체인에 checkpoint()를 추가한 후, 범위를 좁혀 가면서 단계적으로 에러 발생 지점을 찾을 수 있다.

-> 나는 로컬에서 chekpoint() 찍어가면서 테스트해볼 때 사용할 것 같다. 운영은 글쎄... 에러가 예상되는 지점을 어찌 예상하고 checkpoint()를 찍으리..

log() Operator를 사용한 디버깅

✅ log()

log()는 Reactor Sequence 동작을 로그로 출력한다.

@Slf4j
public class Example12_7 {
    public static Map<String, String> fruits = new HashMap<>();

    static {
        fruits.put("banana", "바나나");
        fruits.put("apple", "사과");
        fruits.put("pear", "배");
        fruits.put("grape", "포도");
    }

    public static void main(String[] args) {
        Flux.fromArray(new String[]{"BANANAS", "APPLES", "PEARS", "MELONS"})
                .map(String::toLowerCase)
                .map(fruit -> fruit.substring(0, fruit.length() - 1))
                .log() // 로그 출력
                .map(fruits::get)
                .subscribe(
                        log::info,
                        error -> log.error("# onError:", error));
    }
}

<결과>

21:21:46.594 [main] INFO - | onSubscribe([Fuseable] FluxMapFuseable.MapFuseableSubscriber)
21:21:46.598 [main] INFO - | request(unbounded)
21:21:46.599 [main] INFO - | onNext(banana)
21:21:46.600 [main] INFO - 바나나
21:21:46.600 [main] INFO - | onNext(apple)
21:21:46.601 [main] INFO - 사과
21:21:46.601 [main] INFO - | onNext(pear)
21:21:46.602 [main] INFO - 배
21:21:46.602 [main] INFO - | onNext(melon)
21:21:46.612 [main] INFO - | cancel()
21:21:46.619 [main] ERROR- # onError:
java.lang.NullPointerException: The mapper [chapter12.Example12_7$$Lambda$38/0x0000000800150040] returned a null value.
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:115)
	...

onSubscribe(), reqeust(), onNext() 같은 Signal이 출력되었다.

이 Siganl들을 두 번째 map() Operator에서 발생한 Signal들이다.

로그 마지막 즈음에 cancel() Signal이 출력되었다.

-> 이는 두 번째 map() Operator가 "melon"이라는 문자열을 emit했지만 두 번째 map() Operator 이후의 어떤 지점에서 "melon" 문자열을 처리하는 중에 에러가 발생했음을 의미한다.

-> 다행히 두 번째 map() Operator 이후에 map Operator가 하나 밖에 없기 때문에 세 번째 map() Operator에서 문제가 발생했음을 알 수 있다.

다음은 로그를 분석하기 쉽게 수정한 코드다.

@Slf4j
public class Example12_7 {
    public static Map<String, String> fruits = new HashMap<>();

    static {
        fruits.put("banana", "바나나");
        fruits.put("apple", "사과");
        fruits.put("pear", "배");
        fruits.put("grape", "포도");
    }

    public static void main(String[] args) {
        Flux.fromArray(new String[]{"BANANAS", "APPLES", "PEARS", "MELONS"})
                .map(String::toLowerCase)
                .map(fruit -> fruit.substring(0, fruit.length() - 1))
                .log("Fruit.Substring", Level.FINE) // 로그 출력
                .map(fruits::get)
                .subscribe(
                        log::info,
                        error -> log.error("# onError:", error));
    }
}

<결과>

21:25:29.737 [main] DEBUG Fruit.Substring - | onSubscribe([Fuseable] FluxMapFuseable.MapFuseableSubscriber)
21:25:29.740 [main] DEBUG Fruit.Substring - | request(unbounded)
21:25:29.741 [main] DEBUG Fruit.Substring - | onNext(banana)
21:25:29.741 [main] INFO - 바나나
21:25:29.744 [main] DEBUG Fruit.Substring - | onNext(apple)
21:25:29.745 [main] INFO - 사과
21:25:29.745 [main] DEBUG Fruit.Substring - | onNext(pear)
21:25:29.745 [main] INFO - 배
21:25:29.745 [main] DEBUG Fruit.Substring - | onNext(melon)
21:25:29.756 [main] DEBUG Fruit.Substring - | cancel()
21:25:29.762 [main] ERROR- # onError:
java.lang.NullPointerException: The mapper [chapter12.Example12_7$$Lambda$38/0x0000000800150040] returned a null value.
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:115)
	...

로그 레벨이 모두 DEBUG로 바뀌었다 -> 이는 log()의 두 번째 파라미터인 Level.FINE 덕분이다.
(Level.FINE은 Java에서 지원하는 로그 레벨이며, Slf4j 로깅 프레임워크에서 사용하는 DEBUG 레벨에 해당한다)

또한, log()의 첫 번째 파라미터인 카테고리가 map() Operator에서 발생한 로그들에 표시가 되고 있다.

✅ 총 정리

Hooks.onOperatorDebug(): 에러가 발생한 스택트레이스를 알 수 있다. (전체 애플리케이션 스택트레이스 확인해야 함)

ReactorDebugAgent: 에러가 발생한 스택트레이스를 알 수 있다. (특정 Operator 체인 내의 스택트레이스 확인 가능)

checkpoint(): 에러가 발생한 스택트레이스를 알 수 있다. (특정 Operator 체인 내의 스택트레이스 확인 가능)

log(): Signal 흐름을 통해 내부 동작을 상세하게 분석.

+) 사견

개발할 때: 어디에서 에러가 발생할지 모르므로, 일단 reator-tools 라이브러리 의존해서 ReactorDebugAgent 켜둔다. (Spring Boot 사용하면, 라이브러리만 추가해도 알아서 에러가 발생한 스택트레이스 찾아줌)

개발하는 도중 에러가 발생했을 때: ReactorDebugAgent가 알려주는 스택트레이스로 고칠 수 있는 것들은 고치고, 동작을 보다 상세하게 알고 싶다면 log() 쓴다.

프로덕션에 배포: reator-tools 라이브러리 의존한채로 배포하면 운영 로그에서 에러 스택트레이스 상세하게 볼 수 있겠다. (아직 reactor 프로젝트를 배포해본 적은 없다)

(checkpoint(), log()는 프로덕션에 꼭 필요하지 않는 이상 로컬에서만 쓸 것 같다)

저작자표시 비영리 변경금지

'book > 스프링으로 시작하는 리액티브 프로그래밍' 카테고리의 다른 글

[리액티브 프로그래밍] Operator (0)	2024.05.13
[리액티브 프로그래밍] Testing (0)	2024.05.08
[리액티브 프로그래밍] Context (0)	2024.05.06
[리액티브 프로그래밍] Scheduler (0)	2024.04.21
[리액티브 프로그래밍] Sinks (0)	2024.04.21

Reactor에서의 디버깅 방법

Debug Mode를 사용한 디버깅

checkpoint() Operator를 사용한 디버깅

log() Operator를 사용한 디버깅

'book > 스프링으로 시작하는 리액티브 프로그래밍' 카테고리의 다른 글

티스토리툴바