loading...

메모리 모니터링과 원인 분석

Java Memory Profiling에 대하여2 : 메모리 모니터링과 원인 분석

이어서

앞선 글에서 Java의 메모리 구조와 OOME가 발생하는 케이스에 대해 알아보았다면, 이번 글에서는 OOME를 예측할 수 있는 모니터링 방법과, OOME가 발생했을 때 덤프를 통해 원인분석을 하는 방법에 대해서 알아보고자 한다. 보통 서버를 관리하는 사용자들은 CLI 환경에서 작업하기 때문에, mat를 제외하고는 모두 CLI 기반의 기본적인 툴을 소개하고자 한다.

jstat

jvm이 설치되어 있는 디렉토리의 $JAVA_HOME/bin 디렉토리에 보면 jstat이라는 툴이 존재한다. 이 툴은 실행 중인 VM의 GC 상태를 모니터링할 수 있는 툴이다. 기본 사용법은 다음과 같다.

1. jps 명령어 또는 ps 명령어를 통해 모니터링 대상앱의 pid를 확인한다.
2. jstat ‐gcutil <pid> <interval>

이렇듯 정말 쉽고 간단하게 실행할 수 있으면서도 아주 상세한 정보를 제공하는 파워풀한 툴이다. 각각의 OOME 케이스에 대해서 실행 예제를 살펴보자.

그림 1: 케이스1 Heapspace : c:\user\sds>jstat-gcutil 28488 2000을 도스화면에서 입력한다/s0 0.00 0.00 0.00/s1 0.00 84.98 84.98 0.00 0.00/e 55.68 11.92 61.52 13.78/0 0.00 26.77 26.77 47.19 47.19/m 17.36 75.80 75.80 75.82 75.82 75.82 75.82 75.82/ccs 19.39 76.77 76.77 76.77 76.77 ygc 0 1 1 2 2 3 3 4 4 4 /ygci 0.000 0.011 0.011 0.042 0.042 0.06 0.065 0.079 0.079/fgc 0 0 0 1 1 1 1/fgct 0.000 0.000 0.000 0.022 0.022 0.022 0.022 0.043 0.043 0.043/gct 0.000 0.011 0.011 0.064 0.064 0.087 그림 1: 케이스1 Heapspace 그림 2: 케이스2 GC overhead limit exceeded : c:\user\sds>jstat-gcutil 30712 1000을 도스화면에서 입력한다/s0 0.00 0.00 0.00/s1 0.00 84.98 84.98 0.00 0.00/e 55.68 11.92 61.52 13.78/0 0.00 26.77 26.77 47.19 47.19/m 17.36 75.80 75.80 75.82 75.82 75.82 75.82 75.82/ccs 19.39 76.77 76.77 76.77 76.77 ygc 0 1 1 2 2 3 3 4 4 4 /ygci 0.000 0.011 0.011 0.042 0.042 0.06 0.065 0.079 0.079/fgc 0 0 0 1 1 1 1/fgct 0.000 0.000 0.000 0.022 0.022 0.022 0.022 0.043 0.043 0.043/gct 0.000 0.011 0.011 0.064 0.064 0.087 그림 2: 케이스2 GC overhead limit exceeded
로그 각 항목별 의미
항목 설명
S0 Survivor 0 영역의 사용량
S1 Survivor 1 영역의 사용량
E Eden 영역의 사용량
O Old 영역의 사용량
M Metaspace 영역의 사용량
CCS Compressed Class 영역의 사용량
YGC Young 영역의 GC 횟수
YGCT Young 영역의 GC 누적시간
FGC Full GC 횟수
FGCT Full GC 누적시간
GCT 전체 GC 누적시간
표1 - 로그 각 항목별 의미

1편에서 케이스1의 Heapspace 에러의 경우는 할당할 메모리가 부족하면 나는 에러였다. 여기서 그림1을 보면 로그에 E, O영역의 사용량이 100%에 가깝게 가는 것을 볼 수가 있는데, 이 때 해당 에러가 발생하는 것이다. 주의할 점은 사용량이 100%를 향하다가 중간중간 줄어드는 모습이 보일 것이다. 이것은 GC를 통해 가용메모리를 확보했거나, Capacity를 늘려서 상대적으로 사용량이 줄어든 것이다. 1번 예제에서는 GC를 실행시킬 것도 없이 메모리가 부족해서 바로 에러가 난 경우다. 중요한 것은 그림2인데, Real world에서는 그림2에서 보이는 로그와 그림1번이 결합된 형태로 메모리 부족 징후를 보이게 된다. 예를 들면 더 이상 늘릴 Capacity도 남지 않았고, GC를 해도 가용메모리가 확보가 되지 않는 상태다. 그림2를 자세히 보면 FGC, FGCT, GCT가 급격하게 증가하는 모습을 볼 수 있는데 이는 실행 중인 프로그램이 어떻게든 안 쓰는 메모리를 확보해서 작업을 처리하려고 하는 것이다. 예제에서는 빨리 에러를 발생시키려 하다 보니 FGCT와 GCT 수치가 얼마 안 되지만, 실제 서버를 운영하다 보면 이 수치가 엄청나게 증가하는 것을 목격할 수도 있다. 여기서 강조하고 싶은 것은 꼭 에러가 나지 않았더라도 모니터링상 FGCT와 GCT가 많이 높아지는 구간이 자주 있다면, 간당간당하게 어플리케이션이 목숨을 유지하고 있다는 뜻이니 어떤 작업을 할 때 이 수치가 올라가는지 확인하고, 코드를 다시 검토하거나, 메모리를 늘리는 등 예방적 조치를 하라는 것이다. 이외에도 앞선 글의 케이스3 Metaspace 에러의 경우는 그림1, 2와 거의 동일하지만 E, O 항목 대신 M, CCS 항목을 보면 비슷한 양상을 보인다.

