Garbage Collection in Weblogic

Part 1: Garbage Collection - Basics

Overview:
In java world, Garbage Collection is one of the most important areas which is often overlooked by developers. But its fun to watch when it drives you nut when JVM starts running with low memory or Out Of Memory due to memory leak. Memory leak can happen due to our application or third party libraries or vendor product issue etc…(no one is perfect in this world).

Early this year, despite of having 2GB heap size, our weblogic 10.3.2 server running with JDK1.6_29 was crashing every hour or so due to OutOfMemory error. After spending good amount of time and digging it deeper, we found that it was happening due to huge amount of memory being used by weblogic’s proprietary or default SSL API i.e. “certicom”.
During investigation, I learned a lot about monitoring memory, taking heap dumps and tools to use to browse dump files. I thought of sharing my experience, so that others can benefit from same.

I feel it’s a good idea to start from basics of garbage collections and go further. I have divided this post in 3 part series.

In this series, we will see basics of

1. Local or instance variables.
2. Stack Section
3. Heap Section
4. Static Section
5. Garbage Collection.

Introduction:

Local Variables:
Local variables are those which are declared inside the method body including method parameters. Local variables are alive as long as method execution is on the stack OR method reaches to its completion.
For e.g.

?

1 2 3 4 5 6

public int addOne(int number){  int sum=number+1;  return sum;   //number and sum are local variables }

Instance Variables:
Instance variables are those which are declared within class but outside of any method. Instance variables (could be primitive or reference to another object) live on heap inside the object they belong to.
For e.g.

?

1 2 3 4 5 6 7

public class Test{  private int count;  private String name;  private AnOtherObject ref;   //count,name and ref are instance variable. }

For better memory management, JVM has three different sections called Stack, Heap (Garbage Collectible Heap) and Static where things live.

Stack 

1. Stack section is the place where all local primitive or reference variables and method invocation live.
2. Each executing thread runs in (or has) its own Stack.
3. When a method is called, a frame is created on top of stack.
4. After method is done its execution, frame is popped off the stack and control goes back to the calling method.
5. If an object is created inside the method body then
1. creation of that object will happen on the heap.
2. reference variable will be created on the stack.
3. linking mechanism will link reference variable (from stack) to the object (on heap).
6. Variables declared inside the method are NOT visible to any other method on the stack.
7. As soon as method is popped off the stack, all its local variables, reference variables get flushed away.

Heap 

1. Heap section is the place where all objects live.
2. Instance variables (primitive or reference) declared inside the object also live on heap.
3. If an instance variable is a reference to another object (non-primitive type) then,
1. reference variable will be created in the referring object.
2. referred object will be created on heap.
3. linking mechanism will link reference variable (from heap) to the object (on heap).

Static 

1. Static section is the place where static data or static method lives.
2. Static fields/methods belong to a class and not tied to specific instance of that class.

For better understanding, Lets look into below example and picture to see logical view of Stack, Heap and Static sections in JVM.

?

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33

public class Test{  public void testMe(){   doSomething();  }     public void doSomething(){   int count=0;   AnotherObject o1=new AnotherObject(5);   //more code   doSomeMore();  }     public void doSomeMore(){   int x=0;   AnotherObject o2=new AnotherObject(7);   //more code  }     public static void main(String arg[]){   Test t1=new Test();   t1.testMe();  } }   public class AnotherObject{  private int a;  private static status;     public AnotherObject(int value){   this.a=value;  }    }

How does JVM create Heap?

When we invoke main method of java class, the first thing JVM does is to acquire default or configured size memory from underlying Operating system in order to run our program in a given memory. (In part 2 discuss details about configurations etc…)

Lifecycle:
Life cycle of an object entirely depends upon the “scope” or “visibility” of its reference variable and reference variable could be declared as “local variable” Or “instance variable”.

Local variables are alive as long as the method is on the stack.
Instance variables are alive as long enclosing instance on heap has valid reference to it.

Object Destruction (Garbage Collection):
Once objects are created on heap, they occupies some memory.Those objects are considered LIVE on heap as long as they have valid reference referring to them. As soon as reference goes away, object is considered as an orphan and can be safely removed from memory by the Garbage Collection. Sometimes,having too many objects doing nothing (due to some bug in code) can occupy whole memory and lead to OutOfMemory issue. (how to troubleshoot OOM issue is covered in Part 3 of this serires).

Lets look into the example below and its pictorial representation to see logical view on heap.

?

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40

public class GarbageCollectionExample {    public static void main(String[] args) {   //create instance of KeyValuePair , assign key="Rajesh", value="Khullar"   KeyValuePair kvp1=new KeyValuePair("Rajesh","Khullar");// Execution 1       //create another instance of KeyValuePair , assign key="Test", value="Me"   KeyValuePair kvp2=new KeyValuePair("Test","Me");// Execution 2       // assign reference of kvp1 to kvp3.   KeyValuePair kvp3=kvp1;// Execution 3       //make it GC candidate   kvp1=null;// Execution 4       //at this point, still 2 live objects on heap which has valid references       //now mark it null and hand over to GC.   kvp3=null;// Execution 5       //at this point, only 1 live object with valid reference on heap            }    }   class KeyValuePair{  private String key;  private String value;     public KeyValuePair(String key,String value){   this.key=key;   this.value=value;  }     public String getKeyValue(){   return this.key+" : "+this.value;  } }

1. Types of Garbage Collector and their configuration.
2. Heap Memory and how to configure the size.
3. Types of Garbage Collections.
4. JVM Options for GC.
5. How to read GC Logs.

Introduction:

As we all know that the application server and the applications deployed inside it runs on the JVM heap and garbage collector works as heap administrator or care taker to manage the heap and keep the memory up-to-date by removing all un-wanted objects and moving long lived objects here and there to avoid memory issues.

Type of Garbage Collector:
  As per oracle documentation,

1. Serial Collector:  The serial collector uses a single thread to perform all garbage collection work, which makes it relatively efficient since there is no communication overhead between threads. It is best-suited to single processor machines, since it cannot take advantage of multiprocessor hardware, although it can be useful on multiprocessors for applications with small data sets (up to approximately 100MB). The serial collector is selected by default on certain hardware and operating system configurations, or we can enable it using JVM Option = -XX:+UseSerialGC. This is kind of “stop-the-world” collector , where all application threads must be stopped in order to run full GC.
2. Parallel Collector: The parallel collector (also known as the throughput collector) performs minor collections in parallel, which can significantly reduce garbage collection overhead. It is intended for applications with medium- to large-sized data sets that are run on multiprocessor or multi-threaded hardware. The parallel collector is selected by default on certain hardware and operating system configurations, or we can enable it using JVM Option= -XX:+UseParallelGC. This is kind of “stop-the-world” collector , where all application threads must be stopped in order to run full GC.
3. Concurrent (mark and sweep) Collector: Recommended for JDK 5 or above. The concurrent collector performs most of its work concurrently (i.e., while the application is still running) to keep garbage collection pauses short. It is designed for applications with medium- to large-sized data sets for which response time is more important than overall throughput, since the techniques used to minimize pauses can reduce application performance. JVM Options  
   -XX:+UseConcMarkSweepGC----- to let JVM know that we want CMS collector.
   -XX:+UseParNewGC ---- to collect young generation concurrently
   -XX: ParallelGCThreads= <number>----- Number of threads to use for GC
   This collector makes two very short stop-the-world pauses (one beginning of the GC and other in the middle of collection) and runs at the same as application threads for the rest of GC cycle. This means that it’s willing to make the trade-off of “false” negatives, failing to identify some garbage due to race condition (the garbage it misses will be collected in following GC cycle).

Heap Memory:

The java memory model divides the “heap” into two categories.

a) Young Generation (aka New Generation)Young generation heap is further classified into three different categories

1. Eden: Eden is the area where all objects initially gets created by the application. Some of the objects may be short lived which dies in Eden itself.
2. From:This is the area where all survived objects in Eden are moved into “from” space.
3. To: This is the place where all survived objects in “From” space are moved into “To” space.

b) Old Generation (aka Tenured space or concurrent mark-sweep generation)This is the area where all survived objects in Young Generation (Eden + From + To) are moved, in other words, long lived objects lives here.

Logical view of JVM heap:

Heap Configurations:

Total Heap:Total heap size includes Young Generation + Old generation (Tenured).

To set minimum heap size to 512MB and maximum heap size 1024MB, use configuration as below

       -Xms512m -Xmx1024m

Young Generation Heap: similarly can set the young generation size using below JVM options.

     -XNewSize ----sets minimum limit of Young Generation

     -XMaxNewSize ----sets maximum limit of young generation.
     
     How does Eden , From and To space gets set ?

     As we discussed earlier, Young generation is a combo of “Eden + From + To” spaces.
     JVM divides   Total young generation into Eden, From and To space using below option

    -XX: SurvivorRatio

     Eden = (From + To) * SurvivorRatio

     So if we set Young Generation size to 512 MB and Survivor Ratio = 8 then

      "From" space will be approximate = 32 MB
      "To" space will be approximate = 32 MB
      "Eden" space will be set to approximate= 448 MB.

PermGen Space: PermGen space is the area where all the class definitions loaded in the JVM and managed. None of object is created or stored in PermGen Space.
 JVM Options: 

-XX: PermSize=512m

-XX: MaxPermSize=512m

Types of Garbage Collections 

a) Minor or Young Collections

b) Major or Full Collection

a) Minor Garbage Collections (aka Young Collections):

1. When an application creates an object it gets created in the Eden space. (as shown in picture below)
2. This cycle continues until Eden space is full and no more space is left to create new object.
3. Minor Garbage collection kicks in which does the following:
1. Remove all unreferenced (not reachable) objects from the Eden space. That means, short lived objects will be removed from the memory.
2. If few of them are still alive (reachable), those are moved from Eden to "From" space (as shown in picture below).
4. Now, when Eden becomes full again, Minor collection kicks in  and does
1. Remove short lived objects from memory.
2. Move survived object from “From” space to “To” space and then Edenspace to “From” space.
5. When Eden becomes full again and after minor collection runs, any object which is still alive in “To” space is moved to “Old Generation” or "Tenured space".

Minor collections are very fast and efficient and do not require any running threads to halt. During minor collections, if any of the young object has a reference to theTenured object (i.e object in Young generation has a reference to the object in Old generation) then the reference held by tenured object must also be scanned by minor collection.

b) Major Collections (aka Full Collections):

