Full GC가 5초씩 걸릴 때 — GC 로그 읽는 법

응답 시간 그래프에 주기적으로 솟는 뾰족한 봉우리가 보인다면 GC를 의심할 시점입니다. 평소 50ms인 API가 몇 분에 한 번 5초씩 걸리는 패턴은 Full GC의 전형적인 흔적입니다. 그런데 GC 로그는 켜 놓고도 무엇을 봐야 할지 몰라 넘어가는 경우가 많습니다. 여기서는 로그를 켜는 법, 그 안에서 읽어야 할 세 가지 숫자, 그리고 힙이 부족한 것인지 누수인지 구분하는 방법을 정리합니다.

먼저 로그를 켠다

Java 9부터 GC 로그 옵션이 통합됐습니다. 예전 자료의 -XX:+PrintGCDetails는 더 이상 권장되지 않습니다.

# Java 9 이상
-Xlog:gc*:file=/var/log/app/gc.log:time,uptime,level,tags:filecount=5,filesize=20M

구간	의미
gc*	GC 관련 태그 전체
file=...	표준 출력이 아닌 파일로 분리 (애플리케이션 로그와 섞이지 않게)
time,uptime	절대 시각과 기동 후 경과 시간 — 장애 시각과 대조하려면 필수
filecount,filesize	로테이션. 없으면 파일이 무한히 커진다

오버헤드는 거의 없으니 운영에 상시 켜 두는 것을 권합니다. 장애가 난 뒤에 켜면 그때는 이미 증거가 없습니다.

로그에서 읽어야 할 세 가지

G1 GC(Java 9 이상 기본)의 로그 한 줄은 대략 이렇게 생겼습니다.

[2026-09-21T10:22:41.310+0900][312.847s] GC(148) Pause Young (Normal)
    (G1 Evacuation Pause) 2048M->512M(4096M) 38.214ms

[2026-09-21T10:24:03.887+0900][395.424s] GC(149) Pause Full
    (G1 Compaction Pause) 3891M->3702M(4096M) 4821.663ms

여기서 봐야 할 것은 셋입니다.

1. 멈춘 시간 (Pause)

줄 끝의 38.214ms, 4821.663ms가 애플리케이션이 완전히 멈춘 시간입니다. 이 순간 모든 요청이 대기합니다.

종류	정상 범위	이상 신호
Young GC	10~50ms	200ms 초과가 잦음
Full GC	거의 발생하지 않아야 정상	주기적으로 발생 · 수 초대

G1에서 Full GC는 “실패했다”는 신호입니다. G1은 원래 Full GC 없이 동시에 정리하도록 설계됐는데, 따라잡지 못해 전면 정지로 떨어진 것이기 때문입니다.

2. 회수량 (앞 → 뒤)

2048M->512M(4096M)은 “GC 전 2048MB, GC 후 512MB, 전체 힙 4096MB”라는 뜻입니다. 이 세 숫자의 관계가 진단의 핵심입니다.

# 정상 — 잘 회수된다
2048M->512M(4096M)     회수 1536M

# 경고 — 회수가 거의 안 된다
3891M->3702M(4096M)    회수 189M  ← 대부분 살아 있는 객체

두 번째처럼 GC 후에도 사용량이 거의 안 줄어들면 힙에 남아 있어야 할 객체가 너무 많다는 뜻입니다. 힙이 부족하거나 누수입니다.

3. 빈도

타임스탬프 간격을 보면 GC가 얼마나 자주 도는지 알 수 있습니다. Young GC가 몇 초에 한 번씩 돈다면 객체를 지나치게 많이 만들고 있다는 신호입니다. 개별 pause는 짧아도 합치면 무시할 수 없습니다.

# Full GC 만 추려 보기
grep "Pause Full" gc.log

# Young GC 빈도 — 시각만 뽑아 간격 확인
grep "Pause Young" gc.log | awk '{print $1}' | tail -20

부족한 것인가, 새는 것인가

증상은 비슷하지만 대응이 완전히 다릅니다. 구분 기준은 Full GC 직후의 사용량 추이 하나입니다.

# 힙 부족  — Full GC 후 사용량이 떨어지긴 한다 (다만 곧 다시 참)
3891M->1204M(4096M)
3902M->1198M(4096M)
3888M->1211M(4096M)     ← 회수 후 수준이 일정하다

# 메모리 누수 — Full GC 를 해도 바닥이 계속 올라간다
3891M->2104M(4096M)
3920M->2688M(4096M)
3950M->3301M(4096M)     ← 회수 후 수준이 계단처럼 상승

회수 후 남는 양(화살표 오른쪽)이 계속 커지면 누수입니다. 어딘가에서 객체 참조를 놓지 않고 있다는 뜻이고, 힙을 늘려도 터지는 시점만 미뤄집니다. 이 경우 힙 덤프를 떠서 범인을 찾아야 합니다. 그 과정은 OOM으로 죽은 서비스, 힙 덤프에서 범인 찾기에 정리했습니다.

로그 없이 지금 상태만 빠르게 보고 싶다면 jstat이 편합니다.

jstat -gcutil <pid> 1000 30      # 1초 간격 30회

  S0     S1     E      O      M     CCS    YGC   YGCT    FGC   FGCT
  0.00  12.50  68.31  91.24  95.10  91.88   412   8.214     7  31.402
                      ↑                                     ↑
                   Old 사용률                          Full GC 횟수

O(Old 영역)가 Full GC 후에도 떨어지지 않으면 누수 쪽입니다.

Full GC를 부르는 흔한 원인

거대 객체(Humongous Object)

