Diagnose growing stop-the-world (STW) GC pauses in a production service
A trading API runs on G1 with -Xmx16g -XX:MaxGCPauseMillis=50. p99 latency was stable for months; after one release it now spikes to several seconds. Traffic volume is unchanged, and heap occupancy after each collection keeps creeping up. -Xlog:gc* shows:
[3021.442s][info][gc] GC(812) Pause Young (Concurrent Start) (G1 Humongous Allocation) 14.2G->13.9G(16G) 62.418ms
[3024.905s][info][gc] GC(813) Pause Young (Normal) (G1 Evacuation Pause) 14.6G->14.4G(16G) 88.301ms
[3026.113s][info][gc] GC(814) To-space exhausted
[3026.113s][info][gc] GC(814) Pause Young (Normal) (G1 Evacuation Pause) 15.1G->15.0G(16G) 1204.772ms
[3029.550s][info][gc] GC(815) Pause Full (G1 Compaction Pause) 15.0G->12.7G(16G) 3841.006ms
[3033.884s][info][gc] GC(816) Pause Full (G1 Compaction Pause) 15.7G->13.1G(16G) 4102.559msThe 50 ms pause-time goal is never met.
Diagnose the cause.
G1 Humongous Allocation marks objects larger than half a region: they are allocated straight into the old gen and collected poorly. They fragment the heap until evacuation has no free region left (To-space exhausted), so G1 falls back to a full stop-the-world compaction — the multi-second pauses. No pause-time goal can survive a fallback full GC. Fix the allocation itself, enlarge -XX:G1HeapRegionSize, and lower InitiatingHeapOccupancyPercent so the concurrent cycle starts earlier.
- ✗Reading
To-space exhaustedas a survivor-sizing issue rather than a lack of free regions - ✗Raising the pause-time goal instead of removing the oversized allocations behind it
- ✗Assuming a rising post-collection occupancy always means an ordinary leak
- →Why does an object larger than half a
G1region skip the young generation? - →Would the low-pause collector
ZGChave avoided this failure, and at what cost?
Analysis
Read the log chain top to bottom.
G1 Humongous Allocation— the application is allocating objects larger than half aG1region. Such an object never passes through eden: it goes straight into the old gen, occupying one or several contiguous regions outright. The tail of the last region is wasted.- The heap fragments: each new humongous object needs a contiguous run of regions, while the free regions are scattered.
To-space exhausted— evacuation (copying the survivors) found no free region. This is not about survivor sizing; it means there are no free regions left at all.Pause Full (G1 Compaction Pause)—G1falls back to a full compaction of the whole heap. It is the oneG1phase thatMaxGCPauseMillisdoes not govern at all. Hence the 3.8 s and 4.1 s pauses.
Key conclusion. The pause-time goal is a budget for ordinary evacuation pauses. Once G1 is forced into a fallback full GC, the goal means nothing. Raising MaxGCPauseMillis is pointless: it does not participate in that path.
What to do.
- Remove the allocation — it is the root cause: the release started buffering a whole response into a single
byte[]/ByteBuffer. Chunk it, stream it, reuse buffers. - Enlarge the region, so fewer objects count as humongous.
- Lower the concurrent-cycle start threshold, so it begins earlier and frees regions before they run out.
- Confirm the diagnosis from the share of humongous regions.
# a larger region means fewer objects cross the humongous threshold (half a region)
java -XX:G1HeapRegionSize=32m \
-XX:InitiatingHeapOccupancyPercent=35 \
-Xlog:gc+heap=debug:file=gc.log \
-Xmx16g -XX:MaxGCPauseMillis=50 -jar app.jar
# share of humongous regions in the heap — confirmation of the diagnosis
jcmd <pid> GC.heap_info
