How to fix the dreaded "java.lang.OutOfMemoryError: PermGen space" exception (classloader leaks)

In the previous blog entry Classloader leaks: the dreaded "java.lang.OutOfMemoryError: PermGen space" exception  I explained how this type of problem can originate in the application code that you deploy to an application server.  In this post I'll explain how to track down the leak so that you can fix it.

Profilers

Memory leak? Use a profiler. Right? Well... generally speaking the answer is yes, but classloader leaks are a bit special...

To refresh your memory (pardon the pun), a memory leak is an object that the system unintentionally hangs on to, thereby making it impossible for the garbage collector to remove this object. The way that profilers find memory leaks is to trace references to a leaked object.

What do I mean by "tracing"? A leaked object can be referenced by another object which itself is a leak. In turn, this object may also be a leak, and so on. This repeats until an object is found that references a leaked object by mistake. This reference is where the problem is, and what you need to fix. Let me try to clarify this by illustrating this with a picture from my previous blog:

In this picture the AppClassloader, LeakServlet.class, STATICNAME, CUSTOMLEVEL, LeakServlet$1.class are all leaked objects. Due to static objects (e.g. STATICNAME) in the picture, that may in turn reference other objects, the number of leaked objects may be in the thousands. Going over each leaked object manually to check if there are any incidental references to it (the red reference in the picture) until you find the troublesome object (CUSTOMLEVEL) is laborious. You would rather have a program find the violating reference for you.

A profiler doesn't tell you which leaked object is interesting to look at (CUSTOMLEVEL). Instead it gives you all leaked objects. Let's say that you would look at STATICNAME. The profiler now should find the route STATICNAME to LEAKSERVLET.class to AppClassloader to LeakServlet1$1.class, to CUSTOMLEVEL to Level.class. In this route, the red line in the picture is the reference that actually causes the leak. I said the profiler should find this route. However, all the profilers that we tried, stop tracing as soon as they reach a class object or classloader. There's a good reason for that: the number of traces grows enormous if it follows through the references through classes. And in most cases, these traces are not very useful.

So no luck with profilers! We need to try something else.

JDK 6.0 to the rescue

When Edward Chou and I worked on tracking down classloader leaks last year, we tried to run the JVM with HPROF and tried to trigger a memory dump; we looked at using Hat to interpret the dump. Hat stands for Heap Analysis Tool, and was developed to read dump files generated with HPROF. Unfortunately, the hat tool blew up reading our dump files. Because we didn't think it was difficult to parse the dump file, we wrote a utility to read the file and track the memory leak.

That was last year. This year we have JDK 6.0; this new JDK comes with a few tools that make looking at the VM's memory a lot simpler. First of all, there's a tool called jmap. This command line tool allows you to trigger a dump file without HPROF. It is as simple as typing something like:
    jmap -dump:format=b,file=leak 3144
Here leak is the filename of the dump, and 3144 is the PID of the process. To find the PID, you can use jps.

Secondly, Hat is now part of the JDK. It is now called jhat. You can run it using a command line like:
    jhat -J-Xmx512m leak
Here leak is the name of the dump file, and as you may have guessed, -J-Xmx512m is a parameter to specify how much memory jhat is allowed to allocate.

When you start jhat it reads the dump file and then listens on an HTTP port. You point your browser to that port (7000 by default) and through that you can browse the memory heap dump. It's a very convenient way of looking at what objects are in memory and how they are connected.

So, it seemed like a good idea to check out what can be done with these new tools to find classloader leaks.

... or not?

Unfortunately, jhat, just like the profilers we tried, also stops tracing when it encounters a class. Now what? I decided to download the JDK source code and find out what the problem is.  Building the whole JDK is a difficult task from what I gather from the documentation. Fortunately, jhat is a nicely modularized program; I could just take the com.sun.tools.hat-packages out of the source tree, load them in my favorite editor and compile the code. The patched code was easily packaged and run: I just jar-ed it and added it to the lib/ext directory of the JDK:
    jar -cf C:\\apps\\Java\\jdk1.6.0\\jre\\lib\\ext\\ahat.jar -C hat\\bin .
    jhat leak

This was really as easy as pie. So after running the program in the debugger for some time, I figured out how it works and what changes I wanted to make. The change is that when you follow the references from a classloader, the modified jhat will follow through all traces from all the instances of the classes that it loaded. With that change, finding the cause of a classloader leak is simple.

