Igor Kromin |   Consultant. Coder. Blogger. Tinkerer. Gamer.

One of the peculiarities we've noticed during our recent bout of performance testing at work was how much JVM heap space was being used and immediately garbage collected by one of our web services. The figures were quite staggering, with a peak use of 3Gb to generate the response message in some cases. This was not impacting the performance of the system overall, but still needed investigating as it gives lots of room for improvements.

After a bit poking around, adding additional debugging to the web services and running it over and over again I was able to track down the source of this problem. It was when a particular XML fragment was being constructed out of JAXB objects, unfortunately this was one of the core fragments in the response so it had to be there.

Not willing to give up on this issue, I decided to see what I could be done to make it better. I had an idea of what I wanted to change, but needed some hard figures to be sure that it would be worthwhile. The idea was to remove JAXB and replace it with Velocity.

I needed a starting point and given the schema I was working with (HL7 v3) is quite complex, I decided to pick the AD data type, which represents an address. The XML for this can be generated without too much work. I opted for a simple 4 line address, which looked like this (the odd name spaces are due to JAXB in this case)...
 Address XML Fragment
<addr xmlns:ns11="urn:hl7-org:v3" xmlns="org.hl7.v3" use="WP">
<ns11:streetAddressLine partType="SAL">1 Blogg Street</ns11:streetAddressLine>
<ns11:city partType="CTY">Joe City</ns11:city>
<ns11:state partType="STA">Blogg State</ns11:state>
<ns11:postalCode partType="ZIP">99999</ns11:postalCode>
</addr>


So that's what I had to work with, next I set up two Java classes, one to generate the XML fragment using JAXB, the other to generate the same fragment using Velocity. I made sure that the following was done too:
  • Velocity template caching turned ON
  • Velocity template reloading turned OFF (0 for the modification interval)
  • Velocity Engine created once only
  • JAXB Context for org.hl7.v3 is created once only
  • JAXB ObjectFactory is static and created once
  • Update: after some feedback I can confirm that schema validation was turned off for this test
  • Both JAXB and Velocity generator classes return the XML fragment as a String
  • Both generator classes set the same values for the generated XML each time during generation

Each test ran in Java 7 with a 4Gb static heap and the default GC settings.

I set up a Runner class that would instantiate the appropriate generator (JAXB or Velocity). This would iterate a number of times, generating the same XML fragment. For the purpose of this article I will show figures from iterating 100,000 times, however I did repeat this with various other iteration counts.



First lets see the number of loaded classes for each of the generators.

With JAXB, over 3000 loaded classes. Not unexpected since the schema is quite complex. This remains steady through the whole time.
classes_jaxb-100m.png


Now with Velocity, the loaded classes also remain steady but are significantly reduced, down to around 1200. Straight away this implies that Velocity has a much lower memory requirement. Again not unexpected.
classes_velocity-100m.png


If you look closer at the time scales in the above graphs you can start to see the implications. JAXB took around 3 minutes to complete what took Velocity just under 15 seconds.

I've gathered some more data, running 100 iterations that each generated 100,000 XML fragments. These are the results...
vel_vs_jaxb_times.png


The initial times spike, but that's normal as everything gets loaded into memory and cached, so that can be ignored. The interesting thing is JAXB always took significantly longer to complete than Velocity. In fact this is an order of magnitude difference here.

So what does this mean? Velocity will always outperform JAXB in generating my XML fragment. That's great, but I really wanted to solve the memory issue, not improve the time it takes to produce my XML. However this is a great bonus.

So lets look at what the heap looked like.

With JAXB the heap usage peaked at around 1.3Gb. As is seen below this is thrashed quite a bit. Lots of object creation and garbage collection appears to be going on. This would be ok, except that this is happening very frequently.
heap_jaxb-100m.png


Compared to Velocity, the peak is around the same, 1.3Gb, however there are far fewer garbage collections.
heap_velocity-100m.png


However the time scales are an issue, so zooming in on a 15 second period during the JAXB test, I get the following heap profile...
heap_jaxbtimeslice-100m.png


This looks remarkably similar to the heap profile for Velocity. However, we have to remember that in the space of 15 seconds, the Velocity generator was able to produce 100x 100,000 XML fragments. The JAXB generator only managed around 100x 555 XML fragments in the same time period.

These numbers can't be easily translated into performance gains for a bigger XML fragment, or even an entire XML document, however this approach seems promising.

Open image gallery
to see this article's graphs.

-i

A quick disclaimer...

Although I put in a great effort into researching all the topics I cover, mistakes can happen. Use of any information from my blog posts should be at own risk and I do not hold any liability towards any information misuse or damages caused by following any of my posts.

All content and opinions expressed on this Blog are my own and do not represent the opinions of my employer (Oracle). Use of any information contained in this blog post/article is subject to this disclaimer.
Hi! You can search my blog here ⤵
NOTE: (2022) This Blog is no longer maintained and I will not be answering any emails or comments.

I am now focusing on Atari Gamer.