실서비스를 배포하고 모니터링하는 중에 테스트하는 동안에는 발견하지 못한 로그가 보이기 시작했다. 다행히 서비스 자체에 영향을 주는 것은 아니라서 긴급하게 수정해야 하는 것은 아니었다. 지금 당장 문제가 되는 것은 아니라도 Exception이 발생하고 있기 때문에 처리는 필요하다. 당장 확인하고 고쳐야 하는 장애가 있을 때 불필요한 로그가 쌓여서 발견을 못한다면 더 큰 문제가 생길 수도 있으니 말이다.
예외가 발생한 위치
서비스가 남기는 로그는 외부에서 받는 1) API request (http request), 2) API response (http response), 3) 요청을 처리하기 위해 앱 내부에서 호출하는 외부 API 호출 로그 세 가지로 분류할 수 있다. 에러가 발생한 위치는 3) 앱 내부에서 호출하는 외부 API 호출 로그였다.
ReactorRejectedExecutionException
은 처음 보는 예외였기 때문에 구글링부터 해봤는데,,, 어떤 상황에서 발생한건지 의심 가는 부분이 아직 없었다. Scheduler unavailable
이라는 메세지가 나에게 스레드 수가 부족하다는 뉘앙스라 좀 헤매게 됐던 것 같다. 스트레스 테스트를 하면서 나온 쿼리가 아니었고, 실서비스는 로드 밸런서 덕분에 스트레스 테스트 환경 때보다 더 적게 요청량을 처리하고 있는 상태였다. 실마리가 있다면 현재 문제가 되는 요청의 쿼리는 기존 테스트 때 사용했던 쿼리가 아니라는 점, 외부 API에서 500 에러를 주고 있다는 점이었다.
reactor.core.Exceptions$ReactorRejectedExecutionException: Scheduler unavailable
at reactor.core.Exceptions.failWithRejected(Exceptions.java:271)
at reactor.core.publisher.Operators.onRejectedExecution(Operators.java:987)
...
예외 상황 재현
디버깅을 위해서 예외 상황을 재현해봤다. 외부 API 응답에 500을 유발하는 쿼리들로 테스트를 해봤는데 단건 호출에 대해서는 예외가 발생하지 않았다. 그래서 Jmeter를 통해 실서비스와 유사하게 요청량을 늘려봤더니 예외가 종종 발생하는 것을 확인할 수 있었다. (실서비스에서도 마찬가지로 하루에 2-3건 발생하긴 했다) 예외 상황이 가끔씩 발생하고 있어서 정확한 원인 파악은 아직 힘들었다.
원인 파악
스택 트레이스만 봐서는 도저히 문제를 해결할 수 없을 것 같아서 리액터 코드를 보면서 언제 해당 예외를 던지는지 확인해보려고 했다. reactor.core.publisher.Operators.onRejectedExecution()
함수의 주석을 읽어보자. 번역기의 도움을 받아서 이해해 보면 '이 예외는 실행이 이미 폐기된(disposed) 경우, 특히 reactor.core.scheduler.Scheduler에 의해 실행이 거부되었음을 나타냅니다.'라고 쓰여있다.
/**
* Return a wrapped {@link RejectedExecutionException} which can be thrown by the
* operator. This exception denotes that an execution was rejected by a
* {@link reactor.core.scheduler.Scheduler}, notably when it was already disposed.
* <p>
* Wrapping is done by calling both {@link Exceptions#failWithRejected(Throwable)} and
* {@link #onOperatorError(Subscription, Throwable, Object, Context)} (with the passed
* {@link Subscription}).
*
* @param original the original execution error
* @param subscription the subscription to pass to onOperatorError.
* @param suppressed a Throwable to be suppressed by the {@link RejectedExecutionException} (or null if not relevant)
* @param dataSignal a value to be passed to {@link #onOperatorError(Subscription, Throwable, Object, Context)} (or null if not relevant)
* @param context a context that might hold a local error consumer
*/
public static RuntimeException onRejectedExecution(Throwable original,
@Nullable Subscription subscription,
@Nullable Throwable suppressed,
@Nullable Object dataSignal,
Context context) {
...
}
스케줄러에 의해 실행이 거부될만한 것이 뭘까? 로직을 보면서 고민하다가 의심스러운 부분을 찾았다. 바로 Mono.zip()
을 사용하는 부분. 마찬가지로 도큐멘테이션을 읽어보자. zip은 인자로 입력받은 모노들의 결과를 튜플로 병합하고 하나의 모노로 리턴한다. 그리고 소스 중에서 에러 또는 빈 상태로 완료되면 다른 소스는 취소되고 zip 결과 모노는 즉시 오류가 나거나 완료된다.
/**
* Merge given monos into a new {@literal Mono} that will be fulfilled when all of the given {@literal Monos}
* have produced an item, aggregating their values into a {@link Tuple2}.
* An error or <strong>empty</strong> completion of any source will cause other sources
* to be cancelled and the resulting Mono to immediately error or complete, respectively.
*/
public static <T1, T2> Mono<Tuple2<T1, T2>> zip(Mono<? extends T1> p1, Mono<? extends T2> p2) {
return zip(p1, p2, Flux.tuple2Function());
}
현재 내 서비스 코드는 외부 API를 동시에 2개 호출하여 결과 여부에 따라 API의 결과 중 하나를 선택하고 있다. 만약 외부 API 호출 중 하나가 500 에러가 났다면 그 즉시 Mono.zip
은 에러 응답을 낼 것이다. 그런데 만약 나머지 외부 API 호출이 아직 큐에 있고 실행하기 전이라면? Mono.zip
이 폐기됐기 때문에 스케줄러에서는 실행할 필요가 없는 호출이라 예외를 발생시킬 것이다. 내 비즈니스 로직의 경우 API 하나가 실패했을 때 다른 API도 실행되기를 원하기 때문에 onErrorReturn() 메서드를
추가해서 디폴트 응답을 추가하는 식으로 수정을 했다. 수정 후 다시 테스트를 해본 결과 해당 예외는 더 이상 발생하지 않았다.
맺음말
이번 이슈를 디버깅하면서 라이브러리를 '설명대로', 그리고 '잘' 써야 한다는 걸 다시 한번 느꼈다. 라이브러리 사용 시 주의사항에 유의해서 코드를 작성했다면 디버깅할 필요도, 예외를 마주칠 일도 없었을 것이다. 문제 원인을 가정해서 시험해 보고 범위를 좁혀가는 경험도 좋지만, 역시 사전에 예방할 수 있다면 예방하는 게 가장 최선이다.
'Tech' 카테고리의 다른 글
ChatGPT 무료 세미나 & 리소스 (2) | 2023.05.08 |
---|---|
ChatGPT로 인한 새로운 패러다임 세미나 참석 후기 (0) | 2023.05.03 |
Google Bard 사용기 & ChatGPT 결과와 비교 (0) | 2023.04.26 |
[Kotlin] 코틀린 Sequence 생성 방법, Iterable과 차이점 (0) | 2023.04.17 |
Microsoft + OpenAI Conference 온라인 참석 후기 (0) | 2023.04.04 |