Long GC Pauses in Java: How to Find the Real Cause

A long GC pause, and 0.09 s of CPU behind it

A colleague pinged me with one line and a paste. "GC pause is 400 ms, the collector is supposed to do 200. Which flag?" The paste had the shape of this line, which I reproduced in the lab below:

[4.805s][info][gc,cpu] User=0.07s Sys=0.02s Real=0.40s

I couldn't answer him from that line alone, and neither can you, yet. Look at it again. The collector spent 0.09 seconds of CPU and the clock moved 0.40. For about 300 ms of that pause, nothing was collecting anything. Long GC pauses are the symptom everybody tunes first, and "tune the collector" is the right answer less often than you'd think.

This article is the triage I wish I'd had written down. Environment for every number below: OpenJDK 21.0.12.1 (Ubuntu build), Linux x86-64, two cores, G1 unless I say otherwise. I did not run JDK 17 or 25, so where I talk about them it's from JEPs and bug reports, and I'll say so.

What's going on, roughly

A GC pause is a stretch of wall-clock time in which your application threads are stopped. The collector does work during it, and that work has a CPU cost you can read off the log. Everything else in that stretch is waiting: for threads to reach a safepoint, for the kernel to give the process CPU, for pages to come back from disk, for a lock.

So the first question is never "which GC flag". It's: how much of this pause was the collector working? The Real versus User+Sys pair answers it in ten seconds. If Real is far bigger than what the threads burned, the collector isn't your problem, and tuning it is a very effective way to waste a week.

When the collector was working, there are two usual suspects on G1: evacuation failure, where it ran out of room to copy survivors, and a big pile of live references. Both show up as named phases in the log if you turn on gc+phases=debug. The decision tree is further down.

A lab in four parts, one cause each

I spent the better part of two days on this, and I got the first lab wrong. I put the JVM in a throttled cgroup, saw 1 to 2 ms pauses, and concluded throttling didn't matter. It matters; my heap was empty. A pause that finishes inside one scheduler period never gets throttled. More on that in a minute.

What you need. Linux with root (or Docker), a JDK 21, nothing else. I used OpenJDK 21.0.12.1 from the Ubuntu package. java -version prints openjdk version "21.0.12.1" 2026-08-18. Jar-free, single-file programs, everything compiled with javac.

Part 1: the CPU quota

// Live.java — ~2 million small live objects, constantly overwritten
import java.util.*;
public class Live {
    static Object[] slots = new Object[2_000_000];
    public static void main(String[] a) throws Exception {
        long end = System.currentTimeMillis() + Long.parseLong(a[0]) * 1000;
        Random r = new Random(1); int i = 0;
        while (System.currentTimeMillis() < end) {
            slots[r.nextInt(slots.length)] = new long[8 + r.nextInt(8)]; // ~100 B live objects, so young GCs have real copying to do
            if (++i % 50_000 == 0) Thread.sleep(1);
        }
    }
}

Baseline first:

javac Live.java
java -Xmx1g -Xms1g -XX:+UseG1GC -XX:ParallelGCThreads=4 -Xlog:gc,gc+cpu:stdout Live 12

Expected: young pauses around 40 to 60 ms early on, and the gc+cpu line showing Real at or below User+Sys, because four threads share the work. Mine: GC(3) 58.676ms, User=0.07s Sys=0.04s Real=0.06s.

Now cap the process at a fifth of one CPU. On a laptop with Docker, docker run --cpus=0.2 ... does the same thing (I did not run the Docker variant; I used a raw cgroup v1 directory, because that's what this sandbox had):

mkdir /sys/fs/cgroup/cpu/lab
echo 100000 > /sys/fs/cgroup/cpu/lab/cpu.cfs_period_us
echo 20000  > /sys/fs/cgroup/cpu/lab/cpu.cfs_quota_us    # 20 ms of CPU per 100 ms, shared by every thread in the group
bash -c 'echo $$ > /sys/fs/cgroup/cpu/lab/cgroup.procs; exec java -Xmx1g -Xms1g -XX:+UseG1GC -XX:ParallelGCThreads=4 -Xlog:gc,gc+cpu:stdout Live 12'

What I saw:

[1.507s][info][gc,cpu] User=0.05s Sys=0.03s Real=0.40s
[4.805s][info][gc,cpu] User=0.07s Sys=0.02s Real=0.40s
[9.201s][info][gc,cpu] User=0.06s Sys=0.04s Real=0.50s

CPU work: about 0.10 s each. Pause: 0.40 to 0.50 s. cpu.stat for the group said 316 of 322 scheduler periods were throttled. That's the container-limit failure in one picture: four GC threads burn the 20 ms budget in about 5 ms of wall time, then every thread in the process, including the ones that were supposed to be stopped and the ones finishing the pause, sits frozen until the next period starts.

The dead end. My first throttled run used Churn, a program with almost no live data, and a 10% quota. Pauses were 1.1 ms and 2.0 ms. I wrote "throttling doesn't show up in pauses" in my notes. It was true for that heap and useless in general. Short pauses fit inside the budget; long ones don't. The pauses that exceed the quota are exactly the ones you're being paged about.

A detail worth knowing. With a quota under one CPU, the JVM doesn't see a fraction. -Xlog:os+container=trace printed CPU Quota is: 10000, CPU Period is: 100000, then OSContainer::active_processor_count: 1. Rounded up to one. So the JVM believes it has a whole core, sizes its GC thread count as if it did, and the kernel hands it a tenth of one. (I forced four GC threads here to make the effect obvious; with one, the effect is smaller, but it's still there.)

