Search code examples
jsongrailsmarshalling

Grails JSON marhsaling using introspection causes severe bottleneck on Classloader.loadClass()


I am using Grails 2.2.4 and have a controller endpoint which converts a domain object list to JSON. Under load (as little as 5 concurrent requests) the marshaling performance is very poor. Taking thread dumps the threads are blocked on:

java.lang.ClassLoader.loadClass(ClassLoader.java:291)

There is a single marhsaler registered to marshal all domain objects using reflection and introspection. Realizing that reflection and introspection is slower than direct method calls, I am still seeing unexpected behavior in that the class loader is caller every time and in turn blocking occurs. An example stacktrace is as follows:

java.lang.Thread.State: BLOCKED (on object monitor)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:291)
    - waiting to lock <785e31830> (a org.grails.plugins.tomcat.ParentDelegatingClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
    at java.beans.Introspector.instantiate(Introspector.java:1470)
    at java.beans.Introspector.findExplicitBeanInfo(Introspector.java:431)
    at java.beans.Introspector.<init>(Introspector.java:380)
    at java.beans.Introspector.getBeanInfo(Introspector.java:167)
    at java.beans.Introspector.getBeanInfo(Introspector.java:230)
    at java.beans.Introspector.<init>(Introspector.java:389)
    at java.beans.Introspector.getBeanInfo(Introspector.java:167)
    at java.beans.Introspector.getBeanInfo(Introspector.java:230)
    at java.beans.Introspector.<init>(Introspector.java:389)
    at java.beans.Introspector.getBeanInfo(Introspector.java:167)
    at java.beans.Introspector.getBeanInfo(Introspector.java:230)
    at java.beans.Introspector.<init>(Introspector.java:389)
    at java.beans.Introspector.getBeanInfo(Introspector.java:167)
    at org.springframework.beans.CachedIntrospectionResults.<init>(CachedIntrospectionResults.java:217)
    at org.springframework.beans.CachedIntrospectionResults.forClass(CachedIntrospectionResults.java:149)
    at org.springframework.beans.BeanWrapperImpl.getCachedIntrospectionResults(BeanWrapperImpl.java:324)
    at org.springframework.beans.BeanWrapperImpl.getPropertyValue(BeanWrapperImpl.java:727)
    at org.springframework.beans.BeanWrapperImpl.getPropertyValue(BeanWrapperImpl.java:721)
    at org.springframework.beans.PropertyAccessor$getPropertyValue.call(Unknown Source)
    at com.ngs.id.RestDomainClassMarshaller.extractValue(RestDomainClassMarshaller.groovy:203)
...
...

A simple benchmark loading the same endpoint with the same parameters results in the loadClass call.

I was under the impression the classes would be at least cached by the class loader and not loaded on every method call to get the property to be marshaled.

The code to retrieve the property value is as follows:

BeanWrapper beanWrapper = PropertyAccessorFactory.forBeanPropertyAccess(domainObject);
return beanWrapper.getPropertyValue(property.getName());

Is there a configuration setting that is needed to ensure the classes are only loaded once? or perhaps a different way to get the property that doesn't result in class loading every time? Or perhaps a more performant way to achieve this?

Writing a custom marshaler per domain class would avoid the reflection and introspection but is going to be a lot of repeat code.

Appreciate any input.


Solution

  • So after much digging this is what I found out.

    Using the BeanUtils.getPropertyDescriptors and getValue will always try and find a BeanInfo class describing the bean using the class loader. In this case we don't provide BeanInfo classes for our grails domain classes so this call is redundant. I found some information where you can provide a custom BeanInfoFactory to bypass this and exclude your packages but I couldn't find how to configure it with Grails.

    Also searching the springframework documentation there is a configuration option you can pass Introspector.IGNORE_ALL_BEANINFO that will tell CachedIntorspectionResults to never look up the bean classes. However this was not available in version 3.1.4 of springframework which was current for grails 2.2.4. The newer versions do appear to have this option.

    So, if using BeanUtils you can't by pass this initial lookup on the class loader. However subsequent loaders should be cached by CachedIntrospectionResults. Unfortunately this doesn't happen in our scenario. There looks to be a bug in the test to see if the lookup is cacheable. See more info on this below.

    The fix was ultimately to fall back to use pure reflection. Rather than use:

    beanWrapper.getPropertyValue(property.getName());
    

    To use:

    PropertyDescription pd = BeanUtils.getPropertyDescriptor(domainObject.getClass(), property.getName())
    pd.readMethod.invoke(domainObject)
    

    Where the pd is cached.

    After fixing this the profiler still showed a lack of caching on CachedIntorspectionResults for the out of the box grails marshaller. This was due to the bad caching implementation in CachedIntrospectionResults. The work around for this was to add the correct class loader to the acceptedClassLoaders in the CachedIntrospectionResults.

    public class EnhanceCachedIntrospectionResultsAcceptedClassLoadersListener implements ServletContextListener {
    
        public void contextInitialized(ServletContextEvent event) {
            CachedIntrospectionResults.acceptClassLoader(Thread.currentThread().getContextClassLoader().getParent());
        }
    
        public void contextDestroyed(ServletContextEvent event) {
            CachedIntrospectionResults.clearClassLoader(Thread.currentThread().getContextClassLoader().getParent());
            Introspector.flushCaches();
        }
    }
    

    Note that it was required to add the parent to the accepted class loader list rather than the current class loader. Not sure if this is specific to grails or not but this fixed the issue. I'm not sure if there may be a side effect to this fix.

    In summary we went from 10 requests/sec in the original setup to 120 requests/sec after using direct reflection and fixing the CachedIntrospectionResults cache.

    However the real eye opened was that if we use a 1-1 marshaller per domain class we were seeing another x2 improvement in performance over the generic marshaller where we test objects for whether they're instances of class etc. We're saving a lot of code with the generic marshaller but there's a lot more work to do to get comparable performance to writing a 1-1 marshaller.

    Hopefully this will be useful to someone else who runs into this ...