1. When minor collection can’t move any more object to tenured space (due to lack of space), then Major Garbage collection kicks in (as shown in picture below).
2. This is a stop the world collection which forces all application threads to be paused to perform object reachability test which in turn marks the live (reachable) objects and sweep all the left out (non-reachable) objects to free the memory. That’s why this garbage collector is called as “mark and sweep collector”. This mark and sweep is extremely a processor intensive operation.
3. This may involve moving around the objects within Old generation, which is called as Compacting.

Safepoints:
As we seen above, Major Garbage collection cannot run without a pause of application threads and application threads cannot be stopped at any random time for GC. There are certain special times, when GC can take place and that is called as “Safepoints”. So full GC to take place, all the threads to be stopped at “Safepoints”.

JVM Options for Garbage Collection:
-verbose:gc ----- to enable GC informations to be printed.  
-XX:+DisableExplicitGC ---- Disable(ignore) explicit call by application like ..System.gc() or Runtime.gc()
-XX:+PrintGCApplicationStoppedTime ---- Print how much time application threads were stopped during GC.
-XX:+PrintGCApplicationConcurrentTime-----Print how much time GC was running along with application threads.
-XX:+PrintGCDetails----causes additional informations to be printed
-XX:+PrintGCTimeStamps ----will add a time stamp at the start of each collection
-Xloggc:C:\\gc.log---- log file name to log GC output
-XX:+PrintClassHistogram
XX:+HeapDumpOnOutOfMemoryError  ------ create automatic heap dump when JVM runs OOM.

