Soft reference test of JVM

Posted by diggysmalls on Sat, 30 Oct 2021 14:57:30 +0200

Soft reference test

Test background

Test environment:

​ jdk8

​ windows

garbage collector

The default JVM parameter used by the command line viewer through PrintCommandLineFlags does not have UseParallelGC:

 xxx>java -XX:+PrintCommandLineFlags -version
-XX:InitialHeapSize=16777216 -XX:MaxHeapSize=268435456 -XX:+PrintCommandLineFlags -XX:-UseLargePagesIndividualAllocation
java version "1.8.0_251"
Java(TM) SE Runtime Environment (build 1.8.0_251-b08)
Java HotSpot(TM) Client VM (build 25.251-b08, mixed mode, sharing)

When running the test, I found that the default GC log output is as follows:

[GC (Allocation Failure) [DefNew: 4728K->280K(4928K), 0.0023187 secs] 6402K->3108K(15872K), 0.0023368 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=6 (full 0):
 def new generation   total 4928K, used 280K [0x05600000, 0x05b50000, 0x05ca0000)
  eden space 4416K,   0% used [0x05600000, 0x05600000, 0x05a50000)
  from space 512K,  54% used [0x05a50000, 0x05a961f8, 0x05ad0000)
  to   space 512K,   0% used [0x05ad0000, 0x05ad0000, 0x05b50000)
 tenured generation   total 10944K, used 2827K [0x05ca0000, 0x06750000, 0x06a00000)
   the space 10944K,  25% used [0x05ca0000, 0x05f62e50, 0x05f63000, 0x06750000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}

After specifying the Parallel Scavenge+SerialOld collector through the parameter (- XX:+UseParallelGC), the GC log is as follows:

[GC (Allocation Failure) [PSYoungGen: 4352K->500K(4864K)] 4352K->1292K(15872K), 0.0016129 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 4864K, used 500K [0x05b80000, 0x060c0000, 0x06200000)
  eden space 4352K, 0% used [0x05b80000,0x05b80000,0x05fc0000)
  from space 512K, 97% used [0x05fc0000,0x0603d2f0,0x06040000)
  to   space 512K, 0% used [0x06040000,0x06040000,0x060c0000)
 ParOldGen       total 11008K, used 791K [0x04e00000, 0x058c0000, 0x05b80000)
  object space 11008K, 7% used [0x04e00000,0x04ec5e20,0x058c0000)
 Metaspace       used 478K, capacity 2547K, committed 2624K, reserved 4480K
}

The GC log of ParNew+CMS collector specified by the parameter (- XX:+UseConcMarkSweepGC) is as follows:

[GC (Allocation Failure) [ParNew: 4416K->512K(4928K), 0.0037318 secs] 4416K->1258K(15872K), 0.0037731 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 
Heap after GC invocations=1 (full 0):
 par new generation   total 4928K, used 512K [0x04c00000, 0x05150000, 0x052a0000)
  eden space 4416K,   0% used [0x04c00000, 0x04c00000, 0x05050000)
  from space 512K, 100% used [0x050d0000, 0x05150000, 0x05150000)
  to   space 512K,   0% used [0x05050000, 0x05050000, 0x050d0000)
 concurrent mark-sweep generation total 10944K, used 746K [0x052a0000, 0x05d50000, 0x06000000)
 Metaspace       used 488K, capacity 2547K, committed 2624K, reserved 4480K
}

Looking back at the in-depth understanding of the Java virtual machine, I found that the original text said:

UseSerialGC is the default value of the virtual machine running in Client mode. After opening, use the collector of Serial+Serial Old

UseParallelGC is the default value of virtual machine running in Server mode before JDK9. After opening, use Parallel Scavenge+SerialOld collector

UseG1GC is the default value in Server mode after JDK9

At this time, go to the command line to check the jvm mode. It is found that the jvm is started in client mode (in fact, there are PrintCommandLineFlags output results above):

xxx\Downloads\arthas-bin> java -version
java version "1.8.0_251"
Java(TM) SE Runtime Environment (build 1.8.0_251-b08)
Java HotSpot(TM) Client VM (build 25.251-b08, mixed mode, sharing)

Next, use the java -XX:+PrintFlagsFinal -version command to find that the usemaximumcompationonsystemgc variable is true:

[the external chain picture transfer fails. The source station may have an anti-theft chain mechanism. It is recommended to save the picture and upload it directly (img-ceUcVUOl-1635600882861)(image-20211030175057486.png)]

Continue to view with jmap -heap:

xxx> jmap -heap 6024
Attaching to process ID 6024, please wait...
Debugger attached successfully.
Client compiler detected.
JVM version is 25.251-b08

using thread-local object allocation.
Mark Sweep Compact GC

Soft reference

Soft references are used to describe some useful but unnecessary objects. Objects associated with soft references will be recycled when memory overflow occurs in the system. If the memory is still insufficient after recycling, a memory overflow exception will be thrown.

The soft reference object itself can be released in conjunction with the reference queue.

There are several doubts about soft citation

1. When will soft referenced objects be recycled? FullGC or MinorGC?

2. Can manually triggered FullGC reclaim soft references?

Test code:

  @Test
    public void softReference() throws InterruptedException {
        System.out.println("begin===============");
        Thread.sleep(50000);
        List<SoftReference<byte[]>> list = new ArrayList<>();

        for (int i = 0; i < 5; i++) {
            SoftReference<byte[]> ref = new SoftReference<>(new byte[_1MB]);
            System.out.println("this is i " + i + "  " + ref.get()+
                    "=======================");
            list.add(ref);
            System.out.println("list = " + list.stream().map(SoftReference::get).collect(Collectors.toList()));
        }
        System.out.println("End of cycle=============");
        System.gc();
        System.out.println("list = " + list.stream().map(SoftReference::get).collect(Collectors.toList()));
    }

The first group of tests (20M heap, storing 5 1M objects)

Parameters:

-Xmx20m -XX:+PrintGCDetails -XX:+PrintHeapAtGC -verbose:gc     

The ratio of Cenozoic old age is 1:2 by default

Actual Cenozoic 4.8M old age 10.6M

Test results:

//Heap condition before running the test program body:
Heap after GC invocations=4 (full 0):
 def new generation   total 4928K, used 425K [0x05400000, 0x05950000, 0x05aa0000)
  eden space 4416K,   0% used [0x05400000, 0x05400000, 0x05850000)
  from space 512K,  83% used [0x05850000, 0x058ba430, 0x058d0000)
  to   space 512K,   0% used [0x058d0000, 0x058d0000, 0x05950000)
 tenured generation   total 10944K, used 1553K [0x05aa0000, 0x06550000, 0x06800000)
   the space 10944K,  14% used [0x05aa0000, 0x05c24438, 0x05c24600, 0x06550000)
 Metaspace       used 1585K, capacity 3513K, committed 3520K, reserved 4480K
}
begin===============
this is i 0  [B@9d1c02=======================
list = [[B@9d1c02]
//Because the new generation memory is not enough to put down new objects (size 1M), MinorGC is triggered once
{Heap before GC invocations=5 (full 0):
 def new generation   total 4928K, used 4728K [0x05400000, 0x05950000, 0x05aa0000)
  eden space 4416K,  98% used [0x05400000, 0x0583b730, 0x05850000)
  from space 512K,  77% used [0x058d0000, 0x05932a88, 0x05950000)
  to   space 512K,   0% used [0x05850000, 0x05850000, 0x058d0000)
 tenured generation   total 10944K, used 1673K [0x05aa0000, 0x06550000, 0x06800000)
   the space 10944K,  15% used [0x05aa0000, 0x05c427e0, 0x05c42800, 0x06550000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [DefNew: 4728K->280K(4928K), 0.0023325 secs] 6402K->3108K(15872K), 0.0023533 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=6 (full 0):
 def new generation   total 4928K, used 280K [0x05400000, 0x05950000, 0x05aa0000)
  eden space 4416K,   0% used [0x05400000, 0x05400000, 0x05850000)
  from space 512K,  54% used [0x05850000, 0x058961f8, 0x058d0000)
  to   space 512K,   0% used [0x058d0000, 0x058d0000, 0x05950000)
 tenured generation   total 10944K, used 2827K [0x05aa0000, 0x06550000, 0x06800000)
   the space 10944K,  25% used [0x05aa0000, 0x05d62e50, 0x05d63000, 0x06550000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}
this is i 1  [B@ac1102=======================
list = [[B@9d1c02, [B@ac1102]
this is i 2  [B@1e8284b=======================
list = [[B@9d1c02, [B@ac1102, [B@1e8284b]
this is i 3  [B@16e2f39=======================
list = [[B@9d1c02, [B@ac1102, [B@1e8284b, [B@16e2f39]
this is i 4  [B@74868d=======================
list = [[B@9d1c02, [B@ac1102, [B@1e8284b, [B@16e2f39, [B@74868d]
End of cycle=============
//Manually triggered fullgc
{Heap before GC invocations=6 (full 0):
 def new generation   total 4928K, used 4463K [0x05400000, 0x05950000, 0x05aa0000)
  eden space 4416K,  94% used [0x05400000, 0x05815d90, 0x05850000)
  from space 512K,  54% used [0x05850000, 0x058961f8, 0x058d0000)
  to   space 512K,   0% used [0x058d0000, 0x058d0000, 0x05950000)
 tenured generation   total 10944K, used 2827K [0x05aa0000, 0x06550000, 0x06800000)
   the space 10944K,  25% used [0x05aa0000, 0x05d62e50, 0x05d63000, 0x06550000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[Full GC (System.gc()) [Tenured: 2827K->7092K(10944K), 0.0082164 secs] 7291K->7092K(15872K), [Metaspace: 2039K->2039K(4480K)], 0.0082763 secs] [Times: user=0.00 sys=0.02, real=0.01 secs] 
Heap after GC invocations=7 (full 1):
 def new generation   total 5376K, used 0K [0x05400000, 0x059d0000, 0x05aa0000)
  eden space 4800K,   0% used [0x05400000, 0x05400000, 0x058b0000)
  from space 576K,   0% used [0x058b0000, 0x058b0000, 0x05940000)
  to   space 576K,   0% used [0x05940000, 0x05940000, 0x059d0000)
 tenured generation   total 11824K, used 7092K [0x05aa0000, 0x0662c000, 0x06800000)
   the space 11824K,  59% used [0x05aa0000, 0x0618d2a8, 0x0618d400, 0x0662c000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}
list = [[B@9d1c02, [B@ac1102, [B@1e8284b, [B@16e2f39, [B@74868d]

Result analysis:

As can be seen from the log results, except that the manual call to System.gc() triggered a FullGC, the other GCS were caused by insufficient memory and unable to allocate objects (Allocation Failure)

If the memory of the new generation is sufficient and the parameter - XX:PretenureSizeThreshold is not set, the objects will be put into the new generation first

When the new generation memory is insufficient to put down new objects, MinorGC will be triggered once

Manually triggered FullGC. If the soft reference object is not recycled at this time (because there is no need to put the newly allocated object)

Guess:

A manually triggered FullGC will not recycle soft reference objects unless it happens to catch up with a lack of memory

The second group of test parameters (stack 20M, storing 5 4M objects)

The parameters are the same as the third group

Test results:

=======================begin===============
==================i 0insert begin=======================
//The new generation of available memory is insufficient to put down the newly allocated object (size 4M), triggering MinorGC
{Heap before GC invocations=5 (full 0):
 def new generation   total 4928K, used 3704K [0x05000000, 0x05550000, 0x056a0000)
  eden space 4416K,  74% used [0x05000000, 0x0533b6c8, 0x05450000)
  from space 512K,  77% used [0x054d0000, 0x05532be8, 0x05550000)
  to   space 512K,   0% used [0x05450000, 0x05450000, 0x054d0000)
 tenured generation   total 10944K, used 1674K [0x056a0000, 0x06150000, 0x06400000)
   the space 10944K,  15% used [0x056a0000, 0x05842838, 0x05842a00, 0x06150000)
 Metaspace       used 2038K, capacity 4176K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [DefNew: 3704K->279K(4928K), 0.0017811 secs] 5378K->2083K(15872K), 0.0017985 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=6 (full 0):
 def new generation   total 4928K, used 279K [0x05000000, 0x05550000, 0x056a0000)
  eden space 4416K,   0% used [0x05000000, 0x05000000, 0x05450000)
  from space 512K,  54% used [0x05450000, 0x05495e10, 0x054d0000)
  to   space 512K,   0% used [0x054d0000, 0x054d0000, 0x05550000)
 tenured generation   total 10944K, used 1803K [0x056a0000, 0x06150000, 0x06400000)
   the space 10944K,  16% used [0x056a0000, 0x05862e98, 0x05863000, 0x06150000)
 Metaspace       used 2038K, capacity 4176K, committed 4288K, reserved 4480K
}
=======================this is i 0  [B@9d1c02=======================
list = [[B@9d1c02]
==================i 1insert begin=======================
//The available memory of the new generation is not enough to put down the second 4M object, trigger MinorGC and put the first 4M object into the old generation
{Heap before GC invocations=6 (full 0):
 def new generation   total 4928K, used 4462K [0x05000000, 0x05550000, 0x056a0000)
  eden space 4416K,  94% used [0x05000000, 0x05415c68, 0x05450000)
  from space 512K,  54% used [0x05450000, 0x05495e10, 0x054d0000)
  to   space 512K,   0% used [0x054d0000, 0x054d0000, 0x05550000)
 tenured generation   total 10944K, used 1803K [0x056a0000, 0x06150000, 0x06400000)
   the space 10944K,  16% used [0x056a0000, 0x05862e98, 0x05863000, 0x06150000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [DefNew: 4462K->1K(4928K), 0.0028861 secs] 6266K->6066K(15872K), 0.0029029 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=7 (full 0):
 def new generation   total 4928K, used 1K [0x05000000, 0x05550000, 0x056a0000)
  eden space 4416K,   0% used [0x05000000, 0x05000000, 0x05450000)
  from space 512K,   0% used [0x054d0000, 0x054d0498, 0x05550000)
  to   space 512K,   0% used [0x05450000, 0x05450000, 0x054d0000)
 tenured generation   total 10944K, used 6065K [0x056a0000, 0x06150000, 0x06400000)
   the space 10944K,  55% used [0x056a0000, 0x05c8c708, 0x05c8c800, 0x06150000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}
=======================this is i 1  [B@ac1102=======================
list = [[B@9d1c02, [B@ac1102]
==================i 2insert begin=======================
//The available memory of the new generation is not enough to put down the third 4M object, trigger MinorGC and put the 4M object of the new generation into the old generation
{Heap before GC invocations=7 (full 0):
 def new generation   total 4928K, used 4184K [0x05000000, 0x05550000, 0x056a0000)
  eden space 4416K,  94% used [0x05000000, 0x05415d18, 0x05450000)
  from space 512K,   0% used [0x054d0000, 0x054d0498, 0x05550000)
  to   space 512K,   0% used [0x05450000, 0x05450000, 0x054d0000)
 tenured generation   total 10944K, used 6065K [0x056a0000, 0x06150000, 0x06400000)
   the space 10944K,  55% used [0x056a0000, 0x05c8c708, 0x05c8c800, 0x06150000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [DefNew: 4184K->1K(4928K), 0.0026732 secs] 10250K->10162K(15872K), 0.0026961 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=8 (full 0):
 def new generation   total 4928K, used 1K [0x05000000, 0x05550000, 0x056a0000)
  eden space 4416K,   0% used [0x05000000, 0x05000000, 0x05450000)
  from space 512K,   0% used [0x05450000, 0x054504b8, 0x054d0000)
  to   space 512K,   0% used [0x054d0000, 0x054d0000, 0x05550000)
 tenured generation   total 10944K, used 10161K [0x056a0000, 0x06150000, 0x06400000)
   the space 10944K,  92% used [0x056a0000, 0x0608c718, 0x0608c800, 0x06150000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}
=======================this is i 2  [B@1e8284b=======================
list = [[B@9d1c02, [B@ac1102, [B@1e8284b]
==================i 3insert begin=======================
//The available memory of the new generation is not enough to put down the fourth 4M object, trigger GC and put the 4M object of the new generation into the old generation
{Heap before GC invocations=8 (full 0):
 def new generation   total 4928K, used 4184K [0x05000000, 0x05550000, 0x056a0000)
  eden space 4416K,  94% used [0x05000000, 0x05415c60, 0x05450000)
  from space 512K,   0% used [0x05450000, 0x054504b8, 0x054d0000)
  to   space 512K,   0% used [0x054d0000, 0x054d0000, 0x05550000)
 tenured generation   total 10944K, used 10161K [0x056a0000, 0x06150000, 0x06400000)
   the space 10944K,  92% used [0x056a0000, 0x0608c718, 0x0608c800, 0x06150000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
 //It can be seen that after GC, the size of the old generation is secretly adjusted from 10944k - > 13696k, and the size of the Cenozoic generation is also changed from 4928K - > 6144k
[GC (Allocation Failure) [DefNew: 4184K->4184K(4928K), 0.0000130 secs][Tenured: 10161K->10161K(10944K), 0.0058053 secs] 14346K->14259K(15872K), [Metaspace: 2039K->2039K(4480K)], 0.0058776 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
Heap after GC invocations=9 (full 1):
 def new generation   total 6144K, used 4097K [0x05000000, 0x056a0000, 0x056a0000)
  eden space 5504K,  74% used [0x05000000, 0x054004e8, 0x05560000)
  from space 640K,   0% used [0x05560000, 0x05560000, 0x05600000)
  to   space 640K,   0% used [0x05600000, 0x05600000, 0x056a0000)
 tenured generation   total 13696K, used 10161K [0x056a0000, 0x06400000, 0x06400000)
   the space 13696K,  74% used [0x056a0000, 0x0608c718, 0x0608c800, 0x06400000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}
//After MinorGC, the space is still insufficient. Because at this time, the old age has put three 4M large objects, triggered a FullGC, and recycled three soft referenced large objects
{Heap before GC invocations=9 (full 1):
 def new generation   total 6144K, used 4097K [0x05000000, 0x056a0000, 0x056a0000)
  eden space 5504K,  74% used [0x05000000, 0x054004e8, 0x05560000)
  from space 640K,   0% used [0x05560000, 0x05560000, 0x05600000)
  to   space 640K,   0% used [0x05600000, 0x05600000, 0x056a0000)
 tenured generation   total 13696K, used 10161K [0x056a0000, 0x06400000, 0x06400000)
   the space 13696K,  74% used [0x056a0000, 0x0608c718, 0x0608c800, 0x06400000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[Full GC (Allocation Failure) [Tenured: 10161K->1791K(13696K), 0.0065782 secs] 14259K->1791K(19840K), [Metaspace: 2039K->2039K(4480K)], 0.0066770 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap after GC invocations=10 (full 2):
 def new generation   total 6144K, used 0K [0x05000000, 0x056a0000, 0x056a0000)
  eden space 5504K,   0% used [0x05000000, 0x05000000, 0x05560000)
  from space 640K,   0% used [0x05560000, 0x05560000, 0x05600000)
  to   space 640K,   0% used [0x05600000, 0x05600000, 0x056a0000)
 tenured generation   total 13696K, used 1791K [0x056a0000, 0x06400000, 0x06400000)
   the space 13696K,  13% used [0x056a0000, 0x0585ffe8, 0x05860000, 0x06400000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
}
=======================this is i 3  [B@16e2f39=======================
list = [null, null, null, [B@16e2f39]
==================i 4insert begin=======================
//The available memory of the new generation is not enough to put down the fifth 4M object, triggering MinorGC
{Heap before GC invocations=10 (full 2):
 def new generation   total 6144K, used 4314K [0x05000000, 0x056a0000, 0x056a0000)
  eden space 5504K,  78% used [0x05000000, 0x054369a0, 0x05560000)
  from space 640K,   0% used [0x05560000, 0x05560000, 0x05600000)
  to   space 640K,   0% used [0x05600000, 0x05600000, 0x056a0000)
 tenured generation   total 13696K, used 1791K [0x056a0000, 0x06400000, 0x06400000)
   the space 13696K,  13% used [0x056a0000, 0x0585ffe8, 0x05860000, 0x06400000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [DefNew: 4314K->0K(6144K), 0.0014850 secs] 6106K->5888K(19840K), 0.0015090 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=11 (full 2):
 def new generation   total 6144K, used 0K [0x05000000, 0x056a0000, 0x056a0000)
  eden space 5504K,   0% used [0x05000000, 0x05000000, 0x05560000)
  from space 640K,   0% used [0x05600000, 0x05600020, 0x056a0000)
  to   space 640K,   0% used [0x05560000, 0x05560000, 0x05600000)
 tenured generation   total 13696K, used 5887K [0x056a0000, 0x06400000, 0x06400000)
   the space 13696K,  42% used [0x056a0000, 0x05c5fff8, 0x05c60000, 0x06400000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
}
=======================this is i 4  [B@74868d=======================
list = [null, null, null, [B@16e2f39, [B@74868d]
=======================End of cycle=============
//Manually triggered FullGC
{Heap before GC invocations=11 (full 2):
 def new generation   total 6144K, used 4203K [0x05000000, 0x056a0000, 0x056a0000)
  eden space 5504K,  76% used [0x05000000, 0x0541abf8, 0x05560000)
  from space 640K,   0% used [0x05600000, 0x05600020, 0x056a0000)
  to   space 640K,   0% used [0x05560000, 0x05560000, 0x05600000)
 tenured generation   total 13696K, used 5887K [0x056a0000, 0x06400000, 0x06400000)
   the space 13696K,  42% used [0x056a0000, 0x05c5fff8, 0x05c60000, 0x06400000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
[Full GC (System.gc()) [Tenured: 5887K->9984K(13696K), 0.0067799 secs] 10091K->9984K(19840K), [Metaspace: 2024K->2024K(4480K)], 0.0068097 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap after GC invocations=12 (full 3):
 def new generation   total 6144K, used 0K [0x05000000, 0x056a0000, 0x056a0000)
  eden space 5504K,   0% used [0x05000000, 0x05000000, 0x05560000)
  from space 640K,   0% used [0x05600000, 0x05600000, 0x056a0000)
  to   space 640K,   0% used [0x05560000, 0x05560000, 0x05600000)
 tenured generation   total 13696K, used 9984K [0x056a0000, 0x06400000, 0x06400000)
   the space 13696K,  72% used [0x056a0000, 0x06060068, 0x06060200, 0x06400000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
}
list = [null, null, null, [B@16e2f39, [B@74868d]

Result analysis

It can be seen that when the memory is insufficient, MinorGC will be used first. If not enough, FullGC will be triggered to reclaim soft referenced objects

During the operation, the virtual opportunity adjusts the size of the new generation and the old generation according to the situation

The third group of tests (pile 20M, store 5 4M objects, and go directly if the size exceeds 1M)

parameter

-Xmx20m -XX:PretenureSizeThreshold=1048576 -XX:+PrintGCDetails -XX:+PrintHeapAtGC -verbose:gc    
Specifies the maximum heap size of 30 M,Object exceeds 1 M Put it directly into the elderly generation and print it GC Detailed log, printing GC Heap memory before and after

Test results:

{Heap before GC invocations=3 (full 0):
 def new generation   total 4928K, used 4888K [0x04c00000, 0x05150000, 0x052a0000)
  eden space 4416K, 100% used [0x04c00000, 0x05050000, 0x05050000)
  from space 512K,  92% used [0x050d0000, 0x05146210, 0x05150000)
  to   space 512K,   0% used [0x05050000, 0x05050000, 0x050d0000)
 tenured generation   total 10944K, used 1446K [0x052a0000, 0x05d50000, 0x06000000)
   the space 10944K,  13% used [0x052a0000, 0x054099c8, 0x05409a00, 0x05d50000)
 Metaspace       used 1585K, capacity 3513K, committed 3520K, reserved 4480K
[GC (Allocation Failure) [DefNew: 4888K->425K(4928K), 0.0015817 secs] 6334K->1978K(15872K), 0.0015963 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=4 (full 0):
 def new generation   total 4928K, used 425K [0x04c00000, 0x05150000, 0x052a0000)
  eden space 4416K,   0% used [0x04c00000, 0x04c00000, 0x05050000)
  from space 512K,  83% used [0x05050000, 0x050ba430, 0x050d0000)
  to   space 512K,   0% used [0x050d0000, 0x050d0000, 0x05150000)
 tenured generation   total 10944K, used 1553K [0x052a0000, 0x05d50000, 0x06000000)
   the space 10944K,  14% used [0x052a0000, 0x05424498, 0x05424600, 0x05d50000)
 Metaspace       used 1585K, capacity 3513K, committed 3520K, reserved 4480K
}
//You can see that the available space in the old age is about 9M, and you can put two 4M objects
=======================begin===============
==================i 0insert begin=======================
=======================this is i 0  [B@9d1c02=======================
list = [[B@9d1c02]
==================i 1insert begin=======================
=======================this is i 1  [B@ac1102=======================
list = [[B@9d1c02, [B@ac1102]
==================i 2insert begin=======================
//As predicted, the space of the third 4M object is insufficient, triggering MajorGC and secretly increasing the space of the new generation & old age
{Heap before GC invocations=5 (full 0):
 def new generation   total 4928K, used 3704K [0x04c00000, 0x05150000, 0x052a0000)
  eden space 4416K,  74% used [0x04c00000, 0x04f3b6c8, 0x05050000)
  from space 512K,  77% used [0x050d0000, 0x05132be8, 0x05150000)
  to   space 512K,   0% used [0x05050000, 0x05050000, 0x050d0000)
 tenured generation   total 10944K, used 9866K [0x052a0000, 0x05d50000, 0x06000000)
   the space 10944K,  90% used [0x052a0000, 0x05c42860, 0x05c42a00, 0x05d50000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [Tenured: 9866K->10276K(10944K), 0.0100149 secs] 13570K->10276K(15872K), [Metaspace: 2039K->2039K(4480K)], 0.0100743 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap after GC invocations=6 (full 1):
 def new generation   total 6144K, used 0K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   0% used [0x04c00000, 0x04c00000, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 10276K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  75% used [0x052a0000, 0x05ca9058, 0x05ca9200, 0x06000000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}
//The space is still insufficient. When FullGC is triggered, the first two 4M objects are recycled
{Heap before GC invocations=6 (full 1):
 def new generation   total 6144K, used 0K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   0% used [0x04c00000, 0x04c00000, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 10276K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  75% used [0x052a0000, 0x05ca9058, 0x05ca9200, 0x06000000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[Full GC (Allocation Failure) [Tenured: 10276K->1905K(13696K), 0.0072390 secs] 10276K->1905K(19840K), [Metaspace: 2039K->2039K(4480K)], 0.0073446 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
Heap after GC invocations=7 (full 2):
 def new generation   total 6144K, used 0K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   0% used [0x04c00000, 0x04c00000, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 1905K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  13% used [0x052a0000, 0x0547c5e0, 0x0547c600, 0x06000000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
}
=======================this is i 2  [B@1e8284b=======================
list = [null, null, [B@1e8284b]
==================i 3insert begin=======================
=======================this is i 3  [B@16e2f39=======================
list = [null, null, [B@1e8284b, [B@16e2f39]
==================i 4insert begin=======================
//After two 4M objects are put in, the space is insufficient, triggering GC
{Heap before GC invocations=7 (full 2):
 def new generation   total 6144K, used 219K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   3% used [0x04c00000, 0x04c36f70, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 10097K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  73% used [0x052a0000, 0x05c7c600, 0x05c7c600, 0x06000000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [Tenured: 10097K->10097K(13696K), 0.0068210 secs] 10317K->10097K(19840K), [Metaspace: 2024K->2024K(4480K)], 0.0068536 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap after GC invocations=8 (full 3):
 def new generation   total 6144K, used 0K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   0% used [0x04c00000, 0x04c00000, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 10097K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  73% used [0x052a0000, 0x05c7c640, 0x05c7c800, 0x06000000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
}
//The space is still insufficient. Trigger FullGC and recycle two 4M large objects
{Heap before GC invocations=8 (full 3):
 def new generation   total 6144K, used 0K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   0% used [0x04c00000, 0x04c00000, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 10097K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  73% used [0x052a0000, 0x05c7c640, 0x05c7c800, 0x06000000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
[Full GC (Allocation Failure) [Tenured: 10097K->1614K(13696K), 0.0065856 secs] 10097K->1614K(19840K), [Metaspace: 2024K->2024K(4480K)], 0.0066211 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
Heap after GC invocations=9 (full 4):
 def new generation   total 6144K, used 0K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   0% used [0x04c00000, 0x04c00000, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 1614K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  11% used [0x052a0000, 0x05433b90, 0x05433c00, 0x06000000)
 Metaspace       used 2024K, capacity 4149K, committed 4288K, reserved 4480K
}
=======================this is i 4  [B@74868d=======================
list = [null, null, null, null, [B@74868d]
=======================End of cycle=============
list = [null, null, null, null, [B@74868d]

Result analysis:

After the large object is configured to be directly promoted to the older generation, when the memory of the older generation is insufficient, the GC is triggered first, and then the FullGC is recycled

When reading the log, I was confused about this GC log:

{Heap before GC invocations=5 (full 0):
 def new generation   total 4928K, used 3704K [0x04c00000, 0x05150000, 0x052a0000)
  eden space 4416K,  74% used [0x04c00000, 0x04f3b6c8, 0x05050000)
  from space 512K,  77% used [0x050d0000, 0x05132be8, 0x05150000)
  to   space 512K,   0% used [0x05050000, 0x05050000, 0x050d0000)
 tenured generation   total 10944K, used 9866K [0x052a0000, 0x05d50000, 0x06000000)
   the space 10944K,  90% used [0x052a0000, 0x05c42860, 0x05c42a00, 0x05d50000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
[GC (Allocation Failure) [Tenured: 9866K->10276K(10944K), 0.0100149 secs] 13570K->10276K(15872K), [Metaspace: 2039K->2039K(4480K)], 0.0100743 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap after GC invocations=6 (full 1):
 def new generation   total 6144K, used 0K [0x04c00000, 0x052a0000, 0x052a0000)
  eden space 5504K,   0% used [0x04c00000, 0x04c00000, 0x05160000)
  from space 640K,   0% used [0x05160000, 0x05160000, 0x05200000)
  to   space 640K,   0% used [0x05200000, 0x05200000, 0x052a0000)
 tenured generation   total 13696K, used 10276K [0x052a0000, 0x06000000, 0x06000000)
   the space 13696K,  75% used [0x052a0000, 0x05ca9058, 0x05ca9200, 0x06000000)
 Metaspace       used 2039K, capacity 4179K, committed 4288K, reserved 4480K
}

It can be seen from the heap memory before and after GC that this GC recycles both the new generation and the old generation. I'm very confused here and don't quite understand the difference between [GC] and [FullGC] in the log.

It is said that the difference between [GC] and [FullGC] is that the pause type is different. FullGC indicates that STW has occurred. However, all collectors need to pause the user thread in the initial marking stage, STW. Personally, I prefer the following:

In understanding Java virtual machine, MinorGC, MajorGC and FullGC are described as follows:

Partial GC

Not a complete collection of the entire Java heap garbage collection

Minor GC/Young GC

The goal is just a new generation of garbage collection

Major GC/Old GC

The goal is garbage collection in the old age (at present, only CMS garbage collector will collect the old age separately)

Mixed GC

The goal is to collect the garbage collection of the whole new generation and some old ages. At present, only G1 collector has this behavior

Full GC

Collect garbage collection for the entire Java heap and method area

Moreover, there is a paragraph in the book:

Generally, only the new generation can collect independently. Except for CMS collector, there is no collection only for the old generation

So can we think that other old collectors will affect the new generation more or less when they work (after all, there are cross generation references)

Topics: jvm