An example

Let's look at the example from my previous blog as depicted in the picture above. Using NetBeans I created the following servlet and deployed it to Glassfish:

 1 package com.stc.test;
 2
 3 import java.io.\*;
 4 import java.net.\*;
 5 import java.util.logging.Level;
 6 import java.util.logging.Logger;
 7 import javax.servlet.\*;
 8 import javax.servlet.http.\*;
 9
10 public class Leak extends HttpServlet {
11
12     protected void processRequest(HttpServletRequest request, HttpServletResponse response)
13     throws ServletException, IOException {
14         response.setContentType("text/html;charset=UTF-8");
15         PrintWriter out = response.getWriter();
16         out.println("<html><body><pre>");
17         Level custom = new Level("LEAK", 950) {};
18         Logger.getLogger(this.getClass().getName()).log(custom, "New level created");
19         out.println("</pre></body></html>");
20         out.close();
21     }
22+    HTTPServlet methods. Click on the + sign on the left to edit the code
48 }
49

I invoked the servlet to cause the leak. Next I undeployed the servlet. Then I triggered a heap dump:
    jmap -dump:format=b,file=leak 3144
and fired up the modified jhat:
    jhat -J-Xmx512m leak
and brought up the browser. The opening screen shows amongst other things, all classes that are found in the dump:

Finding objects that were leaked is easy since I know that I shouldn't see any objects of the classes that I deployed. Recall that I deployed a class com.stc.test.Leak; so I searched in the browser for the com.stc.test package, and found these classes (never mind the NoLeak class: I used it for testing).

Clicking on the link class com.stc.test.Leak brings up the following screen:

Clicking on the classloader link brings up the following screen:

Scrolling down, I see Reference Chains from Rootset / Exclude weak refs . Clicking on this link invokes the code that I modified; the following screen comes up:

And there's the link to java.util.Logging.Level that we've been looking for!

Easy as pie!

Summarizing, the steps are:

1. undeploy the application that is leaking
2. trigger a memory dump
3. run jhat (with modification)
4. find a leaked class
5. locate the classloader
6. find the "Reference chains from root set"
7. inspect the chains, locate the accidental reference, and fix the code

I'll contact the JDK team to see if they are willing to accept the changes I made to jhat. If you cannot wait, send me an email or leave a comment.

Update (April 2007): Java SE SDK 6.0 update 1 has the updated code.

Other Permgen space tidbits

After fixing the classloader leak, you of course want to test to see if the memory leak has disappeared. You could again trigger a memory dump and run jhat. What you also could try is to see if the amount of used permgen space memory goes up continuously after each deployment/undeployment of your application.

You can monitor permgen space usage using jconsole. You can see the memory usage go up when you repeatedly deploy and undeploy an application. However, this may not be a classloader / memory leak. As it turns out, it's difficult to predict when the garbage collector cleans up permgen space. Pressing the button in Run GC in jconsole does not do the trick. Only when you encounter a java.lang.OutOfMemoryError: PermGen space exception can you be sure that there really was no memory. This is a bit more involved than it should be!

How can we force the garbage collector to kick in? We can force a java.lang.OutOfMemoryError: PermGen space and then releasing the memory after which we force the garbage collector to kick in. I wrote the following servlet to do that:

package com.stc.test;

import java.io.\*;
import java.util.ArrayList;
import javax.servlet.\*;
import javax.servlet.http.\*;

