HP

HPjmeter 4.1 User's Guide

English
  HPjmeter 4.1 User's Guide   

Chapter 6 Analyzing Garbage Collection Data

HPjmeter allows you to process garbage collection (GC) data from Java virtual machines.

Separating the GC data collection step from the analysis step has the following advantages:

  • The data analysis can be done at a different time and on a different platform than was used to run the application. For example, it can be done on a desktop system or on a laptop.

  • A non-interactive agent will often impose less overhead than an interactive one.

  • The data files obtained naturally facilitate comparison of different runs or creation of a history of performance improvements.

For detailed analysis of the efficiency of garbage collection, it is useful to take a close look at garbage collection patterns. A study of patterns of garbage collection can help you determine whether or not the best GC type and heap size are being applied appropriately during the application run. You can also use detailed GC data to uncover problems in the application programming.

With the collection of verbose GC data, HPjmeter is able to present extensive details about the memory usage and garbage collection (GC) exhibited when an application is running. Details are presented in a data summary and in graphic visualizers that can be adjusted to focus on particular aspects of the data.

Obtaining Garbage Collection Data

The -Xverbosegc option, available for the HP-UX HotSpot™ VM, was specifically designed to produce ASCII garbage collection data files for in-depth analysis using HPjmeter.

-Xloggc can be useful for quick comparison of garbage collection behavior across different platforms.

The GC viewer automatically opens when you open an Xverbosegc or Xloggc file from the HPjmeter console.

Data Collection with -Xverbosegc

-Xverbosegc produces detailed information about the performance of individual garbage collector types for the entire Java application.

To run your application with an option to capture the garbage collection information, use the following command:

$ java ... -Xverbosegc[0|1][:file=[stdout|stderr|filename[,[n][h][d][u][t]]]]

The following table lists examples of supported -Xverbosegc options for capturing garbage collection data. This table provides information for Java 1.5.0.04. Other versions may differ from this. HPjmeter correctly presents and labels collected data based on the Java version running with the application. To see the complete list of available options for the Java version you are running, use

$ java ... -Xverbosegc:help 

To see the availability of HPjmeter metrics from -Xverbosegc data collection, see –Xverbosegc and –Xloggc Options and Their Corresponding Metrics.

Table 6-1 Supported -Xverbosegc options for Java 1.5.0.04

0|10 prints after every old generation garbage collection or after a full GC1 prints after every garbage collection (default)
:file=[stdout|stderr|filename] stderr (default) directs output to standard error stream stdout directs output to standard output stream filename where the output shall be written
[n[h[d[u[t]]]]]where:
  • n prevents appending the pid to the log filename

  • h appends the hostname to the log file name

  • u appends the username to the log file name

  • d appends the date to the log file name

  • t appends the time to the log file name

 

At every selected garbage collection, the following 20 fields are printed. These values hold true for Java 1.5.0.04. Other versions may differ. To see the complete list of available fields for the Java version you are running, use

java ... -Xverbosegc:help

Table 6-2 Fields Captured in GC Log Data When Using -Xverbosegc print options

%1Type of garbage collection.1 = scavenge (of new generation only)2 = old generation GC or full GC3 = complete background, concurrent mark and sweep (CMS) GC4 = incomplete background, concurrent mark and sweep GC11 = Ongoing CMS GC
%2This value varies depending on the value of %1.
  • When %1 is equal to 1, %2 indicates whether or not a parallel scavenge occurred. Possible values are:

    • 0: non-parallel scavenge

    • n(>0): parallel scavenge with n number of parallel GC threads

  • When %1 is equal to 2, %2 indicates that an old generation GC or full GC has occurred. Reasons for the GC are given as:

    • 1: Allocation failure, followed by a failed scavenge, leading to a full GC

    • 2: Call to System.gc made

    • 3: Tenured generation is full

    • 4: Permanent generation is full

    • 5: Scavenge followed by a train collection

    • 6: Concurrent-Mark-Sweep (CMS) generation is full

    • 7: Old generation expanded on last scavenge

    • 8: Old generation too full to scavenge

    • 9: FullGCAlot

    • 10: Allocation profiler triggered

    • 11: JVMTI-forced garbage collection

    • 12: Adaptive size policy

    • 13: Last ditch collection

    • 14: GC Locker-Initiated GC

    • 15: Heap Dump Triggered GC (HP implementation)

    • 16: Heap Dump Triggered GC

  • When %1 is equal to 3, %2 indicates that a complete background, concurrent mark and sweep GC has occurred. Reasons for the GC are given as:

    • 1: Occupancy > initiating occupancy

    • 2: Expanded recently

    • 3: Incremental collection will fail

    • 4: Linear allocation will fail

    • 5: Anticipated promotion

  • When %1 is equal to 4, %2 indicates that an incomplete background, concurrent mark and sweep GC has occurred as a result of exiting after yielding to foreground GC. The form for this data set is given as n.m where n is the GC reason as follows:

    • 1: Occupancy > initiating occupancy

    • 2: Expanded recently

    • 3: Incremental collection will fail

    • 4: Linear allocation will fail

    • 5: Anticipated promotion

    • 6: Incremental CMS garbage collection

    and m indicates the background CMS state when yielding, as follows:

    • 0: Resetting

    • 1: Idling

    • 2: Initial marking

    • 3: Marking

    • 4: Final marking

    • 5: Pre-cleaning

    • 6: Sweeping

    • 7. Abortable pre-cleaning

  • When %1 is equal to 11, %2 indicates the stop-the-world phase of CMS GC, as follows:

    • 2: Initial marking (first stop-the-world phase)

    • 4: Final marking (second stop–the-world phase)

