Hibernate queries slow down drastically after an entity is loaded in the session

Question

I'm using Hibernate EntityManager, and am experiencing a weird slowdown in my Hibernate queries. Take a look at this code:

public void testQuerySpeed() {
    for(int i = 0; i < 1000; i++) {
        em.createNativeQuery("SELECT 1").getResultList();
    }
}

This runs in about 750ms on my machine. Not blazing fast considering it's just selecting a constant integer, but acceptable. My problem arises the moment ANY entities are loaded in my EntityManager session before I launch my query:

public void testQuerySpeed() {
    CommercialContact contact = em.find(CommercialContact.class, 1890871l);

    for(int i = 0; i < 1000; i++) {
        em.createNativeQuery("SELECT 1").getSingleResult();
    }
}

The em.find() is fast, but the runtime 1000 queries increased more than ten-fold, to about 10 seconds. If I put an em.clear() after the em.find(), the problem goes away again and runtime goes back to 750ms.

I've used a native query here, but the problem exists with HQL queries as well. It seems ALL queries take at least 70ms whenever an entity is in the EntityManager session.

This performance drop is really hurting us when generating lists where n+1 queries are needed.

I've tested the latest Hibernate 3.5 beta, and have the exact same problem. Has anyone seen this problem, or any ideas on how to fix it?

I'm using PostgreSQL 8.3, using resource local transactions (running in Tomcat). Using the built-in connection pool, but using C3P0 made no difference.

Answer 1

I also have to recommend using a JVM profiler to look at where the time is going. It also may not hurt to turn on the SQL statement logging for the Hibernate Session just to make sure that you're not running more SQL than you think you are.

The thing that first comes to mind here is the "flushing" behavior of the Hibernate Session. Do you explicitly set a specific flush mode on the Session? If not, then you get "auto" flushing which will do some amount of checking the objects you have in your session to determine whether or not there are changes in memory that need to be "flushed" back to the database (inside of a transaction, of course).

I guess the easiest thing to try first to see if it has any effect is to modify the test code you showed above to specify that you want flushing to occur manually when you commit your database transaction:

public void testQuerySpeed() {
 em.setFlushMode(FlushModeType.COMMIT); // assuming you're using JPA annotations
 CommercialContact contact = em.find(CommercialContact.class, 1890871l);

 for(int i = 0; i < 1000; i++) {
  em.createNativeQuery("SELECT 1").getSingleResult();
 }
}

Another thought I suppose would be to ask whether or not you can perform your bulk tasks in a separate EntityManager, which could work if you're just doing UPDATEs or INSERTs.

Answer 2

Your executing a native query which is not saying anything about what it will be touching and thus Hibernate will have to (for consistency sake) flush() against all data from all tables it knows about (and your single find() might have fetched more than just one object so it might not be a trivial operation).

To optimize this make sure that you use the SQLQuery.add* methods to define what the query is actually doing. In this case query.addSynchronizedQuerySpace("bogustablename") should do the trick about telling Hibernate that this query is just scalar data from no specific table.

Answer 3

I had essentially the same problem (query inside a loop). I proceeded a profiling verification with JProfiler...the execution of my interested method spent 572 seconds and hibernate dirty-checking takes 457 seconds of this time (about 80%). Amazing, isn't it? I must say that I had a lot of entities managed by EntityManager. If I introduce em.flush()/em.clear() or em.setFlushMode(FlushModeType.COMMIT) in the offending code, the performance problem goes away.

profiler result is available at http://img1.imagilive.com/0110/hibernate_dirty_checking_bad_perfomances0ce.png