Monday, February 08, 2021

Testing EpsilonGC

Lets create a small program to test EpsilonGC. 

This program would have to create enough objects to exhaust available heap memory so that the behavior of EpsilonGC can be studied.

Here is a simple program that will help us with this

class TestEpsilonGC {

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

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

This code creates byte array of 1MB size on each iteration through the loop. 

Now lets try to run this program with default garbage collector and with EpsilonGC enabled, giving it a maximum of 10MB heap space and enabling verbose:gc

Running with default gc configuration.  Here is the command and the output

java -verbose:gc -Xmx10M TestEpsilonGC
[0.032s][info][gc] Using G1
Allocating iteration: 0 Done
Allocating iteration: 1 Done
Allocating iteration: 2[0.114s][info][gc] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation) 4M->0M(10M) 3.739ms
[0.114s][info][gc] GC(1) Concurrent Cycle
 Done
Allocating iteration: 3 Done
Allocating iteration: 4 Done
Allocating iteration: 5[0.129s][info][gc] GC(1) Pause Remark 8M->8M(10M) 13.647ms
 Done
Allocating iteration: 6[0.130s][info][gc] GC(1) Pause Cleanup 8M->8M(10M) 0.203ms
[0.138s][info][gc] GC(2) To-space exhausted
[0.138s][info][gc] GC(2) Pause Young (Normal) (G1 Humongous Allocation) 8M->0M(10M) 7.786ms
[0.139s][info][gc] GC(1) Concurrent Cycle 24.785ms
 Done
Allocating iteration: 7 Done
Allocating iteration: 8[0.141s][info][gc] GC(3) Pause Young (Concurrent Start) (G1 Humongous Allocation) 4M->0M(10M) 1.592ms
[0.141s][info][gc] GC(4) Concurrent Cycle
 Done
Allocating iteration: 9 Done
Allocating iteration: 10 Done
Allocating iteration: 11 Done
[0.148s][info][gc] GC(4) Pause Remark 8M->8M(10M) 1.111ms
[0.150s][info][gc] GC(4) Pause Cleanup 8M->8M(10M) 0.145ms
[0.151s][info][gc] GC(4) Concurrent Cycle 9.700ms

As you can see, this has used G1 collector, which is the default garbage collector. You can also see that intermittent GC cycles kicking in to reclaim memory. The program ran to completion successfully indicating that the loop completed 12 iterations allocating 1.2MB of objects, using the space reclaimed by the GC.

Now lets see the same code in action with EpsilonGC configuration. 

java -verbose:gc -Xmx10M -XX:+UnlockExperimentalVMOptions -XX:+UseEpsilonGC TestEpsilonGC
[0.419s][info][gc] Using Epsilon
[0.425s][warning][gc,init] Consider enabling -XX:+AlwaysPreTouch to avoid memory commit hiccups
[0.513s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 524K (5.12%) used
Allocating iteration: 0[0.581s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 1935K (18.90%) used
 Done
Allocating iteration: 1[0.582s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 2959K (28.90%) used
 Done
Allocating iteration: 2[0.583s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 3983K (38.90%) used
 Done
Allocating iteration: 3[0.583s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 5007K (48.90%) used
 Done
Allocating iteration: 4[0.584s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 6031K (58.90%) used
 Done
Allocating iteration: 5[0.585s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 7055K (68.90%) used
 Done
Allocating iteration: 6[0.586s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 8079K (78.90%) used
 Done
Allocating iteration: 7[0.587s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 9103K (88.90%) used
 Done
Allocating iteration: 8[0.588s][info   ][gc     ] Heap: 10240K reserved, 10240K (100.00%) committed, 10127K (98.90%) used
 Done
Allocating iteration: 9Terminating due to java.lang.OutOfMemoryError: Java heap space

This has thrown OutOfMemoryError on the 10th iteration of the loop, indicating that by this time it has used up the heap space and there is not enough space left to continue with the iteration. Instead of GC kicking in, the program has terminated with the OutOfMemoryError.

How performant is EpsilonGC compared to other GC configurations? We will explore that in the next post


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


No comments:

Post a Comment