Java features automatic garbage collection, but sometimes garbage collection is not ideal and our own services are not supporting it. In this case, we need to take a look at the garbage collection according to the GC’s log section in order to tune for better efficiency.
This article will learn how to set some parameters related to GC logging and what the printed logs mean.
Different garbage collectors have different log formats. My local environment is JDK1.8, so I use the default Parallel Insane + Parallel Old garbage collector, which I tested in this article.
Use -xMS50m -XMX50m -xmn20m to control the heap size of this code.
-Xms50m: indicates the minimum heap memory of 50M
-Xmx50m: indicates the maximum heap memory of 50M
-Xmn20m: 20M in the new generation, 30M in the old age
It means that the maximum and minimum size of Java heap are both 50MB and unchangeable. Since the new generation can be divided into Eden zone and two Survivor zones (from zone and to zone) with a ratio of 8:1:1, Eden zone is about 16M, from zone and to zone are 2M each.
PSYoungGen: The garbage collector is Parallel insane
ParOldGen: indicates that the garbage collector is Parallel old
1. The simplest argument -xx :+PrintGC
The code is as follows:
/** * vm parameters: -Xms50m -Xmx50m -Xmn20m -XX:+PrintGC */ public class Allocation { private static final int _1MB = 1024 * 1024; private static void testAllocation(){ byte[] one = new byte[6*_1MB]; byte[] two = new byte[6*_1MB]; byte[] three = new byte[6*_1MB]; } public static void main(String[] args) { testAllocation(); }}Copy the codeThe following output is displayed:
[GC (Allocation Failure) 15360K->13162K(48640K), 0.0092840 secs]
Copy the codeWell, just to be brief, the meaning of the log is that a minor GC was triggered. Before the GC, 15360K of heap space was used, and after the GC, 13162K of heap space was used, and the total heap space was 48640K. Finally, the time of this GC is 0.0092840 secs.
PrintGC prints such a short log that you can only see the general information, not the details.
2. Detailed parameters: -xx :+PrintGCDetails
Configuration: -xMS50m -XMX50m -xmn20m-xx :+PrintGCDetails
Log input is as follows (code reference above) :
Let’s explain the meaning of the above log sentence by sentence
-
[PSYoungGen: 15105K->946K(17920K)] 15105K->13242K(48640K), 0.0118657 secs] [Times: User sys = = 0.03 0.00, real = 0.01 secs]
Allocation Failure (GC) indicates the minor GC that occurs. The usage of the new generation is 15105K before the collection and 946K after the collection (17920K in total). The total heap usage decreases from 15105K to 13242K(48640K in size). Finally, the amount of time GC takes, with user representing user-mode CPU time, sys representing system CPU time, and real representing the actual amount of time GC takes
-
PSYoungGen total 17920K, used 7397K
The total space of young generation is 17920K, and 7397K has been used (young generation = Eden +from/to)
-
eden space 15360K, 42% used
The space of Eden district is 15360K, 42% of which has been used
-
from space 2560K, 36% used
The space of the FROM area is 2560K, 36% of which has been used
-
to space 2560K, 0% used
To space 2560K, 0% used
-
ParOldGen total 30720K, used 12296K / object space 30720K, 40% used
Old age total space 30720K. 12296K has been used, the percentage is 40%
-
Metaspace used 3348K
The use of meta-space is free of heap memory
The above is the output content of the detailed GC logs, and there is a more detailed parameter, which is printed before and after the collection. If you can’t see the collection information, you can also compare the above logs.
Add: Full GC can also occur when the old generation is out of memory
0.211: [Full GC (Ergonomics) [PSYoungGen: 914K->0K(17920K)] [ParOldGen: [Times: Times] [Metaspace: 3350K->3350K], [Metaspace: 3350K->3350K] User sys = = 0.02 0.00, real = 0.01 secs]Copy the code3. Detailed parameters before and after recycling: -xx :+PrintHeapAtGC
-Xms50m -Xmx50m -Xmn20m -XX:+PrintHeapAtGC
Log input is as follows (code reference above) :
Most of them are the same as the above log content, refer to the specific meaning of the above, but this time two logs are printed,
- Heap before GC invocations=1 (full 0) : Information about the Heap space before GC occurs
- Heap after GC invocations=1 (full 0) : information about the Heap space after GC occurs
4. GC occurs at -xx :PrintGCTimeStamps
-Xms50m -Xmx50m -Xmn20m -XX:+PrintGC -XX:+PrintGCTimeStamps
The log is as follows (code reference above)
0.199: [GC (Allocation Failure) 9268K->6970K(48640K), 0.0073891 secs]
Copy the codeThe above [0.199] is the time when the GC occurred (this time is the offset after the virtual machine started).
5. The application execution time parameters: – XX: + PrintGCApplicationConcurrentTime
-Xms50m -Xmx50m -Xmn20m -XX:+PrintGCTimeStamps -XX:+PrintGC -XX:+PrintGCApplicationConcurrentTime
The log is as follows (code reference above)
0.236: Application time: 0.0088226 seconds
0.236: [GC (Allocation Failure) 9268K->7018K(48640K), 0.0080782 secs]
0.251: Application time: 0.0074303 seconds
Copy the codeThe output above is the execution time of the program
6. The application pause time parameters: – XX: + PrintGCApplicationStoppedTime
-Xms50m -Xmx50m -Xmn20m -XX:+PrintGCTimeStamps -XX:+PrintGC -XX:+PrintGCApplicationStoppedTime
The log is as follows (code reference above)
0.181: [GC (Allocation Failure) 15360K->13210K(48640K), 0.0107874 secs] Total time for which application Threads were stopped: 0.0109662 seconds, Stopping Threads took: 0.0000396 secondsCopy the codeThe output above is the pause time of the program
7. Log drop disk parameter: -xloggc
-Xms50m -Xmx50m -Xmn20m -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/Users/ajisun/Desktop/logs/gc.log
By default, gc logs are exported to the console, but it is not convenient for us to save and analyze problems. Therefore, the VIRTUAL machine also provides log output file, which is specified by the parameter -xloggc. After starting the program, the log output is in the corresponding directory gc.log file
8. To summarize
In total, there are seven GC log related parameters that you can tune the log output to. Observe the system status and rectify faults based on the memory of logs.
- The simplest argument -xx :+PrintGC
- -xx :+PrintGCDetails
- -xx :+PrintHeapAtGC
- The GC occurs at -xx :PrintGCTimeStamps
- Application execution time parameters: – XX: + PrintGCApplicationConcurrentTime
- Application pause time parameters: – XX: + PrintGCApplicationStoppedTime
- Log drop disk parameter: -xloggc
The original address
I am Mr. Ji, with the output force input and continue to learn, continue to share the series of technical articles, as well as the whole network worth collecting good articles, welcome to pay attention to the public number, do a continuous growth of technical people.
Personal website
The JVM virtual machine series historical articles
1. Virtual Machine series: how to divide JVM runtime heap memory;
2. Virtual Machine series: Garbage collection algorithm in JVM;
3. Virtual Machine Series: JVM runtime data area;
4. Virtual Machine series: creation of objects in JVM, memory layout and access location;
5. Virtual Machine series: garbage collector in JVM;
6. Virtual Machine series: Memory allocation in the JVM;