Inside JVM–GC(Garbage collection)

一、Common Problems in Java SE Application

This message is based on the following materials.
http://java.sun.com/developer/technicalArticles/J2SE/monitoring/#Insufficient_Memory
http://java.sun.com/developer/technicalArticles/javase/troubleshoot//

1. Java Memory Basic

1.1 Heap, Non-Heap, and Native

Heap memory is the runtime data area from which memory for all class instances and arrays is allocated.
Non-heap memory includes the method area and memory required for the internal processing or optimization of the JVM.
It stores per-class structures such as a runtime constant pool, field and method data, and the code for methods and constructors.
Native memory is the virtual memory managed by the operating system. When the memory is insufficient for an application to allocate, a java.lang.OutOfMemoryError will be thrown.

1.2 GC and Full GC

The garbage collector (GC) detects garbage, defined as objects that are no longer reachable, then reclaims it and makes space available to the running program. The GC typically works in a stop-the-world fashion — that is, it freezes the heap when working.

The above diagram describes the layout of HotSpot VM Heap and it consists of three parts: perm generation, old generation and new/yang generation. The perm generation is basically for class loading. Next are the old and young generation. The young generation is further broken up into three spaces: Eden, Survivor Space 1 (SS#1) and Survivor Space 2 (SS#2).

Garbage Collection

1. When you have a new object, the object gets created in Eden space.
2. So after running for a while, Eden space will fill up.a minor garbage collection occurs, in which all the objects alive in Eden are copied over to SS#1. Eden is then empty and ready to receive new objects.
3. After the minor GC, objects are allocated to Eden again. After a time, the Eden space fills up again, and another minor GC occurs. The objects surviving in SS#1 and Eden are copied to SS#2, and both SS#1 and Eden are reset. Although objects are frequently recopied, either from Eden or from one SS to another, at any one time, only Eden and one SS are operating.
4. Every time an object moves from Eden to SS or from one SS to another, a counter and its header is incremented. By default, if the copying occurs 16 times or more, the HotSpot VM stops copying them and moves them to the old generation.
5. If an object can’t be created in Eden, it goes directly to the old generation. Moving an object from SS to the old generation because of its age is called tenuring. Because of tenuring, the old generation becomes full over time. This calls for garbage collection of the old generation, which is called a full GC. A full GC is a compaction process that is slower than a minor GC.

2. Memory Problems: out of memory, memory leak and Frequently full GC

  • java.lang.OutOfMemoryError: Java heap space => It indicates that an object could not be allocated in the Java heap.
    1. Configuration issue, where the specified heap size (or the default size, if not specified) is insufficient for the application.
    2. The application is unintentionally holding references to objects, and this prevents the objects from being garbage collected. This is the Java language equivalent of a memory leak.
    3. One other potential source of OutOfMemoryError arises with applications that make excessive use of finalizers.
  • java.lang.OutOfMemoryError: PermGen space => the permanent generation is full.
    1. If an application loads a very large number of classes, then the size of the permanent generation might need to be increased using the -XX:MaxPermSize option.
    2. Interned java.lang.String objects are also stored in the permanent generation.If an application interns a huge number of strings, the permanent generation might need to be increased from its default setting.
  • java.lang.OutOfMemoryError: Requested array size exceeds VM limit
    attempted to allocate an array that is larger than the heap size
  • java.lang.OutOfMemoryError: request <size> bytes for <reason>. Out of swap space?
         The Java Native Interface (JNI) code or the native library of an application and the JVM implementation allocate memory from the native heap. An OutOfMemoryError will be thrown when an allocation in the native heap fails.
  • java.lang.OutOfMemoryError: <reason> <stack trace> (Native method)
         an indication that a native method has encountered an allocation failure. The difference between this and the previous message is that the allocation failure was detected in a JNI or native method rather than in Java VM code.

3. Thread Problems: dead lock, infinite loop and high lock contention

  • Dead Lock

    1. block by object monitor: Each object is associated with a monitor. If a thread invokes a synchronized method on an object, that object is locked.
    2. block by java.util.concurrent.locks
  • Looping Thread
        
    If thread CPU time is continuously increasing, but it is not unresponsive. An infinite loop may consume all available CPU cycles and cause the rest of the application to be unresponsive.
  • High Lock Contention
         Synchronization is heavily used in multithreaded applications to ensure mutually exclusive access to a shared resource or to coordinate and complete tasks among multiple threads.
    Or too many threads are waiting for a limited resource.

Troubleshooting Tools in Java SE Application

1. Command line tools

NAME Description Target Problem
jstat Java Virtual Machine Statistics Monitoring Tool JVM memory statistics including memory usage, garbage collection time, class loading, and the just-in-time compiler statistics
jmap Java Memory Map It prints shared object memory maps or heap memory details of a given process, core file, or remote debug server. It offers an inclusive, detailed memory configuration and information on free space capacity
jhat Java Heap Analysis Tool Parse a binary heap dump, launch a web browser, and present standard queries.
jps Java Virtual Machine Process Status Tool The jps tool lists the instrumented HotSpot Java Virtual Machines (JVMs) on the target system. In other words, it lists java application and its process id.
jstack Java Stack Trace It provides the stack traces of all the threads attached to a VM, such as application threads and interval VM threads. It also performs deadlock detection and will perform a stack trace if the VM is hung
HPROF The Heap and CPU Profiling Agent a heap-CPU profiling tool that collects information on CPU usage, heap dumps, and thread states, uses the JVM Tool Interface (JVMTI), so every JVM has a diagnostic interface
jinfo Java Configuration Info jinfo prints Java configuration information for a given Java process or core file or a remote debug server. And it can set java configuration property at runtime.
XX:+HeapDumpOnOutOfMemoryError When an OutOfMemoryError is thrown, a heap dump file named java_pid<pid>.hprof will be created automatically

2. Visual Tools

NAME Description Target Problem
jconsole Launch a GUI to monitor and manage Java applications and Java VMs on a local or remote machine. Memory and Thread Problem
jvisualvm Java Visual VM Java VisualVM relies on tools such as jstat, jinfo, jstack, and jmap to obtain detailed information about applications running inside a JVM. It then presents the data in a unified, graphically rich manner.

 

二、GC(Garbage collection) Log and Analysis

This article is trying to summarize what’ the JVM GC log and how can we use it to analyse memory issues.

1. How To Generate Sun JVM GC Log

Generally, -Xloggc:d:\gc.log -XX:+PrintGCDetails is enough. Please see following details. And for the full list, please see from http://www.tagtraum.com/gcviewer-vmflags.html#sun.verbose
-verbose:gc
Prints out information about garbage collections to standard out. To print the same information to a file, use -Xloggc:<file>
Example:
[GC 325407K->83000K(776768K), 0.2300771 secs]
[GC 325816K->83372K(776768K), 0.2454258 secs]
[Full GC 267628K->83769K(776768K), 1.8479984 secs]

See -Xloggc
Supported by: 1.3, 1.4, 1.5
-Xloggc:<file>
Prints information about garbage collections to the specified file.
In conjunction with -XX:+PrintGCDetails this is the best setting for the free GCViewer.
Supported by: 1.4, 1.5
-XX:+PrintGCDetails
Instructs the VM to be more verbose when printing out garbage collecion data. Specifically it does not only tell you that there was a collection, but also what impact it had on the different generations.
This flag is very useful when tuning generation sizes.
In conjunction with -Xloggc this is the best setting for the free GCViewer.
Example:
2.459: [GC 2.459: [DefNew: 3967K->0K(4032K), 0.0141600 secs] 8559K->7454K(16320K), 0.0143588 secs]
Supported by: 1.4, 1.5

2. How To Read GC Log

verbose:gc prints information at every collection
  [GC 325407K                      -> 83000K                     (776768K),                                            0.2300771 secs]
   [ GC  the combined size of live objects before GC  ->  the combined size of live objects after GC  (the total available space, not counting the space in the permanent generation),  pause time]    
[GC 325816K->83372K(776768K), 0.2454258 secs]
[Full GC 267628K->83769K(776768K), 1.8479984 secs]
XX:+PrintGCDetails for the J2SE Platform version 1.5 
[GC [DefNew:                  64575K
    ->   959K              (64576K),                                    0.0457646 secs]  196016K                         ->                133633K            (261184K),       0.0459067 secs]]
