Query Cache - Cached query results were not up-to-date

[wirnse]

Hello!

We are facing a problem with our application which uses hibernate second level cache -> query cache.

On to now we used infinispan in local mode. Because we now have to cluster our application it is necessary to cluster infinispan.

We observed that our queries, which should hit the cache, now hit the database.

After a debugging session we think we found what the problem is.

When an entity gets updated the timestamp cache gets updated too. This is happening in two steps → preInvalidate and invalidate.

Have a look at https://github.com/hibernate/hibernate-orm/blob/5.4.3/hibernate-core/src/main/java/org/hibernate/cache/internal/TimestampsCacheEnabledImpl.java#L47

So in preInvalidate the new timestamp which gets stored in the timestamp cache gets set to:

final Long ts = regionFactory.nextTimestamp() + regionFactory.getTimeout();

where regionFactory.getTimeout(); is hard coded 60000L in  https://github.com/hibernate/hibernate-orm/blob/master/hibernate-core/src/main/java/org/hibernate/cache/spi/RegionFactory.java#L89https://github.com/hibernate/hibernate-orm/blob/5.4.3/hibernate-core/src/main/java/org/hibernate/cache/spi/RegionFactory.java

So in other words now+1 Minute.

Then in invalidate the timestamp cache gets updated again: https://github.com/hibernate/hibernate-orm/blob/5.4.3/hibernate-core/src/main/java/org/hibernate/cache/internal/TimestampsCacheEnabledImpl.java#L77

The timestamps new value is "now".

So back in infinispan this happens:

Becaue we are now having a clustered cache the following implementation is called:

https://github.com/infinispan/infinispan/blob/9.4.14.Final/hibernate/cache-v53/src/main/java/org/infinispan/hibernate/cache/v53/impl/ClusteredTimestampsRegionImpl.java#L66

In https://github.com/infinispan/infinispan/blob/9.4.14.Final/hibernate/cache-v53/src/main/java/org/infinispan/hibernate/cache/v53/impl/ClusteredTimestampsRegionImpl.java#L124 the new value gets compared with the old value.

The higher value, which is the one from the preInvalidate (now+1 Minute), is put into the cache.

Every cacheable query gets checked if it is up to date here:

https://github.com/hibernate/hibernate-orm/blob/5.4.3/hibernate-core/src/main/java/org/hibernate/cache/internal/QueryResultsCacheImpl.java#L160

So in the next minute when a query is executed it hits the database because it sees that the now executed query is older than the timestamp in the timestamp cache (preInvalidte now +1 Minute).

Hope my explanation isn’t to complicated and correct.

Basically the query cache can’t be used in our application with this implementation.

Is this a feature or a bug?

Are we using it wrong?

Is there another approach to it?

Every hint is most welcome. :-D

Best Regards,

Herbert