This article has been updated to include the GC Portal software for Linux and Java Desktop System (JDS), available both for Sun Java System Application Server 7 (formerly Sun ONE Application Server 7 (S1AS7)) and Tomcat servers. Originally, it was made available only for Solaris and Windows. This version of the GC Portal software also includes VisualGC integrated within the GC Portal.

The GC Portal enables analysis and performance tuning of Java applications from a garbage collection (GC) perspective by mining the verbose:gc logs generated by the JVM. GC Portal is a one-stop page for GC issues and includes an extensive collection of whitepapers, case studies and other material. The Portal is intended to be used with HotSpot JVM from Sun Microsystems, distributed as part of Java 2, Standard Edition (J2SE). Use of the GC Portal enables developers to model application and JVM behaviors from a GC perspective. This article introduces the design and features of the GC Portal, to enable developers to use it as a tool for analyzing and tuning GC.

The GC Portal requires the use of the following switches by the JVM for the generation of verbose:gc logs which are processed by the Portal for analysis.

    -verbose:gc


    -XX:+PrintGCTimeStamps

    -XX:+PrintGCDetails

          

Other JVM switches are not required to be used for generating the appropriate logs for GC Portal, but can be added as considered appropriate for tuning and sizing the JVM and the application. Note: -XX switches are non-standard and are also subject to change without notice in future JVM releases.

Application Modeling and Performance Tuning from a GC Perspective

Modeling Java applications makes it possible for developers to remove unpredictability attributed to the frequency and duration of pauses for garbage collection. These pauses are directly related to:

• Number and total size of objects created and alive
• Average lifetime of these objects
• Size of the JVM heap

Based on the analysis provided by the GC Portal for a specific set of verbose:gc log files fed to the Portal, developers can build a model which helps them understand the application and JVM behavior better.

The verbose:gc logs contain valuable information about:

• GC pause times
• Frequency of GC
• Application run times
• Size of objects created and destroyed
• Rate of object creation
• Memory recycled at each GC

The behavior of the application can be charted and analyzed to determine the different relationships between pause duration, frequency of pauses, object creation rate, and memory freed. Analysis of this information can enable developers to tune an application's performance, optimizing GC frequency and collection times by specifying the best heap sizes, other JVM options, and alternate GC algorithms for a given situation.

Information Derived from verbose:gc Logs for Analyzing and Modeling GC Behavior

This kind of information can be used to performance tune the process of garbage collection.

Average GC pauses in the young and old generation

The average time the application is suspended while garbage collection is done in the JVM.

Average GC frequency in the young and old generation

The periodicity at which the garbage collector runs in the young and the old generation. This can be obtained since the time instance of each GC activity is logged.

GC sequential overhead

The percentage of system time for which the application is suspended for garbage collection to take place. Calculated as Avg. GC pause * Avg. GC frequency * 100%

GC concurrent overhead

The percentage of system time for which garbage collection happens concurrently with the application. Calculated as Avg. concurrent GC time (sweeping phase) * Avg. concurrent GC frequency / no. of CPUs

Memory recycled by each GC in the young and old generation

The total garbage collected during each GC.

Allocation rate

The rate at which data gets allocated by the application in the young generation. If young generation heap occupancy_at_start_of_current_gc=x, occupancy_at_end_of_previous_gc = y and the GC frequency is 1 per second, then the allocation rate is approximately x-y per second.

Promotion rate

The rate at which data gets promoted to the old generation.

Total data allocated by the application

This is the total data which is allocated by the application per transaction.

Total data can be split into short term data and long term data

Long term data is what survives the young generation GC cycles and is promoted to the old generation.

Short term data

The short lived data that dies very quickly and is collected in the young generation. This can be calculated as Total Data - Long Term Data.

Total active data

This is the total data alive at any instance of time. This is critical for building a model for sizing the JVM heap. For example, for a load of 100 transactions per second, with long term data of 50K per transaction lasting for a minimum of 40 seconds, the minimum memory footprint of the old generation would have to be

            50K*40s*100 = 200M

