IBM Java 1.4 Heap Fragmentation GC Log 분석

[kiki]

이번에는 IBM Java 1.4 버전의 고질적인 문제점이라 할 수 있는 Heap Fragmentaion과 관련된 GC Log를 분석하는 방법과 이에 대한 대처 방안에 대해 적어 보도록 하겠습니다.

우선 IBM Java 1.4의 Heap Fragmentation이란 무엇인지 알아 보도록 하겠습니다.

IBM JVM는 Sun 계열의 JVM과 달리 One Heap 구조를 가집니다.

그렇다면 One Heap 구조란 무엇일까요? Sun 게열의 JVM은 Generational Heap 구조로써 각 세대별(New, Old, Permanent) 메모리 구조가 분리되어 있는 구조입니다.

즉 생성된 Object가 젊은것들은 New, 늙은 것들은 Old, Object instance화 되기 위해 참고되는 class 메타 정보들은 Permanent로 나누어 집니다.

Garbage Collector가 이러한 영역들을 활용하여 Garbage Collection을 처리하게 됩니다.

IBM JVM은 이러한 Generational 한 영역으로 나누어 지지 않고 하나의 Heap에 모든 JVM이 사용하는 메모리를 그냥 사용합니다.

이러한 이유로 Sun JVM과 IBM JVM은 메모리 관련 튜닝이나 장애 처리를 위한 GC Log 분석을 위한 접근 방법이 많이 다릅니다.

제가 포스트 제목으로 IBM Java 1.4 라고 한 것은 IBM의 Java는 1.4와 1.5,1.6 간의 GC Log 포맷이 많이 달라 분석하기 위한 접근 방법이 또 다릅니다.

이번 포스트는 IBM Java 1.4에 대한 Heap Fragmentation에 대한 GC Log 분석만 다루도록 하겠습니다. 다음에 1.5, 1.6을 다루도록 하겠습니다.

참고로 IBM에서는 JVM의 Heap Fragmentation의 문제점으로 고심하던 끝에 1.5 버전 부터를 Generational Heap 구조를 사용할 수 있는 옵션(gencon 옵션)을 지원하게 됩니다.

제 개인적으로는 IBM이 자존심이 강한 기업이라는 것을 엿볼 수 있는 부분인데요.

이러한 Generational Heap 구조는 디폴트가 아니고 옵션사항으로 만들어 놓았습니다.

독자적인 구조를 고집하였으나 끝낸 꼬리를 내렸지만 완전히 내리진 않을 것이죠.

이러한 문제점을 해결하기 위해서는 Pinned class(Class 메타 정보라고 보셔도 될듯합니다.) 를 별도의 영역으로 잡고 더 이상 사용하려면 오류를 내는 것도(Sun 계열에서 Permanent full) 괜찮은 방법으로 저는 생각합니다.

그렇다면 Heap Fragmentation은 왜 발생하는 것일까요?

일반적으로 메모리를 allocation하기 위해서는 allocation 하는 양만큼의 일련된 메모리 block이 필요합니다.

한번에 할당하기 위한 메모리 block이 없으면 더이상 메모리가 없어 무시무시한 "OutOfMemory" 오류가 발생합니다. 

여기서 Heap Fragmentation이 발생하면 free 메모리가 많이 있어도 일련된 메모리 block이 부족한 것을 의미하는 것입니다.

그러다 보니 Heap Fragmentation이 심해지면 질수록 아주 작은 메모리 block을 allocation 요청해도 할당할 수 있는 메모리가 없어 GC를 일으키게 되며 이러한 현상이 지속적으로 발생하다 보면 시스템 성능이 점점 느려지면서 끝내는 "OutOfMemory"로 가는 것입니다.

그렇다면 이러한 Heap Fragmentation은 왜 발생하는 것일까요? 위에서 말씀드렸던 Pinned class 때문입니다.

IBM JVM이 One Heap을 사용하다 보니 이 Pinned class에 대한 영역(Pinned cluster로써 kCluster, pCluster 영역)을 넘어서 Data Heap 부분에 임의적으로 Pinned class가 위치하게 됩니다.

또한 이러한 Pinned class들은 GC의 대상이 되지 않아 compaction 으로 인한 위치 이동이 되지 않습니다.

그러다 보니 Fragmentation이 발생하게 됩니다.

아래는 Heap Fragmentaion이 발생하는 경우에 대한 그림입니다.

그렇다면 Pinned cluster라는게 어떻게 pinned class들을 저장하고 관리 되는지를 말씀드리겠습니다.

Pinned cluster라는 영역은 크게 kCluster와 pCluster로 나누어 집니다. kCluster에 pinned class가 먼저 저장되게 되는데요. 

이러한 kCluster는 기본적으로 1280 entry들에 각 class block당 256byte로 설정됩니다. kCluster의 영역을 모두 사용하게 되면 16kbyte의 pCluster 영역에 저장하게 됩니다.

이 pCluser 마저 다 사용하게 되면 2kbyte 짜리의 pCluster들이 Data Heap 영역에 임의적으로 생성되게 됩니다.

작은 양의 class를 사용하는 시스템의 경우는 별 문제가 없지만 대량의 class를 사용하는 시스템은 pinned class로 인한 Heap Fragmentation으로 GC가 과도하게 발생하여 성능 및 Heap Memory 부족의 문제가 발생할 수 있습니다.

이번에 보여드릴 사례는 HP JVM을 통해 운영하던 시스템은 IBM JVM으로 전환하면서 Heap Fragmentation이 발생하여 GC가 많이 발생하여 성능상에 문제가 된 경우입니다.

