Hibernate Wars: The Query Cache Strikes Back

Not so long ago, in a galaxy not very far away... a middle-aged programmer battled to free memory from the dark side of the hibernate query cache.  He was successful, or so it seemed. For the query cache memory problems had risen from the ashes -- stronger and more bloated than ever...

What's With All This Garbage?

We hit a case at work (again), where the java server process came to a grinding halt.  It wasn't dead, it just wasn't making much forward progress either.  A quick look at the heap stats showed we were nearly at capacity and that garbage collection was eating all CPU time, thus not allowing any real work to happen.  Looks like it is time to whip out the ol' memory profiler.  This time I went with Eclipse's Memory Analysis Tool .  It's pretty slick.  I suggest you try it.

Query Cache Waste Redux

Not terribly unexpected, the hibernate caches were the top consumer of heap space.  I have previously explored ways to trim down the memory used by the query cache.  But, we depend heavily on it and size it pretty big, so that's why I wasn't too surprised to see them at the top of the heap report.  Drilling down a little further showed that it was not the contents of the query cache results that were causing the problem.  That was the unexpected part.  Rats, our friend QueryKey is once again a giant waster of memory.



What is it this time?  In A Dirty Little Secret, I showed that you should use object identifiers in your HQL and as parameters so that full objects are not stored as part of the QueryKey.  This was a major win.  I also showed that by providing a decorator query cache implementation, you can reduce all duplicate stored parameters by replacing them with canonical representations.  Using MAT (Memory Analysis Tool), I proved that this was still working as expected.



What I hadn't previously accounted for was the QueryKey.sqlQueryString field.  Since we use a lot of natural id query cache optimizations, we have tens of thousands (and in some cases, well over 100,000) copies of identical queries tucked away in QueryKey as the sqlQueryString (thus, differentiated only by the query parameters).  And since hibernate generated SQL is not exactly terse, we have a nice formula for memory explosion.

Different Tune, Same Dance

We're already using my decorated query cache which eliminates duplicates in the parameters.  So I decide to modify it to also swap out the sqlQueryString for a canonical representation.  One caveat is that sqlQueryString is private and final.  Lo and behold, you can modify private final fields with reflection in Java 1.5!  Granted, you could really do some silly stuff and fake out the JVM and screw up compiler optimizations, but we're only replacing the field with another String that should be functionally equivalent, so hopefully any 'weirdness' is mitigated.  Again, for licensing reasons I won't paste the whole query cache decorator.  Creating the full one (and the factory to instantiate it) is left as an exercise to the reader.



The modified query cache decorator looks like this:

 
    private final Map<Object, Object> canonicalObjects = new HashMap<Object, Object>();

 
    public boolean put(QueryKey key, Type[] returnTypes,
        @SuppressWarnings("unchecked") List result, boolean isNaturalKeyLookup,
        SessionImplementor session) throws HibernateException {

        // duplicate natural key shortcut for space and time efficiency
        if (isNaturalKeyLookup && result.isEmpty()) {
            return false;
        }

        canonicalizeKey(key);

        return queryCache.put(key, returnTypes, result, isNaturalKeyLookup,
            session);
    }

    private void canonicalizeKey(QueryKey key) {
        try {
            synchronized (canonicalObjects) {
                canonicalizeParamValues(key);
                canonicalizeQueryString(key);
            }
        } catch (Exception e) {
            throw Exceptions.toRuntime(e);
        }
    }

    private void canonicalizeParamValues(QueryKey key)
        throws NoSuchFieldException, IllegalAccessException {
        final Field valuesField;
        valuesField = key.getClass().getDeclaredField("values");
        valuesField.setAccessible(true);
        final Object[] values = (Object[]) valuesField.get(key);
        canonicalizeValues(values);
    }

    private void canonicalizeQueryString(QueryKey key)
        throws NoSuchFieldException, IllegalAccessException {
        final Field sqlQueryString;
        sqlQueryString = key.getClass().getDeclaredField("sqlQueryString");
        sqlQueryString.setAccessible(true);
        Object sql = sqlQueryString.get(key);
        Object co = ensureCanonicalObject(sql);
        if (co != sql) {
            sqlQueryString.set(key, co);
        }
    }

    private void canonicalizeValues(Object[] values) {
        for (int i = 0; i < values.length; i++) {
            Object object = values[i];
            Object co = ensureCanonicalObject(object);
            values[i] = co;
        }
    }

    // assumes canonicalObjects is locked. TODO: consider a concurrent hash
    // map and putIfAbsent().
    private Object ensureCanonicalObject(Object object) {
        Object co = canonicalObjects.get(object);
        if (co == null) {
            co = object;
            canonicalObjects.put(object, co);
        } else if (co != object) {
            // System.out.println("using pre-existing canonical object "
            // + co);
        }
        return co;
    }

