Some profiling numbers

[bill.burke]

Emailed this to Adrian, but I'll post here for discussion. I think the numbers are very important especially for JUnit testing I did a profile of a simple Embeddable EJB3 app. Total time to 3.8 secs without profiling, but here's the breakdown after running through JProfiler.

Downloaded JProfiler and profiled a simple standalone app with 1 Session bean and 1 Entity bean.

66 % of time in bootstrapping basic services
30% of time was taken in deploying the beans (EJB/Entity)

Interesting break downs (% are in total profile)
----------------

bootstrapping:

28.7% of time was in creating all the org.jboss.reflect objects (getTypeInfo)
15% of time was in getSchemaBinding for the MC
6.3% of time was just calling org.jboss.logging.Logger.getLogger (1 invocation)
5.7% unmarshalling all the bean.xml
12.3% in actually deploying JBoss services
7.1% in deploying the AOP XML

EJB/Entity Deployment:

20% HibernatePersistence.createEntityManagerFactory
9.8% Creating the Session Bean.

3% running the actual app.

The most glaring numbers as far as MC is concerned is the huge time in creating the reflect objects. I still think these reflect objects are useless as all they do is copy directly from java.lang.reflect objects.

The other is just loading up the schema and the creation of the Logger.

Are we stuck or is there something we can do here?

[starksm64]

This seems like a microbenchmark. Why do you think these number are significant?

[adrian.brock]

The first one is a known issue:
http://jira.jboss.com/jira/browse/JBMICROCONT-15

[adrian.brock]

Getting JBossXB to use the same reflection model/cache would also
remove some duplicate/inefficent work:

[ejort@htimes2 binding]$ grep -ri getMethod *
AbstractMarshaller.java: method = providerClass.getMethod(methodName, args);
DelegatingObjectModelFactory.java: Method[] methods = typedFactory.getClass().getMethods();
DelegatingObjectModelFactory.java: Method method = ObjectModelBuilder.getMethodForElement(typedFactory,
DelegatingObjectModelFactory.java: Method method = ObjectModelBuilder.getMethodForElement(typedFactory,
DelegatingObjectModelFactory.java: Method method = addMethods.getMethodForChild(child.getClass());
DelegatingObjectModelFactory.java: Method method = ObjectModelBuilder.getMethodForElement(typedFactory,
DelegatingObjectModelFactory.java: public Method getMethodForChild(Class child)
MappingObjectModelFactory.java: getter = o.getClass().getMethod("get" + xmlToCls, null);
MappingObjectModelFactory.java: getter = oCls.getMethod("get" + xmlToCls, null);
MappingObjectModelFactory.java: getter = parentCls.getMethod("get" + xmlToCls, null);
MappingObjectModelFactory.java: setter = parentCls.getMethod("set" + xmlToCls, new Class[]{getter.getReturnType()});
MappingObjectModelFactory.java: Method getter = oCls.getMethod("get" + xmlToCls, null);
MappingObjectModelFactory.java: setter = oCls.getMethod("set" + xmlToCls, new Class[]{getter.getReturnType()});
MappingObjectModelProvider.java: String getterStr = Util.xmlNameToGetMethodName(localName, ignoreLowLine);
MappingObjectModelProvider.java: getter = o.getClass().getMethod(getterStr, null);
MappingObjectModelProvider.java: getter = o.getClass().getMethod(booleanGetterStr, null);
metadata/unmarshalling/impl/AttributeBindingImpl.java: getter = parentClass.getMethod("get" + baseMethodName, null);
metadata/unmarshalling/impl/AttributeBindingImpl.java: setter = parentClass.getMethod("set" + baseMethodName, new Class[]{getter.getReturnType()});
metadata/unmarshalling/impl/DocumentBindingFactoryImpl.java: tmpGetter = parentType.getMethod("get" + baseMethodName, null);
metadata/unmarshalling/impl/DocumentBindingFactoryImpl.java: tmpSetter = parentType.getMethod("set" + baseMethodName, new Class[]{tmpGetter.getReturnType()});
metadata/unmarshalling/impl/DocumentBindingFactoryImpl.java: tmpGetter = parentType.getMethod("get" + baseMethodName, null);
metadata/unmarshalling/impl/DocumentBindingFactoryImpl.java: tmpSetter = parentType.getMethod("set" + baseMethodName, new Class[]{tmpGetter.getReturnType()});
metadata/unmarshalling/impl/RuntimeDocumentBinding.java: getter = parentType.getMethod("get" + baseMethodName, null);
metadata/unmarshalling/impl/RuntimeDocumentBinding.java: setter = parentType.getMethod("set" + baseMethodName, new Class[]{getter.getReturnType()});
metadata/unmarshalling/impl/XsdBinder.java: getter = parentType.getMethod("get" + elBasedClsName, null);
metadata/unmarshalling/impl/XsdBinder.java: setter = parentType.getMethod("set" + elBasedClsName, new Class[]{getter.getReturnType()});
metadata/marshalling/ObjectModelBindingFactory.java: getter = ownerClass.getMethod(getterName, null);
metadata/AddMethodMetaData.java: public String getMethodName()
ObjectModelBuilder.java: static Method getMethodForElement(Object factory, String name, Class[] params)
ObjectModelBuilder.java: method = factory.getClass().getMethod(name, params);
SchemalessMarshaller.java: Method[] methods = aClass.getMethods();
SchemalessObjectModelFactory.java: Method getter = parent.getClass().getMethod("get" + localName, null);
sunday/unmarshalling/impl/runtime/RtElementHandler.java: Util.xmlNameToGetMethodName(elementName.getLocalPart(), term.getSchema().isIgnoreLowLine()) :
sunday/unmarshalling/impl/runtime/RtElementHandler.java: Method getter = parentClass.getMethod(getterName, null);
sunday/unmarshalling/impl/runtime/RtElementHandler.java: getValueMethod = o.getClass().getMethod(getValueMethodName, null);
sunday/unmarshalling/impl/runtime/RtElementHandler.java: o.getClass().getMethod(setValueMethodName, new Class[]{getValueMethod.getReturnType()});
sunday/unmarshalling/impl/runtime/RtElementHandler.java: private static Method getSetMethod(Class cls, String getMethodName, String setMethodName)
sunday/unmarshalling/impl/runtime/RtElementHandler.java: getKeyMethod = cls.getMethod(getMethodName, null);
sunday/unmarshalling/impl/runtime/RtElementHandler.java: throw new JBossXBRuntimeException("Method " + getMethodName + " not found in " + cls);
sunday/unmarshalling/impl/runtime/RtElementHandler.java: setKeyMethod = cls.getMethod(setMethodName, new Class[]{getKeyMethod.getReturnType()});
sunday/unmarshalling/impl/runtime/RtElementHandler.java: addMethodMetaData.getMethodName() +
sunday/unmarshalling/impl/runtime/RtElementHandler.java: addMethodMetaData.getMethodName() +
sunday/unmarshalling/impl/runtime/RtElementHandler.java: addMethod = ownerClass.getMethod(addMethodMetaData.getMethodName(), new Class[]{valueType});
sunday/unmarshalling/impl/runtime/RtElementHandler.java: addMethodMetaData.getMethodName() +
sunday/unmarshalling/impl/runtime/RtElementHandler.java: addMethodMetaData.getMethodName() +
sunday/unmarshalling/impl/runtime/RtElementHandler.java: keyMethod = oClass.getMethod(getKeyMethodName, null);
sunday/unmarshalling/impl/runtime/RtElementHandler.java: putMethod = ownerClass.getMethod(putMethodName, new Class[]{keyType, valueType});
sunday/unmarshalling/impl/runtime/RtElementHandler.java: valueMethod = oClass.getMethod(valueMethodName, null);
sunday/unmarshalling/impl/runtime/RtUtil.java: getter = cls.getMethod("get" + methodBase, null);
sunday/unmarshalling/impl/runtime/RtUtil.java: getter = cls.getMethod("is" + methodBase, null);
sunday/unmarshalling/impl/runtime/RtUtil.java: setter = cls.getMethod("set" + methodBase, new Class[]{fieldType});
sunday/unmarshalling/impl/runtime/RtUtil.java: Method getter = cls.getMethod("get" + methodBase, null);
sunday/unmarshalling/impl/runtime/RtUtil.java: setter = cls.getMethod("set" + methodBase, new Class[]{getter.getReturnType()});
sunday/unmarshalling/impl/runtime/RtCharactersHandler.java: method = cls.getMethod(methodName, new Class[]{String.class, NamespaceContext.class});
sunday/unmarshalling/XsdBinder.java: addMethodMetaData.getMethodName() + ", valueType=" + addMethodMetaData.getValueType()
sunday/unmarshalling/XsdBinder.java: addMethodMetaData.getMethodName() +
Util.java: public static String xmlNameToGetMethodName(String name, boolean ignoreLowLine)

[adrian.brock]

Load reflection model on demand? Think that would help?

Yes, that is what we discussed before in some AOP thread.
It should load the reflection objects lazily on demand.

In a similar discussion on the dev-list I also said that everybody creating
their own reflection cache is both a waste of time and memory.
e.g. How many places do you think store primitive -> primitive.class
in the codebase?

[bill.burke]

This seems like a microbenchmark. Why do you think these number are significant?

I don't think these are insignificant. One of the things we're pushing is that EJB3 can be unit tested. My little program I benched took 3.8 seconds to run of which 97% was bootstrapping.

[bill.burke]

Load reflection model on demand? Think that would help?

Yes, that is what we discussed before in some AOP thread.
It should load the reflection objects lazily on demand.

In a similar discussion on the dev-list I also said that everybody creating
their own reflection cache is both a waste of time and memory.
e.g. How many places do you think store primitive -> primitive.class
in the codebase?

I still don't like the idea of writing wrappers around metadata that already exists in the VM, but maybe a cache and lazy loading will do the trick.

[adrian.brock]

If the VM did it itself, there wouldn't be a problem (and caching reflection objects wouldn't
produce the performance gain that we see).

[adrian.brock]

If the VM did it itself, there wouldn't be a problem (and caching reflection objects wouldn't
produce the performance gain that we see).

But that's still no excuse for a crappy implementation that ends up caching
all possibly reachable reflection objects :-)

[adrian.brock]

I've done a simple fix that stops it leaking across the entire space
via class references. This still needs completing for other objects, but I doubt that
will have the same impact.

[adrian.brock]

This might also reduce the Logger.getLogger() calls as it will statically initializing
less classes?

[aloubyansky]

Getting JBossXB to use the same reflection model/cache would also
remove some duplicate/inefficent work

Definitely, reflection and introspection is used in a heavy and dirty way there.