JPA annotations performance

[Darren S]

Hi Lukas,

I was performance testing my application and surprisingly found the JPA annotation support in jOOQ to be a pretty significant bottleneck.  The test I'm doing is essentially a significant amount of "get by id" and "update by id," a couple hundred threads in parallel.  So the SQL is super simple.  I'm looking for some guidance on what is the best route forward.  I had once asked about caching the reflection information in the default mapper and I believe you said there was some option or it wasn't cached by default.  Regardless, here's the details.

I highly recommend running Java Mission Control to reproduce this.  Its freely available and packaged by default in the latest Java 7 JDKs.  If you run it, look in the threads section for "contention."  Basically what I'm seeing is that in a 60 second sample, over 30s is waiting on a lock held while the JDK is parsing the annotations.  Because I have a high degree of concurrency on a small amount of tables (record classes) this leads to a significant amount of blocking.  Basically, everytime you list the methods of a class, you actually get a new list with new Method instances.  So when you call getAnnotation() it seems to actually parse the class bytes (or something).  Then it caches the result in the Method obj.  But if you get the method object over and over again, the caching is defeated.

I disabled JPA by just changing the code and having isJPAenabled() return false.  That sped up my application by almost 10x.  I can't actually get rid of the JPA,  I need the annotations.  But I don't need JPA for the jOOQ mapper specifically.  Specifically, I need jOOQ to generate the JPA annotations on the objects so that other programs can read the metadata, but at runtime I'm just using the generated record classes, so the JPA information is not needed by jOOQ.  So is there some option to turn on caching or do I need to implemented a custom mapping provider?

Thanks,
Darren

[Lukas Eder]

Hi Darren,

Thanks for reporting this. I'll be tracking this issue as #2955

https://github.com/jOOQ/jOOQ/issues/2955

Awesome news that Oracle now ships Mission Control with the JDK 7u40+. Just about when I was going to renew my YourKit license :-)

So let's see if I read this correctly. The only significant contention I get from the jOOQ integration tests originate from the benchmarks for the into() method:

(disregard the AbstractLifecycleListener.testMethod()). Does the above stack trace match your experience? Or is this really on the getAnnotation() calls? Could you please provide me with a screenshot from your side? Is there a way to reproduce this issue easily?

Note, if you're using the generated record classes, you may prefer using this method:

- http://www.jooq.org/javadoc/3.2.x/org/jooq/Record.html#into(org.jooq.Table)

Over this one:

- http://www.jooq.org/javadoc/3.2.x/org/jooq/Record.html#into(java.lang.Class)

If you want to implement a cache, you may need to resort to implementing your own RecordMapperProvider:

http://www.jooq.org/doc/3.2/manual/sql-execution/fetching/pojos-with-recordmapper-provider/

... and have that RecordMapperProvider manage a Map<Class<?>, DefaultRecordMapper>, which returns a previously initialised DefaultRecordMapper when the same Class key is encountered. The reason this wasn't implemented in jOOQ is because caches that use Class keys need to properly hook into ClassLoader mechanisms in order to invalidate themselves. In those discussions, we didn't come to a satisfactory solution.

Cheers

Lukas

2014/1/15 Darren S <darren.s...@gmail.com>

--
You received this message because you are subscribed to the Google Groups "jOOQ User Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to jooq-user+...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Darren Shepherd]

I've broken the environment where I tested this, so I'll probably get back to you tomorrow.  The stack trace is a bit different.  It is on the getAnnotation() call not the getMethods() call.  I'm also using jdk1.7.0_45 just incase that matters.  I'll see if there is some easy way that I can reproduce it too.

Darren

--
You received this message because you are subscribed to a topic in the Google Groups "jOOQ User Group" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/jooq-user/YpIpRVVsd5A/unsubscribe.
To unsubscribe from this group and all its topics, send an email to jooq-user+...@googlegroups.com.

[Lukas Eder]

Hi Darren,

I had tried once more and in a different Mission Control tab, I could also see that getAnnotation() is incredibly expensive. Much more than getMethods() or anything else. I'll investigate this more in-depth soon. Further head start on a sensible solution is still appreciated, though.

Cheers

Lukas

2014/1/15 Darren Shepherd <darren.s...@gmail.com>

[Darren Shepherd]

Regarding caching, using Class as the key is a problem that most loggers have.  I'm curious to see how Log4j, slf4j, jcl, etc have addressed it.  Being that there's no easily available ConcurrentWeakMap, I can see how this could be difficult.   

Darren

On Jan 16, 2014, at 11:03 AM, Lukas Eder <lukas...@gmail.com> wrote:

Hi Darren,