Understand GC Logs

In order to understand GC logs, we got to try to add above JVM options to get detail picture of GC cycle. Before we use JVM options, we should be have clear idea what each option deos and what message it prints.

Lets take a close look for each option and see what kind of message it prints and what does that mean.

Each option's result are  highligted as Green.

-verbose:gc

[Full GC 252523K->252518K(253440K), 0.6746807 secs]

-XX:+PrintGCApplicationStoppedTime

Total time for which application threads were stopped: 0.1796777 seconds

-XX:+PrintGCApplicationConcurrentTime
Application time: 0.0102534 seconds

-XX:+PrintGCDetails
[Full GC [Tenured: 173867K->173867K(174784K), 0.5704368 secs] 252523K->252523K(253440K), [Perm : 100K->100K(12288K)], 0.5704791 secs] [Times: user=0.53 sys=0.00, real=0.57 secs] 


-XX:+PrintGCTimeStamps
3.042: [Full GC 3.042: [Tenured: 173867K->173863K(174784K), 0.6854068 secs] 252523K->252518K(253440K), [Perm : 100K->100K(12288K)], 0.6854853 secs] [Times: user=0.69 sys=0.00, real=0.69 secs]

So far we have seen the data being displayed by the GC options. Now lets see what does each data mean. We will take below snapshot as an example.

