Monitor Java Garbage Collection

Monitoring JVM’s GC refers to the process of figuring out how JVM is running GC. we can find out the following from monitoring it

  1. When an object in young has moved to old and by how much,
  2. or when stop-the-world has occurred and for how long

So we can find out whether the JVM is running GCs effectively, and to determine whether additional tuning of GC is necessary. Based on it we can determine whether application change is required or GC method should be changed.

Monitoring Garbage Collection

There are lot of tools to monitor GC, here we stick to command line based one as it should be easy as it requires no further installation.

JSTAT

JSTAT is a monitoring tool in hotspot JVM. If you have Java installed then you have JSTAT too. other monitoring tools are JPS and JSTATD.

JSTAT provides the following

  • GC operation information
  • Class loaded operation information and JIT operation compiler information

The command is

jstat -gc  vmid  1000

For getting the vmid in Linux we can use the command ps -ef | grep java and it will list all the JVM process. In Windows we can get it from command jps command. The 100o in command indicates that the JSTAT takes the stats for every second.

The options in JSTAT are provided below

class: Displays statistics about the behavior of the class loader.

compiler: Displays statistics about the behavior of the Java HotSpot VM Just-in-Time compiler.

gc: Displays statistics about the behavior of the garbage collected heap.

gccapacity: Displays statistics about the capacities of the generations and their corresponding spaces.

gccause: Displays a summary about garbage collection statistics (same as -gcutil), with the cause of the last and current (when applicable) garbage collection events.

gcnew: Displays statistics of the behavior of the new generation.

gcnewcapacity: Displays statistics about the sizes of the new generations and its corresponding spaces.

gcold: Displays statistics about the behavior of the old generation and metaspace statistics.

gcoldcapacity: Displays statistics about the sizes of the old generation.

gcmetacapacity: Displays statistics about the sizes of the metaspace.

gcutil: Displays a summary about garbage collection statistics.

printcompilation: Displays Java HotSpot VM compilation method statistics.

The advantage of jstat is that it can always monitor the GC operation data of Java applications running on local/remote machine, as long as a console can be used.

Below is the output when -gc option is used.

jstat -gc 7540 1000

   S0C     S1C   S0U    S1U     EC       EU       OC      OU      MC     MU      CCSC      CCSU YGC YGCT FGC FGCT GCT
 94720.0 87552.0 0.0 69979.0 204288.0 169889.8 166400.0 112406.3 96256.0 91234.3 13312.0 11872.5 51 1.903 3 1.582 3.484
 94720.0 87552.0 0.0 69979.0 204288.0 169889.8 166400.0 112406.3 96256.0 91234.3 13312.0 11872.5 51 1.903 3 1.582 3.484
 94720.0 87552.0 0.0 69979.0 204288.0 169889.8 166400.0 112406.3 96256.0 91234.3 13312.0 11872.5 51 1.903 3 1.582 3.484
 94720.0 87552.0 0.0 69979.0 204288.0 169889.8 166400.0 112406.3 96256.0 91234.3 13312.0 11872.5 51 1.903 3 1.582 3.484
 94720.0 87552.0 0.0 69979.0 204288.0 169889.8 166400.0 112406.3 96256.0 91234.3 13312.0 11872.5 51 1.903 3 1.582 3.484
 94720.0 87552.0 0.0 69979.0 204288.0 169889.8 166400.0 112406.3 96256.0 91234.3 13312.0 11872.5 51 1.903 3 1.582 3.484
 94720.0 87552.0 0.0 69979.0 204288.0 169889.8 166400.0 112406.3 96256.0 91234.3 13312.0 11872.5 51 1.903 3 1.582 3.484

The following the legend for gc option

-gc option
Garbage-collected heap statistics.

S0C: Current survivor space 0 capacity (kB).

S1C: Current survivor space 1 capacity (kB).

S0U: Survivor space 0 utilization (kB).

S1U: Survivor space 1 utilization (kB).

EC: Current eden space capacity (kB).

EU: Eden space utilization (kB).

OC: Current old space capacity (kB).

OU: Old space utilization (kB).

MC: Metaspace capacity (kB).

MU: Metacspace utilization (kB).

CCSC: Compressed class space capacity (kB).

CCSU: Compressed class space used (kB).

YGC: Number of young generation garbage collection events.

YGCT: Young generation garbage collection time.

FGC: Number of full GC events.

FGCT: Full garbage collection time.

GCT: Total garbage collection time.

 

contd. The values YGC, YGCT, FGC, FGCT and GCT  are important as they give the GC time of the application.  In this example, YGC is 51  and YGCT is 1.903 So, after calculating the arithmetical average, you can see that it required about 4.29 ms (0.00429 seconds) for each young GC. Likewise, the average full GC time us 500ms. This arithmetic average does not conclude the GC findings as it is average and it takes into extremities in the sequence.  In order to check the individual GC time instead of the arithmetical average time, it is better to use -verbosegc.

VERBOSE:GC

-verbose:gc is one of the JVM options specified when running a Java application. While jstat can monitor any JVM application that has not specified any options, -verbose:gc needs to be specified in the beginning, so it could be seen as an unnecessary option (since jstat can be used instead). However, as -verbosegc displays easy to understand output results whenever a GC occurs, it is very helpful for monitoring rough GC information.

jstat -verbosegc
Monitoring Target Java application running on a machine that can log in to a terminal, or a remote Java application that can connect to the network by using jstatd Only when -verbogc was specified as a JVM starting option
Output information Heap status (usage, maximum size, number of times for GC/time, etc.) Size of ew and old area before/after GC, and GC operation time
Output Time Every designated time Whenever GC occurs
Whenever useful When trying to observe the changes of the size of heap area When trying to see the effect of a single GC

The followings are other options that can be used with -verbosegc.

  • -XX:+PrintGCDetails
  • -XX:+PrintGCTimeStamps
  • -XX:+PrintHeapAtGC
  • -XX:+PrintGCDateStamps

If only -verbosegc is used, then -XX:+PrintGCDetails is applied by default. Additional options for –verbosgc are not exclusive and can be mixed and used together.

When using -verbosegc, you can see the results in the following format whenever a minor GC occurs or full GC occurs.

[GC (Allocation Failure)  349573K->144704K(380928K), 0.0517417 secs]
[Full GC (Ergonomics) 156381K->153832K(501760K), 1.9562082 secs]

Following is the format for the verbose:gc output

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

 

Leave a Reply

Your email address will not be published. Required fields are marked *