JVM OOM 발생 및 원인 분석하기

1) 서론

평소 요리를 할 때 양 조절을 잘하시는 편인가요? 

 

저는 평소 미역국을 할 때면 항상 양 조절이 어렵습니다. 아주 소량의 미역이라고 생각하며 한 주먹 넣고는 하는데요. 약 5분 뒤 이렇게 많은 미역은 도대체 어디서 나온 건지 의문이 들 정도로 불어나곤 합니다.

 

의문을 가지고 미역 봉지를 자세히 보게 되면 20인분이라고 적힌 글자를 볼 수 있습니다. 작은 봉지에 든 작은 미역들을 우습게 보고 넣게 되면 예상치 못하게 불어나곤 합니다. 미리 미역 양, 냄비의 크기를 확인하여 넣었어야 합니다.

 

개발을 할 때도 마찬가지인데요. 적재된 데이터의 양, 단순 코드 실수 등으로 인해 OOM이 발생하고는 합니다. 이번 글에서는 업무 중 발생한 OOM 발생 원인 분석글을 공유드리겠습니다.

 

 

---

2) OOM 발생

(모든 내용은 업무와 관련 없습니다. OOM을 재현하기 위한 간단한 코드들입니다)

• 임의의 객체를 List에 담습니다
• while문이 true이므로 무한대로 돌게 됩니다

// jar 파일 생성
kotlinc Main.kt -include-runtime -d oom-test.jar

// jar 파일 실행
java -Xms215m -Xmx215m -jar oom-test.jar

• Kotlin CLI compiler를 활용하여 jar 파일 생성합니다
• 쉬운 OOM 테스트 위해 최소/최대 heap 메모리 사이즈를 215MB으로 실행합니다

• oom-test.jar 파일 생성 완료

• oom-test.jar 실행
• 2,734,845번 while문이 동작합니다.
• OOM 발생과 함께 Java heap space 메시지가 출력됩니다

---

3) OOM은 왜 발생하는 걸까요?

OOM은 Out Of Memory의 줄임말입니다. 이름 그대로 여유 메모리가 없다는 의미입니다. 흔히 해외 쇼핑할 때 out of stock이라는 표현을 자주 볼 수 있는데요. 재고가 다 나가고 없다는 의미입니다. 이것을 바탕으로 OOM을 조금 더 친숙하게 이해할 수 있을 것 같습니다.

 

OOM을 이해하기 위해서는 JVM의 stack, heap space를 이야기해야 하는데요.

 

Stack 영역의 특징은 각 메서드 단위로 할당됩니다. 메서드 내에서 선언된 참조 변수(reference variable)는 heap 영역에 할당된 객체를 가리키는(point)것뿐입니다. 실제 객체는 heap 영역에 할당되는데요. 만약 메서드 내에서 메서드의 무한재귀 호출 같은 것이 발생한다면 StackOverFlowError가 발생합니다. 즉 stack 영역이 부족하다는 의미입니다.

 

Heap 영역의 특징은 실제 객체가 할당합니다. 객체가 초기화하며 heap 영역에 할당이 되고, stack 영역에서 주소를 참조하는 방식을 사용합니다.

 

Heap 영역에는 young, old generation이 존재하는데요. 최초 객체가 할당이 되면 young generation에 위치하게 됩니다. 더 이상 참조되지 않는 객체는 minor GC에 의해서 제거됩니다. 하지만 계속해서 살아남아(참조되어) young generation이 가득 차게 된다면, old generation으로 copy 하여 이동하게 됩니다. Old generation에서 더 이상 사용하지 않게 된다면 major GC에 의해서 할당된 값이 해제됩니다.

 

만약 더 자세한 내용이 궁금하시다면 아래 글들을 참고해 주세요

• Java Memory Model(자바 메모리 모델)
• JVM Architecture란?

 

만약 old generation에서도 객체들이 계속해서 해제되지 않고 참조되면 어떻게 될까요? 더 이상 할당할 수 있는 heap 메모리 공간이 부족하게 되고, OOM이 발생하게 됩니다.

 

OOM이 발생하게 되면 다양한 원인과 메시지가 존재합니다.

• Java heap space
• GC Overhead limit exceeded
• Requested array size exceeds VM limit
• Metaspace
• Out of swap space?
• Compressed class space
• reason stack_trace_with_native_method

3. 1) OOM "Java heap space "

다양한 원인 중 Java heap space 원인을 파악해 보겠습니다.

 

에러 메시지에서도 볼 수 있듯이 원인은 간단하고 명료합니다. 메모리에 할당된 값이 주어진 heap 사이즈보다 크기 때문에 발생한 문제입니다.

 

특히 young generation에서 minor GC에 의해서 해제되지 않고, old generation에서 오랫동안 살아남은(참조되는) 객체들이 많이 존재하는 것이 원인입니다.

---

4) 그래서 OOM의 원인은 어떻게 확인할 수 있을까요?

위의 로직은 아주 단순하기 때문에 원인이 명확합니다. 하지만 대부분의 현실 세계에서는 아주 복잡한 로직에서 발생하고는 합니다. 심지어 여러 로그가 뒤섞여 OOM이 발생한다면 원인을 파악하기는 어렵습니다.

 

