우리의 Thread는 왜 이렇게 부자가 되었을까?

안녕하세요. NHN Cloud 서비스에서 공통적으로 사용되는 Framework(결제, 인증, 권한 등)를 개발하고 있는 프레임워크개발팀 박시우입니다. 최근 저희 팀에서 OOM 이슈 관련하여, 분석해 본 결과 병렬 처리 진행을 위해 ForkJoinPool을 사용하게 되면서 겪은 이슈에 대해 공유드리고자 합니다. 발생 시점부터, 무엇이 문제였는지 상세히 작성하였고 기본적인 내용도 포함되어 있으므로 한 번쯤 시간 나실 때 담당하시는 서비스도 확인해보시면 좋을 것 같아 글을 쓰게 되었습니다.

1. 문제 발생

• 2021.06. 07. 21시경 NHN Cloud 빌링 1번 서버가 OOM이 발생하였습니다.

org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: unable to create native thread: possibly out of memory or process/resource limits reached

2. 분석

• 왜 OOM 이 발생했는지 분석해보기 위해, 우선 설정된 Heap Size와, 기타 모든 설정을 확인해 보았지만 특별한 이슈가 없었습니다.

• 모든 개발자가 그렇듯 최근에 어떤 변화가 있었는지 생각해봅니다.

  • 1. Spring Boot로 전환함
  • 2. Java 11로 업그레이드함

• nSight(사내 시스템) 를 통해, 언제부터 메모리가 차오르기 시작했는지 확인해 보았으나 Steadily 하게 메모리가 차오른 걸로 보아, 분석하기가 쉽지 않았습니다.

• sar(linux) 로그를 통해, 해당 서버에 남아있는 메모리 Usage를 분석하기 시작했으나, 아주 서서히 오른 기록만 남아있었습니다.

• 프로세스 현황을 통해, Thread 개수가 3만 개가 넘어있다는 걸 확인했습니다.

  • 현재 저희가 실제 리얼 환경에 사용되는 서버는 2대이며, 1대의 서버가 Thread가 3만 개 이상인걸 확인 후 바로 다른 서버의 Thread 개수도 파악해 보았지만 OOM 직전의 단계까지 차오른 상태였습니다.

• 

다른 게 부자여야 하는데 Thread가 왜 이렇게 부자가 되었을까요??

3. 이슈 확인

• 왜 3만 개가 넘는 Thread가 존재하는지 확인하기 위해, dump를 떠보기로 결정하였습니다.

• 애플리케이션에서 현재 어떤 부분을 수행하고 있는지 Stack을 확인하기 위한 작업으로, Thread dump를 생성하기 위해서는 다음 세 가지 정도만 알고 계시면 될 것 같습니다.

  • jstack을 이용하는 방법
  • java VisualVM을 이용하는 방법
  • Kill로 확인하는 방법(java 프로세스에 signal만 전달하면 됩니다.)

• jstack을 이용해서 dump를 파일로 남겨 확인해본 결과, 기본적인 Daemon Thread와, 저희가 예측 가능한 범위에서 Thread가 생성되고 반환되고 있었습니다. 하지만 ForkJoinPool이 이해가지 않을 정도로 많이 잡혀 있었습니다.

• ForkJoinPool만 따로 분리해서 보게 되면 위에 nSight 상에 잡힌 Thread 개수의 대부분이 ForkJoinPool 이였다는 걸 확인하게 되었고

• 이로써 코드에 문제가 있다는 게 확인되었습니다.

  • 

4. ForkJoinPool 분석

ForkJoinPool?

• 일단 기본적으로 Java 7에서 새로 지원하게 된 ForkJoinPool 은 정확히는 ForkJoin Framework라 불러야 하는 게 맞고, ForkJoinPool이 그것의 대표 클래스라고 합니다.
• 하지만 편의상 ForkJoinPool이라 칭하고, 기본적으로 스레드 풀 서비스의 일종입니다.
• 여러 CPU를 최대한 활용하면서, 동기화와 GC를 피할 수 있는 여러 기법이 사용되었기 때문에, Java 뿐만 아니라 타 언어에서도 널리 쓰이는 병렬 처리 기법입니다.
• 이름에서 그렇듯 큰 업무를 작은 업무단위로 쪼개고, 그것을 각기 다른 CPU에서 병렬로 실행한 뒤 취합하는 방식을 취합니다.
• 이는 분할정복 알고리즘과 흡사합니다.

