Part of my job is to provide support for the famous issue tracker
JIRA. Sometimes, we will have to look into client's stack traces and thread dumps to troubleshoot some memory or locking issues which usually caused by third-party plug-ins,
Lucene, etc.
One of the excellent articles I came across is "
Of Thread dumps and stack traces" written by Rajiv Shivane. There are also some people who have given me some good pointers, like, Jed (one of my co-workers, the memory guy) who pointed me to "
JDK 1.5 - Trouble-shooting and Diagnostic Guide" and Rob who lent me the book "
Inside the Java 2 Virtual Machine". Some other good reads that you shouldn't miss are:
Anyway, I spent some time in the weekend to play around with
java
,
jmap
and
jhat
.
Note: jhat 1.1
doesn't recognize 64-bit dump, simply download JDK 1.6 and use the jhat 2.0
which shipped together with it.I will go through an
java.lang.OutOfMemoryError: Java heap space test I have done and give as detailed information as I can.
I have demonstrated this to some people earlier on at work using one of the classic examples:
String vs. StringBuffer.
public class TestStringBuffer{
public static void main(String[] args)
throws Exception{
StringBuffer sb = new StringBuffer();
String s = "foobar";
String which = args[1];
for(int i = 0; i < Integer.parseInt(args[0]); i++){
if(which.equals("sb"))
sb.append(s);
else
s += s;
System.out.println(System.currentTimeMillis() + ": " + i);
Thread.currentThread().sleep(500);
}
}
}
Using the StringBuffer way, the program remains alright even after 10K of iterations. However, it dies immediately with String concatenation around 23th iteration. Before we look deeper into this, here are two interesting JVM startup parameters that you would like to know:
-XX:+HeapDumpOnOutOfMemoryError
, requests HotSpot to generate a binary dump when it runs out of memory.- -
Xmx1024m
, allocates 1GB of heap space
The
jmap
utility can be used to produce snapshot of the currently running JVM process. The
jhat
utility does something similar however in a post-mortem manner.
For instance, running
jmap
on the
StringBuffer case:
yclian@kate:~/devels/test/java$ $JAVA_HOME/bin/jmap -histo 29237
Attaching to process ID 29237, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 1.5.0_09-b03
Iterating over heap. This may take a while...
Unknown oop at 0x00002b7df8296da0
Oop's klass is null
Object Histogram:
Size Count Class description
-------------------------------------------------------
500112 4121 * ConstMethodKlass
433192 4121 * MethodKlass
303824 283 * ConstantPoolKlass
269816 6117 * SymbolKlass
214688 265 * ConstantPoolCacheKlass
183776 283 * InstanceKlassKlass
108768 1044 char[]
83368 455 byte[]
61248 348 java.lang.Class
52096 462 java.lang.Object[]
31400 785 java.lang.String
29168 413 short[]
19584 295 int[]
18720 36 * ObjArrayKlassKlass
15048 213 java.lang.Object[]
7616 136 java.nio.HeapCharBuffer
4592 82 java.nio.HeapByteBuffer
4160 8 * TypeArrayKlassKlass
2784 58 java.util.Hashtable$Entry
2248 31 java.lang.String[]
2128 14 java.util.HashMap$Entry[]
2080 65 java.lang.StringBuilder
2064 10 java.util.Hashtable$Entry[]
2000 10 * KlassKlass
1792 14 java.lang.reflect.Field
1320 11 java.lang.reflect.Constructor
1056 22 java.util.Locale
1040 2 * ArrayKlassKlass
936 9 java.net.URL
864 6 java.lang.Thread
768 12 java.util.HashMap
736 23 java.io.File
696 21 java.lang.Class[]
672 12 java.io.ObjectStreamField
672 21 java.lang.StringBuffer
...
Heap traversal took 2.054 seconds.
And for the
String case:
yclian@kate:~/devels/test/java$ $JAVA_HOME/bin/jmap -histo 29336
Attaching to process ID 29336, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 1.5.0_09-b03
Iterating over heap. This may take a while...
Object Histogram:
Size Count Class description
-------------------------------------------------------
906039672 578 char[]
501216 4132 * ConstMethodKlass
434336 4132 * MethodKlass
304728 284 * ConstantPoolKlass
270328 6127 * SymbolKlass
214688 265 * ConstantPoolCacheKlass
184336 284 * InstanceKlassKlass
71072 351 byte[]
61424 349 java.lang.Class
51216 446 java.lang.Object[]
28960 411 short[]
22520 563 java.lang.String
19088 291 int[]
18720 36 * ObjArrayKlassKlass
13784 202 java.lang.Object[]
4160 8 * TypeArrayKlassKlass
2736 57 java.util.Hashtable$Entry
2128 14 java.util.HashMap$Entry[]
2000 10 * KlassKlass
1936 27 java.lang.String[]
1536 12 java.lang.reflect.Field
1344 7 java.util.Hashtable$Entry[]
1320 11 java.lang.reflect.Constructor
1056 22 java.util.Locale
1040 2 * ArrayKlassKlass
864 6 java.lang.Thread
768 12 java.util.HashMap
728 7 java.net.URL
672 12 java.io.ObjectStreamField
640 10 java.util.LinkedHashMap$Entry
448 8 java.lang.ref.SoftReference
448 7 java.lang.ref.Finalizer
432 9 java.util.HashMap$Entry
384 6 java.util.Hashtable
360 9 java.util.Vector
352 10 java.lang.Class[]
288 3 java.util.jar.JarFile
272 17 java.lang.Object
264 7 java.io.ObjectStreamField[]
256 8 java.io.ExpiringCache$Entry
240 3 sun.nio.cs.UTF_8$Encoder
240 3 java.nio.DirectByteBuffer
216 3 sun.misc.Cleaner
208 2 sun.nio.cs.StreamEncoder$CharsetSE
200 5 java.util.ArrayList
192 3 sun.misc.URLClassPath$JarLoader
176 2 java.io.ExpiringCache$1
160 4 sun.reflect.NativeConstructorAccessorImpl
152 4 java.lang.reflect.Constructor[]
152 1 java.lang.ThreadLocal$ThreadLocalMap$Entry[]
152 1 java.lang.reflect.Method
144 3 java.lang.OutOfMemoryError
...
Heap traversal took 1.323 seconds.
char[]
, 108768 vs. 906039672. Clear example why String concatenation should be discouraged ;-). The histogram is very useful in identifying memory leakage as it shows you the size and number of instances created for a specific object type.
jhat
also allows you to generate some other information such as heap summary and permgen statistics, run it with the
-h
parameter for more information.
Let's examine the binary heap dump produced by the
OutOfMemoryError
using
jhat
.
java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid29613.hprof ...
Heap dump file created [403190555 bytes in 31.321 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
jhat
is one of the best tools comes together with JVM. It starts a HTTP server and provides you a simple interface which enables you to inspect the heap dump with your favorite browser.
Since we were talking about histogram, we will look into histogram again using the
jhat
interface.
So, it actually produces something similar with what we have seen earlier. Except the slightly different use of notation, e.g.
class [C
,
class [B
, etc. Just if you are unsure:
class [C
is char[]
class [B
is byte[]
class [Z
is boolean[]
class [S
is short[]
class [I
is int[]
class [J
is long[]
class [D
is double[]
class [Lpackage.ClassName
is package.ClassName[]
class [[Lpackage.ClassName
is package.ClassName[][]
And therefore, don't be panicked when you see
([[ID[Ljava/lang/String)Z
in the stack trace next time. It is simply just
boolean foo(int[][], double, String[])
.
Clicking into one of the hyper-links (of course, it works just on my machine), for instance,
class [C
will bring me to a page as captured in the screenshot below:
The page gives you more details of the class, such as: loader, subclasses, static/instance data members, instances, references, etc.
I will end this blog entry at this point and I would expect you to spend some time to do some research on it too :-). When I start writing again for Part II, I will be sharing some thread dump tips that I have collected.
- yc, dumped