Ankur
e189da79ba
Complete companion suite for the ankurm.com guide. Everything was compiled and
executed on java 25.0.3+9-LTS-195 (AMD Ryzen 5 5600U, Windows 11); every file
under results/ is unedited program output.
Code
latency/ open-loop latency harness that measures from intended arrival, so
coordinated omission is accounted for rather than hidden. Reports
response time and service time side by side; the gap reached 2910x
on G1.
jmh/ four microbenchmarks isolating one mechanism each: TLAB allocation,
the ZGC load barrier (with a primitive-load control), the write
barrier (with null / old-to-old / primitive controls), and promotion
pressure.
tuning/ provokes ZGC allocation stalls and reads its own JFR recording back,
grouped by page class. jdk.ZAllocationStall is enabled without a
threshold, because the 10 ms default hides most stalls.
internals/ ZGC page classes vs G1 humongous, read from the live VM via
HotSpotDiagnosticMXBean and jdk.ZPageAllocation events.
analysis/ unified GC log parser that keeps stop-the-world pauses and
concurrent phases in separate buckets.
env/ environment capture; proves generational mode from JMX bean names.
Docs
Eight chapters covering the JEP 439/474/490 timeline, colored pointers and both
barriers, allocation stalls, a full flag reference, logging and JFR, benchmark
methodology, corner cases, and a decision procedure.
Headline result (60 s, 20k req/s, 2 GB heap, ~585 MB live)
p50 ZGC 0.006 ms G1 0.005 ms
p99.9 ZGC 1.437 ms G1 95.169 ms
total STW time ZGC 1.503 ms G1 1,139.624 ms
41 lines
1.9 KiB
Plaintext
41 lines
1.9 KiB
Plaintext
==============================================================================
|
|
GC log analysis: g1-latency.log
|
|
==============================================================================
|
|
lines parsed : 1,257
|
|
young / minor cycles : 94
|
|
old / major cycles : 0
|
|
ZGC allocation stalls : 0
|
|
G1 evacuation failures : 16
|
|
full GCs : 4
|
|
|
|
STOP-THE-WORLD PAUSES (this is application freeze time)
|
|
count : 68
|
|
total : 1,139.624 ms
|
|
mean : 16.759 ms
|
|
p50 : 12.857 ms
|
|
p99 : 104.449 ms
|
|
max : 104.449 ms
|
|
|
|
by phase
|
|
Pause Young (Normal) n=17 total= 403.699 ms max=103.308 ms
|
|
Pause Young (Concurrent Start) n=11 total= 153.384 ms max= 20.587 ms
|
|
Pause Remark n=10 total= 13.736 ms max= 1.745 ms
|
|
Pause Cleanup n=9 total= 2.472 ms max= 0.438 ms
|
|
Pause Young (Prepare Mixed) n=8 total= 110.491 ms max= 24.639 ms
|
|
Pause Young (Mixed) n=11 total= 247.284 ms max= 30.879 ms
|
|
Pause Full n=2 total= 208.558 ms max=104.449 ms
|
|
|
|
CONCURRENT PHASES (application keeps running -- NOT freeze time)
|
|
Concurrent Scan Root Regions n=11 total= 12.317 ms max= 1.867 ms
|
|
Concurrent Mark From Roots n=11 total= 191.931 ms max=102.516 ms
|
|
Concurrent Preclean n=10 total= 0.265 ms max= 0.050 ms
|
|
Concurrent Mark n=10 total= 106.217 ms max= 14.524 ms
|
|
Concurrent Rebuild Remembered Sets and Scrub Regions n=10 total= 146.586 ms max=113.784 ms
|
|
Concurrent Clear Claimed Marks n=9 total= 0.227 ms max= 0.039 ms
|
|
Concurrent Cleanup for Next Mark n=9 total= 31.227 ms max= 4.862 ms
|
|
Concurrent Mark Cycle n=11 total= 406.062 ms max=125.183 ms
|
|
|
|
Adding the block above to the pause block would be a category error:
|
|
concurrent time overlaps application execution by design.
|
|
|