castor

Symtoms suggesting XMLClassDescriptorResolver internal descriptor cache memory leak

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: 1.1
  • Fix Version/s: 1.1.1
  • Component/s: XML
  • Labels:
    None
  • Environment:
    Sun Java 1.5.0_06
  • Number of attachments :
    2

Description

I've recently moved from using an old version of Castor (0.9.xxx) to the new stable 1.1. Mainly as i'd like to use the descriptor caching.

However, after moving to castor 1.1 and creating an XMLClassDescriptorResolver as per the xml-best-practices webpage, running my application caused an out of memory expection (heapspace).

So i ran the code under jProfiler and have seen symptoms of a memory leak (or symptoms of not using the resolver correctly .

It's my understanding that when marshalling/unmarshalling, the XMLClassDescriptorResolver should be caching the descriptors for use in subsequent operations. Then on the subsequent operation (marshal / unmarshall) it shouldn't have to create those descriptors again (assumming the same class/xml complex type is being used).

But what i've seen in jProfiler is that after one run of my code there have been 3828 XMLFieldDescriptorImpl objects created (triggering garbage collection a few times doesn't change that number either) then when i run it again (no restart, just second iteration) it finishes what it's doing and the count of XMLFieldDescriptorImpl objects is now 7725!

It increases with each iteration, and after 10 iterations is 38901 objects, taking up 3.4 megabytes in memory - after a while this gets so big it causes the memory exception.

So it looks like it's created new XMLFieldDescriptorImpl for the same classes and xml complex types i used the first time around.

I understand that there is an object graph underneath the root object, hense i understand it needs to load the 3828 descriptors for the object graph underneath my root object. What i don't understand is why when marshalling/unmarshalling the same root class (albeit with possibly different values e.g., two objects of type person might have different names but it's still the same name field) the resolver is loading more descriptors but should in my opinion be using the same descriptors, it is only the values that have changed not the class/fields. I understand that in a complex object graph it may need to load more descriptors for different objects due to it having a larger object graph - but my object is staying relatively similiar each time - therefor i would expect some growth but not constant growth with each iteration.

