Become a JAVAGC expert (2)-How to monitor the Java garbage collection mechanism

This article is the second in a series of articles for the Java GC expert. In the first "Understanding Java garbage Collection mechanism" we learned the implementation of different GC algorithms, how the GC works, what is the new generation and the old age, you should understand the JDK7 of 5 types of GC, and the impact of these 5 types on the application performance.

In this article, I'll explain exactly how the JVM performs garbage collection processing .

What is GC monitoring?

garbage Collection Monitoring refers to the process of figuring out how the JVM performs the GC, for example, we can pinpoint:

1. When a new generation of objects is moved to the old age, the time spent.

2. Stop-the-world when it happened, how long it lasted.

GC monitoring is to identify whether the JVM is performing the GC efficiently, and whether additional performance tuning is necessary. Based on the above information, we can modify the application or adjust the GC algorithm (GC optimization).

How to monitor GC

There are a number of ways to monitor the GC, but the difference is just how the GC operation is presented. GC operations are done by the JVM, and GC monitoring tools simply show you the GC information provided by the JVM, so no matter how you monitor the GC, you will get the same results. So you don't have to learn all the ways to monitor the GC. But because learning about each monitoring method does not take up too much time, knowing a little bit can help you choose the most appropriate way to use different scenarios.

The tools listed below and the JVM parameters do not apply to all HVM vendors. This is because there is no mandatory standard for GC information. In this article we will use the Hotspot JVM (Oracle JVM). Because NHN has been using the Oracle (Sun) JVM, it is easier to use it as an example to explain the tools and JVM parameters we refer to.
First, the GC monitoring method can be divided into two categories: Cui and GUI, depending on the interface you access. The Cui GC monitoring method uses a separate Cui application called "Jstat", or the JVM parameter "VERBOSEGC" when starting the JVM.
The GUI GC monitoring is done by a single graphical application, of which three of the most commonly used applications are "Jconsole", "JVISUALVM" and "Visual GC".
Let's take a detailed study of each method.

Jstat

Jstat is a monitoring tool provided by the Hotspot JVM. Other monitoring tools include JPS and JSTATD. In some cases, you may need to use three tools to monitor your app at the same time. Jstat not only provides information about the GC operation, but also provides information about the class mount operation and the runtime compiler action. This article will cover only the features that Jstat can provide in relation to monitoring GC operation information.
Jstat is placed in the $jdk_home/bin. So as long as Java and Javac can execute, Jstat can do the same.
You can execute the following statements in the command-line environment.

12345678

$> jstat –gc  $<vmid$> 1000S0C       S1C       S0U    S1U      EC         EU          OC         OU         PC         PU         YGC     YGCT    FGC      FGCT     GCT3008.0   3072.0    0.0     1511.1   343360.0   46383.0     699072.0   283690.2   75392.0    41064.3    2540    18.454    4      1.133    19.5883008.0   3072.0    0.0     1511.1   343360.0   47530.9     699072.0   283690.2   75392.0    41064.3    2540    18.454    4      1.133    19.5883008.0   3072.0    0.0     1511.1   343360.0   47793.0     699072.0   283690.2   75392.0    41064.3    2540    18.454    4      1.133    19.588$>

In the example, the actual data will follow the output as follows:

1	S0C    S1C     S0U     S1U    EC     EU     OC     OU     PC

Vmid (virtual machine ID), as its name describes, is the Id,java application of a virtual machine that has its own independent vmid regardless of whether it is running locally or remotely. The Vmid, which runs on the local machine, is called Lvmid (local vmid), usually PID. If you want to get the PID value you can use the PS command or the Windows Task Manager, but we recommend using JPS to get it, because the PID and lvmid are sometimes inconsistent. JPS is implemented in Java PS, the JPS Command returns information for the Vmids and main methods, just as the PS command shows the PIDs and process names.
First, use the JPS command to find the Java application you want to monitor vmid, and use it as a jstat parameter. When several was instances are running on the same device, you will only see the startup (bootstrap) information if you use the JPS command only. We recommend the use of PS-EF in this case | grep Java is used in conjunction with JPS.
To obtain GC performance-related data requires constant monitoring, so when executing Jstat, the GC-monitored information is regularly output.
For example, executing "jstat–gc 1000″ (or 1s) will display GC monitoring data every second." "JSTAT–GC 1000 10″ will be shown every 1 seconds and 10 times.

Parameter name	Describe
Gc	Outputs the current available space for each heap area and the amount of space Used (Eden, Survivor, etc.), the total number of GC executions, and the time it takes for GC operations to accumulate.
Gccapactiy	Outputs the minimum space limit (MS)/Maximum space limit (MX) for each heap area, the current size, and the number of times the GC is executed on top of each zone. (The current used space is not output and the GC execution time).
Gccause	The information provided by the output-gcutil and the reason for the last GC's occurrence and the reason for the current GC being performed
Gcnew	GC performance data for output generation space
Gcnewcapacity	Statistics on the size of the output Cenozoic space.
Gcold	Output GC performance data for the old age space.
Gcoldcapacity	Output statistics of the size of the old age space.
Gcpermcapacity	Statistics that output the size of the persistent space.
Gcutil	Outputs the usage ratio for each heap area, as well as the total number of GC executions and events spent by GC operations.

