We are using Ehcache version 2.4.4 with Hibernate 3.5.5-FINAL. I've got a strange case happening on my debug environment - it looks like Ehcache is getting into a deadlock. Here's the stack trace:

Code:

http-8080-2@7345 daemon, prio=5, in group 'main', status: 'WAIT'
at sun.misc.Unsafe.park(Unsafe.java:-1)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178)
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)
at net.sf.ehcache.store.compound.Segment.put(Segment.java:427)
at net.sf.ehcache.store.compound.CompoundStore.put(CompoundStore.java:141)
at net.sf.ehcache.Cache.putInternal(Cache.java:1434)
at net.sf.ehcache.Cache.put(Cache.java:1367)
at net.sf.ehcache.Cache.put(Cache.java:1339)
at net.sf.ehcache.constructs.EhcacheDecoratorAdapter.put(EhcacheDecoratorAdapter.java:111)
at net.sf.ehcache.hibernate.regions.EhcacheTransactionalDataRegion.put(EhcacheTransactionalDataRegion.java:127)
at net.sf.ehcache.hibernate.strategy.NonStrictReadWriteEhcacheEntityRegionAccessStrategy.putFromLoad(NonStrictReadWriteEhcacheEntityRegionAccessStrategy.java:66)
at net.sf.ehcache.hibernate.nonstop.NonstopAwareEntityRegionAccessStrategy.putFromLoad(NonstopAwareEntityRegionAccessStrategy.java:180)
at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:180)
at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:898)
at org.hibernate.loader.Loader.doQuery(Loader.java:773)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:270)
at org.hibernate.loader.Loader.loadEntity(Loader.java:1953)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:86)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:76)
at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3270)
at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:496)
at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:477)
at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:227)
at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:147)
at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:1080)
at org.hibernate.impl.SessionImpl.immediateLoad(SessionImpl.java:1018)
at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:176)
at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:215)
at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:191)
at vyre.content.items.ItemInfo_$$_javassist_87.equals(ItemInfo_$$_javassist_87.java:-1)
at org.hibernate.util.EqualsHelper.equals(EqualsHelper.java:33)
at org.hibernate.type.AbstractType.isEqual(AbstractType.java:132)
at org.hibernate.type.ComponentType.isEqual(ComponentType.java:153)
at org.hibernate.cache.CacheKey.equals(CacheKey.java:79)
at net.sf.ehcache.store.compound.Segment.containsKey(Segment.java:279)
at net.sf.ehcache.store.compound.CompoundStore.containsKey(CompoundStore.java:353)
at net.sf.ehcache.store.compound.impl.MemoryOnlyStore.containsKeyInMemory(MemoryOnlyStore.java:121)
at net.sf.ehcache.Cache.searchInStoreWithStats(Cache.java:1884)
at net.sf.ehcache.Cache.get(Cache.java:1549)
at net.sf.ehcache.constructs.EhcacheDecoratorAdapter.get(EhcacheDecoratorAdapter.java:75)
at net.sf.ehcache.hibernate.regions.EhcacheTransactionalDataRegion.get(EhcacheTransactionalDataRegion.java:105)
at net.sf.ehcache.hibernate.strategy.NonStrictReadWriteEhcacheEntityRegionAccessStrategy.get(NonStrictReadWriteEhcacheEntityRegionAccessStrategy.java:55)
at net.sf.ehcache.hibernate.nonstop.NonstopAwareEntityRegionAccessStrategy.get(NonstopAwareEntityRegionAccessStrategy.java:122)
at org.hibernate.event.def.DefaultLoadEventListener.loadFromSecondLevelCache(DefaultLoadEventListener.java:586)
at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:459)
at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:227)
at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:147)
at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:1080)
at org.hibernate.impl.SessionImpl.immediateLoad(SessionImpl.java:1018)
at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:176)
at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:215)
at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:191)
at vyre.content.items.Item_$$_javassist_102.getName(Item_$$_javassist_102.java:-1)
at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.velocity.runtime.parser.node.PropertyExecutor.execute(PropertyExecutor.java:142)
at org.apache.velocity.util.introspection.UberspectImpl$VelGetterImpl.invoke(UberspectImpl.java:533)
at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:198)
at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
at org.apache.velocity.runtime.RuntimeInstance.render(RuntimeInstance.java:1277)
at org.apache.velocity.runtime.RuntimeInstance.evaluate(RuntimeInstance.java:1216)
at org.apache.velocity.runtime.RuntimeInstance.evaluate(RuntimeInstance.java:1165)
at org.apache.velocity.app.Velocity.evaluate(Velocity.java:191)
at org.apache.jsp.WEB_002dINF.jsp.pub_005fmodule.taglibs.contentTemplate.search.itemLink_jsp._jspService(itemLink.jsp:36)
(...another hundred or so irrelevant stack trace fragments skipped...)

