Frequent Young GC is simulated
JVM Parameter Settings
Set up heap memory to quickly simulate garbage collection
-XX:NewSize=5242880 -XX:MaxNewSize=5242880 -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC
“-xx :InitialHeapSize” and “-xx :MaxHeapSize” are the InitialHeapSize and maximum heap size
“-xx :NewSize” and “-xx :MaxNewSize” are the initial Cenozoic size and the maximum Cenozoic size
“- XX: PretenureSizeThreshold = 10485760” specifies the large object threshold is 10 MB,
The above parameter sets the heap memory to 10MB, in which the new generation is 5MB, in which the Eden region occupies 4MB, and each Survivor region occupies 0.5MB.
Large objects must be over 10MB before they go directly to the old generation. The young generation uses the ParNew garbage collector and the old generation uses the CMS garbage collector
[img-0UL4VTDA-1620222535690] (F: learning, learning notes, JVM, images, heap memory Settings. PNG)
Print out JVM GC logs
-xx :+PrintGCDetils: prints detailed GC logs. -xx :+PrintGCTimeStamps: prints the time of each GC occurrence. -xloggc: gC.log: Sets the gc log to a disk file
- Full JVM parameter Settings
-XX:NewSize=5242880
-XX:MaxNewSize=5242880
-XX:InitialHeapSize=10485760
-XX:MaxHeapSize=10485760
-XX:SurvivorRatio=8
-XX:PretenureSizeThreshold=10485760
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:gc.log
Copy the code
The sample code
public static void main(String[] args) {
byte[] array1 = new byte[1024 * 1024];
array1 = new byte[1024 * 1024];
array1 = new byte[1024 * 1024];
array1 = null;
byte[] array2 = new byte[2 * 1024 * 1024];
}
Copy the code
Reading,
-
Byte [] array1 = new byte[1024 * 1024];
A 1MB object is placed in the Eden area of the JVM, and a stack frame of the main() method is pushed into the main() thread’s stack frame. Inside the stack frame of the main() method is an array1 variable that points to the 1MB array in the Eden area of the heap.
-
Array1 = new byte[1024 * 1024];
A second array is created in the Eden area of the heap, and the local variable points to the second array. Then the first array is no longer referenced, and the first array becomes a “junk object” that no one refers to
-
Byte [] array1 = new byte[1024 * 1024];
This line of code creates a third array in the Eden area of the heap, and makes the array1 variable point to the third array. The first two arrays are no longer referenced, so they are junk objects
-
Line 4: array1 = null;
Make array1 point to nothing, which will cause all three arrays created to become junk objects. Okay
-
Byte [] array2 = new byte[2 * 1024 * 1024];
Allocate a 2MB array, because the Eden area has a total size of 4MB, and three 1MB arrays have been placed, so the 2MB array cannot be placed, so the Young GC of the Young generation will be triggered at this time
The GC log
A complete log
Java HotSpot(TM) 64-Bit Server VM (25.241-b07) for windows-amd64 JRE (1.8. 0 _241-b07), built on Dec 11 2019 10:21:40 by "rejava" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 12271980k(6714636k free), swap 15185172k(8782272k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC
0.389: [GC (Allocation Failure) 0.389: [ParNew: 3822K->512K(4608K), 0.0023784 secs] 3822K->638K(9728K), 0.0026065 secs] [Times: user=0.00 sys=0.00, real=0.16 secs]
Heap
par new generation total 4608K, used 2601K [0x00000000ff600000.0x00000000ffb00000.0x00000000ffb00000)
eden space 4096K, 51% used [0x00000000ff600000.0x00000000ff80a558.0x00000000ffa00000)
from space 512K, 100% used [0x00000000ffa80000.0x00000000ffb00000.0x00000000ffb00000)
to space 512K, 0% used [0x00000000ffa00000.0x00000000ffa00000.0x00000000ffa80000)
concurrent mark-sweep generation total 5120K, used 126K [0x00000000ffb00000.0x0000000100000000.0x0000000100000000)
Metaspace used 3231K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 350K.capacity 388K.committed 512K.reserved 1048576K
Copy the code
Interpreting GC Logs
0.389: [GC (Allocation Failure) 0.389: [ParNew: 3822K->512K(4608K), 0.0023784 secs] 3822K->638K(9728K), 0.0026065 secs] [Times: user=0.00 sys=0.00, real=0.16 secs] Heap
- ** Allocation Failure (GC) : ** The cause of GC is an object Allocation Failure
- **0.389: ** How many seconds elapsed after your system was running for this GC, in this case it was about 389 milliseconds
- [ParNew: 3822 k – > 512 k (4608 k), 0.0023784 secs]
- ParNew: Triggers the young generation of Yong GC, using the ParNew garbage collector;
- 3822K->512K: this means that a GC was performed on the young generation. 4030KB was used before GC, but only 512KB survived after GC.
- (4608K) : The free space of the young generation is 4608KB, which is 4.5MB (4MB-Eden + 0.5MB- Survivor)
- 0.0023784 secS: it is the time of this GC, about 2.3ms
- 3822K->638K(9728K) : The total available space of the Java heap is 9728KB (9.5MB), which is 4.5MB for the young generation + 5M for the old generation
- **[Times: user=0.00 sys=0.00, real= 0.16secs]
The current heap memory usage that is printed when the JVM exits
-
** PAR New Generation Total 4608K, used 2601K [0x00000000FF600000, 0x00000000FFB00000, 0x00000000FFB00000) : The garbage collector is responsible for a total of 4608KB (4.5MB) of free memory in the young generation, currently using 2601KB (2.5MB)
Why is the young generation taking up 2.5MB of memory at this point before the JVM exits?
There must be a 2MB array in Eden, 2048K, and one that survived From Survivor after the last GC
512KB objects, total: 2048KB + 512KB = 2560KB, but why does the young generation use 2601KB? Each array takes up some extra memory to hold its own object metadata, so you can think of the extra 41KB as the extra memory used by the array object.
-
eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000) from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000) to space 512K, 0% used [0x00000000ffa00000, X00000000ffa00000 0, 0 x00000000ffa80000) :
51% of the 4MB memory in Eden is used because there is a 2MB array in it. Then From Survivor, 512KB is 100% utilization, which is occupied by 512KB unknown objects that survived the previous GC
-
** Concurrent mark-sweep Generation Total 5120K, used 126K [0x00000000FFB00000, 0x0000000100000000, 0x0000000100000000) : The CMS garbage collector, which manages a total of 5MB of old memory space, uses 126KB of space
-
**Metaspace used 3231K, capacity 4496K, committed 4864K, reserved 1056768K class space used 350K, capacity 388K, **Metaspace metadata space and Class space, which hold some Class information, constant pools, things like that, their total capacity at this point, memory used, etc
Trigger the CMS by simulating the scene in which the object enters the old age
The sample code
public static void main(String[] args) {
byte[] array1 = new byte[2 * 1024 * 1024];
array1 = new byte[2* 1024 * 1024];
array1 = null;
byte[] array2 = new byte[128 * 1024];
byte[] array3 = new byte[2 * 1024 * 1024];
}
Copy the code
The GC log
Java HotSpot(TM) 64-bit Server VM (25.241-B07) for Windows-AMD64 JRE (1.8.0_241-b07) Built on Dec 11 2019 10:21:40 by "rejava" with MS VC++ 10.0 (VS2010) Memory: 4k page, physical 12271980k(6872468k free), swap 15185172k(8820136k free) CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -xx :+UseParNewGC 0.269: [Allocation Failure (GC) 0.269: [ParNew: 2424K -> 2424k, 0.0020845secs] 2424K -> 2424k, 0.0020845secs] [Times: User =0.00 sys=0.00, real=0.00 secs] 0.272: [Allocation Failure (GC) 0.272: [ParNew: 2890K->512K(28608k), 0.0014808 secs] 2844K ->3173K(9728K), 0.0015438 secs] [Times: User =0.00 sys=0.00, real=0.00 secs] 0.274: [GC (CMS Initial Mark) [1 CMS- Initial Mark: [Times: user=0.00 sys=0.00, real=0.00 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [cms-concurrent-mark-start] 0.275: [CMs-concurrent-mark: 0.001/0.001secs] [Times: User =0.00 sys=0.00, real=0.00 secS] 0.275: [cms-concurrent-preclean-start] 0.275: [CMs-concurrent-preclean: [Times: user=0.00 sys=0.00, real=0.00 secs] 0.275: [cms-concurrent-abortable-preclean-start] 0.275: [Times: user=0.00 sys=0.00, real=0.00 secs] 0.275: [cms-concurrent-abortable-preclean-start] [CMS - concurrent - abortable - preclean: 0.000/0.000 secs] [Times: Sys =0.00, real=0.00 SECS] Heap PAR new Generation Total 4608K, Used 2629K [0x00000000FF600000, 0x00000000ffb00000, 0x00000000ffb00000) eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff8117e8, 0x00000000ffa00000) from space 512K, 100% used [0x00000000ffa00000, 0x00000000ffa80000, 0x00000000ffa80000) to space 512K, 0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000) concurrent mark-sweep generation total 5120K, used 2661K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000) Metaspace used 3226K, capacity 4496K, committed 4864K, reserved 1056768K class space used 349K, Capacity 388K, committed 512K, reserved 1048576K 0.275: [GC (CMS Final Remark) [YG occupancy: 2629K (4608K)]0.275: [Rescan (PARALLEL), 0.0002505 secs]0.276: [Weak refs processing, 0.0000247 secs]0.276: [class unloading, 0.0003900 secs] 0.276: [the scrub symbol table, 0.0007520 secs] 0.277: [Scrub String table, 0.0001941 secs][1 CMS-remark: 2661K(5120K)] 5291K(9728K), 0.0017775 secs][Times: scrub scrub User sys = = 0.00 0.00, real = 0.00 secs]Copy the code
0.274: [GC (CMS Initial Mark) [1 CMs-initial-mark: 2661K(5120K)] 5249K(528k), 0.000149secs] [Times: User =0.00 sys=0.00, real=0.00 secs] 0.274: [cms-concurrent-mark-start] 0.275: [CMs-concurrent-mark: Secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 0.275: [cms-concurrent-preclean-start] 0.275: [cmS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [cms-concurrent-abortable-preclean-start] 0.275: [CMs-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: User =0.00 sys=0.00, real=0.00 secs] Heap
The above log shows that the CMS goes through four phases: [CMS Initial Mark] —-> [CMS-concurrent-mark] —-> [CMS-concurrent-preclean] —-> [CMS-concurrent-abortable-preclean]