You can only care about the most commonly used commands, and you will often use-gcutil (or-gccause),-GC and–gccapacity.

· The-gcutil is used to check the usage between heaps, the number of GC executions, and the time spent by GC operations.

· -gccapacity and other parameters can be used to check the actual allocated memory size.

With the-GC parameter you can see the following output:

1234	S0C      S1C    …   GCT1248.0   896.0  …   1.2461248.0   896.0  …   1.246…        …      …   …

Different Jstat parameters output different types of columns, as shown in the following table, and output different column information depending on the "jstat option" you use.

Column	Description	Jstat parameters
s0c	The size of the output Survivor0 space. Unit KB.	-gc -gccapacity -gcnew -gcnewcapacity
S1c	The size of the output Survivor1 space. Unit KB.	-gc -gccapacity -gcnew -gcnewcapacity
s0u	The output Survivor0 the size of the used space. Unit KB.	-gc -gcnew
s1u	The output Survivor1 the size of the used space. Unit KB.	-gc -gcnew
EC	The size of the output Eden space. Unit KB.	-gc -gccapacity -gcnew -gcnewcapacity
EU	Output the size of Eden used space. Unit KB.	-gc -gcnew
Oc	Output the size of the old age space. Unit KB.	-gc -gccapacity -gcold -gcoldcapacity
OU	The size of the space used to output the old age. Unit KB.	-gc -gcold
Pc	The size of the output persistence generation space. Unit KB.	-gc -gccapacity -gcold -gcoldcapacity -gcpermcapacity
Pu	Outputs the size of the used space for durable generations. Unit KB.	-gc -gcold
Ygc	The number of times the generation of space GC time occurred.	-gc -gccapacity -gcnew -gcnewcapacity -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause
Ygct	The time taken by the new generation of GC processing.	-gc -gcnew -gcutil -gccause
FGC	The number of times the full GC occurred.	-gc -gccapacity -gcnew -gcnewcapacity -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause
Fgct	Time spent on full GC operations	-gc -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause
GCT	Total time spent by GC operations.	-gc -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause
Ngcmn	Cenozoic minimum space capacity, in kilobytes.	-gccapacity -gcnewcapacity
Ngcmx	Maximum space capacity in the Cenozoic, in kilobytes.	-gccapacity -gcnewcapacity
Ngc	Current space capacity in the new generation, in kilobytes.	-gccapacity -gcnewcapacity
Ogcmn	The minimum space capacity in the old age, in kilobytes.	-gccapacity -gcoldcapacity
Ogcmx	The maximum space capacity in the old age, in kilobytes.	-gccapacity -gcoldcapacity
OGC	The current space capacity system in the old age, in kilobytes.	-gccapacity -gcoldcapacity
Pgcmn	The minimum space capacity of a persistent generation, in kilobytes.	-gccapacity -gcpermcapacity
Pgcmx	The maximum space capacity, in kilobytes, for a persistent generation.	-gccapacity -gcpermcapacity
Pgc	The current space capacity, in kilobytes, for the persistent generation.	-gccapacity -gcpermcapacity
Pc	The current space size of the persistent generation, in kilobytes	-gccapacity -gcpermcapacity
Pu	The current amount of space that is used for the persistent generation, in kilobytes	-gc -gcold
lgcc	Why the last GC occurred	-gccause
Gcc	Why the current GC occurs	-gccause
Tt	The threshold of aging. The number of empty lives in the Cenozoic before being moved to the old age.	-gcnew
Mtt	Maximum age threshold. The number of empty lives in the Cenozoic before being moved to the old age.	-gcnew
Dss	The amount of space required for the survivor area, in kilobytes.	-gcnew

The benefit of jstat is that it can continuously monitor GC operational data, whether or not the Java application is running locally or remotely, as long as there is a console where it can be used. The following information is output when using –gcutil. In GC optimization, you need to pay special attention to YGC, YGCT, FGC, FGCT and GCT.

1234

S0      S1       E        O        P        YGC    YGCT     FGC    FGCT     GCT0.00    66.44    54.12    10.58    86.63    217    0.928     2     0.067    0.9950.00    66.44    54.12    10.58    86.63    217    0.928     2     0.067    0.9950.00    66.44    54.12    10.58    86.63    217    0.928     2     0.067    0.995