As you can see, we simply change the sqlQueryString via reflection just like we do the param values.

Your Mileage May Vary

How much of a win this is for you depends on your use case.  As I said, since we heavily use the natural id query optimization, we had tons of repeated sql strings.  So, exactly how much memory you 'reclaim' in this fashion totally depends on the variety and uniqueness of the queries you run through the hibernate query cache.

Bonus: L2 Cache Reduction

While we're at it, I noticed a few other things that seemed odd in the L2 cache.  There was more HashMap overhead than there was contents in the cache itself.  I poked around the source a bit and saw that every entry in the L2 cache was being turned into a property->value map before it was stored in your L2 cache provider (and the inverse process occurs on the way out).  This seemed odd to me, as we already have a decomposed CacheEntry object which is an array of the Serializable[] properties from your persistent entity.  Why create another (less efficient) representation as well as introduce unnecessary conversions?  After some google-fu, I realized you can bypass this conversion by setting hibernate.cache.use_structured_entries to false in your hibernate configuration.



Any docs I found on hibernate.cache.use_structured_entries merely seemed to suggest that it stores the properties in a more 'human friendly format.'  And, who wouldn't want that?  And, all examples we built on when first starting with hibernate turned it on, so... so did we.  What they don't mention is what it actually does, and the penalty you pay for doing so -- which is apparently too much HashMap overhead for what should be pretty simple in memory storage.



However, be aware -- this only works for non-clustered, in-memory use of L2 cache.  Apparently, if you cluster your JVMs and need L2 cache clustering, the in/out of the property order cannot be guaranteed between JVMs.  Thus, you have to use structured entities in the cache so they can be re-hydrated properly by property name.

Right-Size Your Caches

We moved to the 1.6 release of EH Cache, so... this may only apply to that version.  But, I noticed that whatever you configure as 'max elements' for ehcache, it uses as the 'min capacity' for the ConcurrentHashMap.  Needless to say, if you size them for your potential largest usage, but then deploy to a smaller-usage environment, you can end up with some waste in the overhead for the hash tables.  It didn't seem terribly significant in my case, but it did show up on the radar.

Wrap-Up

Even in today's multi-gigabyte server (heck, even desktop...) environments, memory is still a precious resource.  Even if you have lots of it available, wouldn't you want to make more use of that memory instead of having it wasted?  Freeing up wasted memory means there is more for the 'transient' objects that come and go quickly.  There's less pressure to garbage collect and try to find available heap.  And, there's more memory available to do smart things with useful caching. In short:

• Use a query cache decorator to reduce parameter and SQL string duplication.


• If you are in a single JVM using in memory cache only, use hibernate.cache.use_structured_entries=false in your hibernate configuration.


• Right-size your caches to reduce hash table overhead.

Hibernate Query Cache: A Dirty Little Secret

You Mean, Memory Is Not Infinite?

We're working hard getting MySQL Enterprise Monitor 2.0, featuring Query Analyzer, ready for release. As part of that, we started really ramping up the number of MySQL servers reporting in query data to see how we could scale. Not surprising (to me, anyway), the first efforts did not go so well. My old friend OutOfMemoryError reared its ugly head once again.

Query Cache -- It's More Than Just Results!

