JVM Metaspace 실시간 모니터링

이 글에서 다루는 내용

라즈베리파이에서 운영 중인 Spring Boot 블로그 서버의 GC 로그를 들여다보다가 시작된 이야기로, tail -f로 GC 로그를 실시간으로 관찰하는 방법부터 jstat과 jcmd를 활용해 JVM의 Metaspace 상태를 진단하고 누수 여부를 판별하는 전체 과정을 정리한다. 중간에 jstat이 보여주는 MCMX 값이 실제 MaxMetaspaceSize 설정과 다를 수 있다는 함정, systemctl을 이용해 서비스 PID를 자동으로 찾아 명령어에 넘기는 쉘 패턴, 그리고 Java와 Node.js 운영의 체감 차이까지 함께 다룬다.

tail -f로 GC 로그 실시간 관찰

서버에 접속해 가장 먼저 해본 건 GC 로그를 실시간으로 흘려보는 일이었다.

tail -f /opt/ytylab/logs/gc.log

tail은 파일 끝부분을 보여주는 표준 리눅스 명령어이고, -f는 "follow" 옵션으로 파일이 닫히지 않은 채 새 라인이 추가될 때마다 실시간으로 화면에 출력한다. Ctrl+C로 중단할 수 있다.

로그 자체는 리눅스가 남기는 게 아니라 JVM 실행 시 아래와 같은 옵션으로 지정해둔 파일에 JVM이 직접 기록한다.

-Xlog:gc*:file=/opt/ytylab/logs/gc.log:time,uptime,level,tags

출력되는 G1GC 로그를 보면 사이클별 단계와 소요 시간이 찍힌다. 예를 들어 58M->58M(512M)은 "GC 전후로 힙 사용량이 거의 변하지 않았고, 전체 힙은 512MB 중 58MB를 쓰고 있다"는 뜻이고, Pause Cleanup 0.214ms는 STW 일시 정지 시간이 0.2ms에 불과하다는 의미다. 아주 건강한 상태다.

jstat으로 힙 스냅샷 찍기

로그가 "GC 이벤트의 상세 내역"이라면, jstat은 "지금 이 순간의 힙 스냅샷"이다.

jstat -gc 2912581 5000

PID 2912581번 JVM의 힙/GC 상태를 5초마다 한 줄씩 반복 출력하라는 뜻이다. 뒤에 횟수를 추가하면 그만큼만 출력하고 종료한다.

주요 컬럼은 이렇다.

S0C, S1C, S0U, S1U - Survivor 0/1 영역의 Capacity와 Used
EC, EU - Eden 영역
OC, OU - Old 영역
MC, MU - Metaspace
CCSC, CCSU - Compressed Class Space
YGC, YGCT - Young GC 횟수와 누적 시간
FGC, FGCT - Full GC 횟수와 누적 시간
GCT - 전체 GC 누적 시간

실전에서는 EU가 EC에 가까워지면 곧 Young GC가 터지고, OU가 계속 우상향하면 Old 영역 누수 의심, FGC가 자주 증가하면 STW 이슈로 판단한다.

PID를 자동으로 찾는 쉘 패턴

서비스가 재시작되면 PID는 매번 바뀐다. 매번 ps나 jps로 찾아서 복붙하는 건 번거로우니 쉘의 커맨드 치환으로 해결한다.

jstat -gc $(systemctl show blog-spring.service --property=MainPID --value) 5000

쉘은 $(...) 안쪽을 먼저 실행하고, 그 결과로 바깥 명령어를 치환한 뒤 실행한다. systemctl show는 해당 서비스의 모든 속성을 Key=Value 형태로 출력하는데, --property=MainPID로 필터링하고 --value로 값만 뽑아내면 PID 숫자 하나만 떨어진다. 이 값이 그대로 jstat의 PID 인자로 들어간다.

비슷한 대안으로 pgrep -f, jps | grep, pidof java 같은 방법이 있지만, 여러 JVM이 떠 있을 때 중복 매칭 문제가 생길 수 있다. systemctl show ... --value는 "이 서비스의 메인 프로세스"를 딱 하나 반환하므로 가장 안전하다.