This information is important because they show how much time is spent in GC processing.
In this example, YGC is 217 and YGCT is 0.928, so after a simple calculation of the average number of data, you can see that each new generation of GC takes approximately 4ms (0.004 seconds), while the average time of the full GC is 33MS.
However, it is often impossible to analyze real GC problems by looking at only the average data. This is mainly due to the severe deviation of the GC operation time (in other words, if the time of two full GC is 67ms, then one of the full GC may have performed 10ms and the other may have performed 57ms. In order to better detect each GC processing time, it is best to use –VERBOSEGC to replace the average data.

-verbosegc

-VERBOSEGC is one of the JVM parameters that you can specify when starting a Java application. and Jstat can monitor any JVM application, even if it does not have any parameters. -VERBOSEGC needs to be specified at startup, so you may think it is unnecessary (because Jstat can replace it). However,-VERBOSEGC will show the results of GC in a more understandable way, so it is useful for monitoring GC information.

	Jstat	-verbosegc
Monitoring objects	Java applications running natively can output logs to the terminal, or use the JSTATD command to connect remote Java applications over the network.	Only the JVM that takes-VERBOGC as the startup parameter.
Output information	Heap status (used space, maximum limit, GC executions/time, etc.)	The new generation and old age space size, GC execution time before and after GC execution.
Output time	Every designated time Set the time each time.	Every time a GC occurs.
When it's useful.	When you try to observe the changes in the space of the heap	When you try to understand the effect that a single GC produces.

The following are the available parameters for-VERBOSEGC
· -xx:+printgcdetails
· -xx:+printgctimestamps
· -xx:+printheapatgc
· -xx:+printgcdatestamps (from JDK 6 update 4)

If only-VERBOSEGC was used. Then the default is to add-xx:+printgcdetails. The additional parameters of the –VERBOSGC are not independent. Instead, they are often used together.
After using –VERBOSEGC, you will see the results in the following format each time the GC occurs.

[GC [<collector>: <starting occupancy1>, <ending occupancy1>, <pause time1> secs] < Starting occupancy3>, <ending occupancy3>, <pause time3> secs]

Collecting device	Minor the name of the collector used by the GC.
Starting Occupancy1	The GC performs the pre-Cenozoic space size.
Ending Occupancy1	The post-Cenozoic space size of the GC.
Pause time1	Because execution minor Gc,java the time that the app was paused.
Starting Occupancy3	Total size of heap area before GC execution
Ending Occupancy3	Total size of heap area after GC execution
Pause Time3	The time that the Java application stopped due to the execution of the heap space GC (including the major GC).

This is an example of the-VERBOSEGC output of the minor GC.

1234	S0    S1     E      O      P        YGC    YGCT    FGC    FGCT     GCT0.0066.4454.1210.5886.632170.9282 0.0670.9950.0066.4454.1210.5886.632170.92820.0670.9950.0066.4454.1210.5886.632170.92820.0670.995

This is an example of when full GC occurs

1	[Full GC [Tenured: 3485K->4095K(4096K), 0.1745373 secs] 61244K->7418K(63104K), [Perm : 10756K->10756K(12288K)], 0.1762129 secs] [Times: user=0.19 sys=0.00, real=0.19 secs]

If CMS collector is used, the following CMS information will be output as well.
Because the –VERBOSEGC parameter outputs the log every time a GC event occurs, we can easily observe the effect of the GC operation on the heap space.

(Java) VisualVM + Visual GC

Java Visual VMs are graphical summary and monitoring tools provided by Oracle JDK.

Figure 1:VISUALVM

In addition to the version that comes with your JDK, you can also download visual VMs directly from your website. For convenience, the version included in the JDK is named Java VisualVM (JVISUALVM), and the version provided by the official website is named Visual VM (VisualVM). The two functions are basically the same, with only a few small differences, such as when installing components. Personally, I prefer visual VMs that can be downloaded from the official website.

Figure 2:viusal GC Installation

With Visual GC, you can see more intuitively the information you get from executing jstatd.

Figure 3:visual GC Execution

Hpjmeter

Hpjmeter can easily analyze the results of the-VERBOSEGC output, and if the visual GC can be seen as a graphical version of Jstat, then Hpjmeter is equivalent to a graphical version of –VERBOSGC. Of course, GC analysis is just one of the many features that Hpjmeter offers, and Hpjmeter is a performance monitoring tool developed by HP that can support Hp-ux,linux and Ms Windows.
At first, a hptune was designed to be used for graphical analysis of-VERBOSEGC. The result of the output. However, with the Hptune feature being integrated into the Hpjmeter 3.0 version, there is no need to download the Hptune separately. But when you run an application, the results of the-VERBOSEGC are exported to a separate file.
You can open this file directly with Hpjmeter for more intuitive analysis of GC performance data.

Figure 4:hpjmeter

Next preview

In this paper, we mainly describe if the GC operation information is monitored, this will be the premise of GC optimization. In my personal experience, I recommend using JSTAT to monitor GC operations, and if you feel that the GC operation takes too long to perform, you can use the VERBOSEGC parameter to analyze the GC. The general step of GC optimization is to adjust the GC parameters and analyze the modified results after adding the VERBOSEGC parameter. In the next article, we will use real-world examples to illustrate the best choice for optimizing GC.
Author Sangmin Lee, NHN, performance Engineer Lab senior engineer.

Become a JAVAGC expert (2)-How to monitor the Java garbage collection mechanism