Experimenting with a Groovy Template Engine and PermGen

I had a Groovy application that was using a SimpleTemplateEngine was running out of PermGen space after running for a long period of time. The app was using version 1.7.10 and was running in a Tomcat 6 container.

Load tests consistently showed a linear increase in the PermGen consumption (monitored by JConsole). Originally, the template engine was used to create the template from the template text with every request. Also, the template was injected as a resource to the class using the engine.

After switching the class to create and cache the created template, we were still experiencing an OutOfMemoryError during the load test. Only after removing the use of the engine in its entirety, where we able to observe the PermGen leveling off.

A run of jmap -permstat PID against the application process showed a large number of entries of the form of:

  0x00000000f96bf800      24      233928  0x00000000f7f19558      dead    groovy/lang/GroovyClassLoader$InnerLoader@0x00000000fd784720

To investigate things, I thought I would try to see if I can reproduce the behavior using only a script run by Maven. As I go, I'll record what I see below. To start, I'll use Groovy 1.8.0.

The script will loop and complete a template with every iteration. The first version of the script will use a singe instance of SimpleTemplateEngine, but will call the createTemplate method with every iteration:

  def runs = 5
  def templateText = 'Run number: ${runNumber}'
  def engine = new groovy.text.SimpleTemplateEngine()

  runs.times { i ->
      def binding = [runNumber:"$i"]
      engine.createTemplate(templateText).make(binding)
  }

We'll start the script with verbose class loading on so we see what classes are loaded into PermGen during execution:

  $ export MAVEN_OPTS="-verbose:class"
  $ mvn -o exec:java -Dexec.mainClass=TemplateEngine | tee /tmp/out
  $ grep SimpleTemplateScript /tmp/out
  [Loaded SimpleTemplateScript1 from file:/groovy/shell]
  [Loaded SimpleTemplateScript2 from file:/groovy/shell]
  [Loaded SimpleTemplateScript3 from file:/groovy/shell]
  [Loaded SimpleTemplateScript4 from file:/groovy/shell]
  [Loaded SimpleTemplateScript5 from file:/groovy/shell]

We might suspect that behavior since not only are reading the template everytime through the loop. A new version of the script below again uses the same SimpleTemplateEngine instance and only creates the template once:

  def runs = 5
  def engine = new groovy.text.SimpleTemplateEngine()
  def createdTemplate = engine.createTemplate(templateText)

  runs.times { i ->
      def binding = [runNumber:"$i"]
      createdTemplate.make(binding)
  }

With this version, we only see one class load:

  $ grep SimpleTemplateScript /tmp/out
  [Loaded SimpleTemplateScript1 from file:/groovy/shell]

This is encouraging, but I want to make sure PermGen truly doesn't increase linerally over time. To do so, I'll add a sleep at the beginning of the script so I can attach JConsole to the Maven process and set the number of runs to a really high number:

  sleep(30000)
  println "Starting..."
  def runs = 50000

The PermGen graph is pretty jagged in the case where the createTemplate method is called each time through the loop. However, it appears that space was recovered as well so we do not end up running out of space:

To test the version where we only create the template once, I'm going to up the number of runs to 5,000,000 as execution is much faster without the repeated calls to the createTemplate method. The PermGen graph rises quickly but levels off:

So far, based on the verbose class loading and graph results, it looks like things are a definite improvement over what I was seeing in the original applcation. Just to be sure, I'm going to same experiment creating the template only once with version 1.7.0. as well.

With the single instance approach, the PermGen increased at a very slow rate. Using the approach where we call the createTemplate method with each iteration, the graph is again jagged:

At the end of this little experiment, I don't see any significant differences between Groovy 1.7 and 1.8. My work application was running in a Tomcat container which may also factor into things, along with a slightly different JVM version. Outside of the container, while the PermGen does rise with every load of a SimpleTemplateScript class, the memory is recovered.

I'll likely have to do some more experimentation to understand the behavior I was seeing in the original applcation.