public class RunGC extends HttpServlet {

private static class XClassloader extends ClassLoader {
private byte[] data;
private int len;

public XClassloader(byte[] data, int len) {
super(RunGC.class.getClassLoader());
this.data = data;
this.len = len;
}

public Class findClass(String name) {
return defineClass(name, data, 0, len);
}
}

protected void processRequest(HttpServletRequest request, HttpServletResponse response)
throws ServletException, IOException {
response.setContentType("text/html;charset=UTF-8");
PrintWriter out = response.getWriter();
out.println("<html><body><pre>");

try {
// Load class data
byte[] buf = new byte[1000000];
InputStream inp = this.getClass().getClassLoader()
.getResourceAsStream("com/stc/test/BigFatClass.class");
int n = inp.read(buf);
inp.close();
out.println(n + " bytes read of class data");

// Exhaust permgen
ArrayList keep = new ArrayList();
int nLoadedAtError = 0;
try {
for (int i = 0; i < Integer.MAX_VALUE; i++) {
XClassloader loader = new XClassloader(buf, n);
Class c = loader.findClass("com.stc.test.BigFatClass");
keep.add(c);
}
} catch (Error e) {
nLoadedAtError = keep.size();
}

// Release memory
keep = null;
out.println("Error at " + nLoadedAtError);

// Load one more; this should trigger GC
XClassloader loader = new XClassloader(buf, n);
Class c = loader.findClass("com.stc.test.BigFatClass");
out.println("Loaded one more");
} catch (Exception e) {
e.printStackTrace(out);
}

out.println("</pre></body></html>");
out.close();
}

In this servlet a custom classloader is instantiated which loads a class in that classloader. That class is really present in the web classloader, but the custom classloader is tricked by not delegating to the parent classloader; instead the classloader is instantiating the class using the bytes of the class obtained through getResourceAsStream().

In the servlet it tries to allocate as many of these custom classes as possible, i.e. until the memory exception occurs. Next, the memory is made eligible for garbage collection, and one more classloader is allocated thereby forcing garbage collection.

The number of custom classes that can be loaded until a memory exception occurs, is a good measure of how much permgen space memory is available. As it turns out, this metric is a much more reliable than the one that you get from jconsole.

And more

Edward Chou is thinking of some other ideas to further automate the process of determining exactly where the cause of a classloader leak is. E.g. it should be possible to identifiy the erroneous reference (the red line in the picture) automatically, since this reference is from one classloader to another. Check his blog in the coming days.

Update (April 2007): You can find an interesting usage of jhat's Object Query Language on Sundarajan's blog to compute histograms of reference chains.

Classloader leaks: the dreaded "java.lang.OutOfMemoryError: PermGen space" exception

Did you ever encounter a java.lang.OutOfMemoryError: PermGen space error when you redeployed your application to an application server? Did you curse the application server, while restarting the application server, to continue with your work thinking that this is clearly a bug in the application server. Those application server developers should get their act together, shouldn't they? Well, perhaps. But perhaps it's really  your fault!

Take a look at the following example of an innocent looking servlet.

package com.stc.test;

import java.io.\*;
import java.util.logging.\*;
import javax.servlet.\*;
import javax.servlet.http.\*;

public class MyServlet extends HttpServlet {
protected void doGet(HttpServletRequest request, HttpServletResponse response)
throws ServletException, IOException {
// Log at a custom level
Level customLevel = new Level("OOPS", 555) {};
Logger.getLogger("test").log(customLevel, "doGet() called");
}
}

Try to redeploy this little sample a number of times.  I bet this will eventually fail with the dreaded java.lang.OutOfMemoryError: PermGen space error. If you like to understand what's happening, read on.

The problem in a nutshell

Application servers such as Glassfish allow you to write an application (.ear, .war, etc) and deploy this application with other applications on this application server. Should you feel the need to make a change to your application, you can simply make the change in your source code, compile the source, and redeploy the application without affecting the other still running applications in the application server: you don't need to restart the application server. This mechanism works fine on Glassfish and other application servers (e.g. Java CAPS Integration Server).

The way that this works is that each application is loaded using its own classloader. Simply put, a classloader is a special class that loads .class files from jar files. When you undeploy the application, the classloader is discarded and it and all the classes that it loaded, should be garbage collected sooner or later.

Somehow, something may hold on to the classloader however, and prevent it from being garbage collected. And that's what's causing the java.lang.OutOfMemoryError: PermGen space exception.

PermGen space

What is PermGen space anyways? The memory in the Virtual Machine is divided into a number of regions. One of these regions is PermGen. It's an area of memory that is used to (among other things) load class files. The size of this memory region is fixed, i.e. it does not change when the VM is running. You can specify the size of this region with a commandline switch: -XX:MaxPermSize . The default is 64 Mb on the Sun VMs.

If there's a problem with garbage collecting classes and if you keep loading new classes, the VM will run out of space in that memory region, even if there's plenty of memory available on the heap. Setting the -Xmx parameter will not help: this parameter only specifies the size of the total heap and does not affect the size of the PermGen region.

Garbage collecting and classloaders

When you write something silly like