Also i'm not trying to create a resolver for every class - i'm creating a resolver for each root class and reusing them (and yes i am setting the resolver on the marshaller/unmashaller . I don't think it is thread safe either - so i've implemented it in a thread safe manner.

In the application i help to develop it is impossible for us to use only one resolver, as we have many threads needing to
perform (un)marshalling operations and the implementation of XMLClassDescriptorResolver is not thread safe (it uses HashMaps)
and we cannot afford to block until the resolver is available.

However, i've spent a little time creating a unit test that i believe shows the symptoms of a memory leak. It also shows that using the
resolver does not speed up the (un)marshaling, in fact slowing it down a touch.

The test makes ten iterations of 100 unmarshals then marshals of the same bit of xml. Without a resolver the test completes but with the
resolver the test fails on the 7th iteration with a java heap space exception.

It is best seen from inside jProfiler where the number of xmlfielddesriptors can be tracked.

Here is the output from my test:

u = avg unmarshal time (millis)
m = avg marshal time (millis)
f = free mem (mb)
t = total mem (mb)

Test setup: 10 of 100 unmarshal then marshal, useResolver = false
Iteration 1 : 2047 millis [u:13 m:13 f:0 t:1]
Iteration 2 : 1265 millis [u:7 m:7 f:1 t:1]
Iteration 3 : 1250 millis [u:6 m:6 f:0 t:1]
Iteration 4 : 1188 millis [u:7 m:7 f:0 t:1]
Iteration 5 : 1219 millis [u:6 m:6 f:0 t:1]
Iteration 6 : 1171 millis [u:6 m:6 f:0 t:1]
Iteration 7 : 1204 millis [u:6 m:6 f:0 t:1]
Iteration 8 : 1234 millis [u:6 m:6 f:1 t:1]
Iteration 9 : 1156 millis [u:6 m:6 f:0 t:1]
Iteration 10 : 1203 millis [u:6 m:6 f:1 t:1]
Completed successfully

Test setup: 10 of 100 unmarshal then marshal, useResolver = true
Iteration 1 : 1235 millis [u:6 m:6 f:3 t:13]
Iteration 2 : 1265 millis [u:8 m:8 f:1 t:20]
Iteration 3 : 1532 millis [u:6 m:6 f:7 t:32]
Iteration 4 : 1890 millis [u:11 m:11 f:18 t:54]
Iteration 5 : 1797 millis [u:7 m:7 f:10 t:54]
Iteration 6 : 2047 millis [u:11 m:11 f:3 t:54]
Iteration 7 : 6984 millis [u:31 m:31 f:5 t:63]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space

The small eclipse project i created for this test has been zipped and attached.

Thank you for your time

Activity

Hide
Werner Guttmann added a comment -

As already mentioned on the mailing list, you should create only one resolver for your aplication, and not one resolver per root class. Does this make sense to you ?

Show
Werner Guttmann added a comment - As already mentioned on the mailing list, you should create only one resolver for your aplication, and not one resolver per root class. Does this make sense to you ?
Hide
Simon Lord added a comment -

Werner - please look at the code attached to this issue - i have created only one resolver - this does make sense.

Show
Simon Lord added a comment - Werner - please look at the code attached to this issue - i have created only one resolver - this does make sense.
Hide
Werner Guttmann added a comment -

Simon, it just occured to me that the loadClassDescriptors() on the XMLClassDescriptorResolver interface will only work if you provide the .castor.cdr file with the generated classes. I am dealing with this - by adding documentation in various places - through http://jira.codehaus.org/browse/CASTOR-1913. In addition, Steven has unearthed a genuine bug in the resolveXML() area of XMLClassDescriptorResolverImpl.java, which we'll deal with in this issue.

Show
Werner Guttmann added a comment - Simon, it just occured to me that the loadClassDescriptors() on the XMLClassDescriptorResolver interface will only work if you provide the .castor.cdr file with the generated classes. I am dealing with this - by adding documentation in various places - through http://jira.codehaus.org/browse/CASTOR-1913. In addition, Steven has unearthed a genuine bug in the resolveXML() area of XMLClassDescriptorResolverImpl.java, which we'll deal with in this issue.
Hide
Werner Guttmann added a comment -

Once both issues have been fixed, everything works as expected (with no memory leaks, ...).

Show
Werner Guttmann added a comment - Once both issues have been fixed, everything works as expected (with no memory leaks, ...).
Hide
Steven Dolg added a comment -

Hi Simon,

as Werner already said you discovered a real bug.

Actually there are two conditions that lead to the behaviour you described (which I also experienced when using your test project):

  • the .castor.cdr file is missing (this contains the class names of the descriptors generated)
  • the descriptors are not located in the same package as the actual classes

The bug was obviously introduced with feature that allows to generate descriptors into their own package.
The XMLClassDescriptor was adjusted to find those descriptors as well but stores them using a wrong class name. This causes the XMLClassDescriptorResolver to load the descriptors again and again (this explains the huge number of descriptors created).

I attached a patch that fixes this bug. (Both master and regression test suite worked as before)

As an immediate solution you should include any ".castor.cdr" files generated by the source generator into the JARs you build (the Ant build file you provided doesn't do this). This will "fix" the bug as this will allow the XMLClassDescriptorResolver to "find" the generated descriptors rather than having to "search" for them.

As your test project also showed this issue is not related to multi-threading (since you use a single-threaded application which also shows this wrong behaviour).

As far as I can see it is perfectly valid to use one XMLClassDescriptorResolver for a whole application even if it is multi-threaded (given you provide the .castor.cdr file and the intialization is done before any (un)marshalling is done).

hth,
Steven

Show
Steven Dolg added a comment - Hi Simon, as Werner already said you discovered a real bug. Actually there are two conditions that lead to the behaviour you described (which I also experienced when using your test project):
  • the .castor.cdr file is missing (this contains the class names of the descriptors generated)
  • the descriptors are not located in the same package as the actual classes
The bug was obviously introduced with feature that allows to generate descriptors into their own package. The XMLClassDescriptor was adjusted to find those descriptors as well but stores them using a wrong class name. This causes the XMLClassDescriptorResolver to load the descriptors again and again (this explains the huge number of descriptors created). I attached a patch that fixes this bug. (Both master and regression test suite worked as before) As an immediate solution you should include any ".castor.cdr" files generated by the source generator into the JARs you build (the Ant build file you provided doesn't do this). This will "fix" the bug as this will allow the XMLClassDescriptorResolver to "find" the generated descriptors rather than having to "search" for them. As your test project also showed this issue is not related to multi-threading (since you use a single-threaded application which also shows this wrong behaviour). As far as I can see it is perfectly valid to use one XMLClassDescriptorResolver for a whole application even if it is multi-threaded (given you provide the .castor.cdr file and the intialization is done before any (un)marshalling is done). hth, Steven
Hide
Simon Lord added a comment -

Steven, Werner - thank you very much for fixing this, it is much appreciated

Show
Simon Lord added a comment - Steven, Werner - thank you very much for fixing this, it is much appreciated

People

Vote (0)
Watch (2)

Dates

  • Created:
    Updated:
    Resolved:

Time Tracking

Estimated:
Not Specified
Original Estimate - Not Specified
Remaining:
0m
Remaining Estimate - 0 minutes
Logged:
15m
Time Spent - 15 minutes