3개월간 분석했던 문제의 원인을 드디어 찾아내 개선했던 경험을 기록한다.
근본적인 원인은 부족한 CPU 코어 위에서 Netty 이벤트루프와 가상 스레드 및 GC가 급증하는 트래픽을 처리하기 위해 과도한 일을 떠안으면서 스케줄링 지연이 발생했고, 그 결과 메모리 과부하가 일어난 것으로 추측된다.
실제로, CPU를 1 → 2 로 증가시킨 후, 모든 문제가 해소되었다. 8GB의 사용량에서 600MB정도로 메모리 사용량을 최적화할 수 있었다.
이러한 문제를 해결하기까지 경험했던 여러 삽질들과 배웠던 점들을 기록한다.

수많은 부하테스트 & heap/thread dump

메모리 과부하 원인을 찾기 위해 heap dump와 thread dump를 수 없이 떠봤다.

실제 운영환경과 비슷한 환경에서 부하테스트를 하기 위해 docker로 CPU 및 메모리 제한을 주고 서버를 띄운 뒤 stress test를 진행했다.
그런데 아무리 부하를 많이 줘도 운영 환경처럼 메모리 사용률이 드라마틱하게 증가하지 않았다.
처음에는 부하테스트를 잘못했는지 의심부터 했다. 하지만 문제는 다른 곳에 있었는데, 그것은 바로 GC옵션 이다.

ZGC VS G1GC

운영환경에서의 GC는 ZGC를 사용하고 있었고, 부하테스트를 했을 때에는 JDK21의 기본 GC인 G1GC를 사용하고 있었다. 혹시나 해서 ZGC옵션으로 바꿔서 진행해보니 메모리가 운영환경과 비슷하게 피크를 치는 현상이 발생했다.
옳다구나, 그래서 바로 Heap Dump를 진행했다. 분명 의미가 있는 정보가 나오겠지 생각했다.

Heap Dump를 해도, Thread Dump를 해도 차이가 없어요.. native memory 살펴보기

ZGC 와 G1GC 환경에서 메모리 피크가 일어나는 시점에 아무리 heap dump를 떠봐도, 두 환경에서의 메모리 차이는 정말 미약했다. 해봤자 100MB 안쪽이었던 것 같다. 분명 메모리 사용량은 8배가 차이가 났는데 (350 MB vs 2GB) 어째서 heap dump의 차이는 없는지 의아했다. (아마 Full GC를 한번 트리거하기 때문이 아닐까?)
그래서 heap dump로 보지 못하는 메모리 누수가 있는지 확인하기 위해 JVM옵션에 -XX:NativeMemoryTracking=detail 을 키고 차이를 확인해봤다.
어라? mmap의 committed메모리 지표의 차이가 실제 사용률의 차이랑 비슷했다.

ZGC와 G1GC의 본질적인 차이

ZGC와 G1GC는 전혀 다른 메카니즘이다.
공통적으로 JVM환경에서 Java Heap은 OS가 제공하는 가상 주소 공간을 사용한다.
하지만 ZGC는 STW (Stop-The-World) 시간을 최소화 하기 위해서 heap을 ZPage로 쪼개고, relocation을 STW없이 하기 위해 추가적인 공간을 더 사용한다. 그러기 위해 충분히 많은 committed 메모리를 할당한다고 한다.
반면, G1GC는 relocation을 위해 STW를 하고, GC가 일어난다.

그래서?

메모리 사용률의 드라마틱한 차이는 추가적인 가상 메모리 주소 공간을 할당하기 위한 충분한 committed 메모리로부터 기인한다.

이러한 사실을 알고난 후에, 운영환경에서의 프로메테우스 지표로 RSS메모리 비율, 컨테이너 캐시 메모리 비율을 보여주는 대시보드를 살펴봤는데 피크시간대에 RSS메모리 비율은 고작 5%의 안팎이었고, 컨테이너 캐시 메모리 비율이 80%에 육박했음을 알 수 있었다. 캐시 메모리는 ZGC에 의해 OS로부터 메모리를 받아와 commit 메모리일 것이다.

추가적으로 찾아보니, RSS 메모리에는 committed 메모리가 포함되지 않는다고 한다. '실제 사용'하는 RAM의 크기일 뿐, committed되었다고 다 사용하는건 아니니까.. 당연한 말이다.
다만, 메모리 사용량 지표에는 committed 지표는 포함이된다.
하지만 여기서 왜 heap 사용량은 8기가 까지 쳤는데 컨테이너의 rss메모리사용량은 600메가인지 잘 이해가 되지는 않는다..

여태까지 고작 heap 메모리사용량 비율로 문제를 판단했었는데, 좀 더 정확하게 분석하기 위해서는 RSS메모리, 캐시메모리 비율을 살펴봐야겠다. 특히 ZGC를 사용하는 상황에서는 말이다.

그렇다면 메모리 사용률이 peak치는 것은 무엇때문일까?

그것은 바로 너무 부족한 CPU 코어 탓이다.
System Load Average 지표를 봤는데, I/O 지연시간이 늘어날 때, 해당 지표가 Core수를 상회했다. 약 4배?
반면, CPU의 사용률은 안정적이라면 스케줄링 병목 이 발생한다는 뜻이다. 즉, CPU는 작업을 할당 받으면 어차피 I/O bound한 작업이니까 사용률은 높진 않지만, 할당 받으려고 기다리는 작업들이 너무 많다는 뜻으로 해석할 수 있다.

현재 나의 상황에서 적용해보자면 아래로 정리할 수 있다.

1. Netty event loop에서 비동기로 응답을 받으면,
2. event loop가 다시 가상 스레드를 깨워야 하고
3. 그 가상스레드가 다시 carrier thread를 잡아 실행해야 한다.

I/O 지연 → 참조 객체 수명 증가 → heap 사용량 증가 → GC마저 스케줄링을 받지 못해 GC지연 (실제 메모리 peak때 GC횟수 0) → Heap PEAK! → GC수행시 Heap 복구

컨테이너 캐싱 메모리는 Pod 지표에서 볼 수 있다. JVM에서 사용하는 메모리를 캐싱하는 주체는 컨테이너이니까 당연하다. 애꿎은 JVM지표에서 찾지 말자.

결론

CPU를 늘려 실제 가상스레드 및 GC스레드의 스케줄링 지연을 빠르게 받게 하도록 하자. 그게 근본 원인이다!

CPU overload가 core수의 약 4배이다.
실제 가상스레드가 수행되는 carrier thread의 개수 또한 CPU의 개수랑 동일하게 잡히니, CPU를 2배 높이면 carrier thread가 2배증가되고, CPU또한 병렬처리가 2배더 병렬처리가 되어지므로 4배의 효과를 볼 것이라고 예상해서 2배 증가시켰다.

그 결과는 메모리 사용량을 8GB에서 600MB안쪽으로 최적화 할 수 있었다!

근데.. 당장은.. CPU 늘려서 해결은 했는데.. ZGC를 쓰는게 맞을까...?
G1GC로 바꾸면 훨씬 안정적인 것 같았다.

참고자료

• https://d2.naver.com/helloworld/0128759
• https://www.blog-dreamus.com/post/zgc%EC%97%90-%EB%8C%80%ED%95%B4%EC%84%9C
• https://www.packtpub.com/en-us/learning/how-to-tutorials/getting-started-with-z-garbage-collectorzgc-in-java-11-tutorial/
  위 두가지 블로그에서 ZGC의 자세한 원리가 잘 정리되어 있어 참고했다. 내용이 복잡하고 어렵지만 몇번씩 정독해보면 좋을 것 같다.