태터데스크 관리자

도움말
닫기
적용하기   첫페이지 만들기

태터데스크 메시지

저장하였습니다.

[Enterprise Java는 거대한 동기화 머신이다] - 재미있는 GC 성능 사례 - Part2

Enterprise Java 2007.09.12 17:59
2. Paging In/Out에 의한 GC 지연

가끔 다음과 같은 현상이 발생하는 경우가 있다.

  • 평소에는 Full GC가 1초안에 끝났다. GC에 의해 Heap 사용량은 200M -> 100M 로 줄었다.
  • 그런데 어제 갑자기 Full GC가 20여초가 걸렸다. Heap 사용량의 변화는 210M -> 100M로 평소와 거의 비슷했다.
도대체 무슨 일이 벌어진 것인가?
정확한 원인을 GC log만을 보고 분석하기란 불가능하다. Full GC가 처리해야할 메모리의 양은 거의 비슷하다. 하지만 Full GC 소요시간은 20배가 늘었다. 논리적으로 가능한 이유들을 열거해 보면...
  • Full GC 당시 CPU Load가 심해서 GC 작업이 지연되었다 <-- CPU 문제
  • Full GC 당시 Memory Load가 심해서 Heap 영역이 Page Out 되었다 <-- Memory 문제
  • JVM 버그다 <-- Bug 데이터베이스 검색!!
다행히(?) 의외로 적지 않은 경우 2번째 이유, 즉 Paging In/Out에 의한 GC 지연이 발생한다.

아래에 실제로 발생한 사례가 있다.

다음과 같이 Low Pause Collector를 사용하는 상황에서...

-XX:+UseConMarkSweepGC -Xms2028m -Xmx2028m

New Generation Collection에 30초, Concurrent Mode가 구동되어서 총 78초가 흐르고 실패하고 말았다.

30263.967: [ParNew: 22279K->3192K(57344K), 30.0028214 secs]
30293.970: [CMS (concurrent mode failure): 1507043K->1045599K(2031616K), 78.8167675 secs]
....

위의 GC Log를 보면 한눈에 비정상적인 상황임을 알 수 있다.
  • 첫째, 57M의 New Generation을 정리하는데 무려 30초가 걸렸다.
  • 둘째, CMS(concurrent mode failure)가 무려 78초가 흐른 후 실패하고 말았다. Concurrent mode failure란 Tenured Space가 꽉 차기 전에 Concurrent Mode의 Collection 작업이 끝나지 않았다는 것을 의미한다.
다행히 이 현상이 발생한 당시의 OS 모니터링 정보에 의해 메모리 부족 현상에 의해 Paging In/Out이 왕성하게 발생한 것을 확인할 수 있었다.

시도한 Workaround는 Java Max Heap Size를 줄이는 것이었고, 더불어 몇몇 JVM Option이 수정되었다. Max Heap Size를 줄인 이유는 Java Process가 사용하는 메모리를 줄임으로써 OS에 메모리의 여유분을 주기 위해서이다.

비록 Java가 메모리 관리를 상당히 자동화하지만, 여전히 OS에 종속된 플랫폼이라는 것을 명심해야 한다. 따라서 OS 레벨의 CPU/Memory/IO 모니터링과 Java Heap Monitoring을 병행해야만 좀 더 합리적인 성능 문제 분석을 수행할 수 있다.

-----------------------------------------------------------------------------------------------
다음 글에 계속


신고
Trackback 0 : Comment 0

Write a comment

티스토리 툴바