We're big (ab)users of hibernate query caching, and more importantly to us the natural id optimized query cache. Firing up the profiler, I was not shocked to see that the second level (let's call it L2) and query caches were hogging the majority of memory. But, something didn't smell right...

What I was seeing was tons of object/entity referenes for our persistent objects. However, the hibernate cache does not really work that way. Hibernate 'dehydrates' query results and persistent objects into their primitive components and identifiers. It stores this decomposed data in the L2 and query results cache, and on a cache hit, it rehydrates/recomposes them into the requested persistent object.

But the profiler does not lie. One of our objects, for which there are conceptually 60 some odd instances, had over 20,000 referenced instances on the heap. Yikes. Obviously, we're doing something wrong, or are we... ?

Ok, Mr. Profiler, who is holding the references on the heap? Drill down a bit through the query cache, past some HashMap entries, into the... keys... keys, you say? Hrm, not values. Interesting. Well, looky here. Hibernate's QueryKey is holding on to a Object[] values array, which is holding the majority of our persistent object references. Ouch. In addition to that, it has a map inside of it whose values also contain non-trivial amount of references to our entities.

Well, nuts. Code spelunking ensues. QueryKey is just as it sounds -- an object that can act as a unique key for query results. This means it includes stuff like the SQL query text itself as well as any parameters (positional or named) that specifically identify a unique result set.

Objects, Objects, Everywhere

Now, silly me, since we are using an object relational mapping, I was using objects for the parameters in my HQL. Something along the lines of:

final Cat mate = ...;
final String hql = "from Cat as cat where cat.mate = ?"
final Query q = session.createQuery(hql);
q.setParameter(0, mate);
q.setCacheable(true);

In this case, the entire Cat mate (and everything he references) would be held in perpetuity. Well, until either the query cache exceeds his configured limits and it is evicted, or the table is modified and the results become dirty.

Let's not forget our friends the Criteria queries, either. Because it is only through criteria that we can get our friend the natural id cache optimization. (and please pardon the contrived-ness of the cat natural id example)

final String foo = "something";
final Cat mate = ...;

final Criteria crit;
final NaturalIdentifier natId;

crit = session.createCriteria(Cat.class);
natId = Restrictions.naturalId();
natId.set("mate", mate);
natId.set("foo", foo);
crit.add(natId);
crit.setCacheable(true);

In the same fashion as the HQL, this will result in hard references to 'mate' and 'foo' held for the cache-life of the query results.

How To Make a Bad Problem Worse

Even worse, in our case, was the fact that we would do the equivalent of load the same 'mate' over and over again (maybe this cat is severely non-monogamous). And whether loaded from L2 cache or directly from the database, the mate Cat now existed as multiple instances, even though they are hashCode()/equals() equivalent. But QueryKey in the query cache doesn't know that. He only knows what he is handed. And he is handed equivalent duplicates over and over and over again, and only lets go of them on cache eviction. So, not only do we end up with essentially unnecessary references to objects held onto by the query keys in the cache, we instantiate and hold onto multiple multiple instantiations of the same object and hold on to those, too. Bear with me as I bow my head in shame...

Fix Attempt 1: Make a Smarter Cache

I've been down this road before. I tried to be smarter than Hibernate once before. It did not end well. Unsullied by prior defeat, I resolved to attempt being smarter than Hibernate once again!

Hibernate's query cache implementation is pluggable. So I'm going to write my own. Ok, I'm not going to write my own -- from scratch. My going theory is that I can at least eliminate the duplication of the equivalent objects referenced in memory. I'm going to decorate hibernate's StandardQueryCache and do the following: For each QueryKey coming in a cache put(), introspect the Object[] values (which are positional parameters to the query). For each object in values[], see if an equivalent canonical object has already been seen (same hashCode/equals()). If so, use the canonical object. Else, initialize the canonical store with this newly seen object.

Notice we only have to do this on put(). A get() can use whatever objects already come in, as they are assumed to be hashCode/equals equivalent. Hell, it HAS to work that way, otherwise QueryKey would just be broken from the start. Here is some snippets of relevant code that implement org.hibernate.cache.QueryCache.

