자바 웹 애플리케이션 Out of memory 오류 해결기

발단

어느날 새벽 4시경 잠이 오지 않아서 유투브를 보고 있는데, 평소에는 곤히 자고있을 시간이던 그 타이밍에 관제실로부터 한 통의 쪽지를 받게 되었다. 내가 운영 중인 서비스 WAS중 하나가 CPU 사용률이 90%가 넘게 올라갔으니 확인해달라는 내용이었다. 다행히도 검증계 WAS였지만 지속적으로 모니터링 알람이 송신되고 있는 것 같았으므로 즉시 조치를 취하겠다고 회신했다.

 

1차 원인 파악

보아하니 매일 새벽 2시에 돌고 있던 배치가 제대로 안돌았을 것 같았다. 이 배치는 그 날 사용할 데이터를 DB에서 읽어와 WAS 메모리에 올려놓는 작업을 수행하는데, 데이터양이 많아서 정상적으로 수행되도 몇 분이 소요된다. 그런데 DB 사용로그를 한번 보니 배치가 수행되는 딱 그 시간대에 사용량이 아래와 같이 튀고 있었다.

 

DB 사용 로그

더 볼 필요도 없이 해당 DB를 사용하는 여러 작업들이 겹쳤을 것이라 생각됐다. 사용량 로그를 조금 더 보니 그 전 날에도, 전전날에도 위 같은 수준은 아니지만 비슷한 시간대에 사용량이 튀고 있었음을 확인할 수 있었다.

 

여기서 DB 부하 문제로 섣부르게 확신을 하고, 그동안 문제없이 돌아가고 있었으므로 애플리케이션 내부적인 이슈는 없었을 것이라 판단해 일단 재기동을 했다. 문제없이 서버가 올라가고 앱은 다시 잘 작동되었다.

 

날이 밝은 뒤 시스템팀에 이슈를 전달하고 해당 시간대(새벽 2시경)의 DB 부하 문제에 대해 문의했다. 하지만 해당 시간대에 사용량이 늘기는 하나 전반적인 자원 사용률은 크게 올라가지 않고 있으므로 문제가 없다는 답변을 받게 되었다. 그렇다면 정말 애플리케이션 내부 이슈라는 말인가?

 

2차 원인 파악

로그 파일을 다시 뒤적였다.

 

DB 커넥션 문제였더라면 Time out Exception이 났어야 되는데, Out Of Memory가 발생했다. 무언가 다른 문제가 있었다는 것이다.

 

GC 로그

Grafana를 확인해보니 GC가 과도하게 튀고 있었다. 그렇다면 평소보다 데이터가 과도하게 많아서, 이를 WAS내 메모리로 올리는 과정에서 문제가 발생했을 가능성이 높아보였다. DB커넥션에는 아무런 문제가 없고, DB에서는 정상적으로 데이터를 제공해주지만 애플리케이션에서 객체화하는 과정에서 메모리 누수가 발생했을 것이다.

 

실제 오류가 발생했던 일자에 데이터 사이즈가 늘었는지를 볼 필요가 있었다. 배치 수행이 끝나면 10개 테이블에 데이터가 생성되는데, 그 중 가장 비중이 큰 것을 확인해보았다.

 

일자	데이터 사이즈
6월 8일	20.06m
6월 9일	21m
6월 10일	21.52m
6월 11일	20.43m
6월 12일	19m

최초로 이슈가 발생했던 6월 9일에 데이터가 사이즈가 늘기는 했다. 조치가 완료되지 않은 채로 모니터링을 진행했던 9일에도 같은 이슈가 있었는데, 역시 데이터 사이즈가 소폭 증가했다. 일자별로 데이터 증감률이 크지는 않지만 10개 테이블의 증감분을 합치면 충분히 유의미한 차이일 것이고, 또 21m 근처가 heap memory 수용량의 임계라고 가설을 세워볼 수 있다.

 

조치

이 가설을 가지고 1차적으로 다음과 같이 JVM의 메모리 설정을 변경하였다.

 

변경 전	변경 후
-Xms2048m -Xmx2048m (MaxMetaSpaceSIze 설정 없음)	-Xms4096m -Xmx4096m -MaxMetaSpaceSIze=512m

MaxMetaSpaceSIze는 class의 meta 정보와 상수 등을 저장하는 Permanent heap의 사용량이 커졌을 때, Memory Swap이 발생하는 것을 방지하기 위한 설정이다.(참고)

 

검증

그렇다면 이러한 설정 하에서 21m 이상의 데이터를 애플리케이션에서 읽어오도록 시뮬레이션을 해본다면 'heap memory 수용량의 임계'로 세웠던 가설을 검증할 수 있다.

 

실험 번호	JVM 설정	데이터 사이즈	결과
1	-Xms4096m, -Xmx4096m, MaxMetaSpaceSIze=512m	140m (Average * 7)	Out of Memory, CPU use 90% 초과
2	-Xms4096m, -Xmx4096m, MaxMetaSpaceSIze=512m	20m (Average)	정상 기동, CPU use 20%
3	-Xms4096m, -Xmx4096m, MaxMetaSpaceSIze=512m	40m (Average * 2)	정상 기동, CPU use 20%
4	-Xms4096m, -Xmx4096m, MaxMetaSpaceSIze=512m	60m (Average * 3)	정상 기동, CPU use 86.4%
5	-Xms2048m, -Xmx2048m, MaxMetaSpaceSIze=512m	60m (Average * 3)	Out of Memory, CPU use 90% 초과
6	-Xms4096m, -Xmx4096m	60m (Average * 3)	정상 기동, CPU use 79.2%

1,2,3,4 번은 JVM 설정을 통제한 상황에서 데이터 사이즈만 변경해가며 배치 작업을 수행해본 것이고, 데이터 사이즈의 변화에 대한 영향도를 알아보고자 했는데, 임계는 약 60m임을 확인해볼 수 있었다. 4,5,6번에서는 데이터 사이즈를 통제한 상황에서 JVM 설정을 변경해보았는데, 역시 heap size를 낮게 설정했을 때 이슈가 재현되고 있었다. 또한, MaxMetaSpaceSize 설정은 결과에 별다른 영향을 주지 않았다.

 

CPU 사용률 변화

 

결국, 일시적인 데이터 증가로 인해 WAS 메모리로 해당 데이터를 읽어와는 과정에서 heap 메모리가 부족하여 Out of memory 오류가 발생했던 것이다. 초기 진단을 잘못하여 시간을 조금 허비했지만 덕분에 데이터 수용량의 임계치도 확인할 수 있었으니 수확은 있었던 셈이다.

 

 

참고

https://blog.voidmainvoid.net/210

Java8이상에서 MaxMetaspaceSize 설정, 반드시 해야할까?

https://www.holaxprogramming.com/2017/10/09/java-jvm-performance/

Java 시스템 운영 중 알아두면 쓸모 있는 지식들