[GC [
young generation:before GC -> after GC (available young generation heap),  pause time ]   entrie heap before GC -> entire heap after GC, (available heap),     pause time                 ]] 

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

where

<collector> is an internal name for the collector used in the minor collection

<starting occupancy1> is the occupancy of the young generation before the collection

<ending occupancy1> is the occupancy of the young generation after the collection

<pause time1> is the pause time in seconds for the minor collection.

<starting occupancy3> is the occupancy of the entire heap before the collection

<ending occupancy3> is the occupancy of the entire heap after the collection

<pause time3> is the pause time for the entire garbage collection. This would include the time for a major collection is one was done.

 

 

Another way is to use GCViewer
GCViewer is a free open source tool to visualize data produced by the Java VM options 
verbose:gc and Xloggc<file>. It also calculates garbage collection related performance metrics
(throughput, accumulated pauses, longest pause, etc.). This can be very useful when tuning the garbage collection of a particular application by changing generation sizes or setting the initial heap size.
See here 
for a useful summary of garbage collection related JVM parameters.

3. How To Use GC Log

Generally, you can see three signals

(1)  the memory collected by young generation == the memory collected by entire heap? such as

64575K-959K=63616K, and 196016K – 133633K = 62383K, which means 63616K – 62383K =1233K memory moved from yougn generation to tenured section. If every GC will cause this operation, the memory is slowly leaking.
(2) the trace of memory collected by GC? does it become smaller and smaller, which mean more and more memory cannot be collected. It is a very obvious sign of memory leak.
(3) does the pause time is longer and longer? >1s is a obvious sign.