반복 사용할 거라면 alias로 등록해두면 편하다.

alias blog-gc='jstat -gc $(systemctl show blog-spring.service --property=MainPID --value) 5000'

MCMX의 함정 - jstat이 거짓말을 한다

Metaspace 최대 크기가 궁금해 -gccapacity를 실행해봤는데, MCMX 값이 설정한 것보다 크게 나왔다.

MCMN   MCMX     MC      YGC  FGC
 0.0   262144   102336    10    0

-XX:MaxMetaspaceSize는 분명 160MB로 설정했는데, MCMX는 256MB로 찍혔다. 이유를 찾아보니 OpenJDK에 JDK-8077987 버그로 이미 리포트된 이슈였다. jstat의 MCMX는 "실제 설정된 MaxMetaspaceSize"가 아니라 "JVM이 예약한 가상 주소 공간 크기"(Non-class 128MB + Class 128MB)를 보여주고 있었다.

정확한 설정값을 확인하려면 jcmd를 써야 한다.

jcmd $PID VM.flags | tr ' ' '\n' | grep -iE 'metaspace|classspace'

이러면 -XX:MaxMetaspaceSize=167772160 처럼 실제 적용된 플래그만 추출된다. 그리고 VM.metaspace로 내부 구조를 상세히 볼 수 있다.

jcmd $PID VM.metaspace

출력 맨 아래 Settings 섹션에 실제 MaxMetaspaceSize: 160.00 MB 값이 나오며, Used/Committed/Reserved를 분리해서 보여준다. jstat보다 훨씬 정확하다.

실제 진단 - 블로그 서버는 누수인가 아닌가

실제 운영 중인 서버 상태는 이랬다.

MaxMetaspaceSize : 160 MB
현재 committed   : 108 MB  (67% 사용)
Non-Class        : 92.95 / 93.31 / 128 MB  (거의 꽉 참)
Class            : 14.29 / 14.59 / 128 MB  (여유)
로드된 클래스     : 23,242개 (loaders 544개)
Full GC          : 0회

수치만 보면 67% 사용으로 빡빡해 보이지만, 판단의 결정타는 jstat -class의 추이였다.

Loaded  Bytes    Unloaded  Bytes  Time
 21683  41024.5        0    0.0   18.41
 21683  41024.5        0    0.0   18.41
 21683  41024.5        0    0.0   18.41
 21683  41024.5        0    0.0   18.41

7번 샘플링하는 약 70초 동안 모든 값이 미동도 없었다. 특히 Time 컬럼(클래스 로딩/언로딩 누적 시간)이 18.41에서 꼼짝도 안 한다는 건 관찰 기간 내내 신규 클래스 로딩이 전혀 없었다는 뜻이다. 누수가 있다면 이 값이 조금씩이라도 증가해야 한다.

"사용자가 거의 없는 상태"라는 맥락을 반영하면 이 결과는 완벽히 설명된다. 이미 로드된 2.1만개의 클래스로 JVM이 steady state에 도달했고, 트리거가 없으니 새로 로드할 게 없다. Unloaded가 0인 것도 "로딩이 없으니 언로딩도 필요 없다"는 자연스러운 귀결이다.

결론은 누수 아님, 현재 조치 불필요. 다만 실트래픽이 들어오면 Jackson의 동적 Serializer 생성이나 Spring MVC의 프록시 생성으로 10~30MB 추가 증가가 예상되므로, 여유를 원한다면 다음 배포 시 MaxMetaspaceSize를 256MB로 올릴 수 있다.

Java 운영이 어려운가, 익숙하지 않은가

도중에 "Java 서버 운영 쉽지 않네, Node는 좀 쉬우려나?" 하는 생각이 들었지만, 결론은 명확하다. Node가 메모리 튜닝 측면에서 단순한 건 사실이다. --max-old-space-size 하나가 거의 전부고, Metaspace 같은 별도 영역 고민이 없다. 하지만 대신 이벤트 루프 블로킹, Promise 체인 디버깅, 싱글스레드로 인한 CPU 집약 작업 취약성 등 다른 종류의 까다로움이 온다.

