Root Causes of Increased GC Pause

Managed runtimes like JVM or V8 execute garbage collectors to free up memory on behalf of developers.

To prevent memory fragmentation, all application threads are paused to safely track and move live object references. This is known as STW (Stop-The-World).

The mere occurrence of GC is not the problem; rather, it's the prolonged duration of STW that directly leads to service outages.

This can cause issues like API timeouts, Nginx 504 errors, etc.

Root Causes of Increased GC Pause #

When GC pauses increase sharply, it's not simply due to a large number of objects. Delays skyrocket when specific patterns emerge that push the limits of memory structure and GC algorithms. I'll explain this based on G1GC.

Premature Promotion #

This is the most common and critical cause. The JVM heap is largely divided into Young Gen and Old Gen. Most objects are created and quickly disappear, so they are rapidly cleaned up in the Young Gen.

The mechanism occurs when traffic surges, causing the object allocation rate to skyrocket, and the Young Gen space quickly fills up. Objects from currently processing requests that haven't died yet are mistakenly considered long-lived and are promoted to the heavier Old Gen area.

As a result, the Old Gen area fills up rapidly, leading to frequent Full GC (Major GC) that scans the entire heap to clean it, and STW durations can spike to several seconds.

Humongous Allocation #

G1GC manages heap memory by dividing it into regions of the same size. If a single object's size exceeds 50% of a region's size, G1GC classifies it as a humongous object.

Examples include fetching tens of thousands of data records from a DB into a list at once, or allocating large image buffers.

Humongous objects are forcibly allocated directly into contiguous regions of the Old Gen, bypassing the Young Gen. This causes severe memory fragmentation and is a primary culprit for triggering Full GC, even when there's ample free space, due to a lack of contiguous regions.

Increased Marking Time due to Memory Leaks #

In Java, memory isn't completely lost like in C/C++, but there are situations where objects that are no longer used are continuously held in collections (like maps, lists) or static variables, preventing GC from reclaiming them. This is called a memory leak.

This occurs in cases such as implementing a cache directly without eviction, or not removing ThreadLocal variables.

As a result, live objects continuously accumulate in the Old Gen. GC spends most of its time traversing and marking the live object graph, and as the number of objects to mark increases, GC pause time linearly and continuously increases.

OS Level Swapping or Paging #

This is not an internal JVM issue but an infrastructure-level problem.

If the sum of heap memory allocated to the JVM and memory used by the OS exceeds the actual physical RAM, the OS writes data to the disk swap area to free up memory.

Consequently, GC needs to quickly scan objects in memory. However, if objects are swapped to disk, disk I/O occurs, and a GC that should complete at memory speed proceeds at disk speed, causing STW to skyrocket.

Example Data, Result Sets, and Option Log Monitoring #

Let's look at an example based on JVM GC tuning and logging options for JDK 11 and above.

To accurately identify the cause, it's essential to generate detailed GC logs. Add the following options to your production environment's execution script:

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

Let's look at an example of GC log analysis during a sharp increase in GC pause (gc.log).

If you examine the GC logs and see a pattern like the one below, it indicates Full GC caused by humongous objects + premature promotion.

[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 발생!

A normal Young GC was 50ms, but a 10MB object was allocated, exceeding the region size, and a 3.5s Full GC was triggered due to fragmentation.

Real-time GC Monitoring Command: jstat #

Here's how to check the real-time GC status of a JVM process every second by connecting to the server terminal. Assuming the PID is 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

The 'O' (Old Gen utilization) went from 95% to 99%, indicating it's full. The FGC (Full GC count) increased from 5 to 6, and the FGCT (cumulative Full GC time) instantly jumped by a significant 4.6 seconds (20.100 - 15.500). This is a typical sign of system paralysis.

This is how you should approach identifying and resolving the root causes of GC issues.