public boolean put(QueryKey key, Type[] returnTypes,
    @SuppressWarnings("unchecked") List result, boolean isNaturalKeyLookup,
    SessionImplementor session) throws HibernateException {

    // duplicate natural key shortcut for space and time efficiency
    if (isNaturalKeyLookup && result.isEmpty()) {
      return false;
    }

    canonicalizeValuesInKey(key);

    return queryCache.put(key, returnTypes, result, isNaturalKeyLookup,
      session); 
}

private void canonicalizeValuesInKey(QueryKey key) {
    try {
      final Field valuesField;
      valuesField = key.getClass().getDeclaredField("values");
      valuesField.setAccessible(true);
      final Object[] values = (Object[]) valuesField.get(key);
      canonicalizeValues(values);
    } catch (Exception e) {
      throw new RuntimeException(e);
    }
}

private void canonicalizeValues(Object[] values) {
    synchronized (canonicalObjects) {
      for (int i = 0; i < values.length; i++) {
          Object object = values[i];
          Object co = canonicalObjects.get(object);
          if (co == null) {
              co = object;
              canonicalObjects.put(object, co);
          } else if (co != object) {
              // System.out.println("using pre-existing canonical object "
              // + co);
          }
          values[i] = co;
      }
    }
}

It's pretty much what i described. I didn't even attempt to get permission to post the whole thing, because it is probably not worth my time. The only thing missing is a HashMap of the canonical objects, an the instantiation of the StandardQueryCache queryCache. You'll also need to implement org.hibernate.cache.QueryCacheFactory to create this smarter query cache factory, and then plug that into your hibernate config.

This did work as expected. My 'outstanding' objects on the heap were greatly reduced. Unfortunately, it was not good enough. I still had thousands of these guys on the heap, essentially unused except to at some point fetch their numeric id to be used by hibernate's generated SQL. And this didn't take care of the named parameters, which are stored in a map of string names to some other internal hibernate class, which I no longer felt like introspecting via reflection. So anything using named parameters was still potentially duplicated.

Fix Attempt 2: Objects? Who Needs Objects?

Hrm, the last paragraph stirred a thought -- hibernate only needs the id's from these objects. While the academic in me enjoyed the exercise in decorating the query cache to be smarter about duplicate references, the idiot in me said "well, duh. if you only need the id, why not just use the id?" Because we're supposed to use objects! Oh well. It occurred to me that I could rewrite any and all HQL to reference object id's instead of the object property reference itself. It should end up in the same SQL eventually sent to the database. Seems like a cheesy code monkey work around, but the theory is that hibernate QueryKey will only be holding onto Integer and Long references instead of entire object entities.

So, I hunt down all of our our cacheable queries. I change them all to object id queries. The previous Cat business can now look like this:

final Cat mate = <...>;
final String hql = "from Cat as cat where cat.mate.id = ?"
final Query q = session.createQuery(hql);
q.setParameter(0, mate.getId());
q.setCacheable(true);

cat.mate becomes cat.mate.id. The mapped parameter becomes mate.getId(). It could be a named parameter just as well. I didn't find a single HQL in our application that I could not convert this way. Good.

But what about our friend Criteria? He requires objects for the properties, right? At first, I thought this was true. And I was consoled by the fact that my smart query cache would do its best to keep duplication at a minimum. In fact, it was the next day (after resting my brain), that another "I'm an idiot" moment came to light. The Criteria API still just takes strings for property references. Perhaps, it follows the same property resolution rules as HQL? In other words instead of "mate", can I say "mate.id"? And the answer is, YES, yes I can! Woo hoo! Absolutely no more object references for me! Here is what the criteria would like like:

final String foo = "something";
final Cat mate = ...;

final Criteria crit;
final NaturalIdentifier natId;

crit = session.createCriteria(Cat.class);
natId = Restrictions.naturalId();
natId.set("mate.id", mate.getId());
natId.set("foo", foo);
crit.add(natId);
crit.setCacheable(true);