From another side, the GC View provides a very good trace which is easier to be analysed.

三、How to use Eclipse Memory Analyzer to analyze JVM Memeory Issue

This article will have a simple introduction on new tool – Eclipse Memory Analyzer (previously called SAP memory analyzer) and how to use this tool to find some interesting memory issues.

1. Install Memory Analyzer into Your Eclipse

  1. Start the Update Manage via Help → Software Updates…
  2. Choose the tab Available Software and add the Memory Analyzer Update site: http://download.eclipse.org/technology/mat/0.7/update-site/
  3. Pick the Memory Analyzer feature. And click “Install” button to install it.
  4. Accept the license and restart Eclipse

2. Getting a Heap Dump from Sun Virtual Machines

The Memory Analyzer can work with HPROF binary formatted heap dumps. Those heap dumps are written by Sun HotSpot and any VM derived from HotSpot. Depending on your scenario, your OS platform and your JDK version, you have different options to acquire a heap dump.

Vendor / Release -XX:+HeapDumpOnOutOfMemoryError writes heap dump on OutOfMemoryError -XX:+HeapDumpOnCtrlBreak writes heap dump together with thread dump on CTRL+BREAK Sun JMap: jmap.exe -dump:format=b,file=HeapDump.hprof Sun JConsole: Launch jconsole.exe and invoke operation dumpHeap() on HotSpotDiagnostic MBean
1.4.2_12 Yes Yes No No
1.5.0_07 Yes No Yes(Only Solaris and Linux) No
1.6.0_00 Yes No Yes Yes

Generally, the heap dump file will be generated as java_pid3524.hprof

3. Simplest Way To Find Memory Leaks

  1. Eclipse Menu Window → Open Perspective → Memory Analyzer
  2. Eclipse Menu File → Open the Heap Dump => Select the hprof file such as java_pid3524.hprof
  3. The Overview Diagram will be displayed
  4. Click the “Leak Suspects” Report Link
  5. Click Problem Suspect 1 Details link
    You will see