I had tried once more and in a different Mission Control tab, I could also see that getAnnotation() is incredibly expensive. Much more than getMethods() or anything else. I'll investigate this more in-depth soon. Further head start on a sensible solution is still appreciated, though.

Cheers

Lukas

2014/1/15 Darren Shepherd <darren.s...@gmail.com>

I've broken the environment where I tested this, so I'll probably get back to you tomorrow.  The stack trace is a bit different.  It is on the getAnnotation() call not the getMethods() call.  I'm also using jdk1.7.0_45 just incase that matters.  I'll see if there is some easy way that I can reproduce it too.

Darren

On Wed, Jan 15, 2014 at 10:41 AM, Lukas Eder <lukas...@gmail.com> wrote:

Hi Darren,

Thanks for reporting this. I'll be tracking this issue as #2955

https://github.com/jOOQ/jOOQ/issues/2955

Awesome news that Oracle now ships Mission Control with the JDK 7u40+. Just about when I was going to renew my YourKit license :-)

So let's see if I read this correctly. The only significant contention I get from the jOOQ integration tests originate from the benchmarks for the into() method:

<image.png>

[Darren Shepherd]

Now that I think about it if the caching was done in the Configuration object, not stored in some global static, then that would seem like an acceptable solution.  I can't image that in a dynamic classloader situation that you would be sharing the Configuration object such that it would cause a memory.  Or at least in that situation you give the option to disable it.

I found an IBM bug related to this, which is obviously for their J9 JVM, but it seems to indicate that java 7 introduced this slow down.  http://www-01.ibm.com/support/docview.wss?uid=swg1IV53758

Darren

[Lukas Eder]

Hi Darren,

2014/1/17 Darren Shepherd <darren.s...@gmail.com>

Now that I think about it if the caching was done in the Configuration object, not stored in some global static, then that would seem like an acceptable solution.  I can't image that in a dynamic classloader situation that you would be sharing the Configuration object such that it would cause a memory.  Or at least in that situation you give the option to disable it.

Hmm, nice thinking. In principle, the Configuration object already holds a reference to a DefaultRecordMapperProvider. It would probably be safe to implement caching of { Class, DefaultRecordMapper } pairs in there and enable it by default. DefaultRecordMapperProvider could then have a couple of overridable properties that allow for influencing caching, e.g. to turn it off, or to invalidate it. I have registered #2965 for this:

https://github.com/jOOQ/jOOQ/issues/2965

This can be implemented for jOOQ 3.3 and jOOQ 3.2.3

I guess that the last time this issue was discussed, there hadn't been such an elegant SPI yet to inject record mapping behaviour.

 

I found an IBM bug related to this, which is obviously for their J9 JVM, but it seems to indicate that java 7 introduced this slow down.  http://www-01.ibm.com/support/docview.wss?uid=swg1IV53758

Interesting find!

Cheers

Lukas

[Lukas Eder]

Hi Darren,

I'm looking at caching in DefaultRecordMapperProvider. A canonical solution would be this one here:

public class DefaultRecordMapperProvider implements RecordMapperProvider {

    private final ConcurrentHashMap<Key<?, ?>, DefaultRecordMapper<?, ?>> cache = new ConcurrentHashMap<Key<?, ?>, DefaultRecordMapper<?, ?>>();

    @SuppressWarnings("unchecked")
    @Override
    public final <R extends Record, E> RecordMapper<R, E> provide(RecordType<R> rowType, Class<? extends E> type) {
        Key<R, E> key = new Key<R, E>(rowType, type);
        DefaultRecordMapper<?, ?> mapper = cache.get(key);

        if (mapper == null) {
            mapper = new DefaultRecordMapper<R, E>(rowType, type);
            cache.put(key, mapper);
        }

        return (RecordMapper<R, E>) mapper;
    }

    private static class Key<R extends Record, E> {
        final RecordType<R> rowType;
        final Class<? extends E> type;

        Key(RecordType<R> rowType, Class<? extends E> type) {
            this.rowType = rowType;
            this.type = type;
        }

        @Override
        public int hashCode() {
            final int prime = 31;
            int result = 1;
            result = prime * result + ((rowType == null) ? 0 : rowType.hashCode());
            result = prime * result + ((type == null) ? 0 : type.hashCode());
            return result;
        }

        @Override
        public boolean equals(Object that) {
            if (this == that) return true;
            if (that == null) return false;

            Key<?, ?> other = (Key<?, ?>) that;
            if (rowType == null) {
                if (other.rowType != null)
                    return false;
            }
            else if (!rowType.equals(other.rowType))
                return false;
            if (type == null) {
                if (other.type != null)
                    return false;
            }
            else if (!type.equals(other.type))
                return false;
            return true;
        }
    }
}

