Improving Java Application Performance and Scalability by Reducing Garbage Collection Times and Sizing Memory Using JDK 1.4.1

Print-friendly Version

by Nagendra Nagarajayya and J. Steven Mayer
November 2002

New Parallel and Concurrent Collectors for Low Pause and Throughput applications

Abstract

As Java technology becomes more and more pervasive in the enterprise and telecommunications (telco) industry, understanding the behavior of the garbage collector becomes more important. Typically, telco applications are near-real-time applications. Delays measured in milliseconds are not usually a problem, but delays of hundreds of milliseconds, let alone seconds, can spell trouble for applications of this kind -- applications compromise on throughput to provide near-real-time performance. Enterprise applications are transaction oriented and tolerate delays better. They need to crunch as many transactions as possible in the shortest time i.e., the more compute time and resources available, the better. This means, faster and multiple CPUs, lots of memory, increases performance. A garbage collector that can make use of the extra resources, enhances performance.

Garbage collection limitations, which affected the performance of telco and enterprise applications is in the process of being eliminated with the introduction of new parallel and concurrent collectors. The collectors can be used to reduce delays to milliseconds for telco applications -- SIP servers, Call Processing applications --, while increasing throughput by providing more compute time to enterprise applications -- J2EE, OSS/BSS, MOM type of applications.

Analytical and modeling suggestions are presented along with features available in J2SE 1.4.1. A new tool, GC Analyzer, is available to model application behavior and try out the performance tuning suggestions.

Table of Contents

1. Introduction

