JVM Series: Java GC analysis

Java GC is the JVM recorder, calligraphy and painting the JVM's various sections of the performance.

What is a Java GC

Java GC (Garbage Collection, garbage collection, garbage collector) mechanism, is one of the main differences between Java and C++/C, as a Java developer, generally do not need to specifically write memory recycling and garbage cleanup code, memory leaks and overflow problems, Nor does it need to be as jittery as C programmers. This is because there is an automatic memory management and garbage cleanup mechanism in the Java Virtual machine. In a nutshell, this mechanism marks the memory in the JVM (Java Virtual machine) and determines which memory needs to be recycled, automatically reclaims memory according to a certain recycling strategy, and never Stops (Nerver Stop) to ensure that the memory space in the JVM Prevent memory leaks and overflow issues.

Before the advent of the Java language, there is the existence of GC mechanisms, such as the Lisp language, the Java GC mechanism has been perfected, almost automatically for us to do the vast majority of things. However, if we are engaged in large-size application software development, there have been memory optimization requirements, we must study the Java GC mechanism.

In a nutshell, Java GC recycles objects that are not alive through GC collectors, ensuring that the JVM runs more efficiently. If you do not understand the GC algorithm and the garbage collector can refer to this article: JVM series (iii): GC algorithm garbage collector.

How to get the Java GC log

In general, there are two ways to get the GC log, one is to use the command dynamic view, one is to set the relevant parameters in the container to print the GC log.

Command Dynamic View

Java Automatic Tool-line command, Jstat can be used to dynamically monitor the use of JVM memory, statistics of garbage collection information.

For example, frequently used commands to jstat -gc count the behavior of garbage collection heap

$ jstat -gc 1262 S0C    S1C     S0U     S1U   EC       EU        OC         OU        PC       PU         YGC    YGCT    FGC    FGCT     GCT   26112.0 24064.0 6562.5  0.0   564224.0 76274.5   434176.0   388518.3  524288.0 42724.7    320    6.417   1      0.398    6.815

You can also set a fixed time interval to print:

$ jstat -gc 1262 2000 20

This command means that every 2000ms output 1262 GC case, a total output 20 times

Refer to this article for more detailed information: JVM series (iv): JVM tuning-command post

GC Parameters

The main parameters of the JVM's GC log include the following:

• -XX:+PrintGCOutput GC Log
• -XX:+PrintGCDetailsVerbose log of output GC
• -XX:+PrintGCTimeStampsTimestamp of output GC (in the form of base time)
• -XX:+PrintGCDateStampsTimestamp of the output GC (in the form of a date, such as 2017-09-04t21:53:59.234+0800)
• -XX:+PrintHeapAtGCTo print out a heap of information before and after a GC
• -Xloggc:../logs/gc.logThe output path of the log file

In a production environment, configure the appropriate parameters to monitor the operation of the JVM as needed.

Tomcat Setup Example

We often add JVM-related parameters to Tomcat's startup parameters, here's a typical example:

JAVA_OPTS="-server -Xms2000m -Xmx2000m -Xmn800m -XX:PermSize=64m -XX:MaxPermSize=256m -XX:SurvivorRatio=4-verbose:gc -Xloggc:$CATALINA_HOME/logs/gc.log -Djava.awt.headless=true -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Dsun.rmi.dgc.server.gcInterval=600000 -Dsun.rmi.dgc.client.gcInterval=600000-XX:+UseConcMarkSweepGC -XX:MaxTenuringThreshold=15"

According to the above parameters we will do a bit of parsing:

• -Xms2000m -Xmx2000m -Xmn800m -XX:PermSize=64m -XX:MaxPermSize=256m
  Xms, which is the JVM initial heap size for the JVM startup, Xmx is the maximum heap size of the JVM, XMN is the size of the Cenozoic, PermSize is the initial size of the permanent generation, maxpermsize the maximum space for the permanent generation.

• -XX:SurvivorRatio=4
  Survivorratio is the ratio of the size of the Eden area in the Cenozoic space to the survivor area of the salvage space, the default is 8, then the ratio of two survivor to one Eden area is 2:8, and one survivor area represents 1/10 of the entire young generation. This parameter will increase the survivor area, so that the object as far as possible in the Survitor area to stay a little longer, to reduce the age of the object. The idea of getting rid of the rescue space is to get most of the data that cannot be recovered quickly into the old generation, to speed up the recovery of older generations and to reduce the likelihood of an old generation soaring, by setting-xx:survivorratio to a larger value (such as 65536).

• -verbose:gc -Xloggc:$CATALINA_HOME/logs/gc.log
  The information for each garbage collection of the virtual machine is written to the log file, and the file name is specified by the files, which is a flat file with the same contents as the-VERBOSE:GC output.

• -Djava.awt.headless=true
  Headless mode is a configuration mode of the system. In this mode, the system is missing a display device, keyboard, or mouse.

• -XX:+PrintGCTimeStamps -XX:+PrintGCDetails
  Format the GC log

• -Dsun.rmi.dgc.server.gcInterval=600000 -Dsun.rmi.dgc.client.gcInterval=600000
  Specify the time interval for GC when RMI is called

• -XX:+UseConcMarkSweepGC -XX:MaxTenuringThreshold=15
  Using concurrent GC mode, after 15 minor GC into the old generation

How to analyze GC logs

Extract part of GC log

Young GC Recycle log:

2016-07-05T10:43:18.093+0800: 25.395: [GC [PSYoungGen: 274931K->10738K(274944K)] 371093K->147186K(450048K), 0.0668480 secs] [Times: user=0.17 sys=0.08, real=0.07 secs]

Full GC Recycle log:

2016-07-05T10:43:18.160+0800: 25.462: [Full GC [PSYoungGen: 10738K->0K(274944K)] [ParOldGen: 136447K->140379K(302592K)] 147186K->140379K(577536K) [PSPermGen: 85411K->85376K(171008K)], 0.6763541 secs] [Times: user=1.75 sys=0.02, real=0.68 secs]

Through the above log analysis, Psyounggen, Paroldgen, Pspermgen belong to the parallel collector. Which Psyounggen represents the memory change of the younger generation before and after GC recycling; Paroldgen represents the memory change of the old age before and after GC recycling; Pspermgen represents the memory change of the permanent area before and after GC reclamation. Young GC is mainly for the younger generation of memory recovery is more frequent, time-consuming, full GC will be the entire heap of memory to return to the town, time consuming, so generally minimize the number of complete GC

The GC log composition is clearly seen through two graphs:

Young GC Logs:

Full GC LOG:

GC Analysis Tools

Gchisto

Gchisto is a professional analysis of GC log tool, can be analyzed by GC log: Minor GC, full GC time, frequency, etc., through the list, reports, charts and other forms to respond to GC situation. Although the interface is slightly rough, but the function is good.

Once you have configured your local JDK environment, double-click Gchisto.jar and click Add to select Gc.log Log in the popup input box

• GC Pause Stats: The number of times a GC can be viewed, GC time, GC overhead, maximum GC time and minimum GC time, and corresponding histogram

• GC Pause Distribution: View the detailed distribution of GC pauses, the x-axis indicates garbage collection pause times, and the y-axis represents the number of pauses.

• GC Timeline: Show garbage collection across the timeline

But this tool is no longer maintained

GC Easy

This is a web tool that is easy to use online.

Address: Http://gceasy.io

Go to the official website, say packed zip or gz for the suffix of the compression package upload, after a while will get the analysis results.

It is recommended to use this tool for GC analysis.

JVM Series: Java GC analysis