Native Memory

전편에서 Java가 관리하는 영역 이외에 성능 향상을 위해 Native Memory를 사용하는 어플리케이션이 많이 있으니, 메모리 할당시 주의해야 한다고 언급한 적이 있을 것이다. 기본적으로 Java 어플리케이션의 -Xmx 설정은 흔하게 하는데 반면에, -XX:MaxDirectMemorySize는 잘 설정하지 않는데, 이 값을 설정하지 않을 경우 Xmx로 제한한 Heap 메모리만큼 Native Memory를 추가로 사용할 수 있다. 따라서 사용한 라이브러리에 따라 전체적으로는 Xmx 값의 두배+@만큼 시스템 메모리를 사용할 수도 있다는 뜻이다. 이런 어플리케이션을 제대로 메모리 할당없이 실행한다면 시스템의 OOM Killer가 내 프로그램을 계속 죽여나가는 것을 경험할 수 있을 것이다.
그리고 Native Memory의 경우 Java의 관리 영역밖에 내다 놓은 메모리이다 보니 위의 jstat으로 모니터링이 쉽지 않다. 다음의 예제를 보자.

List<ByteBuffer> buffers = new ArrayList<ByteBuffer>();
for(int i = 0 ; i < 100; i++){
buffers.add(ByteBuffer.allocateDirect(25000000));
Thread.sleep(1000);
}

이 프로그램을 메모리 제한을 두고 실행하면 Direct Buffer Memory 에러가 발생하는데, 위와 동일한 방법으로 jstat으로 모니터링 할경우 결과는 다음과 같다.

그림 3: Native Memory사용중 모니터링 : s0 0.00 0.00 0.00/s1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00/e 8.00 8.00 8.00 8.00 8.00 8.00 8.00 8.00/0 0.00 0.00 0.00 0.00 0.00 0.00 0.00/m 17.36 17.36 17.36 17.36 17.36 17.36 17.36/ccs 19.39 19.39 19.39 19.39 19.39 19.39/ ygc 0 1 1 2 2 3 3 4 4 4 /ygci 0.000 0.000 0.000 0.000 0.000 0.000 0.000/fgc 0 0 0 0 0 0 0 0/fgct 0.000 0.000 0.000 0.000 0.000 0.000 0.000 0.000/gct 0.000 0.000 0.000 0.000 0.000 0.000 0.000 그림 3: Native Memory 사용 중 모니터링

그림3을 보면 아무 변화가 없는 것이 확인된다. 이렇듯 Native Memory를 사용하는 어플리케이션을 모니터링 할때는 다음과 같은 특별한 방법이 필요하다.

1. 프로그램 실행 시 -XX:NativeMemoryTracking=summary 옵션을 활성화한다.
2. 사용 중이 아닐 때 jcmd <pid> VM.native_memory baseline을 통해 영점을 맞춘다.
3. 이후 jcmd <pid> VM.native_memory summary.diff를 통해 2번의 영점에서부터의 차이를 모니터링한다.
그림 4: Internal이 급증한 모습 : Java Heap List<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);}ClassList<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);}ThreadList<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);}CodeList<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);}GCList<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);}internalList<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);}symbolList<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);}Native Memory Tracking List<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);} Arena ClunkList<ByteBuffer> buffers =  new ArrayList<ByteBuffer>() for(int i=0;i<100;100;i++){ buffer.ass(bytebuffer.allocatedirect(25000));thread.sleep(1000);} 그림 4: Internal이 급증한 모습

위 그림은 예제를 –Xmx256m으로 실행한 것인데, 에러가 날 당시 total committed 메모리가 Xmx의 거의 두 배가 된 것과, Internal이 급증한 것을 확인할 수 있다.

원인분석

OOME가 발생할 경우 원인을 파악해야 하는데, 보통 정황으로 코드를 추적해서 알아내기도 하지만, Dump 파일을 분석해서 원인을 파악할 수도 있다. Eclipse에서 제공하는 mat라는 프로그램을 통해 간단하게 메모리 부족의 원인분석을 체험해 보자.
먼저 Dump 파일을 준비해야 하는데 메모리 부족 에러가 났을 때 자동으로 생기게 하는 방법과 수동으로 생성하는 방법이 있다.

1   수동
A. jmap ‐dump:format=b,file=<path> <pid>
B. jcmd <pid> GC.heap_dump <path>
2   자동 : 실행 시 옵션에 ‐XX:+HeapDumpOnOutOfMemoryError 를 추가

