힙은 남았는데 서비스가 멈췄다 · GC 로그를 읽는다 · 이론
GC 정지는 힙 사용량 그래프에 없다
한 줄 요약
JVM 힙은 짧게 사는 객체(Young) 와 오래 사는 객체(Old) 를 나눠 관리하고, GC 로그(-Xlog:gc)는 그 정리가 언제, 얼마나 오래 애플리케이션을 멈췄는지 한 줄씩 적는다. 서비스가 느려질 때 가장 먼저 열어야 하는 것이 이 로그다.
왜 이게 필요했나
"힙은 남았는데 서비스가 멈췄다" 는 이 코스 제목은 실제로 두 종류의 사건을 가리킨다. 하나는 이 모듈의 사건 — 힙 사용량 그래프는 60% 인데 응답 시간이 갑자기 3초씩 튄다. 원인은 GC 정지(pause)였다. 정리할 것이 많아지면 JVM 은 애플리케이션 스레드를 전부 세우고(stop-the-world) 청소한다. 힙이 남았다는 것과 청소가 빠르다는 것은 다른 이야기다. 다른 하나는 다음 모듈의 사건 — 힙도 GC 도 멀쩡한데 스레드가 전부 막혀 있다. 둘을 구별하는 첫 도구가 GC 로그다. 로그에 긴 정지가 없으면 범인은 GC 가 아니다.
이 코스가 JVM 을 다루는 이유는 한국 시장의 수요다. 2026-09-11 채용 공고 집계에서 Java 는 전체 160건(16.7%)이지만 한국 6개 회사에서는 108건(38.0%)으로 해외(8.3%)의 네 배가 넘었다. 공고가 "JVM 튜닝 경험", "장애 분석" 을 적을 때 뜻하는 것이 이 모듈부터 시작한다.
어떻게 동작하나
힙 크기는 [java 명령 문서](https://docs.oracle.com/en/java/javase/21/docs/specs/man/java.html)의 -Xms(초기·최소)와 -Xmx(최대)로 정한다. 문서는 서버 배포에서 둘을 같은 값으로 두는 일이 흔하다고 적는다 — 기동 뒤에 힙이 커지느라 생기는 GC 를 피하려는 것이다. 값을 안 주면 시스템 구성에 따라 런타임에 정해지는데, 그 규칙이 -XX:MaxRAMPercentage(기본 25%)와 -XX:InitialRAMPercentage(기본 1.5625%)다. 즉 메모리 8GB 인 기계에서 아무것도 안 적으면 최대 힙은 2GB 다. 컨테이너에서는 이 "기계 메모리" 가 cgroup 한도로 읽힌다(4모듈에서 직접 잰다).
컬렉터는 [사용 가능한 컬렉터](https://docs.oracle.com/en/java/javase/21/gctuning/available-collectors.html) 문서가 세 갈래로 설명한다. Serial 은 스레드 하나로 모든 GC 를 하고 스레드 간 통신 비용이 없어 작은 데이터(문서는 약 100MB 까지라고 적는다)에 맞으며 -XX:+UseSerialGC 로 켠다. Parallel 은 처리량(throughput) 컬렉터로 여러 스레드가 GC 를 나눠 한다. G1 은 대부분의 작업을 애플리케이션과 동시에(mostly concurrent) 하는 컬렉터로, 정지 시간 목표를 높은 확률로 맞추면서 처리량도 유지하도록 설계됐고 서버급 기계에서 기본이다. 어느 것이 좋은가는 정답이 없고, 같은 부하로 돌려 정지 시간을 재 보는 것이 답이다 — 실습에서 그렇게 한다.
로그는 통합 로깅 -Xlog 로 켠다. 문서의 변환표는 옛 PrintGCDetails 가 -Xlog:gc* 에 해당한다고 적는다. -Xlog:gc:file=gc.log 는 GC 이벤트 한 줄씩을, -Xlog:gc*:file=gc.log 는 단계별 세부까지 파일에 남긴다. 실제 출력은 이렇게 생겼다(JDK 21, 실측).
[0.002s][info][gc] Using G1[0.029s][info][gc] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 16M->4M(32M) 1.683ms[0.030s][info][gc] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 19M->4M(32M) 1.005ms읽는 법 — 대괄호는 JVM 기동 뒤 경과 시간, GC(0) 은 GC 번호, Pause Young 은 젊은 세대 정지, 16M->4M(32M) 은 정리 전 → 정리 후(전체 힙), 마지막이 정지 시간이다. -Xlog:gc* 를 켜면 첫머리에 Heap Max Capacity: 64M 같은 초기화 정보가 붙고, 정지 하나가 [gc,start] 와 [gc] 두 줄로 나뉜다. Full GC 는 Pause Full 로 찍힌다 — 이것이 자주 보이면 Old 영역이 계속 차고 있다는 뜻이고, 누수이거나 힙이 작은 것이다.
살아 있는 프로세스는 [jstat](https://docs.oracle.com/en/java/javase/21/docs/specs/man/jstat.html) 으로 본다. jstat -gc <pid> 1000 5 는 1초 간격으로 5번 힙 통계를 찍는다. 열 이름은 문서가 정한다 — S0C/S1C 생존 공간 용량, EC/EU 에덴 용량·사용량, OC/OU Old 용량·사용량, YGC/YGCT Young GC 횟수·시간, FGC/FGCT Full GC 횟수·시간, GCT 전체 GC 시간. YGC 가 초당 수십씩 오르면 할당이 너무 많은 것이고, FGC 가 오르면 Old 가 차는 것이다.
[jcmd](https://docs.oracle.com/en/java/javase/21/docs/specs/man/jcmd.html) 는 같은 기계에서 같은 사용자로 띄운 JVM 에 진단 명령을 보낸다. jcmd -l 이 JVM 목록을, jcmd <pid> GC.heap_info 가 힙 요약을, jcmd <pid> VM.flags 가 실제로 적용된 플래그(-XX:MaxHeapSize= 를 포함해서)를 돌려준다. "설정 파일에는 4g 라고 적었는데" 와 "JVM 이 실제로 쓰는 값" 이 다를 때 VM.flags 가 판정한다.
현장에서 만나는 모습
가장 흔한 것은 로그를 아예 안 켜 둔 서비스다. 장애가 난 뒤에 켤 수는 없다. 두 번째는 -Xmx 를 기계 메모리 전부로 잡는 것 — JVM 은 힙 밖에도 메타스페이스·스레드 스택·코드 캐시·직접 버퍼를 쓰므로 힙이 기계 메모리에 닿으면 OS 가 프로세스를 죽인다. 세 번째는 정지 시간을 평균으로 보는 것이다. 평균 5ms 뒤에 800ms 짜리 Full GC 가 하루 세 번 숨어 있다. 최댓값과 분포를 봐야 한다. 실습에서 로그에서 최대 정지를 뽑는 이유다.
다음 실습에서 할 것
/opt/lab/fixtures/jvm/Churn.java 를 컴파일해 -Xlog:gc 로 로그를 만들고, -Xlog:gc* 세부 로그에서 Young 정지 수를 세고, -Xmx64m 과 -Xmx256m 의 정지 횟수를 비교하고, 최대 정지 시간을 뽑고, jstat -gc 로 살아 있는 프로세스를 관찰하고, Serial 과 G1 을 같은 부하로 견주고, jcmd 로 힙 정보와 실제 플래그를 받는다.