%3Program time at the beginning of the collection, in seconds
%4Garbage collection invocation. Counts of background CMS garbage collections and other garbage collections are maintained separately
%5Size of the object allocation request that forced the GC, in bytes
%6Tenuring threshold - memory allocation that determines how long newborn objects remain in the new generation, in bytes. These spaces are reported:
  • Occupied before garbage collection (Before)

  • Occupied after garbage collection (After)

  • Current capacity (Capacity)

%7, %8, %9Eden sub-space within the new generation, in bytes. These spaces are reported:
  • Before

  • After

  • Capacity

%10, %11,%12Survivor sub-space within the new generation, in bytes. These spaces are reported:
  • Before

  • After

  • Capacity

%13, %14, %15Old generation, in bytes. These spaces are reported:
  • Before

  • After

  • Capacity

%16, %17, %18Permanent generation, in bytes. These spaces are reported for storage of reflective objects:
  • Before

  • After

  • Capacity

%19Total stop-the-world duration, in seconds.
%20Total time used in collection, in seconds.

 

Collecting Allocation Site Statistics for Viewing in HPjmeter

Use the following command to capture allocation site statistics in a file for display in the HPjmeter garbage collection viewer. The GC viewer automatically opens when you open an Xverbosegc file from the HPjmeter console in one of the following ways:

  • Using -XX:+PrintAllocStatistics option to enable the Allocation Statistics function by entering the following:

    $ java ... -XX:+PrintAllocStatistics -Xverbosegc[0|1][:file=[filename[,[n][h][d][u][t]]]]
    
  • Sending a signal to the JVM to capture allocation site statistics data at that time:

    $ kill -PROF pid

    OR

    $ kill -21 pid

Data from the opened file is visible in the Allocation Site Statistics visualizer.

Collecting Glance Data for Viewing in HPjmeter

If you have the HP GlancePlus product installed on your HP-UX system, you can run GlancePlus in adviser mode using the script at /opt/hpjmeter/bin/javaGlanceAdviser.ksh. This script has three command-line parameters: the pid of the Java process for which you want to collect data, the name of the output file to receive the data, and the sampling interval, in seconds. Only the first parameter is required, the second and third are optional. Here is a sample command line to capture Glance data in a file for display in the HPjmeter garbage collection viewer:

$ /opt/hpjmeter/bin/javaGlanceAdviser.ksh 1234 ga.out.1234

This command collects information about process 1234 using the default sampling interval, and writes the results to the file ga.out.1234. You can then open this file in the HPjmeter console to view the data graphically. If you also collected GC information using the -Xverbosegc option, you can append the Glance data to the GC log file and then use HPjmeter to read the combined file. Collecting both the Glance data and the GC data at the same time is very useful because you can view all the data together in one HPjmeter console.

Data from the opened file is visible in the Glance Data visualizer, accessible from the Glance Adviser tab on the GC visualizer. Glance system call data is obtained from the PROC_SYSCALL loop in Glance Plus, and is visible in the Glance System Call Data visualizer, accessible from the Glance System Call tab on the GC visualizer.

Collecting GC Data with Zero Preparation

Zero preparation GC data collection is a feature in the HP JDK/JRE 5.0.14 and later, and 6.0.02 and later. It is started from the command line by sending a signal to the JVM to start GC data collection.

To collect GC data without interrupting an already running application, do the following from the command line:

  1. Confirm that HP JDK/JRE 5.0.14 or later, or 6.0.02 or later is running the application that you want to analyze, and that no -Xverbosegc or -Xloggc option has already been specified.

  2. Locate the process ID of the running Java application.

  3. Start the profiling interval. Send a signal to the JVM by typing:

    kill -PROF pid or kill -21 pid

    The GC data will be written to a file named java_pid.vgc in the current directory of the JVM process.

    Let the collection generated by the JVM continue for the length of time that you think will be meaningful.

  4. Stop the data collection interval by sending the same signal to the JVM:

    kill -PROF pid

    You can now open the saved file in the HPjmeter console and view the collected metrics.

Time periods where no data is collected are shown in a light purple in all the GC graphic visualizers.

Figure 6-1 Appearance of GC Data Collected in Intervals During a Session

Appearance of GC Data Collected in Intervals During a Session
NOTE: For the signal to be captured by the JVM, you must either be logged in as root, or you must be the user who started the JVM.

Related Topics

Data Collection with -Xloggc

-Xloggc directs a smaller set of data to a file than what is available with -Xverbosegc.

For every garbage collection, the following six fields are printed to the log file:

  • Cumulative time since data collection began (in seconds)

  • Garbage collection type

  • Heap in use before the GC event

  • Heap in use after the GC event

  • Current maximum heap size

  • Duration of the GC event

To capture basic -Xloggc data, use the following command:

   $ java ... -Xloggc:filename

More data are available if you start the JVM with the -XX:+PrintGCDetails or -XX:+PrintHeapAtGC options. For example, you can type:

$ java ... -XX:+PrintGCDetails -Xloggc:filename

Use these additional options to obtain more data on GC activity in the eden space, the survivor space, the old generation, and the permanent generation.

NOTE:

Using -XX:+PrintGCDetails and -XX:+PrintHeapAtGC Together

Some JVMs improperly mix the output from these two options, resulting in a data file that cannot be parsed properly by HPjmeter. We recommend using only one of the two options.

To see the availability in HPjmeter of metrics derived from -Xloggc data, see –Xverbosegc and –Xloggc Options and Their Corresponding Metrics.

Naming GC Data Files

The following table shows the file name formats used by default when naming files containing garbage collection data. You may want to follow this convention when naming GC data files, but it is not required.

Table 6-3 Default File Name Suffixes for GC Data

OptionFile Name Suffix
-Xverbosegc.vgc
-Xloggc.vgc