Memory leaks

These can be detected and "out of memory" errors can be better understood by monitoring the garbage collected at each sweep as shown by these logs.

Flags and Switches for Generating GC Logs

There is a lot of useful GC-related information which the JVM can log into a file. This information is used by the GC Portal to tune and size applications and the JVM from a GC perspective. Logs containing detailed GC information are generated when a Java application is run with the following switches:

- verbose:gc This flag turns on the logging of GC information. Available in all JVMs.

-XX:+PrintGCTimeStamps Prints the times at which the GCs happen relative to the start of the application. Available only from J2SE1.4.0.

-XX:+PrintGCDetails Gives details about the GCs, such as:

• Size of the young and old generation before and after GCs
• Size of total heap
• Time it takes for a GC to happen in young and old generation
• Size of objects promoted at every GC

Available only from JVM1.4.0.

Using the GC Portal for Application Modeling and Performance Tuning

The GC Portal can be used to better understand an Application's GC behavior so as to performance tune and size applications to run optimally under lean, peak, and burst conditions. It supports J2SE1.2.2, J2SE1.3, J2SE1.4 and J2SE1.4.1 onwards, including the two new garbage collection implementations, the Parallel Collector and the Concurrent Collector. It allows developers to submit GC log files and analyze application behavior, based on these log files. It also considers some application- and environment-specific information including:

• Transaction Rate or Server Load

  This applies to typical server-side applications operating in a Client-Server configuration. For such applications, this is the rate at which the client might be generating a steady load for the server to process and is useful for a steady state analysis of the server. The steady-state analysis may include several scenarios like worst-case/peak/burst situation or an average situation. This information is not mandatory. If it is not available or not applicable, it can be ignored. In such a case, some of the information presented by the Portal should also be ignored which includes:

  • Theoretical throughput
  • Short term data
  • Long term data

• Number of processors on the target machine

  This information is used to make certain calculations by the Portal like the Concurrent GC overhead.

• JVM version used by the application (1.2.2_xx, 1.3.x, 1.4.0, 1.4.1)

  Since the verbose:gc log format is not standard, and there have been changes from the JVM, this information is needed by the GC Portal.

GC Portal Design

The GC Portal is comprised of four engines:

• Analyzer and reporting engine
• Graphical engine
• Intelligence engine
• Session and storage engine
• VisualGC

Analyzer and Reporting Engine

• Loads verbose:gc log files, mines them and reports:
  • GC pauses in young and old generation
  • GC frequency in young and old generation
  • Rate of allocation of objects
  • Rate of promotion of objects from young to old generation
  • Total GC time
  • Total Application time
  • Initial and Final heap sizes of young and old generations
  • GC sequential overhead
  • GC concurrent overhead
• Calculates and presents application related information
  • Short term data per transaction
  • Long term data per transaction
  • Theoretical maximum throughput
  • CPU efficiency
  This information can be ignored for applications that are not transaction based, but is relevant for client side applications or those that might exhibit extremely phased behavior.
• Presents detailed GC related behavior of the application and JVM over time
  • User can view the GC data, sampled at chosen intervals of time for the entire run.
  This detailed GC information sampled at chosen intervals for the entire run is extremely useful where applications exhibit varied behavior over time, such as phased, cyclical or randomly reactive applications, and the average summary information might be skewed as a result. This detailed and sampled information can be used to see the application and JVM behavior as it changes over time.
• Detailed memory recycling information over time in young and old generations
  • Memory before GC
  • Memory after GC
  • Memory freed at each GC
• Aging information of objects in young generation
  • Available if -XX:+PrintTenuringDistribution switch is used to generate logs.

Figure 1 is a snapshot of an example report presented by the Analyzer engine of the GC Portal.

Figure 1. Snapshot of the Analysis Engine from the GC Portal

Graphical Engine