G1은 힙을 region으로 나누는데, region 크기의 절반을 넘는 객체는 별도 취급되어 정리가 까다롭습니다. 조회 결과를 한 번에 다 담는 큰 리스트나 배열이 대표적입니다.

# 거대 객체 할당이 보이는지 확인
grep -i "humongous" gc.log

자주 보인다면 코드 쪽을 봐야 합니다. 페이징 없이 전체를 조회하는 쿼리가 가장 흔한 원인입니다. 목록을 통째로 메모리에 올리는 대신 커서 방식으로 나눠 읽는 구조가 필요합니다. 그 원리는 커서 기반 페이징 vs OFFSET에서 다뤘습니다.

힙 크기가 고정되지 않음

# ✗ 초기값과 최대값이 다르면 힙을 늘렸다 줄였다 하며 GC 가 더 돈다
-Xms512m -Xmx4g

# ✓ 운영 서버는 같게 잡는다
-Xms4g -Xmx4g

서버 애플리케이션은 어차피 최대치까지 쓰게 되므로, 처음부터 확보해 두는 편이 안정적입니다.

컨테이너에서 힙을 인식하지 못함

도커에서 -Xmx를 주지 않으면 JVM이 호스트 전체 메모리를 기준으로 힙을 잡는 경우가 있습니다. 컨테이너 한도를 넘어서면 GC가 아니라 OOM Killer에게 프로세스가 죽습니다. 이때는 로그도 안 남습니다.

# 컨테이너 메모리의 비율로 지정 (Java 10 이상)
-XX:MaxRAMPercentage=75.0

컨테이너 환경이라면 이 옵션을 쓰는 편이 안전합니다. 나머지 25%는 메타스페이스·스레드 스택·네이티브 버퍼가 씁니다. 힙만 컨테이너 한도에 맞추면 반드시 넘칩니다.

튜닝은 어디까지

GC 옵션을 손대기 전에 순서를 지키는 편이 낫습니다.

1. 누수부터 배제합니다. 누수라면 어떤 튜닝도 소용없습니다.
2. 객체를 덜 만드는 쪽을 봅니다. 전체 조회, 불필요한 DTO 변환, 과도한 로깅이 흔한 원인입니다.
3. 힙 크기를 조정합니다. 대개 여기까지로 해결됩니다.
4. 그래도 부족하면 목표 pause를 조정합니다.

-XX:MaxGCPauseMillis=200      # G1 이 맞추려고 시도하는 목표 (보장 아님)

이 값을 너무 작게 잡으면 G1이 한 번에 조금씩만 처리하려다 GC 빈도가 올라가 총 정지 시간이 오히려 늘어납니다. 기본값 200ms에서 크게 벗어나지 않는 편이 무난합니다.

대부분의 웹 애플리케이션은 G1 기본 설정으로 충분합니다. 옵션을 늘어놓기 전에 1~3번을 먼저 확인하십시오.

자주 묻는 질문

Q1. 힙을 늘렸더니 Full GC가 사라졌습니다. 끝난 건가요?

누수가 아니라 부족이었다면 맞습니다. 다만 힙이 커지면 Full GC 한 번의 정지 시간도 길어집니다. 4GB에서 3초였다면 16GB에서는 10초가 될 수 있습니다. 빈도가 줄어든 대신 한 번의 충격은 커진 것이므로, 회수 후 사용량 추이를 계속 지켜봐야 합니다.

Q2. G1 말고 다른 GC를 쓰면 나아지나요?

힙이 크고(수십 GB) 정지 시간이 정말 중요하다면 ZGC가 유리합니다. 다만 대부분의 문제는 GC 종류가 아니라 애플리케이션이 만드는 객체 양에서 옵니다. GC를 바꾸기 전에 회수 후 사용량 추이부터 확인하십시오. 바꿀 때는 -XX:+UseZGC 한 줄이지만, 성능 특성이 달라지므로 부하 테스트가 전제입니다.

Q3. Young GC가 100ms씩 걸립니다. 문제인가요?

절대값보다 전체 시간 중 GC가 차지하는 비율로 보십시오. 10초에 한 번 100ms면 1%라 문제가 아니지만, 1초에 한 번이면 10%라 심각합니다. jstat의 YGCT(누적 Young GC 시간)를 기동 후 경과 시간으로 나누면 대략적인 비율이 나옵니다.

Q4. 로그가 너무 많아 읽기 어렵습니다.

gc* 대신 필요한 태그만 켜면 줄어듭니다. 다만 처음 진단할 때는 정보가 많은 편이 낫습니다. 파일이 크면 grep "Pause Full"로 Full GC만 먼저 보고, 그 시각 앞뒤를 들여다보는 순서가 효율적입니다. GCViewer 같은 시각화 도구에 로그를 넣으면 추이를 그래프로 볼 수 있어 훨씬 빠릅니다.

마무리

GC 로그에서 확인할 것은 결국 세 가지입니다. 얼마나 오래 멈췄는지, 얼마나 회수됐는지, 얼마나 자주 도는지. 그중 가장 중요한 것은 회수 후에 남는 양이 시간이 갈수록 늘어나는가입니다.

이 값이 일정하면 힙 크기 문제라 조정으로 해결되고, 계단처럼 올라가면 누수라 힙을 늘려도 소용없습니다. 여기서 길이 갈리므로, 옵션을 손대기 전에 이 구분부터 하십시오.

함께 보면 좋은 글

• OOM으로 죽은 서비스, 힙 덤프에서 범인 찾기 — 누수로 판명됐을 때의 다음 단계
• Pinpoint APM 구축 가이드 — 정지 구간을 지표로 계속 지켜보기
• 커서 기반 페이징 vs OFFSET — 거대 객체를 만들지 않는 조회 방식