그럼 예제 GC 로그를 살펴 보도록 하겠습니다.

=============================================================================================

<AF[1]: Allocation Failure. need 536 bytes, 0 ms since last AF>
<AF[1]: managing allocation failure, action=0 (1353694168/1572862464)>
  <GC(1): GC cycle started Thu Jun 16 05:25:28 2011
  <GC(1): freed 193235248 bytes, 98% free (1546929416/1572862464), in 172 ms>
  <GC(1): mark: 163 ms, sweep: 9 ms, compact: 0 ms>
  <GC(1): refs: soft 0 (age >= 32), weak 0, final 938, phantom 1>
<AF[1]: completed in 193 ms>

........

중략

........

  <GC(58): GC cycle started Thu Jun 16 07:40:50 2011
  <GC(58): freed 202774624 bytes, 84% free (1327538440/1572862464), in 86 ms>
  <GC(58): mark: 70 ms, sweep: 16 ms, compact: 0 ms>
  <GC(58): refs: soft 2 (age >= 32), weak 0, final 989, phantom 12>

........

생략

=============================================================================================

IBM JVM 1.4의 GC Log 포맷입니다.

위에서는 두가지 경우의 GC Log에 대한 포맷인데요. 첫번째는 AF(Allocation Failure)에 대한 부분이며, 두번째는 System GC로 인한 Log입니다. System GC는 "-Xdisableexplicitgc" 옵션으로 강제로 막을 수 있을 것이고요.

AF 부분이 중요한 부분인데요. AF는 Allocation Failure인데요. 요청한 양의 메모리를 allocation 할 수 없어 JVM이 GC를 발생시킨 경우입니다. 즉 뭔가 메모리에 문제(대부분 부족한 경우이겠죠)가 있다는 것이죠. AF 부분 중 특히 action 부분이 GC가 발생한 사유를 알려주는 코드입니다. 굉장히 중요한 부분이라 할 수 있습니다.

그럼 이러한 action코드의 내용은 다음과 같습니다.

action=0 : GC가 pinned free list로 부터 할당하기 위해 시도하였으나 실패한 경우임

action=1 : wilderness 부분을 사용하지 않기 위해 GC가 수행된 경우

action=2 : wilderness 외의 부분에 allocation을 시도했으나 실패한 경우

action=3 : GC가 heap expand를 시도하려고 한 경우

action=4 : GC가 남아 있는 soft reference를 clear하려고 한 경우(free space가 12%이하일때 발생)

action=5 : GC가 transient heap으로 부터 공간을 점유하기 위해 시도하는 경우

action=6 :action은 아니지만, JVM이 heap space가 너무 작거나 너무 크면 메시지를 출력하는 내용임

이 action 코드중 Heap Fragmentation과 관련된 코드는 "0" 입니다.

pinned free list 메모리를 allocation할려고 했지만 실패한 경우입니다.

이번 사례의 GC Log를 보면 거의 대부분의 AF action 코드가 "0" 입니다. 그리고 그 옆의  "(1353694168/1572862464)" 문구에서 전체 중 free 메모리가 많다는 것을 알 수 있습니다.
보통의 경우 Heap 메모리가 가득차서 GC가 발생하면 대부분 action 코드가 "1", "2" 번이 발생하고 그 뒤 Heap이 확장 가능하다면 "3"번이 발생합니다.

그렇다면 이러한 Heap Fragmentation을 피할 수 있는 방법에 대해 설명드리겠습니다.

-Xp와 -Xk 옵션을 통해 적절한 kCluster와 pCluster값을 설정하는 것입니다.

해당 옵션의 format은 다음과 같습니다.

-Xknnn -Xpiii[k],[ooo[k]] 

 - nnn : kCluster에 담을 최대 class의 수

 - iii : 초기 pCluster의 사이즈(kbyte)

 - ooo : pCluster의 overflow시 할당할 사이즈(kbyte) --> 옵션사항

이러한 설정을 통해 적정한 pinned class를 저장할 공간을 할당하는 것입니다.

그러면 어떻게 적정한 크기를 설정할 것인가를 알아봐야 겠죠.

적정값을 알기 위해서는 GC trace data를 생성하여 확인하는 방법이 있습니다.

"-Dibm.dg.trc.print=st_verify" 옵션을 설정하면 다음과 같은 로그가 생성됩니다.

"<GC(VFY-SUM): pinned=4265(classes=3955/freeclasses=0) dosed=10388 movable=1233792 free=5658>"

위와 같은 로그에서 다음과 같은 공식을 얻을 수 있습니다.

- kCluster : -Xk(classes + 10 ~ 15% 값)

- pCluster : -Xp(pinned - classes의 수 * 평균 class 사이즈[kbyte]) --> 이 부분은 예측하기가 쉽지 않습니다.

이렇게 설정하게 되면 어느 정도 Heap Fragmentation을 피할 수 있을 것입니다.

참고로 Heap Fragmentation이 발생한다면 kCluster와 pCluster를 넉넉히 설정하는 것이 좋은 방법입니다.

이것으로 IBM Java 1.4의 Heap Fragmentation에 대한 포스트를 마치기로 하겠습니다.

다음에는 IBM Java의 GC 포맷(1.4, 1.5, 1.6)과 분석 방법에 대해 알아 보도록 하겠습니다.

[출처] IBM Java 1.4 Heap Fragmentation GC Log 분석|작성자 범서기