Part 2: evacuation failure

// Evac.java — everything we allocate stays live for a sliding window
import java.util.*;
public class Evac {
    static ArrayDeque<byte[]> live = new ArrayDeque<>();
    public static void main(String[] a) {
        long end = System.currentTimeMillis() + 25_000;
        long liveBytes = 0, limit = Long.parseLong(a[0]) * 1024 * 1024;
        while (System.currentTimeMillis() < end) {
            byte[] b = new byte[4096];
            live.add(b); liveBytes += b.length;
            while (liveBytes > limit) liveBytes -= live.poll().length;   // window of ~limit MB of live data
        }
    }
}

java -Xmx2g -Xms2g -XX:+UseG1GC -XX:G1ReservePercent=0 -Xlog:gc,gc+cpu:stdout Evac 1900

Forcing levers: production doesn't run with G1ReservePercent=0 (the default is 10, product, G1 only) and doesn't keep 95% of its heap live. I'm taking the safety margin away so the failure happens in seconds.

On 21.0.12.1 I got:

[2.033s][info][gc] GC(22) Pause Young (Normal) (G1 Evacuation Pause) (Evacuation Failure) 1993M->1998M(2048M) 16.521ms
[20.255s][info][gc] GC(681) Pause Young (Normal) (G1 Evacuation Pause) (Evacuation Failure) 2031M->2035M(2048M) 139.245ms

Over 25 seconds: 424 pauses marked (Evacuation Failure) and 212 Pause Full (G1 Compaction Pause), worst Full at 125.3 ms. Note the heap numbers: 2031M->2035M. After the pause, heap use went up. That's the signature. G1 couldn't copy survivors out, so it left them where they were.

The second dead end, which cost me an hour. I grepped for To-space exhausted, the phrase every blog post and old bug report uses, and got zero hits on a log that obviously had evacuation failures. I assumed the lab was broken. It wasn't: on 21.0.12.1 the failure is appended to the pause line itself. That matches the proposal in JDK-8269022 ("Put evacuation failure string directly into gc=info log message"). The bug page didn't list a fix version when I fetched it, so I can't tell you which release changed it. I can tell you that if your alerting greps for To-space exhausted, check it still matches on your JDK.

With -Xlog:gc+phases=debug a failed pause grows an extra phase, Remove Self Forwards, and an Evacuation Failure Regions count. In my small-heap run (128 MB, 115 MB live) one failing pause listed 3 regions, 758 objects, 3,116,896 bytes in that phase. In production the numbers are bigger. JDK-8257774 describes a JDK 11 case where a 435 ms pause spent 363.9 ms in "Evacuation Failure"; the reporter reproduced it on JDK 15 and at tip. I did not confirm if or when that issue was fixed.

Here's the part that surprised me. At 128 MB the failing pauses were cheap: 6.0 ms at worst, against 15.4 ms for the worst non-failing young pause. But there were 2,620 of them and 1,310 Full GCs in 15 seconds. A failed evacuation isn't expensive by itself. It's the signal that the next step is a Full GC, and

Part 3: a pile of references

// Refs.java (excerpt) — 3M WeakReference objects held strongly, referents already dead
for (int i = 0; i < n; i++) refs.add(new WeakReference<>(new Object()));
for (int k = 0; k < 3; k++) System.gc();

java -Xmx2g -Xms2g -XX:+UseG1GC -Xlog:gc,gc+phases=debug:stdout Refs weak 3000000