Subtle, yes. But trust me, it makes a huge difference. Interesting now, that Fix Attempt 2 likely alleviates the need for Fix Attempt 1. At the worst, we end up with lots and lots of Integer/Long object references and even duplicates of them. The profiler says it is not very much in my limited testing. But, I decide to leave the smarter cache in, because it appears to be working, and it does reduce memory.

Lessons Learned

If you use hibernate query caching, and actually want to use memory for caching useful results, and waste as little as possible with overhead, follow some simple advice:

• Write your HQL queries to use identifiers in any substitutable parameters.WHERE clauses, IN lists, etc. Using full objects results in the objects being kept on the heap for the life of the cache entry.
  
• Write your Criteria restrictions to use identifiers as well.
  
• Use the 'smart' query cache implementation skeleton in this article to eliminate duplicate objects used in query keys. This helps a little if you use the ids in your HQL/Criteria, but if you still must use objects then it helps a lot.
  
• If you use a smart query cache implementation, prefer '?' positional parameters over named parameters. I know, I know. I love named parameters too. But the smart query cache implementation in this article only detects duplicates for positional parameters (or params in criteria). Alternatively, feel free to extend the example to locate duplicates in the named parameter map and replace them with canonical ones as well.
  

I'm Not the Only One Who Noticed...

In doing some final research for this post, I came across hibernate core issue HHH-3383. Let's keep our eye on it to see if the wonderful hibernate devs can fix this down at their level, so we don't have to change our code. Also, the issue lists that Criteria cannot be fixed with the same 'use id' workaround. Since I was able to, I wonder if the bug submitter did not realize you can reference dotted property paths in criteria restrictions exactly as you can in HQL. Perhaps I shall start a dialog with him.

Hibernate: Cache Queries the Natural Id Way

I work on the MySQL Enterprise Tools team, formerly of MySQL and now with Sun Microsystems. The 2.0 version of the Enterprise Monitor is well under way. As part of this, the Java server backend has been refactored to utilize Spring and Hibernate. Honestly, I didn't know either one of those technologies before starting this project. Oh, what a fun road it has been...

A big draw for using an off-the-shelf ORM was so that we didn't have to write our own (kind of bad and slightly wrong -- those darn transactions) caching implementations for the custom one-off ORM that existed previously. A lot of our internal meta-model is very static, so clearly caching would be a HUGE win for performance, right?

Not so fast, turbo. Let me continue...

The headline feature for the 2.0 Monitor is "Query Analysis." Coupled with the MySQL Proxy, the Monitor receives captured query data to/from a MySQL server. Once at the monitor, the data can be aggregated, analyzed, and reported upon. What better test for this feature than to use it on ourselves, to tune ourselves!

And this brings me back to hibernate caching. In the course of monitoring ourselves, I noticed that a certain query was happening WAY more than it should be, just based on my gut feeling. The query in question loaded an object that was generally static -- save for one value that represents the frequency of how often some data should be collected. Its the only mutable value, and once in place, it rarely changes.

Hrm... how to debug. First, we checked the cache settings. Whoops -- WAY too low for both the cache expiry timeout and the max cache elements. Fix that. Still sucks. Some cursory hibernate source and log perusal showed that the cache for these objects was being invalidated at a rapid rate. Yes, the entire cache. Even though the objects are essentially static, the query cache takes the safe route and says any change to a related table invalidates any and all queries that reference that table. This makes sense, from a generic cache standpoint. But I thought to myself -- surely there has to be a way. *I* am smarter than hibernate in this case, and *I* can more rightly determine when the query results should be invalidated. Lucky for me, hibernate allows you to extend the StandardQueryCache "up to date" policy checks. w00t. I implemented one, overrode the timeout policy for the object(s) in question, and re-ran tests. FAILURE. Turns out I am not smarter than hibernate.

However, in the process of implementing the custom query cache policy, I had debugged through some more hibernate code and noticed that "natural id" queries are treated special. Some more google-fu, and quickly I come across Queries by Natural Identifier in the hibernate docs.