Some comments on how I understand this situation:
- the stack bottom begins where Apache Velocity is doing an evaluation and is passed a Hibernate proxy object
- this object is cached with "<cache usage="nonstrict-read-write"/>" and has a composite key
- Hibernate attempts to get the entity from the cache
- Hibernate/Ehcache checks equalness of the object (note: the "real" .equals() method is never executed)
- the equal check returns false and the object is being loaded by the Hibernate
- as soon as the load succeeds, the object is placed in the cache
- deadlock?

Hi,
Just looking at the stack trace here, it looks like a put to a segment happens while a resolving a get. This seems unusual. It looks to me like your Item entity is PK with a ItemInfo, is that correct ?
Could you post your mapping files for Item & ItemInfo (and class hierarchy, if applicable) ? I also wonder whether you have multiple entities mapped to the same cache region ? Not really important, but might exacerbate the issue.
I think this might be an issue with the mapping as, if I remember correctly, org.hibernate.type.Type#isEqual shouldn't result in hitting back to the database, which does seem to happen here (and hence populate the cache, while you are currently querying it).
Alex

In other words, ItemInfo is a base object and it contains many Items which contain version-specific data of the base. Item is identified via id of ItemInfo (foreign key) and version of itself (simple integer).

> whether you have multiple entities mapped to the same cache region ?
I think I am, as I am using this advice:
http://stackoverflow.com/questions/4452242/specifying-global-ehcache-capacity tl;dr reasoning is that I don't want to end up manually specifying different capacities for all my regions (100+ of different entity types). I rather want them to be fighting for cache survival - if a certain object is hit more frequently it should have better survival chances, regardless of its type.

This kind of brings to the question on why Hibernate is initializing objects already sitting in the cache? Surely if objects are in the cache, they should be initialized already, otherwise what is the point of caching them?

Well, the cache doesn't hold entities, but dehydrated representations of your entity instances. What happens is that, since your Item.equals() method does compare the PK, it looks like it does load one ItemInfo from the database and puts it in the cache.
Now since you share a single cache for all your regions, you do end up more easily facing that deadlock. I believe this is the only thread locked up, so that is probably trying to upgrade a read lock to a write one.
Chances are that id you'd map your ItemInfo as a Custom type, which then you'd also have to implement UserType#equals(Object, Object), so that it wouldn't require to instantiate the instance itself (the equals is to be performed to lookup the CacheKey in the Cache).
I'd try to map ItemInfo as that, doing all the extra work, so that comparison can be made on the "raw representation" of an ItemInfo.
Another work around would be, if I'm not mistaken, to use a dedicated Cache for ItemInfo, rather than to use a single Cache for all.

You were absolutely right. The mapping I had was loading ItemInfo on request in order to get Item.id (Item.id was a part of Item.equals() check). Phew!

I have redone the mapping and the loading-by-side-effect seems to be gone.

<general-rant>
This is scary stuff... took me absolute ages to understand what's going on, absolute ages to get it redone (still working on it), and will probably take ages to test and cherry-pick all the bugs as changes like these are always ground shattering. I am not saying I blame Ehcache but we only got this issue because we are switching from OSCache. I keep thinking that if Ehcache was using atomic/non-blocking approach, this problem would have never surfaced (I refer to Cliff Click's NBHM). Is this anything you guys are looking at implementing in the future?
</general-rant>

We'll always try to make the product as fast as possible, as long as correctness is ensured. In this particular case the locking itself isn't really the issue, but rather the Read to Write Lock upgrade.
But on a more OSCache related note, ehcache 2.5 (currently in beta) introduces CacheManager level resource management. You're now able to configure a CacheManager to use a maximum of say 500MB of the local heap.
You can read more on this here: http://www.ehcache.org/documentation/user-guide/configuration#memory-based-cache-sizing-ehcache-25-and-higher While the Hibernate region factory will keep on creating a dedicated cache per region, you'll be able to decide how my memory all these caches use. The CacheManager will be the one choosing eviction based on the current access patterns to your caches. While the measurement does come at a cost, we believe it makes tuning sizes much easier, not only for the whole VM resource management, but also in tuning cache sizes amongst each other.