Java 8 GC 모니터링 준비와 Tomcat 튜닝 기록

Heap 크기를 바꾸기 전에 현재 GC가 어느 정도 발생하는지부터 확인했습니다. GC가 자주 실행된다는 인상만으로 설정을 바꾸면 처리량과 응답 시간 중 무엇이 개선됐는지도 판단하기 어렵습니다.

당시에는 jstat과 GC 로그를 남기고 VisualVM으로 메모리 변화를 확인했습니다. 이 글의 명령과 옵션은 과거 Java 8 계열 환경을 설명하는 예시입니다. 이어서 실제로 조정한 Web·Collector 설정과 당시 결과를 함께 정리합니다.

튜닝 필요 여부 판단

GC 튜닝을 공부하면서 Naver D2 글에 나온 다음 기준을 참고했습니다.

이 숫자를 모든 서비스의 정상·장애 기준으로 사용한 것은 아닙니다. 서비스가 허용하는 지연과 현재 부하를 함께 봐야 합니다. GC 시간이 이미 짧고 업무 응답도 정상이라면 Heap 옵션보다 다른 병목을 먼저 살펴볼 수 있습니다.

jstat으로 GC 상태 확인

Java 프로세스를 찾고 1초 간격으로 GC 통계를 확인합니다.

jps -l
jstat -gcutil <PID> 1000

출력 형식의 예시는 다음과 같습니다. 실제 작업 결과 수치가 아니라 컬럼을 설명하기 위한 값입니다.

 S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
  0.00  47.02  83.14  32.01  95.72  92.11    152    6.343     3    1.512    7.855

YGCT / YGC는 누적 평균입니다. 특정 구간의 평균을 보려면 두 시점의 시간 차이를 횟수 차이로 나눠야 합니다. 평균만으로 긴 중단을 알 수는 없어 개별 GC 로그도 함께 확인했습니다.

VisualVM 연결 준비

당시에는 jstatd로 기본 모니터링 정보를 가져왔습니다. 다음은 원문에 사용한 정책 예시입니다.

grant codebase "file:${java.home}/../lib/tools.jar" {
   permission java.security.AllPermission;
};

jstatd -J-Djava.security.policy=/tmp/tools.policy

추가 정보를 보기 위해 대상 JVM의 JMX도 활성화했습니다. 아래는 인증과 TLS를 끈 당시 내부 진단용 예시이며, 외부 공개용 접속 설정으로 사용하지 않습니다.

-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=9898
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false

jstatd 정책과 JMX 접근은 대상 서버의 권한과 네트워크 범위에 맞춰야 합니다. 프로그램을 띄우는 설정과 원격에서 접근을 허용하는 설정을 함께 확인할 필요가 있습니다.

GC 로그와 Heap Dump

GC 로그를 파일로 남겨 두면 부하가 발생한 시점의 기록을 다시 볼 수 있습니다. 다음은 Java 8 계열의 로그 옵션 예시입니다.

-verbose:gc
-Xloggc:../logs/gc.log
-XX:+PrintGCDateStamps
-XX:+PrintGCDetails
-XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=5
-XX:GCLogFileSize=20m
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=../logs/heap-dump.hprof

로그와 Dump 경로는 JVM 프로세스가 쓸 수 있는 위치여야 합니다. GC 로그와 OOM 시점의 Heap Dump는 목적도 다릅니다. 전자는 수집 주기와 중단 시간을, 후자는 메모리에 남아 있던 객체를 확인하는 데 사용합니다.

저장한 GC 로그는 VisualVM의 상태 변화와 비교하고 GCEasy 분석에도 사용했습니다. 설정 변경 전후를 비교하려면 어느 구간의 부하와 로그인지 함께 남겨야 합니다.

Web과 Collector의 GC 설정 조정

Web 프로세스와 데이터를 처리하는 Collector의 GC 상태를 확인하면서 Heap과 Young 영역 설정을 조정했습니다. 당시 서버는 XenServer 위의 VM이었으므로 결과도 그 환경에서 확인한 값입니다.

