Profiler JAVA Memory Leak

황제낙엽 2010.01.26 16:25 조회 수 : 169 추천:62

sitelink1  
sitelink2  
sitelink3 http://1 
extra_vars4 ko 
extra_vars5 http://lyb1495.tistory.com/6 
extra_vars6 sitelink1 
엄밀하게 말하면 JAVA에서는 C/C++에서와 같은 Memory Leak이 존재하지 않는다. 적어도 JVM의 규약(Specification)상으로는 그렇다. JAVA에서는 한번 사용된 후 더 이상 사용되지 않는 객체, 즉 더 이상 참조(Reference)되지 않는 객체는 Garbage Collector에 의해 자동으로 정리된다. 따라서 Memory Leak이 발생할 수 없다.

JAVA에서의 Memory Leak은 더 정확하게 말하면 Unintentional Object Retention, 즉 의도하지 않은 오브젝트의 계속 보유를 의미한다. 오브젝트를 생성한 후 참조 관계를 정리하지 못한 경우, Garbage Collector는 해당 오브젝트가 사용될 가능성이 있는지 없는지를 판단할 수 없기 때문에 메모리 해제 작업을 수행할 수 없다. 이런 오브젝트들 해제되지 않고 계속 상주하면 JAVA Heap이 불필요한 오브젝트들로 꽉 차게 되고 Out Of Memory Error가 발생하게 된다. 즉, JAVA에서의 Memory Leak은 Unintentional Object Retention에 의한 Out Of Memory Error의 발생으로 요약 정리할 수 있다.

Memory Leak이 있는 경우에는 메모리 공간이 점진적으로 불필요한 객체들로 가득차게 되며, 필연적으로 Out Of Memory Error가 발생한다. 따라서 Out Of Memory Error가 발생하면 우선 메모리 공간의 크기를 검증하고, 다음으로 Memory Leak의 발생 가능성을 검토해 보아야 한다.

불행하게도 Memory Leak이 발생하는 장소를 정확하게 찾아내는 것은 어려운 경우가 많다. 필요한 경우 HProf와 같은 기본적인 Profiler나 JProfiler, JProbe 등과 같은 Profiler를 통해서 메모리 분석을 수행해야 한다.

** JProfiler, JProbe는 상용 JAVA Profiler 이며 Memory 분석을 통한 Memory Leak 검출, 병목지점 찾아내기, 데드락 감시 등의 탁월한 기능을 제공한다. 각각 해당 벤더 홈페이지를 통해 평가판을 다운로드 할 수 있다.