위와 같은 방법을 통해 hprof 확장자를 가진 Dump 파일을 생성할 수 있다. 이제 https://www.eclipse.org/mat/ 이곳에서 MAT를 다운받아 실행 후 File > Open Heap Dump 메뉴를 통해 생성된 덤프 파일을 열어준다. 팁으로 MAT도 java 프로그램이며 MemoryAnalyzer.ini에 기본 메모리 설정이 1024m으로 되어있으니, 큰 덤프파일을 분석할 때 부족한 경우가 많으므로 여유롭게 늘려주자. MAT에는 많은 기능이 있지만 여기서는 코드속 범인을 찾는데 큰 도움이 되는 Dominator Tree에 대해서 알아보려 한다.

그림 5: MAT의 dominator tree : Java.pid34616.hpoof파일을 열면 하단에 MatParkingLot @)xf620de 16 240.009472 99.60%/java util ArrayList @ Oxf620de 24 240.009472 99.60%/javalang Object 73 @)xf620de 16 240.009472 99.60% 그림 5: MAT의 dominator tree

위 그림은 간단한 예제를 실행시킨 덤프 파일을 오픈한 것이다. 왼쪽 화살표가 가리키는 아이콘을 누르면 dominator_tree 탭을 열 수 있고 오른쪽 Retained Heap을 누르면 정렬이 가능하다. 여기서 Retained Heap이란 해당 오브젝트와 연결된 모든 객체를 포함한 메모리 점유량이고, Shallow Heap이란 해당 오브젝트가 단독으로 차지하는 메모리다. 따라서 class 객체의 경우 그 자체로는 Shallow Heap이 작지만 int[1000000]과 같이 단독으로 많은 메모리를 사용하는 객체의 경우 Shallow Heap이 높은 것을 볼 수 있다. 우리가 관심있는 것은 보통 Retained Heap으로 그림처럼 이상하리만치 메모리를 많이 차지하고 있는 항목을 펼치다 보면 어떤 객체가 범인인지 쉽게 확인할 수 있다.

우리의 다음 목적은 저 ParkingLot이라는 객체를 어떻게 하면 제거할 수 있는지 알아보는 것이다. 익히 알고 있듯이 GC는 더 이상 사용되지 않는 객체를 지운다. 그렇다면 이 객체를 사용하고 있는 다른 객체가 있다는 것인데 그럴 땐 해당 객체에서 우클릭 > List objects > with incoming references를 실행한다. 여기서 incoming 이란 해당 객체를 참조하고 있는 객체를 보여주는 것이고, 반대로 outgoing이란 해당 객체가 참조하고 있는 객체를 보여준다.

그림 6: MAT의 inbound list objects: inspector Ox6ae20e0 MatSBuilding  class MatBuilding Ox6ae9f28 javalang Object sun misc Launche Statics Attributes Class Hierachy Value  type name Value ref parkingLot MatParkingLot @ Ox6ae20d0 ref name E tower 클flr java.pid34616hpof 클릭 parkingLotMat$Building @ Ox6ae20e0 그림 6: MAT의 inbound list objects

dominator_tree에서는 보이지 않던 Mat 클래스의 Building이라는 객체가 이 객체를 사용 중임을 알 수 있다. 게다가 이 객체를 클릭하면 좌측에 해당 클래스의 멤버 변수값이 노출되는데, 여기선 객체의 name이라는 속성값이“E tower”임을 알 수 있다. 이제 코드에서 이름이 E tower인 Building 객체를 찾아 수정해 주면 문제를 해결할 수 있다.

마치며

OOME의 해결책은 대체로 메모리 증설이 아니다. 프로그램 로직에 따라 천문학적인 메모리를 필요로 하는 로직이라면 아무리 메모리를 늘린다 한들 해결되지 않을 것이다. 설사 메모리 증설을 하더라도 얼마만큼 증설해야 되는지, 사용자의 데이터 양과 비즈니스 로직을 보고 다각도로 분석하여 제시할 수 있어야 한다. 이제 막 Java 계열에 입문한 개발자라도 오늘 본 것들을 잘 기억해 놓으면, 나중에 메모리가 부족하다고 시스템이 신호를 보낼 때 당황하지 않는 개발자가 될 수 있을 것이다.



▶   해당 콘텐츠는 저작권법에 의하여 보호받는 저작물로 기고자에 저작권이 있습니다.
▶   해당 콘텐츠는 사전 동의없이 2차 가공 및 영리적인 이용을 금하고 있습니다.



이 글이 좋으셨다면 구독&좋아요

여러분의 “구독”과 “좋아요”는
저자에게 큰 힘이 됩니다.

subscribe

구독하기

subscribe

정재부
정재부 인공지능/애널리틱스 전문가

삼성SDS 분석플랫폼Lab

삼성SDS 연구소 분석플랫폼Lab 소속이며, 소프트웨어 개발, 빅데이터 아키텍쳐, 머신러닝에 관한 지식과 업무 경험을 바탕으로 현재 삼성 SDS Brightics 솔루션 개발을 담당하고 있습니다.

공유하기