처음 Collector에서는 약 2초마다 Minor GC가 발생했습니다. 이 시점의 Full GC는 확인하지 못했습니다. 이후 Heap 크기와 NewRatio, SurvivorRatio 등을 바꾸며 GC 주기와 처리 시간을 살펴봤습니다.

상태 확인과 분석 도구

실행 중인 JVM은 jstat으로 확인하고, jstatd와 JMX를 활성화해 VisualVM·Visual GC로 메모리 변화를 봤습니다. 저장한 GC 로그는 GCEasy로 분석했습니다.

당시 jstat 확인 명령은 다음과 같습니다. PID는 대상 Java 프로세스의 값으로 바꿉니다.

jstat -gcutil <PID> 5s 20

YGC와 YGCT는 Young GC 횟수와 누적 시간입니다. 출력값의 YGCT / YGC는 누적 평균입니다. 특정 구간을 비교하려면 두 시점의 증가량을 사용해야 합니다. 누적 평균만으로 가장 긴 중단 시간을 알 수는 없어 주기와 개별 로그도 함께 확인했습니다.

Web과 Collector의 설정 차이

아래는 당시 설정에서 Heap과 세대 크기 관련 옵션만 추린 것입니다. 다른 애플리케이션에 그대로 적용할 권장값은 아닙니다.

Web 서버 설정

Web 서버의 Heap은 1GB로 설정했습니다. NewRatio=3과 SurvivorRatio=6을 사용했습니다.

CATALINA_OPTS="-server \
 -XX:+UseParallelOldGC \
 -Xms1g \
 -Xmx1g \
 -XX:NewRatio=3 \
 -XX:SurvivorRatio=6"

NewRatio=3은 Young과 Old의 비율을 1:3으로 지정하는 옵션입니다. 실제 세대 크기는 GC 정책과 실행 중 상태도 함께 봐야 합니다. 이 값만으로 모든 시점의 영역 크기를 고정했다고 판단하지는 않습니다.

Collector 설정

Collector는 객체 생성이 많아 Eden이 빠르게 차고 있었습니다. Heap은 2GB, NewSize는 1536MB로 두고 SurvivorRatio=20을 사용했습니다.

CATALINA_OPTS="-server \
 -XX:+UseParallelOldGC \
 -Xms2g \
 -Xmx2g \
 -XX:NewSize=1536m \
 -XX:SurvivorRatio=20"

Young 영역을 늘리면 Minor GC 간격을 늘릴 수 있지만 고정된 Heap에서는 Old 영역에 쓸 공간이 줄어듭니다. Survivor도 작게 만들수록 좋은 것은 아닙니다. 살아남은 객체가 Survivor에 들어가지 못하면 Old로 이동할 수 있으므로, Eden 크기와 프로모션을 함께 확인해야 합니다.

NewSize는 Young 영역의 하한을 지정합니다. 이 설정에는 상한인 MaxNewSize를 같은 값으로 두지 않았으므로, Young 영역이 항상 1536MB로 고정되는 구성은 아닙니다.

jstat 확인 결과

설정 변경 후 원문에 남긴 jstat 출력의 평균값과 당시 확인한 주기는 다음과 같습니다.

이 값은 당시 확인 구간의 결과입니다. 튜닝 전후의 모든 지표를 같은 기간과 부하에서 측정한 비교표는 아닙니다.

GCEasy 분석 결과

Web과 Collector의 GC 로그 분석 결과도 따로 남겼습니다.

Collector의 Minor GC 주기는 처음 약 2초에서 약 10초로 조정됐습니다. 다만 Web은 당시 uptime이 짧았고 두 프로세스의 로그 구간도 다르므로, 이 표를 동일 조건의 성능 순위로 읽을 수는 없습니다.

이번 작업에서는 프로세스마다 메모리 사용을 따로 보고 설정을 바꾼 뒤 GC 로그로 다시 확인했습니다. Parallel GC의 과거 설정 기록이며, 다른 GC나 JVM 버전의 기본 설정을 제안하는 글은 아닙니다.

참고 자료

• Oracle Java 8 GC Tuning Guide: 세대 크기와 Survivor 설정 
• Naver D2: Garbage Collection 튜닝 
• Oracle Java 8: jstat