JBoss Reflect Performance Javassist vs Introspection

[kabirkhan]

I have created a simple benchmark where I test the performance of different things using the different implementations. It can be found at https://svn.jboss.org/repos/jbossas/projects/jboss-reflect/trunk/src/test/java/org/jboss/test/benchmark/AccessorBenchmark.java

It first generates 100 classes, each with 100 fields and 100 methods, then it:

• A) Obtains a ClassInfo for each class
• B) Goes through each class and calls getDeclaredField() and getDeclaredMethod() for each field/method. This is done 50 times
• C) Calls FieldInfo.get/set and MethodInfo.get/set once for each field/method
• D) Same as C, but now it happens 50 times

Here are the times:

========== IntrospectionTypeInfoFactory

A - Creating 100 ClassInfos 141ms

B - Getting 100 fields and methods for 100 classes 50 times 1446ms

C - First accessing 100 fields and methods for 100 classes 50 times 116ms

D - Accessing 100 fields and methods for 100 classes 50 times 3545ms

Done!

========== JavassistTypeInfoFactory

A - Creating 100 ClassInfos 164ms

B - Getting 100 fields and methods for 100 classes 50 times 820ms

C - First accessing 100 fields and methods for 100 classes 50 times 4557ms

D - Accessing 100 fields and methods for 100 classes 50 times 272ms

Done!

• Creating the ClassInfos (A) takes about the same time with the two implementations.
• Calling getDeclaredMethod()/-Field() (B) is about twice as fast using Javassist as introspection.
• The first time a joinpoint is invoked is very slow with Javassist (due to generating the class), while subsequent calls are very fast

I'll profile C to see if it can be made faster somehow. Although, 20,000 classes are created so my guess is that creating an output stream for the class bytes for each class and then it with the classloader is the real overhead

[kabirkhan]

I've tried starting AS with the two implementations, and the overhead of creating accessor classes means javassist is slower.

Javassist: ~24.5s

Introspection: ~21s

I need to profile this, but think this is because when configuring beans, we normally only set properties once, so we get the overhead of creating the class, but not the benefit of invoking it lots of times.

I will ask Chiba if there is anything that can be done to JavassistMembersFactory to make this faster.

[kabirkhan]

What we generate is effectively something along the lines of

public class JavassistMethod1 implements JavassistMethod
{
   public Object invoke(Object target, Object[] args) throws Throwable
   {
      if (target == null)
         throw new IllegalArgumentException("Null target");
      if (target instanceof SomeClass == false)
         throw new IllegalArgumentException("Wrong target");
      
      if (args == null || args.length != 10) 
         throw new IllegalArgumentException("Wrong number of parameters");
      
      if (args[0] == null) 
         throw new IllegalArgumentException("Parameter 1 cannot be null for SomeClass.someMethod(long, String)");
      if (args[0] != null && args[0] instanceof Long == false) 
         throw new IllegalArgumentException("Parameter 1 is not an instance of Long for SomeClass.someMethod(long, String)");
      
      if (args[1] != null && args[1] instanceof String == false) 
         throw new IllegalArgumentException("Parameter 2 is not an instance of String for SomeClass.someMethod(long, String)");
      
      return ((SomeClass)target).someMethod(((Long)args[0]).longValue(), (String)args[1]);      
   }
}

Disabling the parameter checking so we end up with this instead reduces the time spent in C from about 4.8s to 3.8s

public class JavassistMethod1 implements JavassistMethod
{
   public Object invoke(Object target, Object[] args) throws Throwable
   {
      return ((SomeClass)target).someMethod(((Long)args[0]).longValue(), (String)args[1]);      
   }
} 

Profiling this, for each JavassistMethod implementation the time taken is roughly

50% generating the bytecode for the method

30% Converting the bytecode to a byte array and creating the class

13% creating the constructor

6% setting the interfaces

Maybe a better approach would be

1) to do the parameter checking in Javassist[Constructor/Method/Field]Info itself

2) to generate less classes? Something like:

public class SomeBeanAccessor implements JavassistBeanAccessor
{
    public Object newInstance(int index, Object[] args) throws Throwable
    {
       if (index == 0)
          return new SomeClass((String)args[0]);
       else if (index == 1)
          return new SomeClass((String)args[1]);

       return null;
    }

    public Object invoke(long hash, Object target, Object[] args) throws Throwable
    {
        if (hash == 121267912)
      return ((SomeClass)target).someMethod(((Long)args[0]).longValue(), (String)args[1]);
    if (hash == 128172981)
      return ((SomeClass)target).otherMethod(((Long)args[0]).longValue(), (String)args[1], (String)args[2]);
   }

