Skip to content
GitLab

Implement GC latency experiment using Java

Closed Santeri Hiltunen requested to merge Hilzu/gc-latency-experiment:master into master

I read your blog post about GC latencies and got interested how JVM GC performs against the ones you benchmarked. I implemented the test in Java as close as I can and investigated the pause times.

$ make run-java
javac Main.java
java -verbosegc -cp . Main
[GC (Allocation Failure)  65536K->69000K(251392K), 0,0262845 secs]
[GC (Allocation Failure)  134536K->138968K(316928K), 0,0318618 secs]
[Full GC (Ergonomics)  138968K->129818K(433664K), 0,0554817 secs]
[GC (Allocation Failure)  260890K->266562K(433664K), 0,0560098 secs]
[Full GC (Ergonomics)  266562K->214847K(617984K), 0,0907139 secs]
[GC (Allocation Failure)  345919K->353087K(687104K), 0,0443100 secs]
[Full GC (Ergonomics)  353087K->214823K(751616K), 0,1059893 secs]
[GC (Allocation Failure)  415015K->426767K(764416K), 0,0541766 secs]
[Full GC (Ergonomics)  426767K->214823K(882688K), 0,1095114 secs]
[GC (Allocation Failure)  427815K->426407K(1143296K), 0,0769198 secs]
[GC (Allocation Failure)  684967K->429031K(1175040K), 0,0792520 secs]

With default settings the maximum GC pause seems to be 110ms and the average 66ms on my machine. That's quite high. We can do better by using the newer low-pause G1 collector:

$ make run-java-g1
javac Main.java
java -XX:+UseG1GC -verbosegc -cp . Main
[GC pause (G1 Evacuation Pause) (young) 24M->23M(256M), 0,0146044 secs]
[GC pause (G1 Evacuation Pause) (young) 36M->38M(512M), 0,0074193 secs]
[GC pause (G1 Evacuation Pause) (young) 63M->64M(1024M), 0,0133094 secs]
[GC pause (G1 Evacuation Pause) (young) 112M->115M(1639M), 0,0237163 secs]
[GC pause (G1 Evacuation Pause) (young) 189M->190M(2131M), 0,0335968 secs]
[GC pause (G1 Evacuation Pause) (young) 287M->287M(2524M), 0,0349800 secs]
[GC pause (G1 Evacuation Pause) (young) 399M->394M(2839M), 0,0497179 secs]
[GC pause (G1 Evacuation Pause) (young) 519M->517M(3091M), 0,0521000 secs]
[GC pause (G1 Evacuation Pause) (young) 653M->646M(3292M), 0,0596223 secs]
[GC pause (G1 Evacuation Pause) (young) 790M->781M(3453M), 0,0600835 secs]
[GC pause (G1 Evacuation Pause) (young) 932M->920M(3582M), 0,0612185 secs]

Now the maximum pause time is 61ms and the average is 37ms. Much better!

The Java version is surprisingly close to the Haskell version in execution time:

$ time ./Main
        1.20 real         1.00 user         0.19 sys
$ time java -cp . Main
        1.25 real         3.82 user         1.69 sys

I'll probably expand this to a blog post.