Java GC Expert series 2:java monitoring of garbage collection

This is the second article in the article "becoming a GC expert series." In the first understanding of Java garbage Collection, we learned several different GC algorithm processing processes, the way GC works, the difference between the new generation and the old age. So far, you should have known about the 5 GC types in JDK 7, and the performance impact of each GC.

In this article, I'll show you how the JVM runs the GC in a real-world environment .

What is GC monitoring

GC monitoring refers to the process of tracking the JVM running a GC at run time. For example, with GC monitoring, we can find:

1. When the new generation of objects will be moved to the old age, how many objects have been moved to the old age.
2. When stop-the-world occurs and how long it lasts.

With GC monitoring, you can see if the JVM is running the GC efficiently and if additional GC tuning is required. Based on this information, we can improve application performance by optimizing the application or changing the GC run mode (GC tuning ).

How to do GC monitoring

There are many ways to monitor GC, except that the presentation of GC operation information is different. The GC is triggered by the JVM, because the information presented by the GC Monitoring tool is provided by the JVM, so the information obtained is consistent regardless of which method is used for GC monitoring. Therefore, there is no need to delve into each GC monitoring tool, just take the time to learn how each tool is used and be able to choose the right tool for different situations.

Because the JVM specification does not require a standard way to expose GC information, the tools or JVM options listed below do not apply to all different JVM implementations. The following introduction is based on the Hotspot JVM(Oracle JVM). Because NHN uses the Oracle (SUN) JVM, it is not too difficult to use the following tools or JVM options.

First, GC monitoring tools are divided into CUI and GUIdepending on the access interface and manner. The classic Cui tool can use a separate Cui application jstat, or it can be implemented by providing a "-verbosegc" option when running the JVM.

The GUI GC monitoring tool is implemented by a separate GUI application, followed by three commonly used GUI GC tools: Jconsole, JVISUALVM, and visual GC.

Here's how to learn each of the GC monitoring methods:

Jstat

Jstat is a monitoring tool built into the hotspot JVM. The Hotspot JVM also has built-in other monitoring tools such as JPS and jstatd. Sometimes these three tools are needed to monitor the operation of a Java application.

Jstat Not only provides information about GC operations, but also provides information about class loading and immediate compiler-related operations. However, this article will only cover the functions that are related to GC operations provided by JSTAT.

The Jstat is located in $JDK_HOME/bin the directory, and the Jstat command should be able to run if the Java or JAVAC commands work correctly.

You can try it on the command line:

$> 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$>

As shown above, the actual memory parts of the data are listed in the following column order:

SOC        s1c        s0u        s1u        EC        EU        OU        PC

Vmid (VM id:virtual Machine ID), see a name indicating the IDof the VM. Virtual machines that run locally or remotely can be specified by Vmid. A Java application running on a local virtual machine is also known as Lvmid(local vmid), usually the same as the PID Vmid. Although you can view the values of the PID by using the PS command or the Task Manager of Windows to get Lvmid, it is recommended to use JPSbecause the PID and lvmid do not always correspond to each other. JPS represents Java PS. As the PS command can see the PIDs and process names, the Vmids and Main method information can be seen through JPS.

Use JPS to find the vmid of the Java application you want to monitor, and then as a jstat parameter. If multiple was instances are running on the same device, only the boot program information can be found using the JPS command only. This is the time to use the command with the JPS command. ps -ef | grep java

GC performance data needs to be continuously observed, so it is necessary to periodically output GC monitoring information when running Jstat.

For example, running jstat -gc <vmid> 1000 (or 1s) will output gc data once every 1s on the console. jstat -gc <vmid> 1000 10 GC data will be output once every 1s, with a total output of 10 times.

GC-related options In addition to -GC, there are some others, as shown in the following table:

Option Name	Description
Gc	The current size and usage of each partition on the output heap space (Ede, Survivor, old, etc.), the total number of GC executions, and the amount of execution time accumulated.
Gccapacity	The minimum and maximum capacity of each partition on the output heap space, the current size, the number of GC executions on each zone (not outputting the current usage and the accumulated GC time-consuming).
Gccause	In addition to outputting the information provided by-gcutil, the reason for the last GC and the current GC is also output.
Gcnew	GC performance data on the Cenozoic.
Gcnewcapacity	Statistical information on the Cenozoic capacity.
Gcold	GC performance data for the old age.
Gcoldcapacity	Statistic information of the old age volume.
Gcpermcapacity	Statistics on the Persistence generation (method area).
Gcutil	Output the usage of each partition in% format. It also outputs the total number of GC executions and the cumulative time-consuming.

