Spring WebFlux와 Reactor에서 디버깅하는 방법 3가지
TL;DR
Hooks.onOperatorDebug()메소드를 애플리케이션 시작 시 실행하기- Publisher assembly 도중에
checkpoint()연산자를 사용하기 log()연산자로 이벤트 로깅하기
Reactor 공식 문서를 참고하여 위 방법 중 하나를 이용하면 됩니다. 전체 애플리케이션 범위를 디버깅할 때는 1번, 범위를 좁혀서 관심있는 Publisher만 디버깅할 때는 2번, Publisher의 이벤트를 로깅하고 싶다면 3번을 사용합니다.
Spring WebFlux에서 디버깅이 어려운 이유?
Reactive Streams 구현체인 Reactor와 Reactor를 기반으로 만들어진 논블로킹 서버 프레임워크인 Spring WebFlux는 일반적인 애플리케이션보다 디버깅이 어렵습니다. 그 이유는 예외 발생 시 보여주는 스택 트레이스로 문제의 원인을 찾기 어렵기 때문입니다. 멀티플렉싱 방식의 논블로킹 서버는 하나의 쓰레드로 여러 요청을 담당하고, 하나의 요청이 여러 쓰레드를 거쳐서 처리될 수 있습니다. 대조적으로 servlet 기반의 Spring Web MVC는 요청마다 전담 쓰레드를 생성해서 핸들링합니다. 따라서 어떤 요청이 쓰레드 A와 쓰레드 B를 거쳐서 처리되던 도중 예외가 발생한다면 쓰레드 B의 스택 트레이스는 볼 수 있지만 A의 스택 트레이스를 볼 수 없어 원인을 파악하기 어렵습니다. 이 문제점은 이전 글인 Armeria의 request scoping과 leak 탐지 에서도 간접적으로 언급되었으니 관심있으시면 참고해주세요~
Spring WebFlux는 Reactor를 기반으로 만들어졌기 때문에 Reactor가 제공하는 디버깅 방법을 적용해 위 문제를 해결할 수 있습니다. 이 글에서는 Reactor 공식 문서에 나와있는 디버깅 방법을 알아보고 간단한 Reactor 코드 예제에 적용해봅니다. 그리고 Reactor에서 이 기능을 어떻게 구현했는지 소스 코드를 분석합니다.
공식 문서에 답이 있다.
Reactor 공식 문서를 보면 예외가 발생하는 예제 시나리오와 자세한 설명까지 곁들여서 디버깅하는 방법을 설명합니다. 읽어보니 설명이 정말 괜찮아서 시간이 있으시면 읽어보시길 추천드립니다. 먼저 Reactor를 디버깅하기 어려운 이유는 선언적으로 Publisher을 조립하는 부분(연산자 체인, assembly)과 실제로 구독하는 곳이 분리되어 있고 서로 다른 쓰레드에서 실행되기 때문입니다. 만약 예외 발생 시 스택 트레이스에서 문제의 원인이 되는 코드 위치를 볼 수 없습니다. 말이 좀 어려운데요. 다음 Spring 블로그의 Reactor 코드 예제를 보겠습니다.
코드를 보면 프로그래밍이 실행된 시각에 따라 2번째 또는 3번째 조건문이 실행될 경우 문제가 발생합니다. 단, 여기서 유의할 점은 elementAt(5) 메소드를 실행할
때 예외가 발생하지 않는다는 것입니다. Publisher의 range, elementAt 등의 연산자를 호출하면 실행을 “계획(describe)“할 뿐 실제 연산 실행은
일어나지 않습니다. 실제 실행은 구독을 하는 순간 시작하기 때문에 예외 역시 block() 메소드를 실행한 후 발생합니다. Reactor는 Publisher를 구독하기 전
다양한 연산자를 호출해 선언적으로 조립하는 부분을 “assembly"라고 합니다.
선언적인 조립부(assembly)와 명시적인 실행(block())을 분리했을 때 장점은 뭘까요? 조립의 결과물인 assembly는 데이터가 도착하면 이렇게 저렇게 처리하겠다는
계획(또는 함수)의 덩어리일 뿐 아무 일도 일어나지 않습니다. 따라서 사용자 또는 프레임워크는 유연하게 이 계획을 상황에 맞게 실행할 수 있습니다. 예를 들어 사용자는 싱글 쓰레드,
멀티 쓰레드 환경을 선택하여 실행할 수 있습니다. 프레임워크는 적절한 근거가 있을 때 최적화를 거쳐 실행할 수도 있습니다. 이는 마치 우리가 프로그램을 작성하고 컴파일러가
(때로는 라인 순서를 바꿔가며) 코드를 최적화하여 실행하는 것과 매우 유사합니다. Reactor를 비롯한 여러 함수형 프로그래밍 프레임워크를 사용하다보면 프로그램
안에서 또 프로그램과 실행을 분리하여 코드를 작성하는 경험을 할 수 있습니다. 신기하지 않나요?
위에서 언급한 것 외에도 여러 장점이 있지만 어쨌든 단점도 있습니다. 현재 상황이 바로 그렇습니다. 실제 실행(구독)을 별도의 쓰레드에서 처리하기 때문에 예외 발생 시 뒤늦게 잘못을 깨달아도 스택 트레이스에는 과거 assembly 정보가 없어 원인을 찾기 어렵습니다. 예를 들어 위 코드를 실행하면 아래 예외 메시지가 출력됩니다. 가장 마지막 줄만 보시면 됩니다.
마지막 줄에 표시되는 코드 위치는 block() 메소드를 실행하는 라인입니다. 그 외 정보로 첫 번째 줄에 IndexOutOfBoundsException과 두 번째 줄을
보고 elementAt() 메소드를 실행 중에 문제가 발생했다는 것을 짐작할 수 있습니다. 하지만 코드에서 elementAt은 3곳에서 쓰였고 그 중 어디서 쓰였는지
특정할 수 없습니다. 이런 문제는 Spring WebFlux에서 똑같이 발생할 수 있습니다. (Spring WebFlux 코드 예제)
다행히 Reactor는 이 문제를 해결할 방법을 제공합니다. 중요한 것만 정리하면 다음과 같습니다.
Hooks.onOperatorDebug()메소드를 애플리케이션 시작 시 실행하기- Publisher assembly 도중에
checkpoint()연산자를 사용하기 log()연산자로 이벤트 로깅하기
먼저 1번을 사용하면 애플리케이션 전체 범위 디버깅이 적용됩니다. Publisher의 모든 연산자를 호출할 때마다 스택 트레이스를 저장하고 전달하는 방식으로 나중에
예외 발생 시 스택 트레이스를 함께 보여줘서 쉽게 문제 원인을 찾을 수 있습니다. 대신 1번은 리소스가 많이 들기 때문에 반드시 테스트나 개발 환경에서만 사용해야
합니다. 1번의 단점을 보완해 관심있는 Publisher와 연산자에 대해서만 디버깅할 수 있는 기능이 2번입니다. Publisher 조립 과정 중간에 checkpoint()
연산자를 실행하면 나중에 예외 발생 시 어떤 체크포인트까지 문제없이 실행됐는지 스택 트레이스에서 확인할 수 있습니다. 마지막으로 3번의 log() 연산자를
사용하면 Publisher를 구독하고 일어나는 일을 세세하게 로그로 확인할 수 있습니다. 위 예제 코드에 적용했을 때 어떻게 스택 트레이스가 바뀌는지는 아래 참고 문헌의
“Reactor 코드 예제 블로그"에서 확인하실 수 있습니다.
Reactor의 소스 코드 분석
사실 이 글을 쓰게 된 계기는 제가 최근에 기여하고 있는 Armeria에서 비슷한 기능을 만들기 위해서 였습니다. 그래서 Reactor에서
어떻게 스택 트레이스를 저장하고 예외 발생 시 보여주는지 구체적으로 Hooks.onOperatorDebug() 메소드를 따라가면서 알아봤습니다.
(실제로는 최신 코드 -> 과거 커밋 -> 최신 코드 순으로 읽었지만 매끄러운 설명을 위해 과거 커밋 -> 최신 코드 순으로 편집했습니다.)
먼저 최초로 기능이 만들어진 커밋을 보겠습니다. 최신 코드는 워낙 다양한 기능들이 복잡하게 엮여있어 동작을 이해하기 어려웠습니다. 가장 간단한 형태인 최초의
커밋을 보고 먼저 대략적인 동작을 파악한 후 최신 코드를 읽어보겠습니다. 최초 커밋 링크를
들어가서 Flux.java부터 보면 어떤 연산자를 호출하든 마지막에 onAssembly 메소드를 실행하여 반환합니다. 무슨 메소드인지 보면 현재 Publisher를
FluxOnAssembly로 감싸서 반환합니다. 이어서 FluxOnAssembly가 뭔지 보면 중요한 로직들을 모두 확인할 수 있습니다. 생성자부터 확인해보면 현재 Publisher의
스택 트레이스를 takeStacktrace() 메소드를 이용해 끄집어내 내부 필드에 저장합니다. 메소드 내용이 좀 복잡하지만 Thread.currentThread().getStackTrace()
메소드를 실행해 현재 속한 쓰레드의 스택 트레이스를 사용한다는 것만 확인하면 충분합니다.
이제 Publisher를 어떤 구독자가 구독하면 FluxOnAssembly#subscribe 메소드가 실행됩니다. 이 때 인자로 받은 구독자를 OnAssemblySubscriber로
감쌉니다. 구독 후 데이터 전송 중 예외가 발생하면 OnAssemblySubscriber#onError(Throwable)을 호출합니다. 메소드를 따라가보면 이전에
저장했던 스택 트레이스를 인자로 받아 OnAssemblyException으로 만들어서 현재 예외 스택 최상단에 addSuppressed() 메소드를 이용해 추가합니다. 이제
사용자는 예외 메시지 최상단에 Reactor가 제공하는 스택 트레이스를 확인하고 문제의 원인을 쉽게 찾을 수 있습니다.
정리하면,
- Publisher의 연산자를 실행할 때마다
onAssembly메소드를 거쳐서 Publisher를FluxOnAssembly로 감싸서 반환한다. FluxOnAssembly를 생성할 때 현재 Publisher가 속한 쓰레드의 스택 트레이스를 내부 필드에 저장한다.FluxOnAssembly를 구독할 때(subscribe메소드) 인자로 받는 구독자를OnAssemblySubscriber로 감싼다.- 예외 발생 시
OnAssemblySubscriber#onError(Throwable)메소드가 실행된다. - 2번에서 저장했던 스택 트레이스를 꺼내서
OnAssemblyException예외로 만들어서 현재 예외 스택의 최상단에 집어넣는다. - 사용자는 스택 트레이스 최상단에서 Reactor가 제공한 스택 트레이스를 확인할 수 있다.
글을 쓰는 시점에 Reactor의 stable 버전은 3.5.8이므로 이를 기준으로 최신 코드를 설명하겠습니다. 다행히 클래스나 메소드 이름이 최초 커밋 코드와 달라지지 않았고 역할도 그대로 입니다. 대신 다른 기능이 많아져서 코드가 (꽤나 많이) 복잡해졌습니다. 그래도 최초 커밋을 이해하고 나니 최신 버전의 코드도 어떻게 동작하는지 얼추 이해할 수 있었습니다. 이 글에서는 간략하게 달라진 점만 짚고 넘어가겠습니다.
먼저 스택 트레이스를 수집하는 방식이 변경되었습니다. 기존에는 Thread.currentThread().getStackTrace() 메소드로 StackTraceElement 배열을
가져와서 문자열로 바꿔 저장했습니다. 최신 버전은 런타임 환경에 따라 크게 3가지 구현체가 있습니다. 관련 코드는 CallSiteSupplierFactory 코드를
참고하시면 확인할 수 있습니다. 공통적으로 3가지 구현체 모두 Supplier<String> 형태로 스택 트레이스를 저장합니다. 예를 들어 자바 9버전 이상에서는
StackWalkerCallSiteSupplierFactory를 사용하는데 자바 9에서 새롭게 추가된 StackWalker를 이용해 스택 트레이스를 조합해 저장합니다. 9버전
미만에서는 Throwable.getStackTrace()를 이용해 최초 커밋과 비슷한 방식으로 스택 트레이스를 가져와 저장합니다.
그 외 FluxOnAssembly, OnAssemblySubscriber, OnAssemblyException은 동작이 크게 달라지지 않았습니다. 다만 최초 커밋보다 스택 트레이스를 더 예쁘게
보여주기 위해서 다양한 처리 과정을 거칩니다. 사실 저는 큰 단위의 동작만 이해했고 세세한 스택 트레이스 편집 로직은 자세히 살펴보지 않았는데요. 관심있으시면
소스코드를 참고하는게 가장 빠른 방법이 될 것 같습니다.
정리
대표적인 논블로킹 서버 프레임워크인 Spring WebFlux는 성능 면에서 장점이 있지만 예외 발생 시 디버깅이 조금 어렵다는 단점이 있습니다. 이는 하나의 요청을 하나의 쓰레드가 담당하는 멀티쓰레딩 방식의 Spring Web MVC와 다르게 하나의 요청이 여러 쓰레드를 거쳐 처리되면서 예외 발생 시 스택 트레이스 정보가 끊기기 때문입니다. 이는 WebFlux의 근간이 되는 Reactor에서 기인한 문제점이기도 합니다. 다행히 Reactor는 이를 해결하기 위한 디버깅 도구를 제공했고 어떻게 사용하는지 알아봤습니다. 추가적으로 어떻게 구현했는지 소스 코드도 간단히 분석해봤습니다.
앞에서 이야기했지만 최근 기여하고 있는 Armeria는 Reactor Netty, Spring WebFlux와 비슷하게 Netty 기반의 논블로킹 마이크로서비스 프레임워크입니다. Armeria에서도 요청이 여러 쓰레드를 거쳐 처리되다가 예외 발생 시 이전 쓰레드의 스택 트레이스를 보여줄 수 없는 문제점이 똑같이 존재합니다. 그래서 같은 문제를 어떻게 해결했는지 Reactor를 참고하여 공부한 내용을 글로 정리해봤습니다. 아직 어떻게 기능을 구현할지 막막하지만 비동기 서버에 대한 이해가 늘어난 것 같아 기분이 좋네요. 이 글을 읽으시는 분들도 사용하시는 오픈 소스에 유용한 기능을 추가해보기 위해 공부하다보면 성공 실패에 관계없이 좋은 공부가 될 것이라 생각합니다. 😆