5. 의심

• 그럼 코드 내부적으로 ForkJoinPool을 생성하고, 정상적으로 종료하지 않는다는 것이고 빌링 소스코드 상에 병렬 처리를 하는 부분이 어디인지 찾아가기 시작했습니다. 다행히 쉽게 찾을 수 있었고, 해당 소스코드를 살펴보았습니다.

잠깐.. 이 코드는 변경된 적이 없는데?? 8에서 11로 올라온 지가 며칠 되지 않았고, 8에서는 ForkJoinPool이 문제가 없었나??

5.1 여기서 문득 머릿속을 스쳤던 생각

• Common Thread Pool은 static thread pool instance 이므로 메모리 누수가 발생하지 않지만, 코드 상에 보면, ForkJoinPool은 Custom thread pool로 생성되기 때문에 Common Thread Pool과는 별개로 추가적으로 Thread가 생성되는 것이고 "이 코드에서는 ForkJoinPool 지역변수 이기 때문에 해당 로직이 수행되고 나서 ForkJoinPool Instance는 참조 해제가 될 거니까.. 결국에는 GC가 될 것이다." 라고 생각했으나, 실제로는 Thread가 해제되지 않았습니다. ㅠ.ㅠ

• 그럼 8에서는?? 저 코드는 2017년에 만들어진 코드이고, 반납을 하지 않았다면 진작에 OOM이 발생했어야 된다고 의심됩니다.

5.2 의심이 사실이 되어버리는 순간...

• 확인해야 할 부분은 이렇게 생성한 ForkJoinPool 은 언제 Thread 가 해제되는가?? 추가로 8과 11의 차이가 있는가? 정도였습니다.

1. 명시적으로 Shutdown() 해주는 방법이 있고
2. 암시적으로 Thread Pool 이 해제되는 Case가 어떤 경우가 있는가?를 파헤쳐 보기 시작합니다.

• 일단 OOM의 급한불은 꺼야 하니깐..

• shutdown()을 통해 Thread 가 정상적으로 반납되는 부분을 확인하고, 배포해서 안정적으로 서비스가 돌아가게 만들어 놓았습니다.

• 하지만 궁금한 건 위 문제점의 2번. Thread pool이 해제되는 Case가 어떤 경우가 있는가를 조사해 보았으나 https://www.baeldung.com/java-8-parallel-streams-custom-threadpool의 내용을 참고해볼 때 Custom Thread Pool은 안 되는 게 맞다.라고 결론 지을 수 있었습니다.

• 만약 저게 맞다면, 우리는 지금까지 시한폭탄을 들고 있었던 것이고.. 원인 파악을 위해 테스트 코드를 작성했습니다.

Java 8에서의 테스트 (ForkJoinPool의 동작 방식을 알기 위해 Local에서 테스트 코드 작성)

• Java 8 버전으로 테스트하였고, 정상적으로 ForkJoinPool의 Thread를 반납하는 것을 확인하였습니다.

Java 11에서의 테스트

• 동일한 코드임에도 11은 반납을 하지 않았습니다.

6. 재 의심

• 위 내용을 종합해볼 때, 다음과 같은 결론을 지을 수 있습니다.
  • 1.8 에서는 아무런 문제가 되지 않고 해당 로직은 정상적으로 수행한 뒤 반납했을 것이다.
  • 11로 올라오면서 ForkJoinPool을 반납하지 못하고 , 저 로직이 수행되는 부분에서 매번 Thread가 생성되었을 것이다.

7. 추적

• 11이 문제라는 확정을 지었으니, 어떤 부분이 문제일지를 찾아내야 합니다.

  • 우선 8의 반납이 어떻게 되는지의 과정을 찾아갑니다.
  • ForkJoinPool의 코드를 하나하나 파고들어서 디버깅해본 결과 work queue에 처리할 일감이 없으면 16초 이후에는 WorkerThread가 종료된다는 것을 확인할 수 있었습니다.
  • ForkJoinPool 클래스의 내부 동작 방식 디버깅
  • 

