CompletableFuture와 에러로그

 

회사 업무 중 completableFuture를 사용하여 데이터를 처리하는 로직이 있다. 묘하게 데이터가 이상한 경우가 있었다.

서버 로그를 보면 에러로그는 하나도 없이 깨끗하다.

마치 몸이 안좋아 병원에 갔는데, 이상이 없으니 식단조절하고 스트레스 관리를 하라는 경우처럼...

난감했다...하지만 포기하지 않고 열심히 구글링은 해보던 중 힌트를 발견했다. 바로 exceptionally!!!!

뭔가 딱 봐도 익셉션을 처리하게 생긴 아이 같지 않은가.

그렇다면 가볍게 코드를 보면서 얘기해보자.

 

우선 completableFuture안에서 익셉션이 발생한 경우이다.

이 경우 우리는 보통 에러가 발생하여 관련된 로그가 남는 것을 기대할 것이다.

그러나 실제 결과는 어떠할까?

아무런 에러 로그 없이 정상 실행 후 종료된 것을 볼 수 있다.

 

그렇다면 그냥 익셉션 로그 자체가 남지 않는 것은 아닐까?

메인 스레드에서 익셉션을 발생시켜보았다.

익셉션 에러가 발생한 것을 볼 수 있다.

그렇다면 completableFuture안에서 발생한 익셉션인 경우에만 익셉션 로그가 남지 않는 것을 볼 수 있다.

왜 그런 것일까?

 

아래는 runAsync의 내부 소스이다. 이 소스를 찾아 들어가 보면

runAsync에서 asyncRunStage라는 메소드를 실행하고, 그 안의 execute안에 실제 비즈니스 로직인 runnable을 구현한 인자를 받는 AsyncRun을 파라미터로 받고 있다.

결국 AsyncRun의 run메소드가 실제 비즈니스 로직이 실행되는 구간이며,

우리가 구현한 비즈니스 로직은 try catch로 잡혀있어 익셉션이 발생해도, exceptionally를 구현하지 않으면 익셉션에 관한 로그를 볼 수 가 없던 것이다.

 

그렇다면 excpetionally를 구현하여 다시 실행해보자.

completableFuture안에서 발생한 익셉션 로그가 잘 찍힌것을 볼 수 있다.

(* 디버깅을 해보면 실제 exceptionally의 로직은 d.postComplete()메소드에서 실행되는 것을 볼 수 있다. 사실 조금 더 딥하게 소스를 분석해보고 싶었으나, 내부로 들어갈수록 난이도가 높아져 우선은 이정도로 정리하였다. 조금 더 실력이 쌓이면 그 때 다시한번 조금 더 딥하게 분석해볼 예정이다.)

 

굉장히 기본적인 내용이지만, 해당 내용을 숙지하지 않고 개발을 하다보니 엄청나게 오랫동안 삽질을 했다. 

역시 기초의 중요성을 다시한번 느꼈던 시간이었던 것 같다.

 

* 개발하면서 경험한 것들을 가볍게 기록하는 블로기이기 때문에, 잘못된 정보가 있다면 언제든지 댓글 부탁드리겠습니다.