If you only care about the GC frequency, you usually use -gcutil(or-gccause), -gc, -gccapacity .

• -gcutil is used to detect the amount of usage on each area, the number of GC executions, and the cumulative time
• The -gccapacity and several other options can be used to output the actual allocated memory size.

The output using the -GC option is as follows:

s0c         s1c ...    GCT1248.0     896.0 ...    1.2461248.0      896.0 ...         1.246 ...        .....    ..... ...

Assigning different options to Jstat lists different columns, as shown in the following. The Jstat option for outputting this information is listed on the right side of the table.

Data Columns	Description	Supported Jstat Options
s0c	Current capacity of Survivor0	-gc -gccapacity -gcnew -gcnewcapacity
S1c	Current capacity of S1	-gc -gccapacity -gcnew -gcnewcapacity
T02	Usage of S0	-gc -gcnew
s1u	Usage of S1	-gc -gcnew
EC	Current capacity of Eden area	-gc -gccapacity -gcnew -gcnewcapacity
EU	Usage of Eden Area	-gc -gcnew
Oc	Current capacity in old area	-gc -gccapacity -gcnew -gcnewcapacity
OU	Old area usage	-gc -gcnew
Pc	Current capacity of the method area	-gc -gccapacity -gcold -gcoldcapacity -gcpermcapacity
Pu	Usage of method Area	-gc -gcold
Ygc	Young GC Number	-gc -gccapacity -gcnew -gcnewcapacity -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause
Ygct	Young GC accumulates time-consuming	-gc -gcnew -gcutil -gccause
FGC	Full GC Count	-gc -gccapacity -gcnew -gcnewcapacity -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause
Fgct	Full GC cumulative time-consuming	-gc -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause
GCT	GC Total cumulative time-consuming	-gc -gcold -gcoldcapacity -gccapacity -gcpermcapacity -gcutil -gccause
Ngcmn	Cenozoic Minimum capacity	-gccapacity -gcnewcapacity
Ngcmx	Cenozoic Maximum Capacity	-gccapacity -gcnewcapacity
Ngc	New Generation Current capacity	-gccapacity -gcnewcapacity
Ogcmn	Old age Minimum capacity	-gccapacity -gcoldcapacity
Ogcmx	Old age Maximum Capacity	-gccapacity -gcoldcapacity
OGC	The old age current capacity	-gccapacity -gcoldcapacity
Pgcmn	Method Area Minimum capacity	-gccapacity -gcpermcapacity
Pgcmx	Method Area Maximum Capacity	-gccapacity -gcpermcapacity
Pgc	Method Area Current capacity	-gccapacity -gcpermcapacity
Pc	Current capacity of the method area	-gccapacity -gcpermcapacity
Pu	Method Area Usage	-gccapacity -gcold
lgcc	Why the last GC occurred	-gccause
Gcc	Why the current GC occurs	-gccause
Tt	Survival threshold, if the object moves more than this threshold in the Cenozoic, it will be moved to the old age	-gcnew
Mtt	Maximum survival threshold, if the object moves more than this threshold in the Cenozoic, it will be moved to the old age	-gcnew
Dss	Ideal capacity of the survivor area	-gcnew

Number of capacity in table is: KB

The advantage of Jstat is that both local and remote Java applications, you can view the data related to GC operations through the JSTAT command and output this information through the console. When you use the -gcutil option, information for the following fields is output. When doing GC tuning, pay particular attention to YGC, ygct, FGC, fgct , and GCT data changes.

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, which counts the time-consuming situation of the GC runtime and reflects the performance metrics of the GC.

In the above example,YGC is 217 times, ygct is 0.928, and the average time for each young GC is 4ms (0.004 s). It is also possible to calculate the average time spent for full GC is 33MS.

However, the average value does not help to find the GC problem that is implemented, because each time the GC is time consuming there is usually a huge deviation (that is, if the average of the full GC is 0.067s, it may mean that one GC takes 1ms and the other lasts 134ms). To be able to observe the independent time-consuming rather than the average of each GC, a better way is to use -verbosegc.

-verbosegc