 private void x1() {
        for (;;) {
            List c = new ArrayList();
        }
    }

you're continuously allocating objects; yet the program doesn't run out of memory: the objects that you create are garbage collected thereby freeing up space so that you can allocate another object. An object can only be garbage collected if the object is "unreachable". What this means is that there is no way to access the object from anywhere in the program. If nobody can access the object, there's no point in keeping the object, so it gets garbage collected. Let's take a look at the memory picture of the servlet example. First, let's even further simplify this example:

package com.stc.test;

import java.io.\*;
import java.net.\*;
import javax.servlet.\*;
import javax.servlet.http.\*;

public class Servlet1 extends HttpServlet {
private static final String STATICNAME = "Simple";
protected void doGet(HttpServletRequest request, HttpServletResponse response)
throws ServletException, IOException {
}
}

After loading the above servlet, the following objects are in memory (ofcourse limited to the relevant ones):

In this picture you see the objects loaded by the application classloader in yellow, and the rest in green. You see a simplified container object that holds references to the application classloader that was created just for this application, and to the servlet instance so that the container can invoke the doGet() method on it when a web request comes in. Note that the STATICNAME object is owned by the class object. Other important things to notice:

1. Like each object, the Servlet1 instance holds a reference to its class (Servlet1.class).
2. Each class object (e.g. Servlet1.class) holds a reference to the classloader that loaded it.
3. Each classloader holds references to all the classes that it loaded.

The important consequence of this is that whenever an object outside of AppClassloader holds a reference to an object loaded by AppClassloader, none of the classes can be garbage collected.

To illustrate this, let's see what happens when the application gets undeployed: the Container object nullifies its references to the Servlet1 instance and to the AppClassloader object.

As you can see, none of the objects are reachable, so they all can be garbage collected. Now let's see what happens when we use the original example where we use the Level class:

package com.stc.test;

import java.io.\*;
import java.net.\*;
import java.util.logging.\*;
import javax.servlet.\*;
import javax.servlet.http.\*;

public class LeakServlet extends HttpServlet {
private static final String STATICNAME = "This leaks!";
private static final Level CUSTOMLEVEL = new Level("test", 550) {}; // anon class!

protected void doGet(HttpServletRequest request, HttpServletResponse response)
throws ServletException, IOException {
Logger.getLogger("test").log(CUSTOMLEVEL, "doGet called");
}
}

Note that the CUSTOMLEVEL's class is an anonymous class. That is necessary because the constructor of Level is protected. Let's take a look at the memory picture of this scenario:

In this picture you see something you may not have expected: the Level class holds a static member to all Level objects that were created. Here's the constructor of the Level class in the JDK:

 protected Level(String name, int value) {
this.name = name;
this.value = value;
synchronized (Level.class) {
known.add(this);
}
}

Here known is a static ArrayList in the Level class. Now what happens if the application is undeployed?

Only the LeakServlet object can be garbage collected. Because of the reference to the CUSTOMLEVEL object from outside of AppClassloader, the  CUSTOMLEVEL anyonymous class objects (LeakServlet$1.class) cannot be garbage collected, and through that neither can the AppClassloader, and hence none of the classes that the AppClassloader loaded can be garbage collected.

Conclusion: any reference from outside the application to an object in the application of which the class is loaded by the application's classloader will cause a classloader leak.

More sneaky problems

I don't blame you if you didn't see the problem with the Level class: it's sneaky. Last year we had some undeployment problems in our application server. My team, in particular Edward Chou, spent some time to track them all down. Next to the problem with Level, here are some other problems Edward and I encountered. For instance, if you happen to use some of the Apache Commons BeanHelper's code: there's a static cache in that code that refers to Method objects. The Method object holds a reference to the class the Method points to. Not a problem if the Apache Commons code is loaded in your application's classloader. However, you do have a problem if this code is also present in the classpath of the application server because those classes take precedence. As a result now you have references to classes in your application from the application server's classloader... a classloader leak!

I did not mentiond yet the simplest recipe for disaster: a thread started by the application while the thread does not exit after the application is undeployed.

Detection and solution

Classloader leaks are difficult. Detecting if there's such a leak without having to deploy/undeploy a large number of times is difficult. Finding the source of a classloader leak is even trickier. This is because all the profilers that we tried at the time, did not follow links through classloaders. Therefore we resorted to writing some custom code to find the leaks from memory dump files. Since that exercise, new tools came to market in JDK 6. The next blog will outline what the easiest approach today is for tracking down a glassloader leak.

Transactions, disks, and performance

So far I've written only a handful of blogs. My blogs are technical and dry and consequently the hit count of my blog is low. However, it has generated some interest from people in far away places and generated some interesting discussions through email. One of the things that came up is data integrity and disk performance. And that's the topic of this blog...

Maintaining data integrity

Consider a simple scenario: an MDB reads from a JMS queue, and for each message that it receives, it writes a record to a database. Let's say that you want to minimize the chance that you would lose or duplicate data in the case of failure. What kind of failure? Let's say that power failures or system crashes are your biggest worries.

How do we minimize the chance of losing or duplicating data? First of all, you want to make sure that receiving the message from the queue and the writing to the database happens in one single transaction. One of the easiest ways of doing that is to use an application server like Glassfish. How does Glassfish help? It starts a distributed (two phase) transaction. The transactional state is persisted by the JMS server and database, and by Glassfish through its transaction log. In the event of a system crash, the system will come back up and by using the persisted transactional state, Glassfish can make sure that either the transaction is fully committed or fully rolled back. Ergo, no data is lost or duplicated. The details of this are fascinating, but let's look at that some other time.

Thus, reliable persistence that is immune to system crashes (e.g. the Blue Screen of Death (BSOD)) or power failures is important. That means that when a program thinks that the data has been persisted on the disk, it in fact should have been written in the magnetic media of the disk. Why do I stress this? Because it's less trivial than you might think: the operating system and drive may cache the data in the write cache. Therefore you will have to disable the write cache in the OS on the one hand; in your application you will have to make sure that the data is indeed sync-ed to disk on the other hand.

Turning off the write cache, syncing to disk... no big deal, right? Unfortunately there are many systems in which the performance drops like a stone when you do that. Let's look at why that is, and how good systems solve this performance problem.

The expense of writing to disk

As you know, data on a disk is organized in concentrical circles. Each circle (track) is divided up in sectors. When the disk controller writes data to the disk, it has to position the write head to the right track and wait until the disk has rotated such that the beginning of the sector is under the write head. These are mechanical operations; they are not measured in nano seconds or micro seconds, but rather in milliseconds. As it turns out, a drive can do about one hundred of these operations per second. So, as a rule of thumb, a drive can perform one hundred writes per second. And this hasn't changed much in the past few decades, and it won't change in the next decade.

Writes per second is one aspect. The number of bytes that can be written per second is another.  This is measured in megabytes per second. Fortunately over the past decades this rate has steadily increased and it likely will continue to do so. That's why formatting a 300 Gb drive today doesn't take 10000 times longer than it took to format a 30 Mb drive 15 years ago.

Key is that the more you can send to the disk in one write operation, the more data you can write.  To demonstrate this, I've done some measurements on my desktop machine.

This chart shows that the number of write operations per second remains constant up to approximately 32 kb. (Note that the x-axis is logarithmic) That means that whether you try to write 32768 bytes or just one single byte per write operation, the maximum number of writes per second remains the same. Of course the amount of data you can write to the disk goes up if you put more data in a single write operation. Put another way, if you need to write 1 kb chunks of data, you can process 32 times faster if you combine your chunks into one 32 kb chunk.

What you can see in this chart is that the amount of data you can write to the disk per second (data rate) increases with the number of bytes per write. Of course that can not increase infinitely: the data rate eventually becomes constant. (Note that the x-axis and y-axis are both logarithmic). The data rate at a write size of 32 kb is approx 3.4 Mb/sec and levels off at a write size of approx 1 Mb to 6 Mb/sec.

These measurements were done on a $300 PC with a cheap hard drive running Windows. I've done the same measurements on more expensive hardware with more expensive drives and found similar results: most drives perform slightly better, but the overall picture is the same.

The lesson: if you have to write small amounts of data, try to combine these in one write operation.

Multi threading

Back to our example of JMS and a database. As I mentioned, for each message picked up from the queue and written to the database, there are several write operations. For now, let's assume that the data written for the processing of single message cannot be combined into one write operation. However, if we process the messages concurrently, we can combine the data being written from multiple threads in one write operation!

Good transaction loggers, good databases that are optimize for transaction processing, and good JMS servers, all try to combine the data from multiple concurrent transactions into as few write operations as possible. As an example, here are some measurements I did against STCMS on the same hardware as above. STCMS is the JMS server that ships with Java CAPS.

As you can see, for small messages the throughput of the system increases almost linearly with the number of threads. This happens because one of the design principles of STCMS is to consolidate as much data as possible in a single write operation. Of course when you increase the size of the messages, or if you increase the number of threads indefinitely, you will eventually hit the limit on the data rate. This is why the performance for large messages does not scale like it does for small messages. Of course when increasing the number of threads to large numbers, you will also hit other limits due to the overhead in thread switching.

Note that the measurements in this chart were done on a queue-to-queue and topic-to-topic scenario about three years ago. The STCMS shipping today performs a lot better, e.g. there's no difference in performance anymore between queues and topics, so don't use these numbers as benchmark numbers for STCMS; I'm just using them to prove the point of the power of write-consolidation.

Other optimizations in the transaction manager

Combining data that needs to be written to the disk from many threads into one write operation is definitely a good thing for both resource managers (the JMS server and database server in our example) and the transaction manager.  Are there other things that can be done specifically in the area of the transaction manager? Yes, there are: let's see if we can minimize the number of times data needs to be written for each message.

Last agent commit The first thing that comes to mind is last-agent commit optimization. That means that in our example, one of the resource managers will not do a two phase commit, but instead only do a single phase commit, thereby saving another write. Most transaction managers can do this, e.g. the transaction manager in Glassfish does this.

Piggy backing on another persistence store Instead of writing to its own persistence store, the transaction log could write its data to the persistence store of one of the resource managers participating in the transaction. By doing so, it can push its data into the same write operation that the resource manager needs to do anyway. For instance, the transaction manager can write its transaction state into the database. An extra table in the database is all it takes. Alternatively, the JMS server could provide some extensions so that the transaction log can write its data to the persistence store of the JMS server.

Logless transactions If the resource manager (e.g. JMS) doesn't have an API that allows the transaction manager to use its persistence store, the transaction manager could sneak in some data of its own in the XID. The XID is just a string of bytes that the resource manager treats as an opaque entity. The transaction manager could put some data in the XID that identifies the last Resource Manager; in the case of a system crash, the transaction manager will query all known resource managers and obtain a list of in-doubt XIDs. The presence of the in-doubt XID of the last resource in the transaction signifies that all resources were successfully prepared and that commit should be called; the absence signifies that the prepare phase was incomplete and that rollback should be called. This mechanism was invented by SeeBeyond a few years ago (patent pending). There are some intricacies in this system; perhaps a topic for a future blog? Leave a comment to this blog if you're interested.

Beyond the disk

The scenario we've been looking at is one in which data needs to be persisted so that no data gets lost in case of a system crash or power failure.  What about a disk failure? We could use a RAID system. Are there other ways? Sure! We could involve multiple computers: clustering! If each machine that needs to safeguard transaction data would also write its data to another node in a cluster, that data would survive a crash of the primary node. Assuming that a crash of two nodes at the same time is very unlikely, this forms a reliable solution. On both nodes, data can be written to the disk using a write caching scheme so that the number of writes per second is no longer the limiting factor.

We can go even further for short-lived objects. Consider this scenario:
    insert into A values ('a', 'b')
    update A set value = 'c' where pk = 'a'
    delete A where pk = 'a'
why write the value ('a', 'b') to the disk at all? Hence, a smart write cache can avoid any disk writes for short lived objects. Of course typical data that the transaction manager generates are short lived objects. JMS messages are another example of objects that may have a short life span.

A pluggable transaction manager... and what about Glassfish?

It would be nice if transaction managers had a pluggable architecture so that depending on your specific scenario, you could choose the appropriate transaction manager log persistence strategy.

Isn't clustering something difficult and expensive? Difficult to develop yes, but not difficult to use. Sun Java System Application Server 8.x EE already has strong support for clustering. Glassfish will soon have support for clustering too. And with that clustering will become available to everybody!