Why does query caching with Hibernate make the query ten times slower?

Question

I'm currently experimenting with EJB3 as a prestudy for a major project at work. One of the things I'm looking into is query caching.

I've made a very simple domain model with JPA annotations, a @Local business interface and a @Stateless implementation in an EJB-JAR, deployed in an EAR together with a very simple webapp to do some basic testing. The EAR is deployed in JBoss 5.0.1 default config with no modifications. This was very straighforward, and worked as expected.

However, my latest test involved query caching, and I got some strange results:

• I have a domain class that only maps an ID and a String value, and have created about 10000 rows in that particular table
• In the business bean, there's a very simple query, SELECT m FROM MyClass m
• With no cache, this executes in about 400ms on average
• With query cache enabled (through hints on the query), the first execution of course takes a little longer, about 1200ms. The next executions take 3500ms on average!

This puzzled me, so I enabled Hibernate's show_sql to look at the log. Uncached, and on the first execution with cache enabled, there is one SELECT logged, as expected. When I should get cache hits, Hibernate logs one SELECT for each row in the database table.

That would certainly explain the slow execution time, but can anyone tell me why this happens?

Answer 1

Hi Nils-Petter. The way that the query cache works is that it only caches the ID's of the objects returned by the query. So, your initial SELECT statement might return all the objects, and Hibernate will give them back to you and remember the ID's.

The next time you issue the query, however, Hibernate goes through the list of ID's and realizes it needs to materialize the actual data. So it goes back to the database to get the rest. And it does one SELECT per row, which is exactly what you are seeing.

Now, before you think, "this feature is obviously broken", the reason it works this way is that the Query Cache is designed to work in concert with the Second Level Cache. If the objects are stored in the L2 cache after the first query, then Hibernate will look there instead to satisfy the per-ID requests.

I highly recommend you pick up the book Java Persistence with Hibernate to learn more about this. Chapter 13 in particular covers optimizing queries, and how to use the cache effectively.

EDIT: I originally, mistakenly, labeled this the "N+1" problem, which it is not (although the symptoms are very similar). The rest of the answer still stands though.

Answer 2

You might find some useful info on my blog about the query cache here:

• http://tech.puredanger.com/2009/07/10/hibernate-query-cache/