Wednesday, October 2, 2013

How to start investigating Java's OutOfMemoryError

This blog post addresses services/support people and doesn't provide too much detailed information about memory management in Java.

You get out of memory, now what? First of all you need to understand what kind of OutOfMemory is it. You may run out of OS virtual memory, native memory allocated to Java process, or Java heap. The error message normally gives a good indication of specifics, see a few examples:
OutOfMemoryError: Java heap space
OutOfMemoryError: PermGen space
OutOfMemoryError: unable to create new native thread
OutOfMemoryError: requested XXX bytes for ChunkPool::allocate

A typical Java process has a heap where Objects go into, which is also divided into different sections. Depending on the implementation of JVM they might be called: Eden Space (New), From Space (Survivor 1), To Space (Survivor 2), Old Generation (Tenured), and Perm Generation (it is considered outside Heap in some implementations). For a detailed explanation see this page or this page. On top it add memory required for class-loaders, garbage collection process, threads stack, JNI, native memory buffers, etc. For a detailed explanation see this page.

Here, I'm going to list what you need to know before analyzing an OutOfMemoryError:

1- What is the architecture of your machine and the JVM running your Java process: 32-bit, 64-bit, or else? How to proceed from here depends on answers to this question, because a 32-bit Java process is limited to about 3GB of usable virtual memory in user space with default settings, and 4GB in best case.
$ uname -a
Linux houman-laptop 3.9.10-100.fc17.x86_64 #1 SMP Sun Jul 14 01:31:27 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux
$ java -version
java version "1.7.0_25"
Java(TM) SE Runtime Environment (build 1.7.0_25-b15)
Java HotSpot(TM) 64-Bit Server VM (build 23.25-b01, mixed mode)

The commands above tell me that I'm running a 64-bit JVM on a 64-bin machine.

2- How much memory is allocated to the Java process?
$ ps awwwxo pid,user,%mem,%cpu,vsz,rss,cmd | head -1; ps awwwxo pid,user,%mem,%cpu,vsz,rss,cmd | grep tomcat
 2885 houman   10.2  1.0 3405352 826028 /usr/java/jdk1.7.0_25/bin/java ... org.apache.catalina.startup.Bootstrap start
 5774 houman    0.0  0.0 109408   872 grep --color=auto tomcat

The command above suggests that my Java process is allocated 3.4GB of memory by OS (VSZ) and is currently utilizing 0.8GB (RSS) of it.

3- How much memory is allocated to Java heap?
$ /usr/java/jdk1.7.0_25/bin/jmap -heap 2885
Attaching to process ID 2885, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 23.25-b01
using thread-local object allocation.
Parallel GC with 4 thread(s)
Heap Configuration:
   MinHeapFreeRatio = 40
   MaxHeapFreeRatio = 70
   MaxHeapSize      = 536870912 (512.0MB)
   NewSize          = 1310720 (1.25MB)
   MaxNewSize       = 17592186044415 MB
   OldSize          = 5439488 (5.1875MB)
   NewRatio         = 2
   SurvivorRatio    = 8
   PermSize         = 134217728 (128.0MB)
   MaxPermSize      = 268435456 (256.0MB)
   G1HeapRegionSize = 0 (0.0MB)
Heap Usage:
PS Young Generation
Eden Space:
   capacity = 55836672 (53.25MB)
   used     = 44561864 (42.49750518798828MB)
   free     = 11274808 (10.752494812011719MB)
   79.8075214797902% used
From Space:
   capacity = 59637760 (56.875MB)
   used     = 51424800 (49.042510986328125MB)
   free     = 8212960 (7.832489013671875MB)
   86.2285907451923% used
To Space:
   capacity = 59637760 (56.875MB)
   used     = 0 (0.0MB)
   free     = 59637760 (56.875MB)
   0.0% used
PS Old Generation
   capacity = 300941312 (287.0MB)
   used     = 124813120 (119.03106689453125MB)
   free     = 176128192 (167.96893310546875MB)
   41.47423933607361% used
PS Perm Generation
   capacity = 209780736 (200.0625MB)
   used     = 124733744 (118.95536804199219MB)
   free     = 85046992 (81.10713195800781MB)
   59.459103051292566% used
37997 interned Strings occupying 4151064 bytes.

It says my Java process has 287MB in old generation (119MB used) and 200MB in perm generation (118MB used) for example. On top it also indicates what are the ultimate limits for the Java process. When utilization of these 2 sections get high and the capacity is near the maximum available (Eden + From + To + PS Old grow towards MaxHeapSize, and PS Perm grows towards MaxPermSize), chances are you are running out of heap space, one way or another. Referring to this picture might help you understand the output better:

This command will tell you about garbage collections performed and the time spent doing so:
$ /usr/java/jdk1.7.0_25/bin/jstat -gcutil 2885
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT   
  0.00   86.34  20.72  41.71  59.46 83      1.991   6      1.832    3.823

This command will tell you about biggest objects that live in heap:
$ /usr/java/jdk1.7.0_25/bin/jmap -histo 2885 | head -20
 num     #instances         #bytes  class name
   1:          1244       81546688  [Lorg.apache.activemq.command.DataStructure;
   2:        229010       31452120  <constMethodKlass>
   3:        229010       31156304  <methodKlass>
   4:        239863       28604688  [C
   5:         18433       22196816  <constantPoolKlass>
   6:         39290       15346496  [B
   7:         18433       14414408  <instanceKlassKlass>
   8:         14020       13783136  <constantPoolCacheKlass>
   9:         71423        6119320  [Ljava.util.HashMap$Entry;
  10:        237082        5689968  java.lang.String
  11:         50255        5038688  [I
  12:        125650        4020800  java.util.HashMap$Entry
  13:         97931        3917240  java.util.LinkedHashMap$Entry
  14:         42557        3404560  java.lang.reflect.Method
  15:        107680        3022072  [Ljava.lang.String;
  16:         38100        2438400  java.util.LinkedHashMap
  17:         19563        2362808  java.lang.Class

To investigate further, we might need to refer to the application logs, or use a more sophisticate tools (like YourKit, or Eclipse Memory Analyzer).

4- How much more memory are you using besides heap? Now deduct the RSS figure by your heap capacity, and that's what you are using for everything else.
$ bc
bc 1.06.95
Copyright 1991-1994, 1997, 1998, 2000, 2004, 2006 Free Software Foundation, Inc.
This is free software with ABSOLUTELY NO WARRANTY.
For details type `warranty'.
826.028 - (53.25+56.875+56.875+287.0+200.0625)

For me, it was 171MB. If this number is too high, it is worth checking threads. Running too many threads can affect memory usage of the application.
$ /usr/java/jdk1.7.0_25/bin/jstack 2885
Output is too long...

There is no easy way to figure out what's wrong if native memory usage is too high, there are some methods mentioned here though.