들어가며
이번 글은 메모리 관련 이슈의 정의와 해결 과정을 공유하여, 유사한 문제를 겪는 개발자분들께 도움이 되고자 작성했습니다.
또한, GC 동작 원리를 심도 있게 탐구함으로써 이해도를 높이고, 문제 해결 과정에서 발생했던 몇 가지 오해를 바로잡아 추후 유사한 문제를 예방하는 것을 목표로 합니다.
* 본 글은 Java8 버젼 JVM의 CMSGC에 대한 내용입니다.
사건의 발단 - 성장하는 메모리
APM을 모니터링 하던 중 이상현상을 보이는 지표를 발견했습니다.
(((아 메모리 주식 살 걸) 라고 할때 살 걸) 라고 할 때 살 걸) 라고 할 때 살 걸
지속적인 성장을 보여주는 메모리를 발견했습니다.(왜 나 대신 니가 성장을)
배포하고 난 이후로 지속적인 우상향을 보여주고 있는 상황이여서
메모리 누수를 의심하게 되었습니다.
증거를 수집하자 - Heap Dump
Dump를 생성해보자
메모리 누수가 의심 되는 상황에서 할 수 있는 가장 첫번째 작업은 Heap Dump를 생성하는 것입니다.
jmap 명령어를 사용하여 간편하게 Dump 를 생성 할 수 있습니다.
jmap -dump:file=heapdump.hprof <pid>*주의 : 따라하지 마시오 (후술 하겠지만 여기서 첫번째 실수가 생겼습니다. )
명령의 결과로 3GB 남짓의 Dump 파일이 생성되었습니다.
Dump 를 분석해보자
지원하는 기능이 많고 간편하게 사용 할 수 있는 Eclipse Memory Analyzer 툴을 사용해서 분석했습니다.
분석 결과를 마주했을 때 첫번째로 당황했던 부분은 3GB 남짓의 덤프 파일에서 분석 한 내용이 194MB? 라는 점이였습니다.
관련 내용을 찾아보니 Memory Analyzer 에서 기본적으로 GC 수집 대상으로 낙인이 찍힌 객체들은(미사용 객체) 분석 결과에서 제외되도록 설정이 되어있었습니다.
관련 설정을 켜주고 Dump를 다시 분석하니 맞게 나오는 것을 확인 할 수 있습니다. (Details 부분을 보시면 첫번째 분석에서는 Unreachable Object에 대해 볼 수 있는 Histogram 을 별도로 제공)
하지만, 저희에게 필요한 것은 누수가 일어나고 있는 객체의 분석, 즉 GC 수집 대상으로 낙인 찍히지 않은 객체들이기 때문에
첫번째 분석 결과로 확인하는 것이 더 적절합니다.
저희가 찾아야하는 객체는 수명주기가 길고, 용량을 많이 차지하는 객체들입니다.
Memory Analyzer에서는 분석 결과 이런 유형의 객체들을 찾아주는 Leak Suspects 항목을 제공합니다.
Leak Suspects 버튼을 눌러 분석을 요청합니다.
누수로 의심되는 객체 분석 결과 ClassLoader 종류의 객체가 두가지가 나왔습니다.
ClassLoader 에서 메모리 누수가..? 여기서 부터 뭔가 이상함을 감지했지만 분석 결과를 조금 더 파악해보기로 했습니다.
dominator_tree 항목을 통해 어떤 객체에서 해당 객체를 참조하고 있는지 얼만큼의 용량을 차지하는지 확인 해볼 수 있습니다.
- Shallow Heap
- 해당 객체 자체가 차지하는 메모리
- Retained Heap
- 직접 또는 간접적으로 참조하는 모든 객체가 차지하는 메모리
Class Loader... 너 맞아?
Class Loader 관련 메모리 누수에 대한 내용을 열심히 찾아보니...
- Tomcat 재기동 하지 않은채로 배포하는 방식을 채택하게 되면 동적 클래스 로딩으로 인한 ClassLoader가 해제되지 않고 메모리에 남아있으면서 누수가 발생
- ThreadLocal에서 ClassLoader 를 참조하면서 스레드 풀의 스레드가 반환되지 않아 누수가 발생
크게 두가지 상황이 대부분이였는데.. 저희 시스템에서는 두가지 전부 관련 내용이 없는 상황이였습니다.
이 때 부터 사건이 미궁에 빠지면서 범인을 찾기위해 삽질을 하기 시작했습니다.
그럼 누가 범인이야?
인사이트를 얻기 위해 여기저기 현재 상황을 공유하고 질문 하여 다양한 답변들을 받았습니다.
의심 할 수 있는 것들을 전부 의심하기 시작했습니다.
- Stream을 열고 close 하지 않아 생기는 메모리 누수
- static으로 선언된 변수의 Map, HashMap에 적재되고 사용되지 않는 객체들
- JDBC Connection 관련 connection을 맺고 close 하지 않는 경우
- 완료되지 않은 Future와 ExecutorService
등등...
이 중에서 가장 빈번하게 발생하는 부분인 Stream resource의 미반환 상황을 찾아봤습니다.
InputStream 너 범인해라
Stream을 획득하고 close 하지 않는 부분을 발견하고 "이거다" 싶은 마음에
Visual VM, JProfiler 를 총 동원하여 local 환경을 모니터링 하고
NGrinder를 통해 의심되는 코드를 사용하는 api에 5천건 정도의 호출을 보냈습니다.
하지만 base line은 높아지지 않았고... 성급하게 판단하고 결론지은 결과의 쓴 맛을 보게됐습니다.
수 많은 삽질을 거치고 나서야 GC 의 동작에 대해서 다시 자세하게 살펴볼 생각이 들었습니다.
GC 를 파헤쳐 보자(CMSGC)
모든 기술은 기술의 탄생 배경을 살펴보면 해당 기술의 핵심 가치에 접근하기 쉬워진다고 생각하기 때문에
CMSGC의 탄생 배경에 대해서 먼저 알아보겠습니다.
왜 도입되었을까?
CMSGC(Concurrent Mark Sweep)는 약어에서도 힌트를 얻으셨을 수 있듯, 동시성을 유지하기 위해 등장했습니다.
여기서 의미하는 동시성이란, 어플리케이션 동작과 가비지컬렉션이 동시에 수행됨을 의미합니다.
기존의 Parallel GC와 Serial GC 에서의 너무 긴 STW(Stop-the-World) 가 문제가 됐습니다.
특히나 당시 빠르게 성장하는 웹 애플리케이션의 환경에서는 치명적인 단점이였습니다.
어떻게 이 문제를 해결했지?
이름 그대로 Concurrent(동시에) Marking(마킹) 함으로써 STW 시간을 최대한 짧게 가져가서 높은 응답속도를 낼 수 있었습니다.
크게 총 5가지의 단계를 거칩니다.
- Initial Mark (짧은 STW 발생) - 루트 객체에서 직접 참조되는 객체만 마킹
- Concurrent Marking - Initial Mark에서 마킹된 객체를 기반으로 모든 연결된 객체를 마킹 (어플리케이션 실행과 동시에 실행)
- Remark (STW 발생) - 병렬 마킹 도중 누락된 객체가 있는지 확인하고 최종 마킹 수행
- Concurrent Sweep - 마킹된 객체가 아닌 모든 객체의 메모리 해제 (어플리케이션과 병렬 실행)
- Resetting - 다음 GC 주기를 준비하기 위해 데이터 구조를 초기화
내부적으로 어떤 구조로 수집될까?
CMS GC가 어떻게 처리되는지에 대해 전체적인 흐름을 이해했으니,
각 단계가 내부적으로 어떤 구조와 메커니즘을 통해 작동하는지 살펴보겠습니다.
Heap 내부 구조는 다음과 같은 4개의 영역으로 구분됩니다.
- Eden
- Survivors 0
- Survivors 1
- Old Generation
여기서 Edne, S0, S1은 Young Generation 에 속합니다.
최초 객체가 생성되면 Eden 영역에 저장됩니다. Eden 공간이 가득차게 되면 Minor GC가 발생합니다.
Minor GC는 총 3가지 작업을 진행합니다.
- Eden 영역에서 살아 남은 객체를 현재 비활성화 Survivors 영역으로 이동
- 현재 활성화 Survivors 영역에서 살아남은 객체를 비활성화 Survivors 영역으로 이동하면서 생존 횟수 카운팅
- 생존 횟수가 임계값에 도달한 살아남은 객체를 Old Generation으로 승격
* 여기서 S0과 S1는 번갈아가면서 한쪽만 사용이 됩니다.
💡 왜 Survivors 영역은 한쪽만 사용될까?
- 생존과 이동의 관리를 효율적으로 하기 위함
- Minor GC가 수행 될 때마다 다른 Survivors 영역을 사용함으로써 메모리 파편화를 방지 할 수 있음
- 사용된 영역을 초기화 하고 새로운 영역에 새롭게 적재하는 것이기에
- Survivors 영역을 교차하며 이동하는 횟수를 가지고 카운팅을 하는 방식을 사용하기 위해
이렇게 실행되는 Minor GC는 STW 이벤트가 발생하며 빠르고 주기적으로 실행됩니다.
이 과정을 반복하다보면 Old Generation의 영역에 객체를 담을 수 없는 상황이 옵니다.
이 때 Major GC(Full GC)가 발생합니다. Major GC는 Heap 영역의 모든 미사용 객체를 메모리에서 해제합니다.
이렇게 실행되는 Major GC는 STW 이벤트가 발생하며 느리고 긴 주기를 가지고 실행됩니다.
수사는 다시 원점으로
이제 CMSGC 의 동작 방식에 대해서도 정확히 알아봤으니 다시 범인을 찾기위해 단서를 수집해야 합니다.
한번 더 Dump를 생성해보자
누수된 객체를 찾기위해서는 일정 간격을 두고 Dump를 생성해서 비교해봐야 한다는 조언을 듣게되고
다시 한번 Dump를 생성하기로 합니다.
여기서 최초에 Dump 생성 시 실수했던 부분을 바로잡게됩니다.
바로 live 옵션을 주지 않고 dump를 생성했던 것인데
live 옵션을 주고 dump를 생성해야 FullGC를 수행한 후 dump를 생성해서
FullGC가 돌았음에도 해제되지 않은 객체들을 식별해서 분석하기가 용이합니다.
jmap -dump:live,format=b,file=heapdump.hprof <pid>
live 옵션을 주고 dump를 생성합니다.
메모리.. 다 비었는데요?
dump를 생성하자 FullGC가 돌면서 메모리 사용률이 급격히 떨어지는 것을 확인 할 수 있었습니다.
여기서부터 아차 싶었습니다. 여태 FullGC가 동작하지 않고 Minor GC만 수행됐던게 아닐까..?
로그를 확인해보자
떨리는 마음으로 확인결과
Heap Dump 요청에 의한 Full GC 동작과 Full GC 동작 이후에 싹 정리가 된 메모리 들을 확인 할 수 있었습니다.
예상했던 상황을 사실로 만들어줄만한 증거가 나온겁니다.
근데 왜 Full GC가 안돌지?
여기서 든 의문점은 그럼 언제 FullGC가 동작하는가? 였습니다.
Old Generation의 threshold 를 넘긴 순간인 것을 확인 했고,
해당 설정 값을 확인했지만 따로 설정되어 있지 않아 기본 값을 따르는 것으로 보였습니다.
-XX:CMSInitiatingOccupancyFraction
Oracle 공식문서에 따르면 threshold 기본 값은 92%입니다.
그럼 Old Gen의 영역은 전체 메모리의 어느정도를 차지하는거지?
그럼 실제로 Old Generation의 영역은 얼마나 차지하고 있고 그 영역의 92%는 전체 메모리의 어느정도 인가를 알아보기위해
Young Gen과 Old Gen의 비율에 대한 설정 값을 찾아봤습니다.
-XX:NewRatio
해당 옵션을 통해 설정이 가능하며 이 또한 별도로 설정되어 있지 않은 것으로 보아
1:2 비율 즉 1/3 의 YoungGen 과 2/3의 OldGen 으로 구성된다고 볼 수 있습니다.
그럼 FullGC가 돌아야지!
이상했습니다. APM에서의 메모리 사용률은 Heap에 전체 크기에 대한 사용률입니다.
그런데 이 수치가 80%에 육박했다는 것은 2/3 영역을 차지하는 OldGen 이 92% 이상 찼다는 것을 의미할겁니다.
그렇다면 지금 APM과 GC Log 중에서 누군가 거짓말을 하고 있는것으로 보였습니다.
APM에서 메모리 점유율이 80%를 육박하는 시점에 GC Log를 살펴보겠습니다.
PSYoungGen 의 GC를 수행시켜 용량을 줄이고 (괄호 안의 용량은 총 용량) 최종적으로 전체 메모리에서 해당 수치만큼 정리가 된 것을 확인 할 수 있었습니다.
그런데 APM에서 80%를 육박하는 시점에 실제로는 전체 메모리 사용률이 50%인거 보니 보여주는 지표에 대해서 정확하게 파악 할 필요가 생겼습니다.
APM 개발사에 문의했더니 부하를 줄이기 위해 5분 단위로 평균 값을 지표에 나타낸다고 하더군요
따라서 사건의 전말은
- YoungGen 영역이 빠르게 차고 소멸되면서 OldGen 영역이 누적되고 Old + Young 의 평균 값이 80% 정도 되는 지표를 보이고 있었음
- APM을 보다가 80%를 넘어가자 불안한 마음에 서버를 재기동
- 다시 정상화 되어 MinorGC 만 수행되며 1번 상황을 반복
이렇다고 볼 수 있습니다.
전말을 뒷받침하기 위해 실제 메모리를 모니터링 해보겠습니다.
현 시점에서도 지표상 70~80%에 육박하는 사용률을 보여주는 인스턴스에 접속해서
jstat -gc <pid> <주기>
jstat 명령어를 통해 모니터링을 수행합니다.
C는 해당 영역의 총 크기를 의미하고 U는 영역 사용량을 의미합니다. (*MB단위, 기본적으로는 Byte 단위지만 awk 명령어를 추가해 보기좋게 만들었습니다)
즉, 좌측부터 S0의 크기, S1의 크기, S0 사용량, S1 사용량, Eden 크기, Eden 사용량 OldGen 크기, OldGen 사용량
OldGen 영역의 크기에 비례한 사용량을 보면 알 수 있 듯, 실제로는 50~60% 정도의 Old 영역이 찬것으로 확인됩니다.
즉, APM 성능으로 인해 집계하는 과정에서 즉각적인 데이터를 보여주기 어려움으로 인한 것이였습니다.
다른 서비스보다 사용량이 많고 반영이 자주 있지 않은 APP 이다 보니 이것이 좀 더 부각되어 나타났던 것이고
확인 결과 다른 운영중인 서버에서도 우상향 그래프를 보여주는 모습을 발견할 수 있었습니다.
(메모리 사이즈 자체가 크고 반영이 자주 있어서 80~90% 까지 가지 않았을 뿐)
마무리하며...
결론은 어플리케이션 및 메모리는 아무 잘못이 없었다..
이번 기회를 통해 모니터링 시스템에서 데이터를 수집하는 방식이 다양하고
직관적인 내용 뿐 아니라 모니터링 시스템에서 성능 상 빈틈이 생기는 부분들을 이해하고 지표를 봐야한다는 것을 이해하게 되었습니다.
(GC에 대한 자세한 동작 과정을 얻은것은 덤)
이 글을 보시는 저와 같은 주니어 개발자분들은 모니터링 지표가 우상향 한다고 무조건 누수를 의심하기 전에
FullGC가 실행된 시점 이후에도 baseline이 높아지는지 꼭 확인하고 세부적인 내용을 확인하시면 좋을듯 합니다.
실제로 메모리가 누수되는 상황이였다면 몇가지 튜닝 포인트로 영역 비율 조정 및 영역 크기, metaspace 크기 조정 등이 있습니다만.. 일반적으로는 기본 값을 사용하는게 좋을듯 합니다. (그냥 스케일 업을)
추가로 알아보면 좋을 것들
CMSGC에서는 FullGC가 일어나면서 Old Generation 영역을 정리하는데 여기서 메모리 파편화가 발생하는 문제가 있고
병렬로 어플리케이션 동작과 동시에 GC 작업을 수행하기 때문에 CPU 자원을 많이 소모한다는 단점이 존재합니다.
이런 CMSGC의 단점을 해결하기 위해서 Java9 부터는 G1 GC가 채택되었는데 다음 시간에는 이 G1 GC에 대해서 깊게 알아보는 시간을 가져볼까 합니다.
(참고 : Java9 부터 CMSGC는 deprecated 되었으며, Java14 부터는 Drop 되었습니다.)
- 메모리 파편화
- G1 GC의 동작 원리
- 어떻게 G1 GC는 CMSGC의 한계를 극복했을까
- G1 GC 다음 세대인 ZGC
- ZGC와 Java21의 Virtual Thread
- GC 튜닝에 대한 공식 문서
담고 싶은 내용이 많다보니 생각보다 길어져서 글이 좀 길어졌네요 긴 글 읽어주셔서 감사드립니다! 도움이 되셨다면 구독 좋아요 알림설정까지(?)
'Java' 카테고리의 다른 글
| [Base64] 빼앗긴 Parameter 찾습니다. (3) | 2024.10.11 |
|---|---|
| [Transactional] 거래가 왜 없었을까요? (0) | 2024.08.18 |
| [Transactional] 거래가 있었는데요.. 없었습니다 (2) | 2024.08.17 |
| [Java의 동시성] - Java에서 동시성 문제를 해결하는 방법 (1) | 2023.05.07 |
| [동시성 문제] - 동시성 문제란 무엇이며 어떻게 해결해야할까? (0) | 2023.05.01 |
