GC Pause 증가의 근본 원인

jvm이나 v8 같은 매니지드 런타임은 개발자 대신 메모리를 해제하기 위해 가비지 컬렉터를 실행한다.

이때 메모리 파편화를 막기 위해 살아있는 객체 참조를 안전하게 추적 및 이동시키기 위해 애플리케이션의 모든 스레드를 일시정지 시키는데 이를 stw라고 한다.

단순한 gc 발생 자체가 문제가 아니라 이 stw에 소요되는 시간이 길어지는것이 서비스 장애로 직결된다.

api timeout, nginx 504 등 원인이 될수있음

gc pause 증가의 근본 원인 #

gc pause가 급격히 늘어났을때 이유는 단순히 객체가 많아서만이 아니다. 메모리 구조와 gc 알고리즘의 한게를 찌르는 특정 패턴이 발생했을때 지연이 치솟는다. g1gc 기준으로 설명해보겠다.

premature promotion 조기 승격 #

가장 흔하면서도 치명적인 원인인데, jvm 힙은 크게 young gen, old gen으로 나뉜다. 대부분의 객체는 금방 생성되었다가 사라지믈 young gen에서 빠르게 정리된다.

발생 메커니즘은 트래픽이 몰려 객체 생성률 allocation rate이 급증하면 young gen 공간이 순식간에 꽉 찬다. gc가 미처 죽지 않은 현재 처리중인 요청의 객체들은 오래 살아남은것으로 착각해 무거운 old gen 영역으로 승격 시켜 버린다.

결과적으로 old gen 영역이 빠르게 차오르며 이를 정리하기 위해 전체 힙을 뒤지는 full gc major gc가 빈번하게 발생하고 stw단위가 수초로 치솟는다.

거대 객체 할당 humongouse allocation #

g1gc는 힙 메모리를 동일한 크기의 region으로 쪼개서 관리하는데 만약 하나의 객체 크기가 region크기의 50을 초과하면 g1 gc는 이를 거대객체 humongous object로 분류한다.

한 번에 수만건의 데이터를 list로 db에서 퍼오거나 큰 사이즈의 이미지 버퍼를 할당할때등이 있고

거대객체는 young gen을 거치지 않고 바로 old gen의 연속된 region으로 강제 할당된다. 이는 심각한 메모리 파편화를 유발하며 여유 공간이 충분함에도 연속된 공간이 부족해 full gc를 유발하는 주범이 된다.

memory leak에 의한 마킹 시간 증가 #

java에서는 c/c++처럼 메모리가 완전히 유실되지는 않지만, 더 이상 사용하지 않는 객체를 컬렉션 map, list이나 static 변수에 계속 담아두어 gc가 회수하지 못하는 상태가 잇는데 이를 누수라고 한다.

캐시를 직접 구현해놓고 evict를 하지 않거나 threadlocal 변수를 remove하지 않거나 같은경우에 발생한다.

결과적으로 old gen에 살아있는 객체가 계속 누적되고 gc는 살아있는 객체 그래프를 순회하며 마킹하는데 시간을 가장 많이 쓰는데, 이 마킹 대상이 많아지므로 gc pause 시간이 선형적으로 계속 증가한다.

os level swapping or paging #

jvm 내부 문제가 아니라 인프라 레벨의 문제다.

jvm에 할당된 힙메모리와 os가 사용하는 메모리의 합이 실제 물리적 ram을 초과하면 os는 메모리 확보를 위해 디스크 swap영역에 데이터를 쓴다.

결과적으로 gc는 메모리에 있는 객체를 빠르게 스캔해야 하는데, 객체가 디스크에 내려가있으면 디스크 io가 발생하고 메모리 속도로 끝나야할 gc가 디스크 속도로 진행되니 stw가 치솟게 된다.

예시 자료 및 결과 셋, 옵션 로그 모니터링 #

jvm gc 튜닝 및 로깅 옵션 jdk 11이상 기준으로 예시를 들어보자.

정확한 원인 파악을 위해서는 gc 로그를 상세하게 남기는것이 필수고 운영 환경 실행 스크립트에 다음 옵션들을 추가한다.

java -Xms4G -Xmx4G \
     -XX:+UseG1GC \
     -XX:MaxGCPauseMillis=200 \          # GC Pause 목표 시간을 200ms로 설정
     -XX:G1HeapRegionSize=8M \           # 거대 객체 방지를 위해 리전 크기를 명시적으로 설정 (기본은 자동)
     -Xlog:gc*,gc+age=trace,safepoint:file=/var/log/app/gc.log:utctime,pid,tags:filecount=10,filesize=50M \
     -jar my-application.jar

gc pause 급증시 gc 로그 분석 예시를 들어보자 gc.log

gc로그를 까봤을때 아래와 같은 형태가 보이면 거대 객체 + 조기 승격에 의한 full gc이다.

[2026-03-15T15:00:10.123+0900][info][gc,pause] GC(120) Pause Young (Normal) (G1 Evacuation Pause) 450M->150M(4096M) 50.123ms
[2026-03-15T15:00:15.456+0900][info][gc,humongous] GC(121) G1 Humongous Allocation 10485760B  # 10MB 짜리 거대 객체 할당됨!
[2026-03-15T15:00:15.500+0900][info][gc,pause] GC(122) Pause Full (System.gc()) 3800M->1200M(4096M) 3500.456ms # 3.5초의 치명적인 STW 발생!

정상적인 young gc는 50ms였지만 10mb 크기의 객체가 할당되며 리전 크기를 초과했고 단편화때문에 3.5s짜리 ful lgc가 터져버린것

실시간 gc 모니터링 명령어 jstat #

서버 터미널에 접속해 jvm 프로세스의 실시간 gc 상태를 1초마다 확인하는 방법이다. pid가 12345라 쳤을때

# 1000ms(1초) 간격으로 GC 상태 출력
jstat -gcutil 12345 1000

S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
  0.00 100.00  80.50  95.10  98.20  95.00   4510   45.123     5   15.500   60.623
  0.00 100.00 100.00  99.90  98.20  95.00   4511   45.150     6   20.100   65.250

O는 old gen 사용률로 95%에서 99%로 꽉찼고 FGC(count)수가 5에서 6으로 늘어나 순간 FGCT fullgc 누적시간이 무려 4.6초 20.100 - 15.500으로 증가했다 전형적인 시스템 마비 징후

이런식으로 접근하여 gc의 원인을 파악하고 해결해야한다.