It is evident that the cache object might explode as it depends on the { RecordType × Class<?> } cartesian product, where RecordType itself has an immense "possible instances" complexity of O(n!) (all the permutations of possible field combinations). A possibility would be to use a LRUCache, but that might not be generally applicable.

What is your opinion on this? Or anyone else on the group?

Lukas

2014/1/20 Lukas Eder <lukas...@gmail.com>

[Darren Shepherd]

Yeah, doesn't exactly seem ideal. But at the end of the day, we're
not exactly looking for RecordMapper caching, but instead caching of
reflection information. Would it be possible to change the annotation
utils methods, such as getAnnotatedMembers(), to accept a
Configuration object as an argument, then do something like the
following:

static final List<java.lang.reflect.Field>
getAnnotatedMembers(Configuration configuration, Class<?> type, String
name) {
if ( configuration instanceof SomeMagicalInterface ) {
((SomeMagicalInterface)configuration).getCachedStuff(type, name);
}
...
}

If we are focusing on just providing caching for reflection, it may
make sense to not specifically tie the interface and logic to the
record mapper. In fact you could just use Configuration.data(...) as
your cache.

Darren

[Lukas Eder]

Hi Darren,

2014-01-24 Darren Shepherd <darren.s...@gmail.com>

Yeah, doesn't exactly seem ideal.  But at the end of the day, we're
not exactly looking for RecordMapper caching, but instead caching of
reflection information.

The reason I mentioned this is because RecordMapper already does its own reflection information caching. But that doesn't help, of course, if RecordMapper is not reused very often.

 

Would it be possible to change the annotation
utils methods, such as getAnnotatedMembers(), to accept a
Configuration object as an argument, then do something like the
following:

    static final List<java.lang.reflect.Field>
getAnnotatedMembers(Configuration configuration, Class<?> type, String
name) {
        if ( configuration instanceof SomeMagicalInterface ) {
            ((SomeMagicalInterface)configuration).getCachedStuff(type, name);
        }
        ...
    }

If we are focusing on just providing caching for reflection, it may
make sense to not specifically tie the interface and logic to the
record mapper.  In fact you could just use Configuration.data(...) as
your cache.

That's not a bad idea at all. jOOQ currently puts all sorts of "local" flags with the "org.jooq.xxx" namespace in various copies of that map, mostly for the lifecycle of an ExecuteListener. But having a cache for arbitrary things in there is likely to work around any class loading issues that might arise with a static cache.

So essentially, the cache could globally store { org.jooq.Field, java.lang.Class } => { List<java.lang.reflect.Method>, List<java.lang.reflect.Field> }, or something similar. Sounds like a plan!

Cheers

Lukas

[Lukas Eder]

Hi Darren,

This is now fixed on GitHub master for jOOQ 3.3:

https://github.com/jOOQ/jOOQ/commit/c3d5f4d819736ce3c9f4bcc3a7cc4645dd94a5ba

I have added a new Setting to activate / deactivate this cache. The flag defaults to true in jOOQ 3.3.x and will default to false when merged onto jOOQ 3.2.4.

By adding such a cache, I have observed tremendous performance improvements both when using "mapping by jOOQ's naming conventions" (A) and "mapping by annotations" (B). For 200'000 runs of Result.into(Class) with four Records:

A: From 7.3 seconds to 0.9 seconds

B: From 134 seconds to 1.4 seconds (!)

The latter is what you have observed yourself and can be verified impressively on these Oracle Java Mission Control screenshots:

Before:

After:

As can be seen, the actual work from the map() method now makes up most of the CPU effort.

It would be awesome, of course, if you could verify these results at your side if you have time next week.

Cheers

Lukas

[Darren Shepherd]

Thanks!  This looks great.  I will definitely retest myself.  I'm under some deadlines at the moment with my $dayjob so I might not be able to evaluate it until next Friday.

Darren

On Feb 8, 2014, at 7:27 AM, Lukas Eder <lukas...@gmail.com> wrote:

Hi Darren,

This is now fixed on GitHub master for jOOQ 3.3:

https://github.com/jOOQ/jOOQ/commit/c3d5f4d819736ce3c9f4bcc3a7cc4645dd94a5ba

I have added a new Setting to activate / deactivate this cache. The flag defaults to true in jOOQ 3.3.x and will default to false when merged onto jOOQ 3.2.4.

By adding such a cache, I have observed tremendous performance improvements both when using "mapping by jOOQ's naming conventions" (A) and "mapping by annotations" (B). For 200'000 runs of Result.into(Class) with four Records:

A: From 7.3 seconds to 0.9 seconds

B: From 134 seconds to 1.4 seconds (!)

The latter is what you have observed yourself and can be verified impressively on these Oracle Java Mission Control screenshots:

Before:

<image.png>

After:

<image.png>