I expected Reference Processing to be the villain. A full GC logged Pause Full (System.gc()) 182M->108M(2048M) 280.729ms, and inside it:

Phase 1: Reference Processing 27.761ms

A second run gave Reference Processing 29.836ms next to Mark live objects 171.991ms. So reference processing was about a tenth of the pause. The rest was the plain cost of walking 3 million live WeakReference objects. The accurate sentence is "this pause is long because the live set is large", not "because of references". In the same run a young collection logged Reference Processing: 4.72ms at the gc+phases=debug level. On this lab, ParallelRefProcEnabled printed true (product, default on 21.0.12.1), so the work was already spread across threads.

I tried the same thing with 3 million objects that override finalize(). It didn't reproduce anything: my objects died young and the log showed Reference Processing at 0.015 ms. I'm not going to tell you finalizers don't cause long pauses (they have a long history of it); I'm telling you I couldn't make this lab show it.

Part 4: what I could not reproduce

Swap and transparent huge pages. The sandbox has no swap, and /sys/kernel/mm/transparent_hugepage/enabled says [madvise], so the JVM only gets huge pages if you ask. Both of these produce the same log shape as the CPU quota (Real much larger than User+Sys), and I can't show you a log of them. I'm leaning on a Red Hat knowledge base entry that lists swap and paging as a cause of that gap, and says to compare sar swap and paging metrics against the timestamps of the long collections.

Cleanup. rmdir /sys/fs/cgroup/cpu/lab after the processes exit, and delete any .log files. Nothing here writes heap dumps.

What a pause is made of

A pause line is one number made from several parts. Writing them out in order is most of the diagnosis:

1. Time to safepoint. The VM asks every Java thread to stop and waits. This sits before the collector starts, and it isn't in the pause time in the gc log line. I wrote it up in safepoints in the JVM; one thread in a long counted loop can add seconds that no GC log line mentions.
2. Collector work. Root scanning, evacuation or marking, reference processing, cleanup. This is the part tuning changes.
3. Waiting while the collector runs. The process isn't scheduled (CPU quota, a noisy neighbour, a busy host), a page it needs is on disk (swap), or the kernel is zeroing a huge page.
4. After the pause. Threads restart, caches are cold. Not in the log; it's why your p99 can look worse than the pause says.

The CPU numbers cover part 2 only. The Real figure covers 2 and 3. And -Xlog:safepoint reports part 1. Compare the three and you know which part is long.

                  long pause reported
                          |
          -Xlog:safepoint: is TTSP the big number?
              yes ---------------> a thread was slow to stop: not the collector
              no
                          |
          gc+cpu: Real >> User+Sys ?
              yes ---------------> collector was waiting: CPU quota, swap, THP, noisy host
              no
                          |
          gc+phases=debug: which phase is long?
         /               |                 \
 Evacuation Failure   Reference Processing   Scan/Evacuate with huge live set
 (G1 only)            (see weak/soft/final)  (heap sizing, allocation, young gen)

Version by version

This is where I'm weakest, and I'd rather say it than guess. What I verified against 21.0.12.1: the (Evacuation Failure) text on the pause line, no To-space exhausted line, the phase names Remove Self Forwards, Evacuation Failure Regions, Reference Processing, and the flag defaults printed in the lab. What I did not run: JDK 17, JDK 22+, JDK 25.

Things I'm taking from documents rather than runs:

JDK 9    G1 becomes the default collector (JEP 248); unified logging arrives (JEP 158)
JDK 10   Thread-local handshakes (JEP 312): some stop-the-world operations stop one thread, not all
JDK 21   (this lab) Evacuation failure on the pause line; ParallelRefProcEnabled=true
JDK 11 -> 15  JDK-8257774 reproduced: burst of humongous allocations then failed evacuation

If you run another LTS, run the four labs there. Each takes under a minute.

The flags everyone copies

A hot Slack thread about a long pause always ends with somebody pasting a flag line. These are the ones I see.

-XX:MaxGCPauseMillis=50 (product, G1; the default is 200 ms). It's a goal G1 uses to choose how much to collect per pause. If the pause is long because the CPU was throttled, or because evacuation failed, G1 can't plan its way out. The only effect I've seen on a throttled container is smaller young generations and more frequent pauses.

-XX:ParallelGCThreads=N to "use more cores". Under a CPU quota, more threads burn the budget faster and then everything waits. In my throttled run, four GC threads under a 20% quota gave 0.40 to 0.50 s pauses for 0.10 s of work. More threads would have made that ratio worse.