Most of the information that is presented by the Analyzer engine in tabular form can be plotted graphically. Multiple charts can be plotted on the same graph to aid comparisons.

• Graphical Presentation of Detailed Timeline GC Analysis
• Graphical Presentation of Memory Recycling Information at every GC
• Graphical comparison of GC information from various log files
• Graphical Presentation of Object Age Tenuring information for every "Age"

Figure 2. Snapshot of the Graphical Engine of the GC Portal

Intelligence Engine

The Intelligence Engine is comprised of:

• General Recommendations

  This section provides papers covering general information and recommendations on tuning GC performance. The Portal does not provide dynamic recommendations or automatic tuning. The Recommendations include general information on how to:

  • Reduce GC pause and frequency
  • Reduce GC sequential overhead
  • Size the young and old generation heaps to handle a given load
  • Detect memory leaks
  • Choose collectors
  • Choose different JVM options and switches.
• Empirical Modeling

  Rank the application runs based on data analyzed from multiple verbose:gc logs. The user can choose the files (amongst all those were loaded) for modeling based on the following choices:

  • Transaction rate
  • Number of processors
  • Young generation size
  • Old generation size
  • JDK version
  • Heap sizes
  The user can rank the optimal JVM environment based on the following criteria:
  • GC pauses
  • GC sequential overhead
  • GC frequency
  • CPU efficiency
  The user can also view the graphical comparison of the various runs.



Figure 3. Snapshot of the Intelligence engine of the GC Portal

• Projections for sizing and tuning through "what-if" scenarios

  How GC behavior might change with change in size of the young generation. This functionality is currently limited and works only on J2SE1.4.1 onwards using the Concurrent Collector. Projection output shows potential changes in:

  • GC pause
  • GC frequency
  • GC sequential load
  • CPU utilization (%)
  • Speedup
  • Allocation rate
  • Promotion rate
  • Size of Short-lived data
  • Size of long-lived data

• Case Studies

  Some real world case studies on how to tune from a GC perspective.

• White Papers

  Pointers to some white papers with in-depth details on GC tuning.

Session and Storage Engine

• Manage user sessions
• Manage and store user profiles
• Manage and store user data/logs securely
• Make the user/data logs available for reference viewing, and empirical modeling

Figure 4. Snapshot of the Storage Engine of the GC Portal

VisualGC

The visualgc tool attaches itself to an instrumented HotSpot JVM and collects and graphically displays garbage collection, class loader, and HotSpot compiler performance data. It is incorporated into the GC Portal for gathering GC-related information at JVM runtime. GC Portal uses the webstart tool for running and displaying the visualGC information in a browser. More details on this tool are available at the CoolStuff - jvmstat page. The ReadMe file for running VisualGC from within the GC Portal is built into the GC Portal Software.

Acknowledgments:

The author would like to thank Mayank Srivastava, Nagendra Nagarajayya, Nandula Narasimham and S.R.Venkatramanan for their contribution to the GC Portal. The author would also like to thank the Sun JVM garbage collection architects and experts John Coomes, David Detlefs, Steve Heller, Peter Kessler, Ross Knippel, Jon Masamitsu, James Mcilree and Y.S. Ramakrishna for their help and guidance on this work. The author would also like to thank the members of Sun's JVM performance team, Timothy Cramer and Brian Doherty (author of VisualGC and jvmstat tools) for their help towards integrating VisualGC into GC Portal.

About the Author:

Alka Gupta is a Member of the Technical Staff at Sun Microsystems. She's responsible for working with Sun's ISV's and partners to help them adopt the emerging Sun technologies and platforms quickly and efficiently. She has been working in the area of performance tuning on Sun platforms for almost 7 years, and has been in this industry for nearly 10 years. Alka graduated from the Indian Institute of Technology (IIT), India.

References:

• Java HotSpot VM Options
• New Parallel Collector
• Sun ONE
• JSR 174
• Sun Docs
• VisualGC