This paper is an update to our previous paper "Improving Java Application Performance and Scalability by Reducing Garbage Collection Times and Sizing Memory Using JDK 1.2.2" [1], (see http://wireless.java.sun.com/midp/articles/garbage/#1). That paper focussed on improving performance of telecommunication (telco) applications by optimizing garbage collection using collectors like the concurrent garbage collector. The paper also introduced application modeling, and its use to make application behavior deterministic.

The paper builds on the earlier paper and introduces new collectors and options in J2SE 1.4.1. The new collectors can be used to tune performance of both telco and enterprise applications. Garbage collection (GC) delays can be successfully lowered to be in milliseconds with the help of the parallel and the concurrent collector -- size the young-generation to about 64 MB, and the older generation to about 500 MB. So GC, a sizable contributor to performance degradation can be tuned, improving application efficiency to 90+%.

A new tool, GC Analyzer that works with the JDK 1.4.1 verbose GC logs can be downloaded to model application behavior and try out the performance tuning suggestions, (see Appendix A3 for download instructions).

1.1 Introduction to Garbage Collection, And Existing Garbage Collectors

The previous paper also introduced garbage collection, different collectors like the copy collector, mark-sweep-compact collector, incremental collector, generational collection and the advanced concurrent collector. These are covered in the first couple of sections, and can be accessed from http://wireless.java.sun.com/midp/articles/garbage/#1.

JDK 1.4.1 has all of the above collectors, and in addition offers new collectors.

2. New Garbage Collectors in JDK 1.4.1

The Java platform now provides new collectors like the young generation parallel collector and the old generation concurrent collector. In fact, there are two parallel collectors, one, which works in conjunction with the old generation concurrent collector, and is for near real-time or pause dependent applications, while the second is for enterprise or throughput oriented applications - J2EE, billing, payroll, OSS/BSS, MOM apps. The parallel collectors make use of multiple threads to parallelize and scale young generation collections on SMP architectures, speeding up the scavenging¹. The difference between the two collectors is that the low-pause parallel collector works with the new concurrent older collector and with the traditional mark-compact collector, while the throughput parallel collector, at the moment, works only with the mark-compact collector.

2.1 Low Pause Collectors

2.1.1 Parallel Copying Collector

The Parallel Copying Collector is similar to the Copying Collector [1], but instead of using one thread to collect young generation garbage, the collector allocates as many threads as the number of CPUs to parallelize the collection. The parallel copying collector works with both the concurrent collector and the default mark-compact collector.

Figure 1 - Single Threaded & Parallel Collection

The parallel copying collection is still stop-the-world, but the cost of the collection is now dependent on the live data in the young generation heap, divided by the number of CPUs available. So bigger younger generations can be used to eliminate temporary objects while still keeping the pause low. The degree of parallelism i.e., the number of threads collecting can be tuned. This parallel collector works very well from small to big young generations.

The figure (Fig. 1) illustrates the difference between the single threaded and parallel copy collection. The green arrows represent application threads, and the red arrow(s) represent GC threads. The application threads (green arrows) are stopped when a copy collection has to take place. In case of the parallel copy collector, the work is done by n number of threads compared to 1 thread in case of the single threaded copy collector.

2.1.2 Concurrent Collector

The concurrent collector uses a background thread that runs concurrently with the application threads to enable both garbage collection and object allocation/modification to happen at the same time. The collector collects the garbage in phases, two are stop-the-world phases, and four are concurrent and run along with the application threads. The phases in order are, initial-mark phase (stop-the-world), mark-phase (concurrent), pre-cleaning phase (concurrent), remark-phase (stop-the-world), sweep-phase (concurrent) and reset-phase (concurrent). The initial-mark phase takes a snapshot of the old generation heap objects followed by the marking and pre-cleaning of live objects. Once marking is complete, a remark-phase takes a second snapshot of the heap objects to capture changes in live objects. This is followed by a sweep phase to collect dead objects - coalescing of dead objects space may also happen here. The reset phase clears the collector data structures for the next collection cycle. The collector does most of its work concurrently, suspending application execution only briefly.

Figure 2 - Concurrent Collection

The figure (Fig. 2) illustrates the main phases of the concurrent collection. The green arrows represent application threads, and the red, GC thread(s). The small red arrow represents, the brief stop-the-world marking phases, when a snapshot of the heap is made. The GC thread (big red arrow) runs concurrently with application threads (green arrows) to mark and sweep the heap.

Note: If "the rate of creation" of objects is too high, and the concurrent collector is not able to keep up with the concurrent collection, it falls back to the traditional mark-sweep collector.

2.2 Throughput Collectors

2.2.1 Parallel Scavenge Collector

Figure 3 - Parallel Collection

The parallel scavenge collector is similar to the parallel copying collector, and collects young generation garbage. The collector is targeted towards large young generation heaps and to scale with more CPUs. It works very well with large young generation heap sizes that are in gigabytes, like 12GB to 80GB or more, and scales very well with increase in CPUs, 8 CPUs or more. It is designed to maximize throughput in enterprise environments where plenty of memory and processing power is available.

The parallel scavenge collector is again stop-the-world, and is designed to keep the pause down. The degree of parallelism can again be controlled. In addition, the collector has an adaptive tuning policy that can be turned on to optimize the collection. It balances the heap layout by resizing, Eden, Survivor spaces and old generation sizes to minimize the time spent in the collection. Since the heap layout is different for this collector, with large young generations, and smaller older generations, a new feature called "promotion undo" prevents old generation out-of-memory exceptions by allowing the parallel collector to finish the young generation collection.

The figure (Fig. 3) illustrates the application threads (green arrows) which are stopped when a copy collection has to take place. The red arrow represents the n number of parallel threads employed in the collection.

2.2.2 Mark-Compact Collector

The parallel scavenge collector interacts with the mark-sweep-compact collector, the default old generation collector. The mark-compact collector is the traditional mark-compact collector, and is very efficient for enterprise environments where pause is not a big criterion. The throughput collectors are designed to maximize the younger generation heap while keeping the older generation heap to the needed minimum - old generation is intended to very long-term objects only.

Figure 4 - Mark-Compact Collection

The figure (Fig. 4) illustrates a stop-the-world, old generation mark-sweep-compact collection. The application threads (green arrows) are stopped during the collection. The old generation collection single threaded.

3. Heap Layout in JDK 1.4.1

3.1 Young Generation Heap

In JDK 1.4.1, the heap is divided into 3 generations, young generation, old generation, and permanent generation. Young generation is further divided into an Eden, and Semi-spaces.

Figure 5 - Heap layout

The size of the Eden and semi-spaces is controlled by the SurvivorRatio and can be calculated roughly as:

Eden = NewSize - ((NewSize / ( SurvivorRatio + 2)) * 2)
From space = (NewSize - Eden) / 2
To space = (NewSize - Eden) / 2

NewSize is the size of the young generation and can be specified on the command line using -XX:NewSize option. SurvivorRatio is an integer number and can range from 1 to a very high value.

The young generation can be sized using the following options:

-XX:NewSize
-XX:MaxNewSize
-XX:SurvivorRatio

For example, to size a 128 MB young generation with an Eden of 64MB, a Semi-Space size of 32MB, the NewSize, MaxNewSize, and SurvivorRatio values can be specified as follows:

java -Xms512m -Xmx512m -XX:NewSize=128m -XX:MaxNewSize=128m \
    -XX:SurvivorRatio=2 application

3.2 Old Generation Heap

The old generation or the tenured generation is used to hold or age objects promoted from the younger generation. The maximum size of the older generation is controlled by the -Xms parameter.

For the previous example to size a 256 MB old generation heap with a young generation of 256 MB the -mx value can be specified as:

java -Xms512m -Xmx512m -XX:NewSize=256m -XX:MaxNewSize=256m \
    -XX:SurvivorRatio=2 application

The young generation takes 256 MB and the old generation 256 MB. -Xms is used to specify the initial size of the heap.

3.3 Permanent Generation Heap

The permanent generation is used to store class objects and related meta data. The default space for this is 4 MB, and can be sized using the -XX:PermSize, and -XX:MaxPermSize option.

Sometimes you will see Full GCs in the log file, and this could be due to the permanent generation being expanded. This could be prevented by sizing the permanent generation with a bigger heap using the -XX:PermSize and -XX:MaxPermSize options.

For example:

java -Xms512m -Xmx512m -XX:NewSize=256m -XX:MaxNewSize=256m \
    -XX:SurvivorRatio=2 -XX:PermSize=64m -XX:MaxPermSize=64m application

Another way of disabling permanent generation collection is to use the -Xnoclassgc option. This is should be used with care since this disables class objects from being collected. To use this, size the permanent generation bigger so that there is enough space to store class objects, and a garbage collection is not needed to free up space.

For example:

java -Xms512m -Xmx512m -XX:NewSize=256m -XX:MaxNewSize=256m \
    -XX:SurvivorRatio=2 -XX:PermSize=128m -XX:MaxPermSize=128m \
    -Xnoclassgc application

4. Using JDK 1.4.1 - Different options

4.1 Default usage

A java application can be started using the following command:

java application

By default, the young generation uses 2 MB for the Eden, and 64KB for the semi-space. The older generation heap starts from about 5MB and grows up to 44MB. The default permanent generation is 4MB.

4.2 Using The -Xms and -Xms Switches

The old generation, default heap size can be overridden by using the -Xms and -Xmx switches to specify the initial and maximum sizes respectively:

java -Xms <initial size> -Xmx <maximum size> program

For example:

java -Xms128m -Xmx512m application

4.3 Using the :XX Switches to Enable the New Low Pause or Throughput Collectors

4.3.1 Using the Low Pause Collectors

The young generation, parallel copying collector can be enabled by using the -XX:+UseParNewGC option, while the older generation, concurrent collector can be enabled by using the -XX:+ UseConcMarkSweepGC option.

For example:

java -server -Xms512m -Xmx512m -XX:NewSize=64m -XX:MaxNewSize=64m \
    -XX:SurvivorRatio=2 -XX:+ UseConcMarkSweepGC \
    -XX:+UseParNewGC application

Note:

1. If -XX:+UseParNewGC is not specified, the young generation will make use of the default copying collector [1].
2. If -XX+UseParNewGC is specified on a single processor machine, the default copy collector is used since the number of CPUs is 1. You can force the parallel copy collector to be enabled by increasing the degree of parallelism.

4.3.1.1 Controlling the Degree of Parallelism²

By default, the parallel copy collector will start as many threads as CPUs on the machine, but if the degree of parallelism needs to controlled, then it can be specified by the following option:

-XX:ParallelGCThreads=<desired parallelism>

Default value is equal to number of CPUs.

For example, to use 4 parallel threads to process young generation collection:

java -server -Xms512m -Xmx512m -XX:NewSize=64m -XX:MaxNewSize=64m \
    -XX:SurvivorRatio=2 -XX:+UseParNewGC -XX:ParallelGCThreads=4 \
    -XX:+UseConcMarkSweepGC application

4.3.1.2 Simulating The "promoteall" Modifier In JDK 1.4.1

"promoteall" is a modifier available in JDK 1.2.2 that enables promotion of all live objects at a young generation collection to be promoted to the older generation without any tenuring. There is no "promoteall" modifier in JDK 1.4.1, but similar behavior can be achieved by controlling the tenuring distribution. The number of times an object is aged in the young generation is controlled by the option MaxTenuringThreshold. Setting this option to 0 means objects are not copied, but are promoted directly to the older generation. SurvivorRatio should be increased to 20000 or a high value (see 3.1 for heap calculations) so that Eden occupies most of the Young Generation Heap space.

-XX:MaxTenuringThreshold=0 -XX:SurvivorRatio=20000

For example:

java -server -Xms512m -Xmx512m -XX:NewSize=64m -XX:MaxNewSize=64m \
    -XX:SurvivorRatio=20000 -XX:MaxTenuringThreshold=0 \
    -XX:+UseParNewGC -XX:+UseConcMarkSweepGC application

4.3.1.3 Controlling the Concurrent collection initiation

The concurrent collector background thread starts running when the percentage of allocated space in the old generation goes above the -XX:CMSInitiatingOccupancyFraction, default value is 68%. This value can be changed and the concurrent collector can be started earlier by specifying the following option:

-XX:CMSInitiatingOccupancyFraction=<percent>

For example:

java -server -Xms512m -Xmx512m -XX:NewSize=64m -XX:MaxNewSize=64m \
    -XX:SurvivorRatio=20000 -XX:MaxTenuringThreshold=0 \
    -XX:+UseParNewGC -XX:+UseConcMarkSweepGC \
    -XX:CMSInitiatingOccupancyFraction=35 application

4.3.2 Using the Throughput Collectors

The young generation, parallel scavenge collector, can be enabled by using the -XX:UseParallelGC option. The older generation collector need not be specified since the mark-compact collector is used by default.

For 32 bit usage:

java -server -Xms3072m -Xmx3072m -XX:NewSize=2560m \
    -XX:MaxNewSize=2560m XX:SurvivorRatio=2 \
    -XX:+UseParallelGC application

For 64 bit usage:

java -server -d64 -Xms8192m -Xmx8192m -XX:NewSize=7168m \
    -XX:MaxNewSize=7168m XX:SurvivorRatio=2 \
    -XX:+UseParallelGC application

Note:

1. -XX:TargetSurvivorRatio is a tenuring threshold that is used to copy the tenured objects in the young generation. With large heaps and a SurvivorRatio of 2, survivor semi-space might be wasted, as the TargetSurvivorRatio by default is 50. This could be increased to maybe 75 or 90, maximizing use of the space.

4.3.2.1 Controlling the Degree of Parallelism

Again, by default, the parallel scavenge collector will start as many threads as CPUs on a machine, but if the degree of parallelism needs to controlled, then it can be specified by the following switch:

-XX:ParallelGCThreads=<desired parallelism>

Default value is equal to number of CPUs.

For example, to use 4 parallel threads to process young generation collection:

java -server -Xms3072m -Xmx3072m -XX:NewSize=2560m \
    -XX:MaxNewSize=2560m XX:SurvivorRatio=2 \
    -XX:+UseParallelGC -XX:ParallelGCThreads=4 application

4.3.2.2 Adaptive Sizing for Performance

The Parallel scavenge collector performs better when used with the -XX:+UseAdaptiveSizePolicy. This automatically sizes the young generation and chooses an optimum survivor ratio to maximize performance. The parallel scavenge collector should always be used with the -XX:UseAdaptiveSizePolicy.

For example:

java -server -Xms3072m -XX:+UseParallelGC \
    -XX:+UseAdaptiveSizePolicy application

5. Problems with earlier JDK versions, and how they are now getting solved with the new collectors

The biggest problem with JDK 1.2.2_08 was stop-the-world collection, which introduced serialization. Serialization directly affects scalability and throughput (see next section 6). Even though the GC pause, in JDK 1.2.2_08, was reduced to less than 100 ms range - using the concurrent collector and sizing the younger generation smaller, about 12-16MB --, any increase in load would increase the frequency and pause, as the young generation collection was single threaded. This problem is now solved with JDK 1.4.1, as the young generation collection is parallel (multi-threaded) and run on multiple CPUs at the same time. The collection is still stop-the-world but happens in parallel, resulting in smaller pauses even with bigger young generations. The decreased frequency of the collection and pause, reduces the serialization problem as application threads run for a longer duration increasing the scalability and throughput. So GC serialization, which was one of the biggest factors affecting scalability, especially with increased loads, will be less of a factor.

See the earlier paper, section 3, for more details of the Garbage Collection problem, http://wireless.java.sun.com/midp/articles/garbage/#3 .

6. How GC Pauses Affect Scalability and Execution Efficiency

Linear scalability [28] of an application running on an SMP (Symmetrical Multi Processing)-based machine is directly limited by the serial parts of the application. The serial parts of a Java application are:

• Stop-the-world GC
• Access to critical sections
• Concurrency overhead such as scheduling, context switching, ...
• System and communication overhead

The percentage of time spent in the serial portions determines the maximum scalability that can be achieved on a multi-processor machine and in turn the execution efficiency of an application. Because the young- and old-generation collectors all have at least some single-threaded stop-the-world behavior, GC will be a limiting factor to scalability even when the rest of the application can run completely in parallel. Using the concurrent collector will help reduce this effect, but will not completely remove it.

The scalability and execution efficiency of an application can be calculated using Amdahl's law.

6.1 Amdahl's Law & Efficiency calculations

If S is the percentage of time spent (by one processor) on serial parts of the program and P is the percentage of time spent (by one processor) on parts of the program that could be done in parallel [13], then:

So if F = 0 (i.e., no serial part), then speedup = N (the ideal value). If F = 1 (i.e., completely serial), then speedup = 1 no matter how many processors are used.

The effect of the serial fraction F on the Speedup when N = 10:

Figure 6 - Speedup

6.1.1 Scaled Speedup

Assuming that the problem size is fixed, then Amdahl's Law can predict the speedup on a parallel machine:

Figure 7 - Scaled Speedup

More details on Amdahl's Law and scaled speedup can be obtained from [13] [14] [22] [23].

6.1.2 Efficiency

Execution efficiency is defined as:

Execution efficiency translates directly to the CPU percentage used by an application. For a linear speedup this is 1, or 100%. The higher the number, the better, because it translates to higher application efficiency.

7. A SIP Server, the Benchmark Application

Our previous paper had used a SIP server to gather research data. This time, most of the work has been done with a simple Java program that simulated creation of different type of objects. The idea was that this program could be extended to emulate different kinds of application behavior from near real time applications (telco) to throughput applications (enterprise). From a macroscopic view of the collector, every application has the same behavior, n number of objects are created / second, of these, a certain percentage is temporary, some intermediate, and the remaining long term. The ratios and the lifetime of these are the most important factor. Next would be the types of objects, object complexity, and relationships between the objects and how these affect the collection. Once this can be emulated, most application behavior can be simulated. The prototype is extremely primitive at the moment, and is available on request.

7.1 Using SIP To Test Real Time Requirements

Session Initiation protocol (SIP) [21] is a protocol defined by the Internet Engineering Task Force (IETF), used to set up a session between two users in real time. It has many applications, but the one focussed in here is setting up a call between users. After a call setup is completed, the SIP portion is complete. The users are then free to pass real-time media (such as voice) between the two endpoints. Note that this portion, the call, does not involve SIP or the servers that are routing SIP call setups.

If this protocol is still unfamiliar, it might help to think of it as akin to Hyper Text Transfer Protocol (HTTP) [24]. It is a similar, text-based protocol founded on the request/response paradigm. One of the key differences is that SIP supports unreliable transport protocols, such as UDP. When using UDP, SIP applications are responsible for ensuring that packets reach their destination. This is accomplished by retransmitting requests until a response is received.

One problem that arises from the model of application-level reliability is retransmission storms. If an application does not respond quickly enough (within 500 ms by default in the specification), the request will be retransmitted. This retransmission continues until a response is received. Each retransmit makes more work for the receiving server. Hence, retransmissions can cause more retransmissions, and thrashing can ensue.

A GC cycle that takes longer than 500 ms will cause retransmissions. One that takes several seconds will ensure many retransmissions. These, in conjunction with the new requests that arrive at the server during garbage collection, will make even more work for the server and it will fall further behind.

Even absent the overburdening problems just described, other constraints make garbage collection pauses unacceptable. There are carrier grade requirements that state acceptable latencies from the moment an initiating side begins a call to the moment it receives a response from the terminating side. These are typically sub-second times, so a multiple-second pause in a SIP server for GC is unacceptable.

7.2 Call Setups

"Call setup" [22] is a concept used throughout this paper. A call setup is simply the combination of an originating side stating that it wishes to initiate a session (a call in this case) and a terminating side responding that it is interested as well. In SIP, there is also the concept of an acknowledgement being sent back to the terminating side after it accepts.

After a call setup is complete, the server must maintain call setup state for 32 seconds in order to handle properly any application-level retransmissions that might occur. This specification is the reason the value of 32 seconds is used as an active duration1 throughout the paper.

8. Modeling Application Behavior to Predict GC Pauses

Modeling Java applications makes it possible for developers to remove unpredictability attributed to the frequency and duration of pauses for GC.

The frequency and pause duration of GC are directly related to the following factors:

• Incoming call-setup rate
• Number and total size of objects created per call setup
• Average lifetime of these objects
• Size of the Java heap

Developers can construct a theoretical model to show application behavior for various call-setup rates, numbers of objects created, object sizes, object lifetimes, and heap sizes. A theoretical model reflects the extremities of the application behavior for the best conditions and the worst. Once developers know these extremities, they can model a real-life scenario that helps predict the maximum call-setup rate that can be achieved with acceptable pauses, and that shows what can happen when call-setup rates exceed the maximum and application performance deteriorates.

8.1 Best-Case Scenario

Assumptions:

• Calculations are for a SIP application, but could be applied to any generic client-server application that has a request, a response, and an active time that request state is maintained
• For simplicity, only call setups are modeled (call tear-downs are not considered)
• The young collector is configured to use the promoteall modifier
• The old generation uses a concurrent collector
• The variables that change from scenario to scenario are listed in a table preceding the results

  Parameter	Assumed value
  Time call-setup state is maintained - active duration of call setup	0 ms
  Time between call setups	10 ms
  Young semi-spacgeneration Eden e size	5 MB
  Young GC Eden thresholdthreshold	100100%
  Oldheap size	N/A
  Old GC threshold	N/A
  Total size of objects per call setup	50 KB
  Lifetime of objects	0 ms

8.2 Worst-Case Scenario

Assumptions:

Parameter	Assumed value
Time call-setup state is maintained - active duration	Infinite
Time between call setups	10 ms
Young Edensemi-space size	5 MB
Young GC Eden thresholdthreshold	100100%
Old heap size	512 MB
Old GC threshold	68%
Total size of objects per call setup	50 KB
Lifetime of objects	Infinite

8.3 A Real Scenario with Each Call Setup Active for 32 Seconds

(Calculated for Concurrent GC)

Assumptions:

Parameter	Assumed value
Time call-setup state is maintained - active duration	32,000 ms
Time between call setups	10 ms
Young Edensemi-space size	5 MB
Young GC threshold	100%
Old heap size	512 MB
Old GC threshold	68%
Total size of objects per call setup	50 KB
Lifetime of objects	50% = 0 ms 50% = 32,000 ms

9. Modeling Application Behavior Using "verbose:gc" Logs

The model above is theoretical and relies on a lot of assumptions; but developers can use the "verbose:gc" log from an actual application run to construct a real-world model. The model will allow one to visualize the runtime behavior of both the application and the garbage collector. The verbose:gc logs contain valuable information about garbage-collection times, the frequency of collections, application run times, number of objects created and destroyed, the rate of object creation, the total size of objects per call, and so on. This information can be analyzed on a time scale, and the behavior of the application can be depicted in graphs and tables that chart the different relationships among pause duration, frequency of pauses, and object creation rate, and suggest how these can affect application performance and scalability. 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 for a given call-setup rate (see 16. Sizing the Young and Old Generations' Heaps).

9.1 Java "verbose:gc" Logs

Logs containing detailed GC information are generated when a Java application is run with the -verbose:gc flag turned on. With earlier JDK versions, specifying this twice on the command line, increased the GC info printed out, and this could then be analyzed. Similar and more richer output is available with JDK 1.4.1 VM, but instead of specifying the -verbose:gc option twice, the below options provide a more detailed output that can be analyzed:

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC

Note:

1. Using -XX:+PrintHeapAtGC generates lot of information. If there are a lot of GCs, and log size is a concern, then this option might be omitted. The collected information is not self-explanatory but can still be processed by the analyzer (see pattern 2, and pattern 7 under Appendix A4.1).
2. -Xloggc is a new option available with J2SE 1.4. This option logs verbose:gc data into a log file. But it does not log the data ouput with the above switches. So it is mentioned here.

For example:

java -server -Xms512m -Xmx512m -XX:NewSize=64m -XX:MaxNewSize=64m \
    -XX:SurvivorRatio=2 -XX:+UseConcMarkSweepGC   -XX:+UseParNewGC \
    -XX:+PrintGCDetails   -XX:+PrintGCTimeStamps   \
    -XX:+PrintHeapAtGC application

9.2 Snapshot of a GC Log

The snapshot below is of a verbose:gc log entry generated by the JDK 1.4.1 VM with the above options. Highlighted phrases with superscript numbers are footnoted below.

0.548403GB: [GC  {Heap before GC invocations=1:
Heap
 par new generation   total 18432K, used 12826K [0xf2800000, 0xf4000000, 0xf4000000)
  eden space  12288K,  99% used1 [0xf2800000, 0xf33ff840, 0xf3400000)
  from space   6144K,   8% used2 [0xf3a00000, 0xf3a87360, 0xf4000000)
  to   space   6144K,   0% used3 [0xf3400000, 0xf3400000, 0xf3a00000)
 concurrent mark-sweep generation total 40960K, used 195K4[0xf4000000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space  40960K,   0% used [0xf4000000, 0xf6800000)
 concurrent-mark-sweep perm gen total 4096K, used 1158K5 [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
0.549364DC: [ParNew: 12826K6->1086K7(18432K8), 0.02798039 secs] 13022K->1282K(59392K)
Heap after GC invocations=2:
Heap
 par new generation   total 18432K, used 1086K [0xf2800000, 0xf4000000, 0xf4000000)
  eden space  12288K,   0% used10 [0xf2800000, 0xf2800000, 0xf3400000)
  from space   6144K,  17% used11 [0xf3400000, 0xf350fbc0, 0xf3a00000)
  to   space   6144K,   0% used12 [0xf3a00000, 0xf3a00000, 0xf4000000)
concurrent mark-sweep generation total 40960K, used 195K13 [0xf4000000, 0xf6800000, 0xf6800000)
CompactibleFreeListSpace space  40960K,   0% used [0xf4000000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K14 [0xf6800000, 0xf6c00000, 0xfa800000)
CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
} , 0.0297669GE secs]

Before GC snapshot

1. Eden Space, usually 100% occupied for a young generation GC
2. From Space, % occupancy before GC
   To Space, should be 0% occupancy
   Old generation heap space, total space 40MB, occupied 195K. Change here from last snapshot indicates direct creation of objects in the older generation
3. Permanent generation, % occupancy

During GC snapshot

4. So much of Eden + From Space occupied at GC
5. After garbage collection, From Space now has this occupancy
6. Eden + 1 Semi-space size
7. Time for GC

After GC snapshot

8. Eden space after GC
9. From space after GC (From and To space have been flipped, look at the addresses)
10. To space is 0
11. Old generation heap occupancy, if objects got promoted, this should show an increase
12. Permanent heap space, should not show a change

GB - GC Begin Time stamp
GE - Collection time
DC - During GC Time stamp

Some derivations:

Total GC time = GE
Time to stop the threads = GB - DC
Time to restart the threads = GE - 9 (above)
GC overhead = GB - DC + GE - 9 (above)

10. Using the GC Analyzer Script to Analyze "verbose:gc" Logs

The GC analyzer is a perl script that analyzes the verbose:gc log file, and reconstructs the application behavior by building a mathematical model. The input to the script is a verbose:gc log file generated using the above options. It provides as output:

• GC-related information
  • Young and old generation pause
  • Periodicity
  • Application times
• Serial Part of the Application
• Scalability factor
• Application Efficiency or CPU utilization
• Call-setup information
• Active-duration information
• Application-behavior information
• Various verifications

Here is snapshot of its output:

Processing 12_12_60_60_1_par_tenure_concgc.log ... Call rate = 90 cps ... Active call-setup duration = 32000 ms Number of CPUs = 4 ---- GC Analyzer Summary : 12_12_60_60_1_par_tenure_concgc.log ---- Application info: Application run time = 101590.05 ms Heap space = 60 MB Eden space = 6144 KB Semispace = 3072 KB Tenured space = 49152 KB Permanent space = 4096 KB Young GC --------- (Copy GC + Promoted GC ) --- Copy gc info: Total # of copy gcs = 94 Avg. size copied = 1789429 bytes Periodicity of copy gc = 992.845278723404 ms Copy time = 87 ms Percent of pause vs run time = 8% Promoted gc info: Total number# of promoted GCs = 216 Average size promoted = 262859 bytes Periodicity of promoted GC = 428.59 ms Promotion time = 41.73 ms Percent of pause vs run time = 8.87 % Young GC info: Total number# of young GCs = 310 Average GC pause = 55.73 ms Copy/Promotion time = 55.73 ms Overhead(suspend,restart threads) time = -9.08 ms Periodicity of GCs = 271.98 ms Percent of pause vs run time = 17.01 % Avg. size directly created old gen = 6868.17 KB Old concurrent GC info: Heap size = 49152 KB Avg. initial-mark threshold = 76.96 % Avg. remark threshold = 77.29 % Avg. Resize size = 277.81 KB Total GC time (stop-the-world) = 735.20 ms Concurrent processing time = 18924.00 ms Total number# of GCs = 120 Average pause = 6.13 ms Periodicity of GC = 840.46 ms Percent of pause vs run time = 0.72 % Percent of concurrent processing vs run time = 18.63 % Total (young and old) GC info: Total count = 430 Total GC time = 18011.80 ms Average pause = 41.89 ms Percent of pause vs run time = 17.73 % Call control info: Call-setups per second (CPS) = 90 Call rate, 1 call every = 11 ms Number# call-setups / young GC = 24.4780986483871 Total call throughput = 7588.21 Total size of short lived data / call-setup = 246285 bytes Total size of long live data / call-setup = 10738 bytes Average size of data / call = 257023 Total size of data created per young gen GC = 6291456 bytes Execution efficiency of application: GC Serial portion of application = 17.73% Actual CPUs = 4 CPUs used for concurrent processing = 3.25 Application Speedup = 2.33 Application Execution efficiency = 0.58 Application CPU Utilization = 58.13 % Concurrent GC CPU Utilization = 7.15 % --- GC Analyzer End Summary ----------------

The detailed output is shown in Appendix A.

The information generated by the analyzer can be used to tune application performance in the following ways:

• Reducing GC collection times
• Reducing the frequency of the young and old GCs
• Detecting memory leaks
• Detecting the rate of creation and destruction of objects, and using it to optimize the call setup rate
• Knowing the actual lifetimes of objects
• Sizing of the young and old generation heaps
• Modeling application and GC behavior
• Determining the scalability and execution efficiency of an application
• Reducing serial part of the application

11. Reducing Garbage Collection Times

Java applications have two types of collections, young-generation and old-generation.

11.1 Young-Generation Collection Times

A young-generation collection occurs when the Eden space is full. A copying collector - could be a parallel copy collector -- is used to copy the live objects in the Eden to the To semi-space, while also copying any live objects in the From semi-space. If the To semi-space is small or almost full, the live objects could be promoted - either from the From space or the Eden --- to the old generation, if they have been aged sufficiently. When developers inspect the GC logs they will find two types of young-generation GCs, copy GCs and promotion GCs.

11.1.1 Snippet from a Copy GC

1.75013: [GC  {Heap before GC invocations=2:
Heap
 par new generation   total 18432K, used 13373K [0xec800000, 0xee000000, 0xee000000)
  eden space  12288K,  99% used [0xec800000, 0xed3ff840, 0xed400000)
  from space   6144K,  17% used1 [0xed400000, 0xed50ff40, 0xeda00000)
  to   space   6144K,   0% used [0xeda00000, 0xeda00000, 0xee000000)
 concurrent mark-sweep generation total 139264K, used 195K [0xee000000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 139264K,   0% used [0xee000000, 0xf6800000)
 concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
1.75102: [ParNew: 13373K->1440K(18432K), 0.0379632 secs] 13569K->1635K(157696K)
Heap after GC invocations=3:
Heap
 par new generation   total 18432K, used 1440K [0xec800000, 0xee000000, 0xee000000)
  eden space  12288K,   0% used [0xec800000, 0xec800000, 0xed400000)
  from space   6144K,  23% used2 [0xeda00000, 0xedb68230, 0xee000000)
  to   space   6144K,   0% used [0xed400000, 0xed400000, 0xeda00000)
 concurrent mark-sweep generation total 139264K, used 195K [0xee000000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 139264K,   0% used [0xee000000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000,  0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
} , 0.0395186 secs]

The above snippet shows tenuring (aging) of temporary objects in the younger generation. No promotions are done in a copy GC. Live objects are copied back and forth between the Eden and the two semi-spaces, allowing the short-term objects (intermediate objects) more time to die. In the above snippet, the size of the tenure goes from 17% to 23%.

1. Before GC part, size of objects being aged in the younger generation is about 17%
2. After GC part, size of objects being aged in the younger generation is about 23%

11.1.2 Snippet from a Promotion GC

3.61664: [GC  {Heap before GC invocations=8:
Heap
 par new generation   total 18432K, used 15568K [0xec800000, 0xee000000, 0xee000000)
  eden space  12288K,  99% used [0xec800000, 0xed3ff800, 0xed400000)
  from space   6144K,  53% used [0xed400000, 0xed734a58, 0xeda00000)
  to   space   6144K,   0% used [0xeda00000, 0xeda00000, 0xee000000)
 concurrent mark-sweep generation total 139264K, used 390K1 [0xee000000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 139264K,   0% used [0xee000000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
3.61775: [ParNew: 15568K->3126K(18432K), 0.0592143 secs] 15959K->4018K(157696K)
Heap after GC invocations=9:
Heap
 par new generation   total 18432K, used 3126K [0xec800000, 0xee000000, 0xee000000)
  eden space  12288K,   0% used [0xec800000, 0xec800000, 0xed400000)
  from space   6144K,  50% used [0xeda00000, 0xedd0d8c0, 0xee000000)
  to   space   6144K,   0% used [0xed400000, 0xed400000, 0xeda00000)
 concurrent mark-sweep generation total 139264K, used 892K2 [0xee000000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 139264K, 0% used [0xee000000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
} , 0.0610121 secs]

The above snippet shows promotion of long-term objects. Live objects, which survive aging in the younger generation, are copied to the old-generation heap space. For a promotion GC, the increase in the old generation space from the Before GC line to After GC line shows the size of the promotion to the older heap.

1. Before GC part, old generation heap occupancy is about 390 KB
2. After GC part, old generation heap occupancy is about 892 KB

The young-generation collection time is directly proportional to the size of the live data in the Eden and the From semi-space. A collection, and hence a pause, occurs when the Eden space is full. Live objects are copied, or promoted if the objects have aged sufficiently. The cost of a copy GC is the time to copy live objects to the To semi-space, while the cost of a promotion GC is the time to promote or copy live objects to the old generation. The cost of promoting is a little higher than that of copying, because the young collector has to interact with the old collector's heap.

Decreasing the young generation size, increases the frequency of young-generation collection and decreases the collection duration, as less live data has accumulated. Similarly, increasing the young generation size, decreases the frequency of young-generation collection and increases the duration of each collection, as more live data accumulates. Note, though, that less frequent collection also provides more time for the short-term data to die. It also partly offsets system overhead like thread scheduling, done at every collection cycle. The net result is a slightly longer collection but at a decreased frequency.

To tune the young generation collection time, developers must determine the right combination of frequency, collection time, and heap size. These three parameters are directly affected by the number of objects created per call setup and the lifetimes of these objects. So in addition to sizing the heap, the code may need to change, to reduce the number of objects created per call setup, and also to reduce the lifetimes of some objects.

The following output from the GC analyzer helps with this task:

• Average pause per young-generation GC
• Rate of promotion
• Average promotion size
• Number of copy GCs
• Frequency or periodicity of copy GCs
• Number of promotion GCs
• Frequency or periodicity of promotion GCs
• Size of data directly created in the older generation

See Appendix A for the detailed output.

11.1.3 Using This Information to Tune an Application

11.1.3.1 Using the simulated promoteall Modifier

Three categories of object lifetime are important to the decision whether to use the promoteall modifier:

• Temporary objects - die before encountering even one young GC
• Intermediate objects - survive at least one young GC, but are collected before promotion
• Long-term objects - live long enough to get promoted

Temporary objects are never copied or promoted because they die almost instantly. Long-term objects are always promoted because they live through multiple young GCs. Only intermediate objects benefit from copying. After the first time they are aged or copied, they usually die and are collected in the next cycle, sparing the collector the cost of promoting them.

If the application has few intermediate objects, using the promoteall modifier decreases the amount of time that the application spends in young GC. This saving comes from not copying long-term objects from one semi-space to the other before promoting them to the old heap anyway.

Intermediate objects that are promoted take slightly more time to promote than to age. Also, the old-heap collector collects these objects, so it again uses slightly more time to collect them when they do die. However, the old-heap collection happens concurrently rather than in the young collector's stop-the-world fashion, so scalability should improve.

Note: The promoteall modifier could be more suited for real-time apps which have pause as a criteria but it could be used with throughput oriented enterprise apps too.

11.1.3.2 Simulated promoteall Modifier Usage

java -server -Xms512m -Xmx512m -XX:NewSize=64m \
-XX:MaxNewSize=64mXX:SurvivorRatio=100 \
-XX:MaxTenuringThreshold=0 -XX:+UseParNewGC  \
-XX:+UseConcMarkSweepGC application

11.1.3.3 Snippet of a Promotion GC with the promoteall Modifier

0.714029: [GC  {Heap before GC invocations=1:
Heap
 par new generation   total 12224K, used 12129K [0xf2800000, 0xf3400000, 0xf3400 000)
  eden space  12160K,  99% used1 [0xf2800000, 0xf33d8700, 0xf33e0000)
  from space     64K,   0% used2 [0xf33f0000, 0xf33f0000, 0xf3400000)
  to   space     64K,   0% used [0xf33e0000, 0xf33e0000, 0xf33f0000)
 concurrent mark-sweep generation total 53248K, used 932K3 [0xf3400000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space  53248K,   1% used [0xf3400000, 0xf6800000)
 concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
0.714918: [ParNew: 12129K->0K(12224K), 0.0119368 secs] 13062K->1362K(65472K)
Heap after GC invocations=2:
Heap par new generation   total 12224K, used 0K [0xf2800000, 0xf3400000, 0xf3400000)
  eden space  12160K,   0% used4 [0xf2800000, 0xf2800000, 0xf33e0000)
  from space     64K,   0% used5 [0xf33e0000, 0xf33e0000, 0xf33f0000)
  to   space     64K,   0% used [0xf33f0000, 0xf33f0000, 0xf3400000)
 concurrent mark-sweep generation total 53248K, used 1362K6 [0xf3400000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space  53248K,   2% used [0xf3400000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
} , 0.0134874 secs]

1. Before GC, Eden space is 100% almost full
2. Before GC, From space is 0%
3. Before GC, Old heap space has about 932KB
4. After GC, Eden space is 0%
5. After GC, From space is 0%
6. After GC, Old heap space has about 1362KB, about 430KB has been promoted

11.1.3.4 Tracking Young GCs that Copy Objects (Throughput apps)

A review of the numbers in " 11.1.1 Snippet from a Copy GC" through " 11.1.3.3 Snippet of a Promotion GC with the promoteall Modifier" will reveal how the copy percentage changes from young GC to young GC. Without the promoteall modifier, this percentage reduces until there are more live objects in the semi-space than are allowed. At that time, these objects are promoted to the old heap, and the threshold is reset to its starting value. This can now be seen by enabling the -XX:+PrintTenuringDistribution option.

11.1.3.4.1 Using the PrintTenuring Distribution

java -server -Xms512m -Xmx512m -XX:NewSize=64m \ -XX:MaxNewSize=64m XX:SurvivorRatio=2 \ -XX:+UseConcMarkSweepGC -XX:+UseParNewGC \ -XX:+PrintGCDetails -XX:+PrintGCTimeStamps \ -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution application

0.729752: [GC  {Heap before GC invocations=1:
Heap
 par new generation   total 18432K, used 12827K [0xf2800000, 0xf4000000, 0xf4000000)
  eden space  12288K,  99% used [0xf2800000, 0xf33ff840, 0xf3400000)
  from space   6144K,   8% used [0xf3a00000, 0xf3a87780, 0xf4000000)
  to   space   6144K,   0% used [0xf3400000, 0xf3400000, 0xf3a00000)
 concurrent mark-sweep generation total 40960K, used 195K [0xf4000000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space  40960K,   0% used [0xf4000000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000) 0.730717: [ParNew
Desired survivor size 3145728 bytes, new threshold 31 (max 31)
- age   1:     600176 bytes,     600176 total1
- age   2:     512592 bytes,    1112768 total2
: 12827K->1088K(18432K), 0.0275376 secs] 13023K->1283K(59392K) Heap after GC invocations=2:
Heap
 par new generation   total 18432K, used 1088K [0xf2800000, 0xf4000000, 0xf4000000)
  eden space  12288K,   0% used [0xf2800000, 0xf2800000, 0xf3400000)
  from space   6144K,  17% used [0xf3400000, 0xf3510078, 0xf3a00000)
  to   space   6144K,   0% used [0xf3a00000, 0xf3a00000, 0xf4000000)
concurrent mark-sweep generation total 40960K, used 195K [0xf4000000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space  40960K,   0% used [0xf4000000, 0xf6800000)
 concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
} , 0.0291855 secs]

1. Lot 1, size 600K
2. Lot 2, size 500K

There are times when tenuring can help application performance. When intermediate objects are given enough time that they become temporary objects, they are collected before they are ever promoted to the old heap. It is for this reason that tenuring is used in the first place. This strategy works well for many classes of application. Determining whether an application will benefit from copying, or from promoting all live objects to the old heap, will help developers configure applications for optimal behavior.

The throughput collector works with very well with large young generation heaps, and works on the idea that copy collection is very efficient. Copy collection is directly proportional to the size of the live objects, and heap is automatically compacted with every collection decreasing locality and fragmentation problems. Since the collector is parallel, pause times are divided by the degree of parallelism, and are lower. The frequency of collection decreases as heap sizes are larger. So the effect is low pause with decrease in frequency.

11.1.3.4.2 Using AdaptiveTenuring

When this is enabled, -XX:+UseAdaptiveSizePolicy, the throughput collector automatically sizes the young generation heap and selects an optimal survivor ratio to bring down the pause and frequency. This should always be turned on, until unless the developer has analyzed the application behavior with the GC analyzer and is sizing the heap manually.

11.1.3.5 Reducing The Size Of Promoted or Tenured Objects

Depending on the application's behavior, merely increasing the size of the young generation may help by allowing long-term objects to become intermediate objects, and intermediate objects to become temporary objects (see 11.1.3.4 Tracking Young GCs that Copy Objects). Increasing the young generation may help, but it does increase the time that each young collection takes. This might be alleviated now with the parallel collectors, and bigger young generations can be used with out comprising on the collection time.

The next step is code inspection. There are a few ways to reduce the time it takes to tenure or promote objects.

The easiest is to find objects that are kept alive longer than necessary, and to stop referring to them as soon as they are no longer needed. Sometimes, this is as simple as setting the last reference to null as soon as the object is no longer needed.

Also look for objects that are unnecessary in the first place, and simply don't create them. If, as is typical, these are temporary objects, avoiding their creation will help indirectly, by reducing the frequency of young GCs. If they are long-term or intermediate objects, the benefit is more direct: they need not be copied or promoted.

Sometimes it is not as simple as just not creating an object. Developers may be able to reduce object sizes by making non-static variables static, or by combining two objects into one, thus reducing tenure or promotion time.

11.1.3.6 Disadvantages of Pooling Objects

In general, object pooling is not usually a good idea. It is one of those concepts in programming that is too often used without really weighing the costs against the benefits. Object reuse can introduce errors into an application that are very hard to debug. Furthermore, retrieving an object from the pool and putting it back can be more expensive than creating the object in the first place, especially on a multi-processor machine, because such operations must be synchronized.

Pooling could violate principles of object-oriented design (OOD). It could also turn out to be expensive to maintain, in exchange for benefits that diminish over time, as garbage collectors become more and more efficient and collection costs keep decreasing. The cost of object creation will also decrease as newer technologies go into VMs.

Because pooled objects are in the old generation, there is an additional cost of re-use: the time required to clean the pooled objects readying it for re-use. Also, any temporary objects created to hold newer data are created in the younger generation with a reference to the older generation, adding to the cost of young GCs [3].

Additionally, the older collector must inspect pooled objects during every collection cycle, adding constant overhead to every collection.

11.1.3.7 Advantages of Pooling Objects

The main benefit of pooling is that once these objects are created and promoted to the old generation, they are not created again, not only saving creation time but also reducing the frequency of young-generation GCs. There are three specific sets of factors that may encourage adoption of a pooling strategy.

The first is the obvious one: pooling of objects that take a long time to create or use up a lot of memory, such as threads and database connections.

Another is the use of static objects. If no state must be maintained on a per-object basis, this is a clear win. A good general rule is to make as many of the application's objects and member variables static as possible.

When it is not possible to make an object static, imposing a policy of one object per thread can work just fine. Such cases are good opportunities to take advantage of a static ThreadLocal variable. These are objects that enable each thread to know about its own instance of a particular class.

11.1.3.8 Seeking Statelessness

An application can achieve its maximum performance if the objects are all or mostly short-lived, and die while still in the young generation. To achieve such short lifetimes, the application must be essentially stateless, or at least maintain state for only a brief period. Minimizing statefulness helps greatly because the young generation's copying collector is very efficient at collecting dead objects. It expends no effort, just skips over them and goes on to the next object. By contrast any object that must be tenured or promoted imposes the cost of copying to a new area of memory.

11.1.3.9 Watching for References that Span Heaps

Developers should avoid creating ephemeral or temporary objects after objects are promoted to the old generation. If the application creates temporary objects that are referenced from objects in the old generation, then the cost of scanning these objects is greater than the cost of scanning the references when they are in the young generation.

11.1.3.10 Flattening Objects

Keeping objects flat, avoiding complex object structures, spares the collector the task of traversing all the references in them. The fewer references there are, the faster the collector can work - but note that trade-offs between good OOD and high performance will arise.

11.1.3.11 Watching for Back References

Look for unnecessary back references to the root object, as these can turn a temporary object into a long-lived one - and can lead to a memory leak, as the reference may never go away.

11.1.3.12 Direct Creation Of Objects In Older Generation

Objects are now directly created in the older generation if the size of the young generation is small, and the size of objects are big. The option -XX:PretenureSizeThreshold=<byte size> in the concurrent collector that can be enabled to indicate the threshold for direct creation in the older generation. This could effectively be used for creation of caches, lookup tables, etc. which are long lived and do not have to go through a promotion cycle of being created in the younger generation and then being copied to the older generation. Use this option with care, since it can degrade performance instead of improving it. The default value is 0 i.e., no objects are created directly in the older generation.

11.1.3.12.1 Snippet showing direct creation of objects in the older heap

Snippet 1

2.23256: [GC  {Heap before GC invocations=5:
Heap
 par new generation   total 9216K, used 7395K [0xec800000, 0xed400000, 0xed400000)
  eden space   6144K,  99% used [0xec800000, 0xecdf7fe0, 0xece00000)
  from space   3072K,  41% used [0xed100000, 0xed240cd0, 0xed400000)
  to   space   3072K,   0% used [0xece00000, 0xece00000, 0xed100000)
concurrent mark-sweep generation total 151552K, used 195K [0xed400000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 151552K,   0% used [0xed400000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
2.23348: [ParNew: 7395K->1445K(9216K), 0.0459140 secs] 7590K->1641K(160768K)
Heap after GC invocations=6:
Heap
 par new generation   total 9216K, used 1445K [0xec800000, 0xed400000, 0xed400000)
  eden space   6144K,   0% used [0xec800000, 0xec800000, 0xece00000)
  from space   3072K,  47% used [0xece00000, 0xecf697a8, 0xed100000)
  to   space   3072K,   0% used [0xed100000, 0xed100000, 0xed400000)
 concurrent mark-sweep generation total 151552K, used 195K [0xed400000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 151552K,   0% used [0xed400000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
} , 0.0475033 secs]

Snippet 2

2.40279: [GC  {Heap before GC invocations=6:
Heap
 par new generation   total 9216K, used 7557K [0xec800000, 0xed400000, 0xed400000)
  eden space   6144K,  99% used [0xec800000, 0xecdf8020, 0xece00000)
  from space   3072K,  47% used [0xece00000, 0xecf697a8, 0xed100000)
  to   space   3072K,   0% used [0xed100000, 0xed100000, 0xed400000)
 concurrent mark-sweep generation total 151552K, used 390K [0xed400000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 151552K,   0% used [0xed400000, 0xf6800000)
 concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
2.40399: [ParNew: 7557K->1441K(9216K), 0.0249896 secs] 7948K->1832K(160768K)
Heap after GC invocations=7:
Heap
 par new generation total 9216K, used 1441K [0xec800000, 0xed400000, 0xed400000)
  eden space   6144K,   0% used [0xec800000, 0xec800000, 0xece00000)
  from space   3072K,  46% used [0xed100000, 0xed2687e8, 0xed400000)
  to   space   3072K,   0% used [0xece00000, 0xece00000, 0xed100000)
 concurrent mark-sweep generation total 151552K, used 390K [0xed400000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 151552K,   0% used [0xed400000, 0xf6800000)
concurrent-mark-sweep perm gen total 4096K, used 1158K [0xf6800000, 0xf6c00000, 0xfa800000)
 CompactibleFreeListSpace space   4096K,  28% used [0xf6800000, 0xf6c00000)
} , 0.0268922 secs]

Walking through the two snippets above, from snippet 1 -- snippet 1 is GC invocation number 5 -- the After GC component shows old generation occupancy is 195K. In snippet 2 -- snippet 2 is GC invocation number 6 --, the Before GC component shows that the old generation size has increased to 390K. This means that objects have been directly created in the older generation. This happens if the size of the objects are quite big compared to the younger generation, so instead of creating them in the young generation, the allocator directly creates them in the older generation.

11.1.3.13 Using NIO

New IO is new way of doing IO operations with JDK 1.4. NIO supports multiplexed IO, a more efficient way of performing IO operations, and this should help bring down the number of threads used to process socket connections. Formerly, every socket connection used to be processed with a dedicated thread. Multiplexed IO allows many socket connections to be polled by a fewer threads. So a thread pool could be used to process the connections. Decreasing the number of threads brings down the number of objects, reduces memory footprint, decreases scheduling contention, while increasing performance.

NIO offers direct buffers which maybe used to create storage outsdie of the Java heap - means avoiding GC --, and can be used to store long life objects like lookup tables, caches, etc. Also, with a direct buffer, the JVM will try to perform native IO operations directly, and this should avoid multiple copies - means reduction in the number of objects created.

NIO also offers MappedByteBuffer, an implementation of a direct buffer, but memory mapped. MappedByteBuffer enables mapping file contents directly to physical memory areas. This should speed large IO operations, and avoid multiple copies between various buffers, meaning less number of objects, and so reduced GC frequency.

11.1.3.14 Making immutable objects mutable like using StringBuffers

Immutable objects serve a very good purpose but might not be good for garbage collection since any change to them would destroy the current object and create a new objects i.e., more garbage. Immutables by description, are objects which change very little overtime. But a basic object like String is immutable, and String is used everywhere. One way to bring down the number of objects created would be to use something like StringBuffers instead of Strings when String manipulation is needed.

11.1.3.15 RMI Initiated Distributed GC

RMI's distributed garbage collection (DGC) algorithm depends on the timeliness of local garbage collection (GC) activity to detect changes in the local reachability states of live remote references, and thus ultimately to permit collection of remote objects that become garbage. Local GC activity that results from normal application execution is often but not necessarily sufficient for effective DGC-- a local GC implementation does not generally know that the detection of particular objects becoming unreachable in a timely fashion is desired for some reason, such as to collect garbage in another Java virtual machine (VM). Therefore, an RMI implementation may take steps to stimulate local GC to detect unreachable objects sooner than it otherwise would.

The local GC initiated is a Full GC, and the default period is 60000 ms. This can be postponed or disabled completely to avoid Full GCs by setting the following options:

-Dsun.rmi.dgc.server.gcInterval=0x7FFFFFFFFFFFFFFE
-Dsun.rmi.dgc.client.gcInterval=0x7FFFFFFFFFFFFFFE
-XX:+DisableExplicitGC

11.1.3.16 Controlling Degree of Parallelism

The default degree of parallelism, as many threads as the number of CPUs, could degrade collection times especially in concurrent situations with other applications. The collection performance could be improved by reducing the parallelism using the -XX:ParallelGCThreads option.

11.1.3.17 References - Soft, Weak, Phantom

Soft,Weak, Phantom References [31] [32] [33] are used to implement data structures like caches. But this is expensive in terms of garbage collection, especially with the concurrent collector. So if possible avoid or use sparingly, especially Weak references as these are collected at every GC cycle.

11.1.3.18 Finalizers

If possible just avoid finalizers [33] as they are very expensive in terms of GC, since the collector needs to do extra processing [30] and run the finalize method if implemented. Another drawback with Finalizers is that finalizer chaining is not automatic and needs to be done explicitly. Not being aware of this, leads to unexpected behavior like holding onto precious resources and maybe memory leaks.

11.1.3.19 Permanent Generation Expansion

Sometimes you will see Full GCs in the log file, and this could be due to the permanent generation being expanded - most interactive applications like Forte Studio have this problem. This could be prevented by specifying a bigger permanent generation using the -XX:PermSize and -XX:MaxPermSize options.

For example:

java -Xms512m -Xmx512m -XX:NewSize=256m -XX:MaxNewSize=256m \
   -XX:SurvivorRatio=2 -XX:PermSize=64m -XX:MaxPermSize=64m application

11.2 Old-Generation Collection Times

11.2.1 Low Pause collectors

While the young-generation collector is a stop-the-world collector but parallel, the old generation concurrent collector runs concurrently with the application. The old collection is made in four stages, two of which are stop-the-world. The stages are:

• Initial Mark phase (stop-the-world)
• Concurrent Mark + precleaning phase
• Remark phase (stop-the-world)
• Concurrent Sweep-reset-phase

11.2.1.1 Initial Mark Phase

When the free memory in the old heap drops below a certain percentage, usually between 40% and 32%, the old-generation collector starts an "initial mark" phase. The initial mark phase takes a snapshot of the heap, and starts traversing the object graph to distinguish the referenced and unreferenced objects. Marking, in a nutshell, is the process of tagging each object that is reachable [3], so that it can be preserved when unmarked objects are collected.

11.2.1.1.1 Snippet of an Initial Mark Phase

97.3699: [GC [1 CMS-initial-mark: 95031K(139264K)] 99056K(157696K), 0.0109899 secs1]

1.1. stop-the-world pause in seconds

11.2.1.2 Concurrent Marking Phase

Once the intial-mark phase is completed, ie., a snapshot of the heap is taken, the marking or tagging of live objects is performed concurrently.

11.2.1.2.1 Snippet of an Concurrent Mark + PreCleaning Phase

97.3913: [CMS-concurrent-mark-start] 138.425: [CMS-concurrent-mark: 28.8972/41.0341 secs] 1.Total concurrent mark time in seconds 2.Current time on a CPU 138.479: [CMS-concurrent-preclean-start] 139.412: [CMS-concurrent-preclean: 0.8262/0.9331 secs] 1.92Total concurrent precleaning time in seconds 2.Current time on a CPU 3.

11.2.1.3 Remark Phase

Once the concurrent mark + precleaning phase is complete, the "remark" phase begins. The collector re-walks parts of the object graph that have potentially changed after they were scanned initially.

11.2.1.3.1 Snippet of a Remark Phase

139.766: [GC139.766: [dirty card accumulation, 0.0042464 secs]139.771: [dirty card rescan, 0.0003622 secs]139.771: [remark from roots, 0.4646618 secs]140.236: [weak refs processing, 0.0104430 secs] [1 CMS-remark: 95031K(139264K)] 104620K(157696K), 0.4803311 secs1]

1. stop-the-world remark time

11.2.1.4 Sweep Phase

The concurrent sweep phase follows the remark phase. In this phase memory is recycled by clearing the unreferenced objects.

11.2.1.4.1 Snippet of Sweep Phase

140.247: [CMS-concurrent-sweep-start] 227.279: [CMS-concurrent-sweep: 64.8272/87.0311 secs] 1.Total concurrent sweep time in seconds 2.Current time on a CPU

Note:

1. If the object creation rate is too high, the concurrent collector will be unable to keep up with the collection. The free threshold may drop below 5%, and the old generation, instead of using the concurrent collector, will employ the traditional mark-sweep, stop-the-world collector to collect the older heap.
2. Another workaround is to start the concurrent collector early by specifying the -XX:CMSInitiatingOccupancyFraction=<percent> option. Set this to 30% or lower so that the concurrent collection can be initiated earlier.

11.2.1.5 Snippet of Traditional Mark-Sweep GC

0.1839: [Full GC  {Heap before GC invocations=9:
Heap
 par new generation   total 49152K, used 40869K [0xd6800000, 0xda800000, 0xda800000)
  eden space  32768K,  74% used [0xd6800000, 0xd7fe94f0, 0xd8800000)
  from space  16384K, 100% used [0xd9800000, 0xda800000, 0xda800000)
  to   space  16384K,   0% used [0xd8800000, 0xd8800000, 0xd9800000)
concurrent mark-sweep generation total 458752K, used 3351K [0xda800000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 458752K,   0% used [0xda800000, 0xf6800000)
concurrent-mark-sweep perm gen total 17416K, used 12459K [0xf6800000, 0xf7902000, 0xfa800000)
 CompactibleFreeListSpace space  17416K,  71% used [0xf6800000, 0xf7902000)
60.1849: [ParNew
Desired survivor size 8388608 bytes, new threshold 31 (max 31)
- age   1:    5582064 bytes,    5582064 total
: 40869K->5478K(49152K), 0.4599039 secs]60.6449: [CMS61.267: [dirty card accumulation, 0.0121228 secs]61.2793: [dirty card rescan, 0.0009173 secs]61.2803: [remark from roots, 0.0922212 secs]61.3727: [weak refs processing, 0.0100280 secs]: 19659K->19059K(458752K), 0.9234530 secs] 44221K->24538K(507904K) Heap after GC invocations=10:
Heap
 par new generation   total 49152K, used 5478K [0xd6800000, 0xda800000, 0xda800000)
  eden space  32768K,   0% used [0xd6800000, 0xd6800000, 0xd8800000)
  from space  16384K,  33% used [0xd8800000, 0xd8d59b48, 0xd9800000)
  to   space  16384K,   0% used [0xd9800000, 0xd9800000, 0xda800000)
 concurrent mark-sweep generation total 458752K, used 19059K [0xda800000, 0xf6800000, 0xf6800000)
 CompactibleFreeListSpace space 458752K,   4% used [0xda800000, 0xf6800000)
 concurrent-mark-sweep perm gen total 20768K, used 12459K [0xf6800000,0xf7c48000, 0xfa800000)
 CompactibleFreeListSpace space  20768K,  59% used [0xf6800000, 0xf7c48000)
} , 1.3867174 secs]

11.2.2 Throughput Collectors

While the young-generation collector is parallel, the old generation collection is executed using the stop-the-world, mark-sweep-compact collector.

11.2.3 Observations Regarding Old-Generation Collections

11.2.3.1 Undersized Old Heaps

After a sweep phase, the size of the heap collected should be equal to or greater than the size of an active duration. Depending on the heap size, more than one active-duration segment could be in the old generation. Based on the time of the active duration, and the frequency of the old-generation GC, all of the objects in the active duration could be collectable.

The GC analyzer provides this ratio, (size of active durations / resize heap space). This value should be less than 1. A value greater than 1 indicates that, when an old generation GC takes place, there are active-duration segments still alive. With the ratio greater than 1, the call rate could be putting pressure on the older generation, forcing on it more frequent collections. If the ratio is too high, it can actually force the old generation to employ the traditional mark-sweep collector. Simply increasing the size of the old-generation heap can alleviate this pressure. Note, though, that too great an increase could lead to a smear effect (16.2.6 Locality of Reference Problems with an Oversized Heap).

The GC analyzer is able to determine the pressure on the older collector, as is described in "13. Detection of Memory Leaks."

11.2.3.2 Checks and Balances

At the end of an active duration, the amount of heap resized should be equal to the size of the objects promoted. If there are lingering references or if the timers are not very sensitive to the actual duration, then a memory leak may result. Memory leaks will fill up the old heap, degrading the old collector's performance and increasing the frequency of the old-generation GC. The GC analyzer reports such behavior.

For a final verification, at the end of the application run, the total size of the old generation objects collected should be compared to the total size of the objects promoted. These should be approximately equal. See "13. Detection of Memory Leaks" for more details.

12. Reducing the Frequency of Young and Old GCs

The frequency of the young GC is directly related to:

• The young generation size
• The call-setup rate
• The rate of object creation
• The objects' lifetimes

12.1 The Young Generation Size - EDEN, Semi-space and Survivor Ratio

Young generation is now made up of Eden space and a semi-space, controlled by the survivor ratio (see 3.1).

Increasing the Eden reduces young-GC frequency but increases individual collection times, because the promotion size could be higher. On the other hand, a ratio of temporary to long-lived objects that is very high could decrease the collection time, as more intermediate objects could die before a tenure GC or a promotion GC occurs. Changing the Eden size entails a trade-off between decreasing frequency and increasing collection times. See "11.1 Young-Generation Collection Times" and "11.2 Old-Generation Collection Times" for details on the effects of a change in the Eden size on frequency and collection time.

12.2 The Incoming Call-Setup Rate and the Rate of Object Creation

Frequency of GC is directly proportional to the call-setup rate and to the size of the objects created per call setup. The GC analyzer reports, per call setup, the total size of objects created, and of the temporary and long-term data created, and the average object size. This information can be used to reduce unnecessary object creation and optimize the application code.

12.3 Object Lifetimes (Low Pause apps and Throughput apps)

The frequency of young GC is also dependent on the lifetimes of the objects created. Long lifetimes lead to unnecessary tenuring in the young generation. Using the promoteall modifier could alleviate this problem, by shifting to the old generation's collector the burden of collecting, sooner or later, all objects alive at the beginning of any young GC. For details on using the promoteall modifier, see "11.1.3.2 Simulated promoteall Modifier Usage".

The lifetimes of objects have a big im