   public Object get(String name, Object target) throws Throwable
   {
      if (name.equals("intField")
          return Integer.valueOf(((SomeClass)target).intField);
      if (name.equals("stringField")
          return ((SomeClass)target).stringField;
   }

   public void set(String name, Object target, Object value) throws Throwable
   {
      if (name.equals("intField")
          ((SomeClass)target).intField = ((Integer)value).intValue();
          return;
      if (name.equals("stringField")
          ((SomeClass)target).stringField = (String)value;
   }
}

First call by Javassist[Constructor/Method/Field]Info to access the member would result in this being created for ALL members, and cached in JavassistTypeInfo.

[kabirkhan]

I have done some performance measurements where I compare the times taken creating the following class, using javassist.bytecode.* and asm

public class JavassistMethod1 implements JavassistMethod
{ 
  public Object invoke(Object target, Object[] args) throws Throwable
  {     
      return Integer.valueOf(((SomeClass)target).someMethod(((Integer)args[0]).intValue(), (String)args[1])).intValue();
  }
} 

Which would be used to call the method:

    int someMethod(int i, String);

The basic flow for what I do for both approaches is the same, whereby I do the following lots of times to generate lots of similar classes:

A) - Create class structure

B) - Add default constructor with body to call super

C) - Add invoke method

C1) - Add invoke method body

D) - Convert class structure from A) into byte[]

E) - Define java.lang.Class by calling ClassLoader.defineClass()

F) - Call Class.newInstance()

1 - Average times (ms) to do A-F is:

Classes	ASM	Javassist	ASM/Javassist
10000	1079	1585	.68
15000	1550	2153	.72
20000	1901	2665	.71

2 - Taking the instantiation out of the equation, so we just do A-E:

Classes	ASM	Javassist	ASM/Javassist
20000	1290	1998	.64

3 - Not loading the class, so we do A-D:

Classes	ASM	Javassist	ASM/Javassist
20000	391	1115	.35
40000	499	1489	.34

4 - Just doing A-C shows that javassist has a massive overhead in step D:

Classes	ASM	Javsssist	ASM/Javassist
40000	524	747	.71
100000	823	1244	.66

5 - Doing A-C with a simplified method body in C1 so it is just the equivalent of {return null;}:

Classes	ASM	Javassist	ASM/Javassist
40000	494	617	.80
100000	723	923	.78

6 - If I don't create the method in C at all, so I just do A-B

Classes	ASM	Javassist	ASM/Javassist
40000	449	589	.76
100000	619	845	.73

So unfortunately Javassist is slower than ASM when it comes to creating new classes. Both at generating the bytecode, and a lot slower at converting the javassist.bytecode.ClassFile to a byte[].

The other overhead in this, as mentioned in a previous post, is the actual loading and instantiation of the classes themselves. So, I think generating less classes that do more stuff is the way forward, although that means a bigger overhead in creating the methods which will be bigger. I will play with creating an asm version of that.

[kabirkhan]

Kabir Khan wrote:

I will play with creating an asm version of that.

BTW this is only to get something up and running sometime soon, we probably should put some work into seeing what can be done to improve ClassFile.write(), and go with that in the longer term?

[kabirkhan]

I've attached the classes I put together for measuring this. I think I included everything needed to make them run, let me know if you have any problems. I used asm 3.2.

I haven't looked too deeply into why the performance is different, but I think it is due to how Bytecode and ConstPool make use of ByteVector and LongVector while their asm counterparts seem to modify the byte array directly. Javassist, on the other hand, needs to convert those to create the byte arrays. I have not done any measurements of this, but I guess with things the way they are that once the class bytes are parsed that javassist would be faster for calling things like getMethod() etc.?

The reason why this becomes important is that this is something that gets called huge numbers of times. However, there are other problems with this approach of generating accessors with bytecode, which means I am not 100% sure we should go with this approach. This is that we end up with:

• having to load a lot of extra classes which takes a lot of time and fills up PermGenSpace
• a lot of instances (although the number of instances probably holds true when we just use java.lang.reflect.Method instead)

My idea of creating bigger accessors isn't that viable either. If you have a class that has 300 members, but only 30 of those are used with the original method you end up with 30 small classes. With the "bigger accessor" idea, you end up with only one class, but with the code to access all 300 members, so that is a waste of memory.