OOM이 발생했을 때 어떻게 원인을 확인할 수 있을까요? 방법은 아래와 같습니다.

• JVM 기동 시 -XX:+HeapDumpOnOutOfMemoryError 옵션을 추가한다
• OOM 발생 시 저장된. hprof 파일을 분석한다

 

JVM 빌드 시 아래와 같이 옵션을 줍니다.

java -Xms215m -Xmx215m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=[파일경로]oom-test-dump.hprof -jar oom-test.jar

4. 1) -XX:+HeapDumpOnOutOfMemoryError

JVM 기동 시 heap 메모리 설정 등 다양한 옵션을 줄 수 있는데요.

 

-XX:+HeapDumpOnOutOfMemoryError 옵션은 OOM이 발생하는 시점에 heap dump를 만듭니다. Heap dump 이름 그대로 당시의 heap 상황을 복사(dump) 합니다.

 

실제 운영 애플리케이션을 기동 하기 전 반드시 옵션을 넣어둬야 합니다. 만약 옵션을 빠뜨린다면 OOM이 발생했을 때 당시의 스냅샷은 존재하지 않고 원인을 파악하는 것은 거의 불가능하니다.

4. 2) hprof 파일 생성

위의 옵션으로 생성된 .hprof 파일을 분석해야 하는데요.

 

대표적인 분석툴은 Eclipse Memory Analyzer(MAT)가 있습니다. 무료 오픈소스이고, 자세한 분석을 도와주기 때문에 인기가 많은데요. 요즈음은 인텔리제이(2023.2.2.ver)에서도 프로파일 기능을 통해 hprof 파일 분석을 도와줍니다. 이번 글에서는 이미 설치되어 있는 인텔리제이로 진행합니다.

• .hprof heap dump 파일 생성됩니다

• 2,734,845개 객체를 생성 및 리스트에 담은 OOM 발생

 

위의 분석 정보는 heap dump가 발생했을 당시의 메모리를 캡처(capture) 한 것입니다.

• LocalDateTime 객체가 2,732,904회 사용되고, 약 67MB 메모리를 차지합니다.
• Object[] 부분을 보면 LocaDateTime 객체가 2,734,845회 생성되어 실제 배열에 담겨 있습니다.
• 실제 생성된 객체와 배열에 담긴 숫자는 당연히 다를 수밖에 없습니다.

 

Heap dump를 확인하니 어떤 연산이 수행됐고, 객체가 얼마나 생성되었는지도 알 수 있습니다. LocalDateTime 객체만 2,732,904회 사용되었고, 이 모든 객체들을 할당하는데 67MB를 사용하고 있습니다.

 

또한 LocalDatetime.now() 내부에서 LocalDate, LocalTime 객체들을 사용하고 있습니다. 이 때문에 now() 함수가 호출된 만큼 비례해서 호출과 메모리 사용량이 증가하고 있습니다.

 

조금 이상한 점은 Arrays.copyOf()가 다수 발생한 것을 볼 수 있는데요. 왜 이렇게 많은 연산이 발생했을까요?

 

ArrayList의 initial capacity는 10입니다. 즉 객체가 메모리에 할당될 때 10개 원소를 저장할 수 있는 공간을 할당합니다. 하지만 add()에 의해 원소는 계속 담길 수 있는데요. Capacity 10을 초과하게 된다면 끝자리에 메모리 공간 1이 추가되지는 않습니다.

 

Capacity를 초과하여 값을 저장하고자 할 때는 grow() 연산을 하게 되는데요. 기존에 할당된 값들을 copy 후 다른 공간에 할당합니다. 그리고 기존 공간 크기 + (기존 공간 크기 % 50)만큼 늘어나게 되는데요.

 

조금 더 정확히는 현재 capacity의 2진수 기준으로 shift 1 하게 됩니다. Initial capacity인 10에서 1개의 추가 원소가 필요하면 15가 됩니다. 10의 2진수는 1010이고, 1 shift 하게 되면 0101입니다. 즉 10진수로 5만큼 늘어나게 됩니다.

 

정리하자면, 아래 세 순서의 연산이 발생합니다.

1. 기존 데이터 copy
2. copy 데이터 할당
3. 기존 데이터 할당 해제

---

5) 결론

OOM이 발생했던 순간의 Heap dump 파일만을 분석했을 때 결론은 이렇습니다.

• LocalDateTime 객체가 아주 많이 생성되었고, 메모리에서 해제되지 않았습니다. 즉 메모리에 계속 남아있습니다.
• Summary의 stack trace를 확인했을 때 Arrays.copyOf() 복사 후 공간 할당 중 OOM 발생했습니다.

 

위의 분석을 바탕으로 while문이 문제라는 것을 확인할 수 있습니다. 그리고 실제 코드 확인 시 while문을 탈출하는 로직이 없다는 것도 파악하고 개선할 수 있었습니다.

---

6) 참고 문헌

코틀린 컴파일 공식문서

오라클 JVM 옵션 공식문서