무료 JAVA Profiler는 Eclipse의 TPTP[http://www.eclipse.org/tptp/] 플랫폼이 있다.

Memory Leak이 단지 OOME만을 일으키는 것은 아니다. Memory Leak이 발생하면 JAVA Heap 공간의 여유 공간이 잘 확보되지 않기 때문에 계속적인 Garbage Collection이 발생한다. 불행 중 다행으로 OOME가 발생하지 않더라도 계속적인 GC 작업에 의해 성능이 저하된다. 따라서 GC Dump를 분석할 때 Memory Leak의 발생 가능성이 있는지 검토해야 한다.



그럼 이제부터 Memory Leak을 검출하고 OOME를 수정하는 과정을 살펴보자.

어플리케이션이 OOME를 발생시킨다면 먼저 어플리케이션이 요구하는 메모리 크기보다 JAVA Heap의 크기가 작게 설정되 있지 않은지 살펴봐야 한다. SUN JVM의 경우 Default JAVA Heap Size는 64m이다. Heap Size의 최대크기는 -Xmx<size> 옵션을 통해 설정할 수 있다. 하지만 만약 어플리케이션에서 Memory Leak이 발생하고 있다면 Heap의 크기를 아무리 크게 잡아주어도 필연적으로 OOME의 발생을 막을수 없다.

Memory Leak을 검출해내기 위해 첫번째로 GC Dump을 이용할 수 있다. SUN JVM에서는 다음과 같은 옵션들을 이용해서 GC Dump를 제어한다.

  • PrintGCDetails : GC 수행 상세 정보를 출력한다.
  • PrintGCTimeStamps : GC 발생 시간 정보를 출력한다.
  • PrintHeapAtGC : GC 발생시 Heap 상세 정보를 출력한다.
  • -Xloggc:<file>: GC Dump를 저장할 파일명을 지정한다. 따로 지정하지 않으면 Console에 바로 출력된다.


GC Dump의 출력 결과는 기본적으로 다음과 같은 포맷을 지닌다.

  • 시간(JVM 시작이후의 시간)
  • Generation이름(DefNew+Tenured, PSYoungGen+PSOldGen, ParNew+CMS-concurrent-mark)
  • Heap Usage 변동: {GC전 Usage} -> {GC후 Usage}({Total Size})
    • 예를 들어 896K->64K(960K) 이면 GC 전에는 896K를 사용했으며, GC 후 64K로 사용량이 줄었으며, 전체 크기는 960K라는 의미이다.
  • GC 소요 시간: GC를 수행하는데 걸린 시간


아래 간단한 예제가 있다.


 0.186: [GC 0.186: [DefNew: 896K->64K(960K), 0.0022028 secs] 896K->434K(5056K), 0.0023143 secs]

위의 예제가 의미하는 바는 다음과 같다.

 

  • JVM 구동후 0.186 초에 수행된 GC 작업이다.
  • DefNew는 Default Serial Collector에서의 Young Generation을 의미한다. 즉 Minor GC가 수행되었다.
  • Young Generation의 크기는 960K이며, 896K를 사용 중이었고, GC 작업에 의해 64K만을 사용하게 되었다. 즉, GC에 의해 832K(896-64)가 Collection 되었다.
  • Minor GC 작업에 0.0022028 초가 소요되었다.
  • 전체 Heap 크기는 5056K이며, Minor GC에 의해 사용량이 896K에서 434K로 줄어들었다.
  • Minor GC를 포함해 GC를 수행하는데 총 소요된 시간은 0.0023143 초이다.


Memory Leak이 발생한 경우 GC Dump은 다음과 같은 전형적인 패턴을 보인다.

 1.564: [GC 1.564: [DefNew: 4543K->447K(4544K), 0.0074507 secs] 55108K->52239K(65088K), 0.0075322 secs]
1.576: [GC 1.576: [DefNew: 4543K->447K(4544K), 0.0084435 secs] 56335K->54675K(65088K), 0.0085257 secs]
1.589: [GC 1.589: [DefNew: 4543K->447K(4544K), 0.0072420 secs] 58771K->55902K(65088K), 0.0073378 secs]
1.600: [GC 1.600: [DefNew: 4543K->447K(4544K), 0.0073699 secs] 59998K->57130K(65088K), 0.0074590 secs]
1.610: [GC 1.610: [DefNew: 4543K->447K(4544K), 0.0075529 secs] 61226K->58357K(65088K), 0.0076395 secs]
1.621: [GC 1.621: [DefNew: 4543K->447K(4544K), 0.0074387 secs] 62453K->59585K(65088K), 0.0075247 secs]
1.632: [GC 1.632: [DefNew: 4543K->4543K(4544K), 0.0000433 secs] 63681K->63681K(65088K), 0.0001028 secs]
1.632: [Full GC 1.632: [Tenured: 59137K->57835K(60544K), 0.2154176 secs] 63681K->57835K(65088K), [Perm : 392K->391K(12288K)], 0.2155249 secs]
1.851: [GC 1.851: [DefNew: 4096K->447K(4544K), 0.0057781 secs] 61931K->59063K(65088K), 0.0058661 secs]
1.860: [GC 1.860: [DefNew: 4543K->447K(4544K), 0.0071495 secs] 63159K->60291K(65088K), 0.0072347 secs]
1.870: [GC 1.871: [DefNew: 4543K->4543K(4544K), 0.0000335 secs]1.871: [Tenured: 59843K->60543K(60544K), 0.1666050 secs] 64387K->61519K(65088K), 0.1667678 secs]
2.038: [Full GC 2.038: [Tenured: 60543K->60543K(60544K), 0.1665533 secs] 62712K->61855K(65088K), [Perm : 391K->391K(12288K)], 0.1666667 secs]
2.234: [Full GC 2.234: [Tenured: 60543K->60543K(60544K), 0.1607975 secs] 65087K->64658K(65088K), [Perm : 391K->391K(12288K)], 0.1609087 secs]
2.425: [Full GC 2.425: [Tenured: 60543K->60543K(60544K), 0.1595010 secs] 65087K->64787K(65088K), [Perm : 391K->391K(12288K)], 0.1596044 secs]

위의 패턴은 다음과 같이 해석할 수 있다.

 

  • Minor GC가 계속해서 일어남에도 불구하고 Heap 사용량이 계속해서 증가하기만 한다.
  • Young Generation과 Old Generation이 모두 꽉찬 시점이 되면 계속해서 Full GC만이 발생한다.
  • 최종적으로 Out Of Memory Error가 발생하게 된다.



보다 정확한 진단위해 JProfiler를 사용해 Memory Leak을 진단해보자. JProfiler는 ej-technologies사에서 만든 상용 JAVA Profiler이다. 글을 쓰는 현재 최신버전은 5.2.2 이다

JProfiler를 최초 구동한 모습은 다음과 같다.


JProfiler에서는 몇개의 샘플을 제공하는데 Memory Leak 검출을 연습하기 위한 예제로 Animated Bezier Curve Demo를 이용한다.


Profiling 을 시작하면 다음과 같은 화면을 볼수 있다.


좌측 상단의 어플리케이션 윈도우를 보면 Leak Memory라는 체크박스가 있는데 여기를 체크하도록 한다. 즉, 어플리케이션에서 Memory Leak이 발생되도록 하는 것이다. 일정 시간이 지난 뒤 JProfiler의 좌측 메뉴에서 VM Telemetry Views를 선택하면 다음과 같은 화면을 볼 수 있다.


어플리케이션의 Heap Memory의 사용현황을 그래표로 표현한 것이다. 어플리케이션이 시작된지 5분을 지점으로 해서 Memory 사용량이 급격하게 늘어나고 있음을 알수 있다.(이 경우 Leak Memory라는 체크박스를 선택한 시점)

정상적인 어플리케이션이라면 일정수준까지 메모리 사용량이 증가하지만, Memory Leak 발생할 경우 그래프는 선형적으로 꾸준히 증가되는 패턴을 보여준다. 이 경우 Leak Memory라는 체크박스를 해제하기 전까지 메모리 사용량은 꾸준히 증가하게 되고 종국에는 OOME를 발생시키게 될 것이다.

** 하단의 탭에서 GC Activity를 통해 GC의 활성화를 확인할 수 있으며 GC가 활성화되면 메모리의 사용량이 줄어들어야 한다.

Memory Leak이 발생되는 모듈을 찾아내기 위해 JProfiler 좌측에서 Memory Views를 선택하고 상단의 Mark Current 버튼을 클릭한다. 일정 시간이 지난 후 화면은 다음과 같다.


Mark Current 버튼을 클릭한 이후 JAVA Object의 변화량을 나타내는 화면이다. 적갈색의 막대 그래프는 버튼을 클릭한 이후 증가된 Object의 Type과 갯수를 나타내준다. 여기서 가장 상위 객체인 java.awt.geom.GeneralPath Object의 갯수가 19% 증가 했음을 확인 할 수 있으며, Memory Leak의 원인으로 의심해 볼 수 있다. 따라서 java.awt.geom.GeneralPath에서 마우스 오른쪽 버튼을 클릭하고 Take Heap Snapshot for Selection을 선택하면 다음과 같은 화면을 볼 수 있다.


위 화면에서 하단의 References 탭을 선택하면 다음과 같은 화면을 볼 수 있다.


java.awt.geom.GeneralPath에서 마우스 오른쪽 버튼을 클릭해 Show Paths To GC Root를 선택한다.


java.awt.geom.GeneralPath Object에 대한 참조관계를 확인할 수 있으며, 이 경우 BezierAnim Object의 leakMap Object가 Memory Leak의 원인으로 생각할 수 있다. BezierAnim에서 마우스 오른쪽 버튼을 클릭해 Show Source를 선택하고 leakMap을 찾아보면 다음과 같은 내용을 볼 수 있다.


leakMap의 entry로 Long Object와 GereralPath Object를 저장하고 있는데, JProfiler의 Memory Views 화면에서 Mark Current 버튼 클릭이후 꾸준히 증가한 Object들과 임치함을 확인할 수 있다. 즉, 바로 여기가 Memory Leak을 발생시키는 부분인 것이다.
번호 제목 글쓴이 날짜 조회 수
38 API 개발 도구 Swagger 황제낙엽 2024.01.19 0
37 Codeply 란? (feat ChatGPT) 황제낙엽 2023.02.21 1
36 오픈소스 설치형 칸반보드 솔루션 모음 황제낙엽 2022.10.08 6
35 DebugView v4.90 (dbgview, 디버그뷰) file 황제낙엽 2021.07.27 13
34 [Postman] Request/Response 모니터, 테스트, 디버깅 file 황제낙엽 2020.07.13 4102
33 크로스 브라우징 환경에서의 웹개발을 위한 도구 조사 file 황제낙엽 2017.02.21 81
32 [Mantis] 메일 서버없이 계정 비번 설정하기 황제낙엽 2016.12.19 131
31 개발 컴퓨터에 Git 설정(구성, 만들기, 복제, 추가) 황제낙엽 2016.08.17 381
30 칸반보드(현황판)를 지켜내는 힘! "꾸준히"와 "제대로" file 황제낙엽 2016.07.18 352
29 무료 칸반보드 Trello (온라인 서비스) file 황제낙엽 2016.07.18 2615
28 무료 칸반보드 TRICHORD (JVM기반, 로컬파일시스템) file 황제낙엽 2016.07.17 326
27 크롬에서 사용하는 온라인 칸반 확장앱 - Kanbanchi file 황제낙엽 2016.07.17 329
26 [번역] 잘 가요 스크럼, 반가워요 칸반 file 황제낙엽 2016.07.17 679
25 스크럼 회고 및 칸반으로의 전향 file 황제낙엽 2016.07.17 230
24 효과적 애자일 프로젝트 수행관리를 위한 우수 칸반(Kanban)툴 12선 황제낙엽 2016.07.17 1282
23 Code Coverage 관련 링크 황제낙엽 2010.06.08 121
22 [가이드북] 형상관리(Subversion)와 이슈 관리(Trac)를 연동하여 프로젝트 개발 환경에 적용하기 file 황제낙엽 2010.04.25 38
» JAVA Memory Leak 황제낙엽 2010.01.26 169
20 어플리케이션 성능측정 황제낙엽 2009.04.30 33
19 성능측정 TPTP 황제낙엽 2009.04.22 99