Measuring performance benefits of using EpsilonGC

Lets do a quick experiment to measure the performance benefit of using EpsilonGC.

For this, lets modify the previous program a bit adding in the code for instrumentation. We will use this modified code for our experiment

class TestEpsilonGC {

    static final int ALLOCATION_SIZE = 1024 * 1024; // 1MB
    static final int LOOP_COUNT = 12;  
    static long start;

    public static void main(String[] args) {
        start();        
        for (int i = 0; i < LOOP_COUNT; i++) {
            System.out.print("Allocating iteration: "+i);
            byte[] array = new byte[ALLOCATION_SIZE];
            System.out.println(" Done");
        }
        end();
    }
    
    static void start() {
        start = System.currentTimeMillis();
}
    
    static void end() {
            System.out.println("Time taken: "+(System.currentTimeMillis() - start)+"ms");
    }
}

Lets run this code with default GC now. We will increase the max heap size to 15M so as to allow the program to complete successfully with both the configurations. 

Here is the command and the output

java -verbose:gc -Xmx15M TestEpsilonGC

[0.012s][info][gc] Using G1
Allocating iteration: 0 Done
Allocating iteration: 1 Done
Allocating iteration: 2 Done
Allocating iteration: 3 Done
Allocating iteration: 4[0.075s][info][gc] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation) 8M->0M(16M) 2.041ms
[0.075s][info][gc] GC(1) Concurrent Cycle
 Done
Allocating iteration: 5 Done
Allocating iteration: 6 Done
Allocating iteration: 7 Done
Allocating iteration: 8 Done
[0.077s][info][gc] GC(1) Pause Remark 10M->10M(16M) 0.578ms
Allocating iteration: 9[0.078s][info][gc] GC(1) Pause Cleanup 12M->12M(16M) 0.108ms
 Done
Allocating iteration: 10[0.078s][info][gc] GC(1) Concurrent Cycle 3.002ms
 Done
Allocating iteration: 11[0.081s][info][gc] GC(2) To-space exhausted
[0.081s][info][gc] GC(2) Pause Young (Concurrent Start) (G1 Humongous Allocation) 14M->0M(16M) 2.460ms
[0.081s][info][gc] GC(3) Concurrent Cycle
 Done
[0.083s][info][gc] GC(3) Pause Remark 2M->2M(14M) 0.644ms
[0.084s][info][gc] GC(3) Pause Cleanup 2M->2M(14M) 0.116ms
[0.084s][info][gc] GC(3) Concurrent Cycle 2.742ms
Time taken: 22ms

It has taken about 22ms to complete.

Now lets run this same program with EpsilonGC enabled. Command used and output are

java -verbose:gc -Xmx15M -XX:+UnlockExperimentalVMOptions -XX:+UseEpsilonGC TestEpsilonGC

[0.010s][info][gc] Using Epsilon
[0.010s][warning][gc,init] Consider enabling -XX:+AlwaysPreTouch to avoid memory commit hiccups
[0.049s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 814K (5.30%) used
Allocating iteration: 0[0.055s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 1919K (12.50%) used
 Done
Allocating iteration: 1[0.056s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 2943K (19.16%) used
 Done
Allocating iteration: 2[0.056s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 3967K (25.83%) used
 Done
Allocating iteration: 3[0.056s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 4991K (32.50%) used
 Done
Allocating iteration: 4[0.057s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 6015K (39.16%) used
 Done
Allocating iteration: 5[0.057s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 7039K (45.83%) used
 Done
Allocating iteration: 6[0.058s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 8063K (52.50%) used
 Done
Allocating iteration: 7[0.058s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 9087K (59.16%) used
 Done
Allocating iteration: 8[0.059s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 10111K (65.83%) used
 Done
Allocating iteration: 9[0.059s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 11135K (72.50%) used
 Done
Allocating iteration: 10[0.060s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 12159K (79.16%) used
 Done
Allocating iteration: 11[0.060s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 13183K (85.83%) used
 Done
Time taken: 13ms
[0.065s][info   ][gc     ] Heap: 15360K reserved, 15360K (100.00%) committed, 13372K (87.06%) used

This has taken just 13ms as against the 22ms taken by the G1 gc configuration. There clearly is a performance advantage in using EpsilonGC. But its use will be limited to very few special cases. 

Sample code used in this post can be downloaded from https://github.com/ashokkumarta/awesomely-java/tree/main/2021/02/Garbage-Collection/EpsilonGC/Measure-of-performance-benefits