How Tomcat ruined my night
posted by Aymeric Levaux
Tomcat is probably one of the more widely used pieces of open source infrastructure and it's a great boon to our productivity. Sometimes, though, a deep-rooted problem can sneak up on you and drag you into a sleep-deprived night of frantic web searching.
One day, I happened to see our production JVM restart, for no apparent reason. Intrigued, I looked into it a little bit more and realised that since the release of JBB v3 last December, it had been restarting roughly 6 times per month. After an OutOfMemory, the JVM dumps its heap into an hprof file, so there were a number of these files on the server, often over 1GB each!
I downloaded an hprof file and tried to open it with jhat, provided with the default Java 6 distro. jhat creates a website for you to visualise the heap [1]. Unfortunately, I couldn't get jhat to work, probably because JavaScript support is not yet implemented in MacOSX's JDK 1.6. I got around this problem by reading the hprof with YourKit Java Profiler 7.0 and quickly saw that vast amounts of memory were being taken up by several huge char arrays (click on the image for a larger version).

As you can see from the screenshot, 115 instances of org.apache.jasper.runtime.BodyContentImpl were holding on to over 560 million bytes worth of objects, keeping them from being garbage-collected and eating up inordinate amounts of RAM. So, what's BodyContentImpl actually doing?
Tomcat maintains a pool of PageContext instances, which in turn have an array of BodyContentImpls. Each BodyContentImpl has an array with the text from the tag's body. This array has a default size of 512 that is hard-coded as org.apache.jasper.Constants.DEFAULT_TAG_BUFFER_SIZE. Once the body of a custom tag gets bigger than that, the array grows and is never reset to its original size. With concurrent users, several such arrays might be created, so if a few popular pages use big custom tags, you can end up with a number of gigantic, un-garbage-collectable char arrays. In our case, this happened because in v3 we started decorating large blocks of JSP code with SiteMesh custom tags.
One solution would be to set the environment variable org.apache.jasper.runtime.BodyContentImpl.LIMIT_BUFFER to true, so that arrays over 512 bytes are released. Another would be to recompile Tomcat with a tag buffer size more suited to our needs. So both choices are extreme: either you maintain huge arrays for ever, or you're constantly creating and garbage collecting arrays, as 512 bytes is a fairly low limit for custom tags. We settled on giving the JVM more RAM to handle the extra garbage collection.
Of course, others have experienced the same problem. What's the word from the Tomcat camp? Well, Remy Maucherat, Tomcat committer, considers that:
One day, I happened to see our production JVM restart, for no apparent reason. Intrigued, I looked into it a little bit more and realised that since the release of JBB v3 last December, it had been restarting roughly 6 times per month. After an OutOfMemory, the JVM dumps its heap into an hprof file, so there were a number of these files on the server, often over 1GB each!
I downloaded an hprof file and tried to open it with jhat, provided with the default Java 6 distro. jhat creates a website for you to visualise the heap [1]. Unfortunately, I couldn't get jhat to work, probably because JavaScript support is not yet implemented in MacOSX's JDK 1.6. I got around this problem by reading the hprof with YourKit Java Profiler 7.0 and quickly saw that vast amounts of memory were being taken up by several huge char arrays (click on the image for a larger version).

As you can see from the screenshot, 115 instances of org.apache.jasper.runtime.BodyContentImpl were holding on to over 560 million bytes worth of objects, keeping them from being garbage-collected and eating up inordinate amounts of RAM. So, what's BodyContentImpl actually doing?
Tomcat maintains a pool of PageContext instances, which in turn have an array of BodyContentImpls. Each BodyContentImpl has an array with the text from the tag's body. This array has a default size of 512 that is hard-coded as org.apache.jasper.Constants.DEFAULT_TAG_BUFFER_SIZE. Once the body of a custom tag gets bigger than that, the array grows and is never reset to its original size. With concurrent users, several such arrays might be created, so if a few popular pages use big custom tags, you can end up with a number of gigantic, un-garbage-collectable char arrays. In our case, this happened because in v3 we started decorating large blocks of JSP code with SiteMesh custom tags.
One solution would be to set the environment variable org.apache.jasper.runtime.BodyContentImpl.LIMIT_BUFFER to true, so that arrays over 512 bytes are released. Another would be to recompile Tomcat with a tag buffer size more suited to our needs. So both choices are extreme: either you maintain huge arrays for ever, or you're constantly creating and garbage collecting arrays, as 512 bytes is a fairly low limit for custom tags. We settled on giving the JVM more RAM to handle the extra garbage collection.
Of course, others have experienced the same problem. What's the word from the Tomcat camp? Well, Remy Maucherat, Tomcat committer, considers that:
Using sensibly written software helps. It should be obvious reading the API that using large body tags is going to be a huge problem.Please draw your own conclusions.
- By the way, jhat loads the whole hprof file into memory, so you may need to use the -J-mx512m flag if you're having OutOfMemory thrown.
Labels: app servers, dev

0 Comments:
Post a Comment
Links to this post:
Create a Link
<< Home