JVM memory allocation and deallocation in this demo explained?

Question

I have a simple demo to check the details of JVM memory allocation and deallocation.

The Java Version

$ java -version
java version "1.8.0_201"
Java(TM) SE Runtime Environment (build 1.8.0_201-b09)
Java HotSpot(TM) 64-Bit Server VM (build 25.201-b09, mixed mode)

The Demo

/**
 * VM Options: -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8
 */
public class DefaultCollector {
    private static final int _1MB = 1024 * 1024;
    public static void main(String... args) {
        byte[] arr1 = new byte[2 * _1MB];
        byte[] arr2 = new byte[2 * _1MB];
        byte[] arr3 = new byte[2 * _1MB];
        byte[] arr4 = new byte[4 * _1MB];
    }
}

The GC logs

[GC (Allocation Failure) [PSYoungGen: 6516K->695K(9216K)] 6516K->4791K(19456K), 0.0019189 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap
 PSYoungGen      total 9216K, used 7408K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 81% used [0x00000000ff600000,0x00000000ffc8e6a8,0x00000000ffe00000)
  from space 1024K, 67% used [0x00000000ffe00000,0x00000000ffeadcb0,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 10240K, used 4096K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 40% used [0x00000000fec00000,0x00000000ff000020,0x00000000ff600000)
 Metaspace       used 3273K, capacity 4556K, committed 4864K, reserved 1056768K
  class space    used 357K, capacity 392K, committed 512K, reserved 1048576K
Disconnected from the target VM, address: '127.0.0.1:38815', transport: 'socket'

My Questions

1. -Xms20M -Xmx20M -Xmn10M -XX:SurvivorRatio=8 already set and eden - 8M, from - 1M, and to - 1M presented clearly, why PSYoungGen total 9216K instead of 10240K?
2. why Allocation Failure since there are spaces still in Tenured and -XX:+HandlePromotionFailure should be true in default since JDK 6 and onwards already?
3. why PSYoungGen: 6516K->695K(9216K) since the three arrays are still alive in Young Generation? is it due to the allocation failure?
4. why Metaspace taking so much memory Metaspace used 3273K? what's in there exactly if not just type information?

---

I also tried other combinations:

1. Size: 1, 1, 1, 4 => eden 70%, tenured 40%

   Why? Shouldn't all in eden instead?

2. Size: 1, 1, 1, 1 => eden 80% (~6M), tenured 0%

   Why 80% (~6M) instead of 4M in eden?

Updated

With the help of @Stephen C, I found out there is an output before the log in IntelliJ Terminal as

/usr/lib/jvm/java-8-oracle/bin/java -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:42103,suspend=y,server=n -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -javaagent:/home/hearen/Downloads/idea-IU-183.5429.30/lib/rt/debugger-agent.jar -Dfile.encoding=UTF-8 -classpath /usr/lib/jvm/java-8-oracle/jre/lib/charsets.jar:/usr/lib/jvm/java-8-oracle/jre/lib/deploy.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/cldrdata.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/dnsns.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/jaccess.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/jfxrt.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/localedata.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/nashorn.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/sunec.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/sunjce_provider.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/sunpkcs11.jar:/usr/lib/jvm/java-8-oracle/jre/lib/ext/zipfs.jar:/usr/lib/jvm/java-8-oracle/jre/lib/javaws.jar:/usr/lib/jvm/java-8-oracle/jre/lib/jce.jar:/usr/lib/jvm/java-8-oracle/jre/lib/jfr.jar:/usr/lib/jvm/java-8-oracle/jre/lib/jfxswt.jar:/usr/lib/jvm/java-8-oracle/jre/lib/jsse.jar:/usr/lib/jvm/java-8-oracle/jre/lib/management-agent.jar:/usr/lib/jvm/java-8-oracle/jre/lib/plugin.jar:/usr/lib/jvm/java-8-oracle/jre/lib/resources.jar:/usr/lib/jvm/java-8-oracle/jre/lib/rt.jar:/home/hearen/git/personal/about-java/target/classes:/usr/lib/jvm/java-8-oracle/lib/dt.jar:/usr/lib/jvm/java-8-oracle/lib/tools.jar:/usr/lib/jvm/java-8-oracle/lib/sa-jdi.jar:/usr/lib/jvm/java-8-oracle/lib/jconsole.jar:/usr/lib/jvm/java-8-oracle/lib/packager.jar:/usr/lib/jvm/java-8-oracle/lib/javafx-mx.jar:/usr/lib/jvm/java-8-oracle/lib/ant-javafx.jar:/home/hearen/.m2/repository/org/projectlombok/lombok/1.16.20/lombok-1.16.20.jar:/home/hearen/.m2/repository/junit/junit/4.11/junit-4.11.jar:/home/hearen/.m2/repository/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar:/home/hearen/.m2/repository/cglib/cglib/3.2.4/cglib-3.2.4.jar:/home/hearen/.m2/repository/org/ow2/asm/asm/5.1/asm-5.1.jar:/home/hearen/.m2/repository/org/apache/ant/ant/1.9.6/ant-1.9.6.jar:/home/hearen/.m2/repository/org/apache/ant/ant-launcher/1.9.6/ant-launcher-1.9.6.jar:/home/hearen/Downloads/idea-IU-183.5429.30/lib/idea_rt.jar jvm.allocation.DefaultCollector

I then manually use the CLI to compile and run the program as

$ javac DefaultCollector.java 
$ java -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 DefaultCollector

The output then become

Heap
 PSYoungGen      total 9216K, used 6815K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 83% used [0x00000000ff600000,0x00000000ffca7ff8,0x00000000ffe00000)
  from space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
  to   space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
 ParOldGen       total 10240K, used 4096K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 40% used [0x00000000fec00000,0x00000000ff000010,0x00000000ff600000)
 Metaspace       used 2464K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 265K, capacity 386K, committed 512K, reserved 1048576K

Apparently the big array 4M is directly into the Tenured while the other three 2M allocated in Young giving us the above results.

Answer 1

I suspect that much of this can be explained by "other things" in your JVM.

The last line of the output is evidence that you have (had) an agent attached to your JVM.

Disconnected from the target VM, address: '127.0.0.1:38815', transport: 'socket'

AFAIK, the agent is going to cause the JVM to load, compile, etc classes that your application doesn't use directly. Then the agent is going to be allocating heap objects for sockets, buffers, etc to handle the monitoring.

This will inflate both regular heap and metaspace usage.

I suggest that you repeat this experiment from the shell / command line without an agent attached. Get the GC stats by turning on GC logging via command line options.

---

Your update.

Apparently the big array 4M is directly into the Tenured while the other three 2M allocated in Young giving us the above results.

Correct. There is a threshold above which objects are allocated directly into tenured space. It can be tuned ....