3.042: [Full GC 3.042: [Tenured: 173867K->173863K(174784K), 0.6854068 secs] 252523K->252518K(253440K), [Perm : 100K->100K(12288K)], 0.6854853 secs] [Times: user=0.69 sys=0.00, real=0.69 secs]

Garbage Collection - Troubleshooting OutOfMemory Issue

Overview:
In Part 2 of this series, we have seen different types of garbage collectors , heap memory and how to configure them using JVM options. Also we have seen how to enable GC logs by setting different options to get more and clear information about the JVM.
In this last part of this series, we will end our "GC trip journey" by looking what to do when an OutOfMemory issue happens

1. How to troubleshoot and
2. Tools to use

Introduction:
Memory leak in application leads to OutOfMemory error in running JVM. When too much time is spent doing garbage collection, Garbage Collector throws OutOfMemory error.In other words, if 98% of the time is being spent in garbage collection and recovering less than 2% of heap , that leads to OutOfMemory error.

Memory Leak Sample:
Below program is intentionally developed to throw OutOfMemory error.

?

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57

package com.test.gc;   import java.util.ArrayList; import java.util.List;   public class OutOfMemory {    private List<keyvaluepair> list=new ArrayList<keyvaluepair>();    private void add(KeyValuePair str){   list.add(str);  }    private void remove(int index){   //this line causes a memory leak   KeyValuePair st=list.get(index);   st=null;  }    public static void main(String[] args) {   System.out.println("Starting");   Thread t=new Thread(new Runnable(){    @Override    public void run() {     OutOfMemory oom=new OutOfMemory();     for(int index=0;index<1000000000;index++){      oom.add(oom.new KeyValuePair());      oom.remove(index);      /*try {       Thread.sleep(3);      } catch (InterruptedException e) {       // TODO Auto-generated catch block       e.printStackTrace();      }*/     }      }   });   t.start();     try {    Thread.sleep(2*60*1000);   } catch (InterruptedException e) {    // TODO Auto-generated catch block    e.printStackTrace();   }    }    class KeyValuePair{   String key;   String value;  }   }   </keyvaluepair></keyvaluepair>

First thing we need to know is PID (process ID) of the running process (which is causing OutOfMemory error). On a given host, there could be number of processes running and there are number of ways to find one. Fortunately java also provides a way to find PID and that is

jps command:

 jps command provides you list of all running java process ids.

Now we have got the process ID , so we can check heap statistics and see how does it look like. "jmap" is the way to go.

 jmap command with "-heap" option:

From jmap command , we have seen that both Young(New) Generation and Old generation heap size is 100% used. That indicates that there is a memory leak. But by looking at above memory statistics we can't figure out which culprit object is causing this issue. There are number of ways to figure the culprit object out. Lets start with simplest way:

 jmap command with "-histo" option:
jmap -histo:live PID

Above snapshot gives enough information about the culprit  which is sitting right there in the memory having 119905 LIVE instances on the heap. If you are a GUI fan and would like see such informations in GUI, then you got to follow below steps. First take memory dump of running process as below.

jmap command with "-dump" option: If you have not set
 "-XX:+HeapDumpOnOutOfMemoryError" option for the JVM then.

jmap -dump:file=FILE_NAME PID  will take the memory dump and save at the supplied location.

Now file dump has been taken and stored in "outofmem_heap.bin" file.Our job is to peak into dump file and find out what kind of instances are being created and how much space they are taking.

 How to read that dump file ?
Again , there are number of ways to peak into dump file , like

1. jhat utility bundled with JDK 5 and above.
2. Visualvm GUI base tool to read the heap dump (part of JDK 7 bundle).
3. Eclipse MemoryAnalyzer tool etc...

1st Option : 
jhat command
jhat needs 10 times more memory to open given size heap dump. for e.g. to open 256MB heap dump, jhat needs atleast 2048MB memory. (it may vary but for me it required this much memory).  
jhat -J-Xmx2048m HEAP_DUMP_FILE_NAME.
Above command reads the heap dump file and runs a server at default port 7000.

Now open Internet explorer and type http://HOST_NAME:7000" (or localhost if running locally). You will see page as below.

Click the link as shown with red arrow above. It will show count of culprit objects taking lot of memory as below.

2nd Option: Visualvm GUI based tool

3rd Option: Eclipse Memory Analyzer:
Memory Ananlyzer tool (MAT) is more powerful as it opens up huge size dump file with no issue. you may have to set more memory (in case you run out of memory issue with MAT while opening huge size file).