• 11의 코드도 동일한지 확인해 보았지만, 8의 로직과는 다른 방식으로 동작하였습니다.

  • 11 버전에는 DEFAULT_KEEPALIVE 가 60으로 잡혀있고, 해당 코드를 타기 위해선 내부적으로 runWorker 메서드에서 반납처리가 진행되어야 하나, 해당 부분의 조건을 만족하지 못하였습니다.
  • 디버깅을 해보면서 확인해본 바로는, WorkQueue 클래스에 stackPred 값이 0이 아니여야만 반납처리가 이루어지는데 어찌 된 영문인지 계속해서 0으로 값이 들어오고 있었습니다.

8. 증명

결국 11의 ForkJoinPool 이 정상적으로 반납되지 않는 현상은 위와 같은 이슈였고.. 아 안되나 보다 라고 마음을 다잡고 있는 와중에 구글링을 하다 보니 같은 실험을 하는 개발자가 있었고.. https://stackoverflow.com/questions/54084915/forkjoinpool-performance-java-8-vs-11

In practice, the observed behavior stems from an undocumented idle timeout of two seconds. Note that according to the comment, the consequence of an elapsed timeout is an attempt to shrink the number of workers which is different to just terminating. So if n thread experience the timeout, not all n threads terminate but the number of threads gets reduced by one and the remaining threads may wait again. Further, the phrase “initial timeout value” already hints at it, the actual timeout gets incremented each time it happens. So it takes n * (n  + 1) seconds for n idle worker thread to terminate due to this (undocumented) timeout.

• 간단하게 번역하면, 이 60초는 종료되는 게 아니고, 대기열에 있는 ForkJoinPool을 하나씩 반납하는 거야..라는 내용입니다.

• 이 내용을 토대로 다시 테스트 코드를 작성하였습니다. 혹시나 해서 테스트 코드를 ParallelStream으로 ForkJoinPool을 병렬로 생성해 테스트를 진행해 보았고, 결과는 다음과 같았습니다. 자세히 보면 313의 ForkJoinPool 은 반납처리되었고, 위 Stack Overflow의 답변 내용이 일치하다는 것을 확인할 수 있었습니다. 그럼 다 반납되려면 5분만 기다리면 되나?해서 기다렸고 정상적으로 반납처리가 되는 부분을 확인했습니다.

9. 결론

• 위 1~8번까지의 내용을 종합적으로 볼 때 실험으로 증명된 내용은 다음과 같습니다.
  • Java 8의 경우 ForkJoinPool의 주기는 16초 이며 shutdown과 동일한 방식으로 종료 처리 가 된다.
    • 이 주기는 javadoc의 문서화되지 않는 내용이므로 정확하게 shutdown()을 명시해 주는 게 좋다.
  • Java 11의 경우 Keep Alive Time 은 실제 Thread의 반납이 아닌 n개의 Thread 개수에서 1만큼 줄어들고, 나머지 Thread는 대기 상태를 나타내고 있으며 실제 시간 초과가 발생할 때마다 증가한다. 따라서 n개의 Thread 가 종료되는 데는 n * (n + 1) 초가 걸린다.
  • 이에 따라 원하는 동작 방식대로 하려면 shutdown()을 명시해 주는 게 좋다.

10. 마치며

• 사실 커스텀한 Thread Pool의 경우 생성과 반납처리에 신경을 써야 하는 부분입니다.
  • 개발자가 자신이 생성한 Thread의 주기에 대해 신경을 써야 하나? 말아야 하나? 에 대한 의견은 많이 갈리지만.. Java 11로 변경한 서비스가 있으시다면 한 번쯤은 짚고 넘어가실 만한 내용이라 생각되어 작성하였습니다.
  • 지금 와서 생각해보면 shutdown() 한 줄로 인해 너무 많은 시간을 돌아온 것 같아 약간의 아쉬움은 남지만.. 이번 시행착오를 통해 아무 생각 없이 생성하고 처리하였던 Thread에 대해 다시 한번 확인해 볼 수 있는 계기가 되어 좋았습니다.

최종 결론

Java 8과 11의 Thread Executor 동작 메커니즘이 다르다. Spring boot를 쓰는 이상 Thread Pool을 일회용으로 쓰지 않기 때문에 문제는 없지만 만약 일회성으로 쓴다면 shutdown을 신경 써야 한다.

• thread pool Executor는 8에서는 GC의 대상이 되어서 자동으로 종료가 되었는데, 11에서부터는 finalize가 deprecated 되었으므로, 반드시 1회성일 경우 shutdown 해주어야 합니다.

●섬네일 이미지 출처: https://javatechnocampus.wordpress.com/2015/10/03/544/