If an accessor is called a lot of times it makes sense to generate a class for it. However, if it is called only a few times, then generating and loading a class for it will be slower due to having to load the class.

The main use-cases I know of are:

• Configuring the properties of the MC beans. For most bean classes I think each property is only installed once. However, in other cases, e.g. the properties of the beans for the AOP metadata + the beans installed by EJB 3 probably get accessed a lot of times, so for these it would make sense to generate classes.
• JBossXB parsing. It is used for parsing the schema, which only happens once, but when parsing the xml files, I think the accessors are used a lot.

I think we need some kind of differentiator, so that for accessors that only get called a few times we just go with norrnal reflection, but for heavily used accessors we go with generating the classes. I'll try to come up with some numbers for how many times we need to access the member for generating the class to be the cheapest option.

The question is what differentiator to use? A few ideas:

• Keep a counter in Javassist[Method/Field/Constructor]Info and once it has been called several times switch to the generated class. The problem with this is, what if this counter kicks in and we end up generating the class and then we don't have enough subsequent accesses to reap the performance benefits, i.e. in this case it would slow it down.
• Use some annotation to say that for a particular class we should always use generated members. If this annotation comes from MC BeanMetaData it could be put into the TypeInfo attachments.

I will build some statistics into JavassistConstructorInfo.newInstance(), JavassistMethodInfo.invoke() etc. so it is possible to get a report of the type of accessor used and the number of calls to help with being able to tune it using annotations unless somebody has some different ideas.

[flavia.rainone]

Kabir Khan wrote:

The question is what differentiator to use? A few ideas:

• Keep a counter in Javassist[Method/Field/Constructor]Info and once it has been called several times switch to the generated class. The problem with this is, what if this counter kicks in and we end up generating the class and then we don't have enough subsequent accesses to reap the performance benefits, i.e. in this case it would slow it down.
• Use some annotation to say that for a particular class we should always use generated members. If this annotation comes from MC BeanMetaData it could be put into the TypeInfo attachments.

I vote for using a combination of those two diferentiators.

[kabirkhan]

To summarize, the steps I want to take here are:

1) Decide if we should bother to do parameter checking. If we decide to keep it, it should be done by Javassist[Method/Constructor/Field]Info and not in the generated JavassistMethod/-Constructor/-Field implementations. This can easily be turned off in the generated classes by passing in check=false to the JavassistMemberFactory create methods.

2) Enable stats for the JavassistMethodInfo.invoke(), JavassistConstructorInfo.newInstance() and JavassistFieldInfo.get()/set() so we can run AS with that and get an idea of the usage of these joinpoints.

3) Avoid creating too many JavassistMethod/-Constructor/-Field implementations. There is an overhead associated with creating these, both in terms of filling up PermGenSpace and in CPU time since each member that gets one of these needs to first generate the class and then to call ClassLoader.defineClass() which takes time. JavassistMethod/-Constructor/-Field should only be generated for Javassist[Method/Constructor/Field]Infos whose invoke()/newInstance()/get()/set() are called a lot. The data from 2) should give us some understanding of which members they are. Javassist[Method/Constructor/Field]Infos which are NOT called a lot should simply use reflection to call the target member. I think reflection should be the default.

4) Come up with some differentiator (as mentioned earlier) to be able to specify if a member should have JavassistMethod/-Constructor/-Field generated or not.

5) Let's stay with Javassist for now, and go with asm if javassist can not be improved upon in the time allowed. Creating yesterday's benchmark, I found as long as you have got the hang of one it is quite easy to look at the other.

I will start off by doing some work on 2) and let you know how far I get with the others before Tuesday

[kabirkhan]

Kabir Khan wrote:

Here are the times:

========== IntrospectionTypeInfoFactory

A - Creating 100 ClassInfos 141ms

B - Getting 100 fields and methods for 100 classes 50 times 1446ms

C - First accessing 100 fields and methods for 100 classes 50 times 116ms

D - Accessing 100 fields and methods for 100 classes 50 times 3545ms

Done!

========== JavassistTypeInfoFactory

A - Creating 100 ClassInfos 164ms

B - Getting 100 fields and methods for 100 classes 50 times 820ms

C - First accessing 100 fields and methods for 100 classes 50 times 4557ms

D - Accessing 100 fields and methods for 100 classes 50 times 272ms

Done!

The output here is a bit misleading. C only accesses the members once, not 50 in order to determine the overhead of creating the JavassistMethod/-Constructor/-Field classes. I've updated the benchmark in svn to read:

========== IntrospectionTypeInfoFactory

A - Creating 100 ClassInfos 141ms

B - Getting 100 fields and methods for 100 classes 50 times 1446ms

C - First accessing 100 fields and methods for 100 classes 116ms

D - Accessing 100 fields and methods for 100 classes 50 times 3545ms

Done!

========== JavassistTypeInfoFactory

A - Creating 100 ClassInfos 164ms

B - Getting 100 fields and methods for 100 classes 50 times 820ms

C - First accessing 100 fields and methods for 100 classes 4557ms

D - Accessing 100 fields and methods for 100 classes 50 times 272ms

Done!

[kabirkhan]

Kabir Khan wrote:

...

2) Enable stats for the JavassistMethodInfo.invoke(), JavassistConstructorInfo.newInstance() and JavassistFieldInfo.get()/set() so we can run AS with that and get an idea of the usage of these joinpoints.

...

4) Come up with some differentiator (as mentioned earlier) to be able to specify if a member should have JavassistMethod/-Constructor/-Field generated or not.

...

Maybe Ales's scanning thingy could somehow integrate with these two points to automagically record annotations for the members in question? I didn't get every detail of what he said on the call, but if this indexed information is pushed into the jars, it should survive AS reboots.

[kabirkhan]

I have implemented a first attempt at my five points above, but am still getting longer AS startup times with the javassist-based implementation of jboss-reflect than the introspection one.

I have added the possibility to record metrics of the invocation count and the invocation time, and an MBean to get hold of the results which look like this:

Invocations (total time in ms) - Member name
============================================
1473 (0) - org.jboss.metadata.javaee.support.NamedMetaData.setName(Ljava/lang/String;)V - {G}
1281 (0) - org.jboss.metadata.web.spec.AttributeMetaData()V - {G}
1219 (0) - org.jboss.metadata.web.spec.AttributeMetaData.setRequired(Ljava/lang/String;)V - {G}
1132 (0) - org.jboss.metadata.javaee.spec.DescriptionImpl()V - {G}
1132 (3) - org.jboss.metadata.javaee.spec.DescriptionImpl.setDescription(Ljava/lang/String;)V - {G}
1127 (2) - org.jboss.metadata.javaee.spec.DescriptionsImpl()V - {G}
988 (0) - org.jboss.metadata.javaee.support.NamedMetaDataWithDescriptions.getDescriptions()Lorg/jboss/annotation/javaee/Descriptions; - {G}
988 (0) - org.jboss.metadata.javaee.support.NamedMetaDataWithDescriptions.setDescriptions(Lorg/jboss/annotation/javaee/Descriptions;)V - {G}
...

The time is not accurate, a lot of the invocations have a long "inherent time" such as org.hornetq.jms.server.impl.JMSServerManagerImpl.start(), and for simple setters the time is too short to be picked up. Anyway, the invocation count gives some idea of what is going on. I noticed that the bean metadata classes don't appear in this list, which is a bit strange so I need to figure out why that is.

By default, to avoid the overhead of generating classes for accessors that will not be used a lot, it is now set up to simply do what the introspection implementation does by default, which is to just invoke the members by reflection. The {G} and {R} after the member name indicates whether the accessor was generated or uses reflection. For frequently used accessors, I currently have a file called forceGenerate.txt in the bin/ folder of AS where you can specify which accessors should use a generated class:

org.jboss.metadata.javaee.support.NamedMetaData.setName(Ljava/lang/String;)V
org.jboss.metadata.web.spec.AttributeMetaData()V
org.jboss.metadata.web.spec.AttributeMetaData.setRequired(Ljava/lang/String;)V
org.jboss.metadata.javaee.spec.DescriptionImpl()V
org.jboss.metadata.javaee.spec.DescriptionImpl.setDescription(Ljava/lang/String;)V
org.jboss.metadata.javaee.spec.DescriptionsImpl()V
org.jboss.metadata.javaee.support.NamedMetaDataWithDescriptions.getDescriptions()Lorg/jboss/annotation/javaee/Descriptions;
org.jboss.metadata.javaee.support.NamedMetaDataWithDescriptions.setDescriptions(Lorg/jboss/annotation/javaee/Descriptions;)V
org.jboss.metadata.web.spec.TagMetaData.getAttributes()Ljava/util/List;
org.jboss.metadata.web.spec.DeferredValueMetaData()V
org.jboss.metadata.web.spec.AttributeMetaData.setDeferredValue(Lorg/jboss/metadata/web/spec/DeferredValueMetaData;)V
org.jboss.metadata.web.spec.DeferredValueMetaData.setType(Ljava/lang/String;)V
org.jboss.metadata.web.spec.AttributeMetaData.setRtexprvalue(Ljava/lang/String;)V