Class name Shallow Heap Retained Heap Percentage
java.lang.Object2261945 @ 0×23d04040 9,047,792 273,923,024 97.00%
com.starcite.commonsearch.client.vendor.impl.VendorImpl @ 0×16b80000 135 136 0.00%

So, “java.lang.Object2261945 @ 0×23d04040” costs around 9M shallow heap (which means directly referred memory), and 273 M retained heap (which means all memory directly or un-directly referred). Now, we can know this is the root cause of memory leak.

So, what’s next? Of course, next step is trying to find which codes cause this issue?
However, it is not an easy thing. You have to use your experiences now.

Any information we can use it as start point? You can find the following information –
Accumulated Objects

Class name Shallow Heap Retained Heap Percentage
java.lang.Thread @ 0×18ff9320 http-8080-1 88 273,945,736 97.01%
java.util.ArrayList @ 0×18ff93a0 24 273,923,048 97.00%
java.lang.Object2261945 @ 0×23d04040 9,047,792 273,923,024 97.00%
com.starcite.commonsearch.client.vendor.impl.VendorImpl @ 0×16b80000 135 136 0.00%

From this view, the memory is used by java.lang.Thread @ 0×18ff9320 http-8080-1. So, it should be happened within one HTTP request.

Then, find this thread within Thread Details section. And click Thread Properties link. Please see

And now you may find some hints, such as VendorSearchMediator, SearchVendorByIDsInput etc. Based on these information, you probably find the root codes –

public SearchVendorByIDsOutput searchVendorByIDs(SearchVendorByIDsInput input) {

List<vendor> vendors = new ArrayList</vendor><vendor>();

for (;;) {
VendorImpl v 
= new VendorImpl();
v.setName(
name);
vendors.add(v);
}
}
</vendor>

4. How to find the memory occupied unused collections – Powerful Object Query Language 1

During the development, you may never notice that a huge number of collections which have been instantiated, but have never been used.

An empty ArrayList, created with the default capacity of 10, costs 80 bytes on a 32 bit system, and 144 bytes on a 64 bit system.

If the class MyValueStorage is commonly used in our application, and there are 500.000 instances of it in the heap, then there will be 80Mb on a 32 bit system (on 64 bit – 144MB) reserved for the specialValues and erroneousValues lists. But only about 5% from them are ever needed. Therefore, it may be a good idea to use a lazy initialization for these two fields (keep them null untill they are actually used). The cost we have to pay is several “if” statements to avoid running into NullPointerExceptions.

  1. Open Object Query Language Studio to execute statements
  2. Check the help pages for a detailed description of the OQL syntax. For the moment we need only a few concrete queries. For finding enpty and unmodified ArrayLists, HashMaps and Hashtables they look like this:
    select * from java.util.ArrayList where size=0 and modCount=0
    select * from java.util.HashMap where size=0 and modCount=0
    select * from java.util.Hashtable where count=0 and modCount=0
  3. See . Then you can get Retained Heap for each item, such as 80 bytes. And there are totally 857 entries. So, they doesn’t take too much memory.

5. How Many Memory used by VendorImpl – Powerful Object Query Language 2

  1. Open Object Query Language Studio to execute statements
  2. Run the following OQL – select * from com.starcite.commonsearch.client.vendor.impl.VendorImpl
  3. Click “show s Histogram” – see VendorImpl-Histogram.jpg. And you will find VendorImpl costs more than 260M. That’s very special.

In summary, Eclipse Memory Analyzer is a very powerful memory analyzer tool. And it can easier find potential memory leaks. And you can also find the memory used by any java object.

BTW, there are some related blogs which are very useful.

http://wiki.eclipse.org/index.php/MemoryAnalyzer – the main entry for this tool

http://kohlerm.blogspot.com/ the blog of Markus Kohler, one of the architect of Eclipse Memory Analyzer

https://www.sdn.sap.com/irj/scn/weblogs?blog=/pub/u/1203, the blog of Krum Tsvetkov

发表评论