이론은 CH 01에서 끝났어요. 이번 장은 실전 진단입니다. 새벽에 타임아웃 알림이 울렸을 때, -Xlog:gc* 출력 몇 줄에서 pause 시간·원인·힙 변화를 읽어 "누수냐, 힙 부족이냐, 과도한 승격이냐"를 5분 안에 가려내는 감각 — 그게 목표예요. 케이스 4개를 증상 → 로그 단서 → 원인 → 처방 흐름으로 파고듭니다.
-Xlog:gc* 로그에서 pause·cause·before/after heap·phase를 항목별로 읽어낼 수 있어요.-Xlog:gc* 한 줄에서 무엇을 읽나Java 9부터 GC 로그는 통합 로깅(Unified Logging)으로 바뀌었어요. -Xlog:gc*:file=gc.log:time,uptime,level,tags처럼 켜면 G1 기준으로 아래 같은 줄이 쏟아집니다. 겁먹지 말고 네 조각만 골라 읽으면 돼요.
[2026-07-09T02:14:33.512+0900][45.113s][info][gc,start] GC(142) Pause Young (Normal) (G1 Evacuation Pause)
[2026-07-09T02:14:33.531+0900][45.132s][info][gc,phases] GC(142) Pre Evacuate Collection Set: 0.2ms
[2026-07-09T02:14:33.531+0900][45.132s][info][gc,phases] GC(142) Evacuate Collection Set: 16.4ms
[2026-07-09T02:14:33.531+0900][45.132s][info][gc,phases] GC(142) Post Evacuate Collection Set: 1.1ms
[2026-07-09T02:14:33.531+0900][45.132s][info][gc,heap ] GC(142) Eden regions: 240->0(232)
[2026-07-09T02:14:33.531+0900][45.132s][info][gc,heap ] GC(142) Survivor regions: 8->16(30)
[2026-07-09T02:14:33.531+0900][45.132s][info][gc,heap ] GC(142) Old regions: 512->524
[2026-07-09T02:14:33.531+0900][45.132s][info][gc ] GC(142) Pause Young (Normal) (G1 Evacuation Pause) 3840M->2612M(6144M) 18.9ms| 읽을 조각 | 로그에서 어디 | 왜 중요한가 |
|---|---|---|
| pause 시간 | 줄 끝 18.9ms | 이 GC가 애플리케이션을 멈춘 시간. 지연 SLO와 직결 |
| 원인(cause) | 괄호 (G1 Evacuation Pause) | 왜 GC가 트리거됐나. Allocation Failure·Metadata GC Threshold·System.gc()·G1 Humongous Allocation 구분 |
| before→after(heap) | 3840M->2612M(6144M) | GC 전 사용량 → 후 사용량 (전체 힙). after가 계속 우상향이면 누수 의심 |
| phase(단계) | gc,phases 줄들 | 어느 단계가 오래 걸렸나. Evacuate Collection Set이 길면 복사량 과다 |
3840M->2612M은 이번 GC가 1228M를 회수했다는 뜻이에요. Full GC가 돌았는데 5900M->5850M(6144M)처럼 거의 안 줄어든다면 회수할 게 없다는 것 — 전형적인 메모리 누수/힙 부족 신호입니다. 반대로 확 줄면 아직 여유가 있는 거예요.-XX:+DisableExplicitGC 검토.
To-space exhausted 또는 Evacuation Failure가 보이면 위험 신호예요 — 살릴 객체를 옮길 공간이 부족해 G1이 Full GC로 후퇴한 상황입니다.
GC 건강을 재는 지표는 5가지예요. 각각 "이 정도면 정상"이라는 감을 가지고 있어야 로그를 봤을 때 이상을 짚어냅니다(수치는 워크로드마다 다르니 절대선이 아니라 감별 기준으로 보세요).
GCeasy·GCViewer에 넣으면 pause 분포와 allocation/promotion rate를 자동 계산해줘요.Old regions: 512->524가 매 GC 반복되면 승격이 누적되는 것.
둘의 관계가 핵심이에요. allocation rate가 높아도 대부분 Young에서 죽으면(promotion rate 낮음) Old는 안정적 → Full GC 안 남. 문제는 promotion rate가 함께 높을 때입니다.
OutOfMemoryError: Java heap space 또는 잦은 Full GC로 멈춤.
로그 단서Full GC 후 after heap이 거의 안 줄고 계속 우상향(5.6G->5.5G(6G)), Full GC 간격이 점점 짧아짐, gc,cpu에서 GC 시간 비중 급증.
감별① 누수: 재시작 후 다시 서서히 상승, after가 톱니 없이 우상향. ② 힙 부족: 트래픽 피크에만 발생, after는 낮게 회복되지만 Old가 자주 참. ③ 과도한 승격: promotion rate가 높고 Old가 빠르게 채워짐.
처방먼저 -XX:+HeapDumpOnOutOfMemoryError로 힙 덤프 확보 → Eclipse MAT dominator tree로 누수 주체 식별. 누수면 코드 수정(진짜 원인), 힙 부족이면 -Xmx 증설, 승격 과다면 케이스 ②로.
Evacuate Collection Set phase가 pause의 대부분을 차지 → 살아서 복사되는 객체가 많다. Survivor regions: 8->40처럼 생존자 급증, Old regions가 매 Young GC마다 증가(조기 승격).
원인Survivor 공간이 작아 age를 못 채우고 조기 승격되거나, 오래 사는 객체가 Young에 많아 복사량(live set)이 큼. 큰 배열/컬렉션이 Young을 통과.
처방Young GC pause는 복사량에 비례 → live set을 줄이는 게 핵심. G1이면 MaxGCPauseMillis를 낮춰 Young 크기를 자동 축소하게 유도, 필요 시 -XX:G1NewSizePercent·SurvivorRatio·MaxTenuringThreshold 조정. 근본은 중간수명 객체를 줄이거나 캐시를 힙 밖으로.
G1 Humongous Allocation, gc,heap에 Humongous regions: N->M이 자주 등장. 큰 byte[]/String/버퍼 할당 지점.
원인G1은 region 크기의 50%를 초과하는 객체를 humongous로 분류해 연속된 Old region에 직접 할당해요. 이 객체는 조각화·회수가 까다롭고 별도 처리라 pause를 유발.
처방① 큰 객체 자체를 분할/스트리밍해 region 절반 밑으로. ② -XX:G1HeapRegionSize를 키워(예 4M→16M/32M) 같은 객체가 humongous 기준을 넘지 않게. ③ 대용량 버퍼는 off-heap(DirectByteBuffer) 검토. region size는 2의 거듭제곱(1M~32M).
G1HeapRegionSize를 명시적으로 키우는 것만으로 humongous 할당이 사라지기도 합니다. 다만 region을 너무 키우면 낭비·pause 특성이 바뀌니 측정하며 올리세요.Integer 등 오토박싱, 반복문 안 문자열 연결, 남용된 스트림/람다 캡처, 방어적 복사, 매 호출 새 컬렉션.
처방지표가 좋아 보여도 낭비 → 할당 자체를 줄인다. 기본형/배열 사용, IntStream 등 기본형 스트림, 객체 재사용(단 신중히), 핫루프 스트림→루프. JFR의 allocation profiling(jdk.ObjectAllocationSample)으로 할당 핫스팟 지목 후 그곳만 수정.
MaxGCPauseMillis 조정 vs ZGC 전환MaxGCPauseMillis를 현실적으로 낮추고 Young/Region 튜닝. 단, 너무 낮추면 Young이 과도하게 작아져 GC 빈도·오버헤드 증가(공짜 아님).
처방ZGC 전환: SLO가 한 자릿수 ms이고 힙이 대용량이면 -XX:+UseZGC(Java 21+는 +ZGenerational). ZGC는 pause가 힙 크기와 거의 무관하게 1ms 이하. 대신 CPU·메모리(예: 컬러 포인터/배리어) 비용과 처리량 트레이드오프를 감수. 벤치로 검증 후 전환.
핵심은 변인 통제예요. 한 번에 여러 플래그를 바꾸면 무엇이 효과였는지 알 수 없어요. 개선이든 악화든 원인을 특정할 수 없으면 지식이 쌓이지 않고, 나중에 롤백도 못 합니다.
| 안티패턴 ❌ | 왜 나쁜가 · 대신 |
|---|---|
| 무작정 힙 키우기 | 누수·낭비는 그대로 지연될 뿐. 힙이 크면 오히려 Full GC pause가 더 길어질 수 있음. 원인부터 진단. |
| 여러 플래그 동시 변경 | 무엇이 효과였는지 알 수 없음 → 한 번에 하나씩. |
| 벤치 없이 추측 | 블로그 플래그 복붙은 워크로드가 다르면 해로움. 내 로그·내 부하로 측정. |
| 평균 pause만 보기 | tail이 SLO를 죽임 → p99/p99.9로 판단. |
System.gc() 남발 | 예측 못 할 Full GC 유발. 라이브러리 호출도 의심. |
-Xlog:gc*) → GCeasy/GCViewer로 pause 분포·allocation/promotion rate 시각화, JFR(Flight Recorder, -XX:StartFlightRecording)로 allocation 프로파일·핫스팟, jstat -gcutil <pid> 1s로 세대별 사용률·GC 횟수 실시간, 힙 문제는 jcmd <pid> GC.heap_dump 후 Eclipse MAT dominator tree. 순서는 언제나 측정 먼저.MaxGCPauseMillis 조정.