If you’ve ever stared at a latency trace where p50 and p99 look boring and healthy, and then a single request sits there at 136ms with no slow query, no lock, no downstream call to blame, this one is for you. I chased that shape for a while before I accepted the boring answer: the request wasn’t slow. The whole JVM stopped, mid-request, to collect garbage, and my request just happened to be holding the thread when it did.
The thing about a stop-the-world pause is it doesn’t show up as a slow anything. It shows up as everything in flight freezing at once, and then the tail latency eats the bill. Your service didn’t do slow work. It did no work, for 136 milliseconds, because the garbage collector had the floor.
The problem
A JVM service under steady allocation load will, sooner or later, stop every application thread and reclaim memory. How long it stops depends almost entirely on which collector you picked and how much live data it has to walk. The default throughput collectors are tuned to reclaim the most memory per CPU-second, which is a great thing to optimize right up until one of those collections lands inside a request you cared about and freezes it for a tenth of a second. The pause isn’t in your code, it isn’t in your profiler’s flame graph as your time, and it doesn’t move when you optimize your handler. It’s the runtime, and the only knob that moves it is the collector.
So I built the same service three times, changed exactly one flag each time, and measured what came out the tail.
The workload
One process, one heap, one loop. It keeps a bounded cache of byte[] payloads live in the old generation, and each “request” allocates a few KB of short-lived garbage, does a little work, and every few requests swaps out a cache entry so some medium-lived objects get promoted. Steady allocation, steady promotion: the shape a real request handler makes. I timed every single request with System.nanoTime into an allocation-free histogram, and separately parsed the actual stop-the-world pauses out of -Xlog:gc. The two agree to the millisecond: the request max is the GC pause, sitting inside a request.
Heap fixed at 4g, live set around 2.5GB, two million requests after warmup, median of three runs. The only variable is the collector.
Same service, same heap, one flag changed
Longest stop-the-world pause
Throughput
The left panel is the whole story. ParallelGC’s worst pause was 136ms and G1’s was 114ms, and in both cases the slowest request in the trace was that pause: 136.5ms for Parallel, 117ms for G1, because the request unlucky enough to be running when the collector kicked in ate the entire freeze. Generational ZGC’s worst pause was 0.55 milliseconds. Same code, same load, same heap. The tail dropped by two orders of magnitude on a single flag.
And then the honest part, which is the right panel. ZGC did not give you that for free. It pushed about 103,713 ops/s against ParallelGC’s 196,768, call it half the throughput. It also has a worse typical latency: ZGC’s p99.9 request was 364µs, while ParallelGC’s p99.9 was 35µs and G1’s was 16µs. For the ordinary request, the throughput collectors are faster. ZGC’s entire pitch is the one number the others can’t promise: the tail never becomes a 100ms freeze. It’s slower on average and never catastrophic at the edge, and that trade is either exactly what you want or exactly what you don’t, depending on whether you’re paid for average throughput or for a p99.9 SLA.
One more caveat I have to put in writing, because the ratio is real but the absolute number depends on scale. Those hundred-millisecond pauses only show up because the live set is large, 2.5GB of stuff the collector has to walk. At a plain 512m heap with a ~188MB live set, the same three collectors gave 22ms, 27ms and 0.15ms. The ratio is still there (~150Ă—), but 25ms is a shrug, not a stall. The bigger your live heap, the longer the throughput collectors have to stop the world to trace it, and the more that one flag is worth. Both regimes are in the repo; I shipped the dramatic one and parked the mild one under results/attempts/.
When the heap itself is the problem
The collector is one axis. The other is how much room you gave it. A collector can only do its job if there’s headroom above your live set: the gap between what you keep alive and -Xmx is the runway the GC has to work in. Squeeze that gap and the collector has to run more often to keep up, and “more often” is not free, it’s CPU you’re spending on bookkeeping instead of requests.
Same workload, same collector this time (G1 throughout) and I only moved -Xmx. Live set around 141MB, four million requests.
G1, same load, only the heap size changes
Time spent in GC
Throughput
At 1g the service spent about a third of its time in GC and did 709,008 ops/s. Shrink the heap toward the live set and it gets worse every step: 512m, 384m, 320m, and at 256m the JVM was spending 78.2% of its wall-clock collecting garbage and running 237,667 ops/s, roughly a third of the 1g throughput, for the same work. The tail moved with it: p99.9 went from 11µs at 1g to 353µs at 256m, a 32× jump, entirely from GC frequency. Nothing changed about the requests. The heap was just too tight, so the collector ran constantly, and constant collection is a tax you pay on every request whether it allocates much or not.
This is the failure that hides behind an out-of-memory panic. The service doesn’t crash. It survives, technically, at a heap you thought was fine because it never actually OOMs. It just quietly burns most of its CPU on garbage collection and does a third of the work, and if you’re only watching for OutOfMemoryError you’ll never see it. The heap never ran out of memory, so nothing alerted, it just ran hot and slow the whole time.
The takeaway
Two knobs, and they’re the ones you set before you write a line of handler code. The collector decides the shape of your tail: ParallelGC and G1 will trace your whole live set in one stop-the-world sweep and freeze a request for a hundred-plus milliseconds doing it, generational ZGC won’t stop for more than about a millisecond but hands you roughly half the throughput and a worse average to buy that. If you’re paid for a p99.9 SLA, that’s a good trade and you should take it; if you’re paid for raw throughput and nobody’s watching the tail, it’s a bad one. Pick on purpose, not by default.
The heap size decides whether the collector you picked even has room to work. Leave real headroom above your live set: the closer -Xmx gets to what you keep alive, the more of your CPU goes to collection instead of requests, and a JVM at 78% time-in-GC is a service that’s technically up and mostly not working. It never throws the error that would tell you.
And the thing I’d tattoo on the trace if I could: your slowest request is often not a request. Before you profile your own code for a tail spike that has no slow work in it, check whether the runtime stopped the world underneath you. The harness, the Java workload, the parsed GC logs and every CSV are in the repo. These are laptop numbers (Temurin 21.0.11, arm64, 10 cores) meant to show the mechanism, not to size your fleet. The mechanism transfers, the absolute milliseconds won’t, so go measure your own before you change a flag in production.
Comments