Now, the docs just aren't real clear on what optimizations can be made internally by utilizing the Criteria with a natural id restriction. But, as I was just in that section of code, I could correlate it. Here's the meaty bit -- if you make a natural id / key lookup, and hibernate recognizes it as such, it can bypass the table timestamp invalidation and go directly to second-level cache to fetch the object. Hibernate knows, with an immutable and unique natural key, that a table modification will not effect the composition of the object in question (of course, an object modification would, and it would have been evicted from L2 cache).

I cannot overemphasize the utility of this discovery. You see, we were making frequent inserts into the table. But existing objects (rows) where changed almost never. But without the natural key lookup, the inserts invalidated all results in the query cache. There you have why I was seeing way more selects for the same objects than I had anticipated.

Some quick assurances that we mapped the natural id correctly, some quick refactoring of the HQL into Criteria queries with natural id restrictions, and whammo, we're good. Lets run the tests and query analysis again... ruh roh. OH COME ON! (not my exact reaction, but I think you can guess what it was really like).

Confident that the natural id cache lookup optimization was what I really really really wanted, there had to be something else going on. More debuggage ensued. I set a breakpoint near the same area in StandardQueryCache where I first noticed the query cache optimization in the first place. Lo and behold, the hibernate metadata for saying "i am a natural key lookup" was returning false.

I am not amused. I am confident my hibernate mapping is correct, because the unique index was present in the schema. Think. Think. Think. Well, I had recently been on an effort to move from the hbm xml mappings to hibernate annotations mappings. @NaturalId support was, in fact, the very reason I had recently upgraded the annotations jar. On a hunch, I reverted the persistence mapping back to the xml form. Debug, the metadata returns the correct value... test, and YES, finally -- the queries issued are in line with my expectations and the rows present in the database. I. Have. Won.

Being the good open-source citizen, I made a hibernate forum post that detailed my findings, including simplified sample code demonstrating the problem. The good folks on the hibernate forum (after questioning the sillyness of my contrived example) were quick to recognize the problem, and I got a hibernate jira issue opened.

The workaround, obviously, is leave the xml mapping in place until the fix makes it into a hibernate release. Not too bad of a deal, I guess, considering the overall win I now have in my cache hit ratio.

In conclusion -- if it makes sense for your data model, the natural id query cache optimization can be a huge performance win for your app. If you have immutable, or rarely changed objects with a constant natural key lookup -- look into the Criteria natural id restriction. And, use the xml mapping until the bug is fixed.

ps -- there is one other performance note to consider, actually. If using the natural id query, and it returns no rows, this NULL result will not be cached. So, if you have more of these than 'object/row found' results, you will still get tons of these queries that you don't expect. Either stop using the natural key optimization (if 'not found' is more common), or extend your object/schema to include a 'not supported' field. In our case, the lack of a row meant "not supported" and we had a flag "not supported" in case it was supported, but then went away. In those cases where something was frequently "not supported" I simply went ahead and created the object/row and just set the flag to false -- thus ensuring the natural key optimization was not subverted.

JUnit Eats Your Memory

Once again, we started getting OutOfMemoryError's in our JUnit test suite. Some necessary refactoring re-introduced me to an old foe that I had battled once before. I figured, what the hell -- an excellent opportunity for my first blog post.

There's an important FAQ in JUnit that should be bold, blinking, italics, and highlighted. The gist is -- if you assign an instance member in a JUnit TestCase (declaration, setUp(), or otherwise), you damn well better assign it to null in tearDown().

You see, JUnit creates an instance of the TestCase class for EVERY test method. It would have you believe, the way it is architected, that the TestCase class in question is instantiated once, every test method is called with setUp() and tearDown() pre- and post-, and all is glorious. But that is not the case. Every test method gets its own test case instance. Oh -- and the important detail -- ALL the classes have references held on them until the END of the test suite run.

So, if you do any sort of non-trivial testing with even moderately large (but transient) objects, be sure to set the refs in your testcase to null in tearDown() so they can be garbage collected.

Better yet -- lets find a newer tool than JUnit. Just because it is ubiquitous doesn't mean it is the best tool.