Doing this for the top 10 used accessors improves the startup time very slightly, but it is still a lot slower than when using the introspection implementation. This leads me to thinking that something in this alternative implementation is playing a bigger part in slowing this down than the accessors. It could be something in the classpools, or maybe some inefficiencies in JavassistTypeInfo and related classes. I'll work on creating some benchmarks that can be run in AS and profile those to get a better idea of what is going on.

[kabirkhan]

I've written an in-AS benchmark which I'll run tomorrow to gather some more information about overheads of creating ClassInfos, looking up methods etc. What I had time to look at so far shows the Javassist implementation to be ~50x slower at obtaining the ClassInfos that the reflect one.

In the meantime, looking into why the BeanMetaData classes don't appear in the statistics, I found this:

   protected TypeInfo get(String name, ClassLoader cl, Class<?> clazz) throws ClassNotFoundException
   {
      if (name == null)
         throw new IllegalArgumentException("Null name");
      if (cl == null)
         throw new IllegalArgumentException("Null classloader");

      try
      {
         CtClass ctClass = poolFactory.getPoolForLoader(cl).get(name);
         return get(ctClass, clazz, cl);
      }
      catch(NotFoundException nfe)
      {
         return delegateToIntrospectionImplementation(cl, name); //End up here for a lot of the bootstrap classes
      }
   }

The above code was written to handle gets for generated proxy classes which will not appear in a classpool. As we know, creating Exceptions is very expensive, and could be at least part of the reason why the javassist implementation performs worse.

The problem seems to be that in the bootstrap DefaultClassPoolFactory is used until it gets replaced by the real one. Flavia, is there a way to get the real ClassPoolFactory to kick in earlier?

[alesj]

The problem seems to be that in the bootstrap DefaultClassPoolFactory is used until it gets replaced by the real one. Flavia, is there a way to get the real ClassPoolFactory to kick in earlier?

We could/should apply this as early as possible in AS -- perhaps even in Main::boot?

[flavia.rainone]

Kabir Khan wrote:

The problem seems to be that in the bootstrap DefaultClassPoolFactory is used until it gets replaced by the real one. Flavia, is there a way to get the real ClassPoolFactory to kick in earlier?

The correct classpool factory kicks in just allright in the JBoss AOP integration. What exactly is being performed before the correct ClassPool Factory is set up?

Taking a look at your implementation, I see that you created in jboss-kernel a ClassPoolFactoryImpl with support to installation and uninstallation of ClassLoaders. By doing this, as far as I can tell, you created a mechanism that is already present in the integration (take a look at the usage of RegisterModuleCallback in aop.xml).

I mean, with things set up the way they are, I thought we had all that we needed to use JBoss Reflection over Javassist with the new pools:

- there is a part that is in aop.xml that concerns ClassPools. I thought of moving this stuff to a new separate file when we integrated JBoss Reflection + Javassist with MC (mainly RegisterModuleCallback stuff)

- in JBoss Reflection, there is a RepositoryClassPoolFactory class, which is the classpoolfactory intended for usage with jboss-classpool. You only need to set it as the classpoolfactory in JavassistTypeInfoFactory and set org.jboss.classpool.spi.ClassPoolRepository as the repository in RepositoryClassPoolFactory:

RepositoryClassPoolFactory cpFactory = new RepositoryClassPoolFactory(ClassPoolRepository.getInstance());
JavassistTypeInfoFactory.setClassPoolFactory(cpFactory);

I thought this would also be configured in this xml file that would contain stuff extracted from aop.xml

So, why do you need ClassPoolFactoryImpl? If you need it for integration, maybe we should get rid of RepositoryClassPoolFactory and put it in its place instead, as RepositoryClassPoolFactory would become useless.

[kabirkhan]

The factories I created are just for unit testing, mocking the behaviour of the real one.

Anyway, I see now that DefaultClassPoolFactory is always used. It seems that the default classpool has reference to the classloader loading up /server/default/conf/bindingservice.beans which is part of the default domain which explains why the default domain ClassPool is able to load up the classes.

I will try using RepositoryClassPoolFactory instead and modify AS startup as required.