-VERBOSEGC is a JVM option when running Java applications. Jstat can monitor any JVM application without specifying a startup parameter,-VERBOSEGC to be specified when the app is turned on, so it looks like -verbosegc is not a necessary option (because you can use Jstat to do the same work )。 However, when GC occurs, the output information of -VERBOSEGC is easier to understand, which is more useful for monitoring chores GC information.

	jstat	-verbosegc
Monitoring target	Can output logs to Java applications on the terminal or remote Java applications that can be connected to the network via JSTATD	Java application with the-VERBOSEGC parameter specified when starting the JVM
Output information	Heap status (usage, maximum capacity, GC count, cumulative time-consuming, etc.)	Capacity changes and GC time-consuming for the Cenozoic and older generations before and after each GC
Output timing	Any specified time	When any GC occurs
Advantage	Easy continuous observation of heap size changes	Observing the effect of single GC on system

You can also specify the following additional options when using -VERBOSEGC :

• -xx:+printgcdetails
• -xx:+printgctimestamps
• -xx:+printheapatgc
• -xx:+printgcdatestamps (options introduced by Jdk6u4)

If you specify only the -verbosegc option, -xx:+printgcdetailsis also specified by default. In addition,-VERBOSEGC can be combined with additional options.

With -VERBOSEGC , when a minor GC occurs, the output data format is as follows:

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

Field	meaning
Collector	The collector used
Starting Occupancy1	The Cenozoic size before GC occurs
Ending Occupancy1	The size of the post-generation GC
Pause time1	Length of time the Java application pauses when executing minor GC
Starting Occupancy3	Total amount of heap space before GC occurs
Ending Occupancy3	Total heap Space Size after GC occurs
Pause Time3	Java application Pause duration when performing overall GC (including full GC)

The following is an example of a full GC output:

[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 the [CMS Recovery Algorithm] () is used, the information about the CMS will be provided shortly thereafter.

Because the -verbosegc option can output the information in log for each GC, it is easy to see how the heap usage changes after GC operations are turned off.

(Java) VisualVM + Visual GC

The Java Virsual VM is a GUI-style charting/monitoring tool provided by Oracle JDK.

Figure 1:VIRSUALVM Interface

Unlike the built-in JDK version, you can download the virsual VM separately on the website. For convenience, the built-in version of the JDK is called Java VIRSUALVM (JVISUALVM), which is downloaded separately from the Web site called the Virsual VM (VISUALVM). The characteristics of the two are not exactly the same, in some ways (such as installing plug-ins, etc.) will be slightly different. Personally, I prefer to use a separately downloaded virsual VM.

After you start the visual VM, if you select the app you want to monitor on the left panel, you'll see the "Monitoring" column. Basic information about the GC and memory heap can be obtained from the monitoring bar.

Although it is possible to get the basic state of GC through the basic features of visual VMs, it is not possible to get more detailed information like using jstat and -verbosegc .

If you want detailed information like Jstat, you need to install the appropriate virsual VM plug-in. The Virsual GC plugin can be obtained from the Tools menu.

Figure 2:virsual GC Installation Interface

by Virsual GC, information provided by JSTATD can be obtained in a more intuitive manner.

Figure 3:virsual GC Runtime interface

Hpjmeter

Hpjmeter is a handy tool for analyzing the results of -VERBOSEGC output. If you think of visual GC as a GUI version of Jstat, then Hpjmeter is the GUI version of-VERBOSEGC. Again, GC analysis is just one of the many features that Hpjmeter provides. Hpjmeter is a performance monitoring tool developed by HP that can be used on Hp-ux,linux and MS Windows.

At first, it was just a tool called Hptune that provided a GUI-style analysis of the -VERBOSEGC. The Hptune has been integrated since Hpjmeter 3.0, so there is no need to download hptune separately.

The output of-VERBOSEGC can be redirected to a separate file during application run.

You can open the file by Hpjmeter and then use the intuitive GUI interface to easily analyze GC data.

Figure 4:hpjmeter

The following chapter describes

This chapter, as a foreshadowing of GC tuning, focuses on how to monitor GC information. In general, I would recommend using Jstat to observe GC operations, and then analyze GC data by -VERBOSEGC when a more time-consuming GC is found. The general process of GC tuning, therefore, is to analyze and compare the changes in -VERBOSEGC output results after using different GC options. The next chapter will show you the best options for GC tuning with real-world examples.

Sangmin Lee, senior engineer of Performance Lab, NHN Company

Java GC Expert series 2:java monitoring of garbage collection