-XX:+DisableExplicitGC. It stops System.gc() from triggering a Full GC, which sounds great until something relied on it to free DirectByteBuffer memory. Check before you set it; the native memory story belongs to the native memory article.

A bigger heap for an evacuation-failure problem. Sometimes right. If the cause is a burst of large allocations, though, a bigger heap delays it and the pause gets longer when it finally arrives. I covered that mechanism in G1 humongous objects.

The fix, in the order I'd try it

Cause before cure. I'll give them in the order you should try them, because the first two cost nothing and the last one costs a lot.

If Real >> User+Sys. The collector isn't slow; the process isn't running. Raise or remove the CPU limit (resources.limits.cpu in Kubernetes: a limit smaller than the burst the GC needs is the usual culprit; a request without a limit is much safer for latency-sensitive JVMs). Check swap (vmstat 1, the si/so columns). Check whether the host is overcommitted. A GC flag cannot fix any of these.

If the pause is marked (Evacuation Failure). G1 ran out of space to copy into. Find out why before sizing: look at the gc+heap before/after numbers, at whether humongous allocation precedes it, at whether a burst of survivors came in. Then: more headroom (-XX:G1ReservePercent, product, default 10, G1 only), or a larger heap, or fewer large short-lived allocations. The last one is a code change and it's the best of the three. A pre-allocated buffer pool or a different data shape often beats any flag.

If Reference Processing is the long phase. Count the references. Millions of WeakReference/SoftReference/PhantomReference objects, or heavy use of finalize() (deprecated for removal since JDK 18, JEP 421), are the usual sources. Cache libraries and ORMs can create them in quantity without you writing one. Fix by reducing them. Make sure ParallelRefProcEnabled is not turned off by an old flag file.

If the live set is big. The pause is long because there is a lot to copy or mark. That's a collector-choice or heap-shape problem, and it is the case where changing the collector is reasonable. I'd read choosing a Java garbage collector before trying anything.

Which "fixes" aren't fixes: raising -Xmx blindly, setting -XX:MaxGCPauseMillis lower and lower, adding GC threads under a quota, and anything that silences the log line.

The metrics worth graphing

Four numbers, from the GC log or from JMX:

• Pause Real per collection (Micrometer: jvm.gc.pause; verify the tag names on your version). Alert on your p99 against the latency budget, not the average.
• Real / (User+Sys) per pause. In healthy parallel pauses it's below 1; sustained values above ~1 mean the collector is waiting. I'd page on that before I paged on a long pause.
• Time to safepoint, from -Xlog:safepoint. Keep it on at info; the overhead is small.
• Container CPU throttling: nr_throttled and throttled_time in cpu.stat, or the equivalent metric from your platform. If it moves when GC pauses move, you've found it without reading a single GC log.

Version safety: the strings I'd watch across an upgrade are the (Evacuation Failure) wording and any phase name your dashboards parse. Parsers that look for To-space exhausted will go silent, not loud. Test log parsing on the new JDK before you test performance on it.

I should be honest that this came together over about two days and one wrong conclusion, and that the cleanest takeaway from it isn't a flag. It's a habit: read the CPU line first.

What to remember

• A long pause is a stretch of wall-clock time. Compare Real with User+Sys before you touch a flag.
• Real far above CPU time means the collector was waiting: CPU quota, swap, a busy host.
• On JDK 21 an evacuation failure shows up as (Evacuation Failure) on the pause line, not as To-space exhausted; the real cost is the Full GC that tends to follow.
• A large Reference Processing number is often a large live set in disguise. Measure the phase, not the vibe.
• Time to safepoint is a separate number. If you aren't logging it, you can't rule it out.

Questions people ask about long GC pauses

What is a long GC pause? One that exceeds your latency budget, not a fixed number. For a service with a 200 ms target, a 400 ms pause is long; for a batch job, it isn't. Use p99, not the mean.

Why is GC real time higher than user plus sys time? The collector was waiting rather than running: the process was CPU-throttled, parts of the heap were swapped out, or the host was busy. Red Hat's guidance lists swapping as a cause and recommends checking sar swap and paging data around the long pauses.

Does a bigger heap shorten GC pauses? Not reliably. It makes young collections less frequent, but evacuation failure and a large live set get worse, not better. Fix the cause first; see heap sizing in containers.

How do I turn on the logging to diagnose it? -Xlog:gc*,gc+cpu,safepoint for the first pass, and gc+phases=debug once you know which collection to look at. The syntax is in the GC logs field guide.