정작 중요한 건 "익숙함"이다. Metaspace까지 들여다보며 진단할 수 있는 수준이라면 이미 Java 개발자 상위 10~20%에 든다고 봐도 된다. 대부분은 -Xmx 만 설정하고 OOM 나면 힙을 늘린다. 장애 상황에서 "이거 Metaspace 이슈네" 하고 10분 만에 해결하는 것과, 새 스택에서 처음부터 용어와 도구를 익히며 며칠 헤매는 것의 차이는 크다.

라즈베리파이 환경이 빡빡하다면 Java를 버릴 게 아니라, GraalVM Native Image(메모리 1/3~1/5, 기동 0.1초), Kotlin 도입(문법 간결화), Virtual Thread(JDK 21+ Loom)로 발전시키는 쪽이 투자 대비 효율이 더 좋다.

명령어 정리

GC 로그 실시간 관찰

# 로그 파일을 실시간으로 따라가며 출력 (Ctrl+C로 중단)
tail -f /opt/ytylab/logs/gc.log

서비스 PID 자동 조회

# systemd 서비스의 메인 PID만 깔끔하게 추출
systemctl show blog-spring.service --property=MainPID --value

# 변수로 저장해 재사용
PID=$(systemctl show blog-spring.service --property=MainPID --value)

jstat - 가벼운 샘플링 도구

# 힙/GC 상태를 5초마다 출력
jstat -gc $PID 5000

# 각 영역의 최소/최대/현재 Capacity 출력
jstat -gccapacity $PID

# Metaspace 전용 상세 Capacity 출력
jstat -gcmetacapacity $PID

# 사용률을 퍼센트로 출력
jstat -gcutil $PID 5000

# 클래스 로딩/언로딩 누적 지표 (누수 진단 핵심)
jstat -class $PID 5000

# 샘플 횟수 제한 (5초 간격으로 10회만)
jstat -gc $PID 5000 10

jcmd - 정밀 진단 도구

# 현재 적용된 JVM 플래그 중 Metaspace 관련만 확인
jcmd $PID VM.flags | tr ' ' '\n' | grep -iE 'metaspace|classspace'

# Metaspace 내부 구조 상세 조회 (Used/Committed/Reserved 분리)
jcmd $PID VM.metaspace

# Full GC 강제 실행 (짧은 STW 발생)
jcmd $PID GC.run

# 로드된 클래스 히스토그램 상위 30개
jcmd $PID GC.class_histogram | head -30

# 힙덤프 생성 (live 옵션으로 도달 가능한 객체만)
jcmd $PID GC.heap_dump -all=false /tmp/heap-$(date +%Y%m%d-%H%M%S).hprof

진단 플로우 단축키

# 자주 쓸 명령어는 alias로 등록
alias blog-gc='jstat -gc $(systemctl show blog-spring.service --property=MainPID --value) 5000'
alias blog-class='jstat -class $(systemctl show blog-spring.service --property=MainPID --value) 5000'
alias blog-meta='jcmd $(systemctl show blog-spring.service --property=MainPID --value) VM.metaspace'

추이 로깅 (장시간 관찰용)

# 타임스탬프 붙여 파일로 저장 (시간당 기울기 분석 가능)
jstat -gc $PID 10000 \
  | awk 'NR==1{print "TIME", $0; fflush(); next}
         {cmd="date +\"%Y-%m-%d_%H:%M:%S\""; cmd | getline t; close(cmd);
          print t, $0; fflush()}' \
  | tee -a /tmp/metaspace-trend.log

Full GC 후 언로딩 테스트

# Before 스냅샷
jstat -class $PID
jcmd $PID VM.metaspace | grep -A2 "Total Usage"

# 강제 Full GC
jcmd $PID GC.run
sleep 5

# After 스냅샷 - Unloaded 증가, MU 감소면 언로딩 정상
jstat -class $PID
jcmd $PID VM.metaspace | grep -A2 "Total Usage"