调试 Hibernate/Ehcache 死锁

Question

我们使用 Ehcache 版本 2.4.4 和 Hibernate 3.5.5-FINAL。我的调试环境中发生了一个奇怪的情况 - 看起来 Ehcache 陷入了僵局。这是堆栈跟踪的相关位：

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...)

我是这样理解情况的：

• 堆栈底部开始于 Apache Velocity 进行评估并传递 Hibernate 代理对象的位置
• 这个对象用<cache usage="nonstrict-read-write"/>缓存并且有一个复合键
• Hibernate 尝试从缓存中获取实体
• Hibernate/Ehcache 检查对象的相等性（注意：永远不会执行“真实”equals 方法）
• 相等检查返回 false 并且对象正在被 Hibernate 加载
• 一旦加载成功，对象就会被放入缓存中
• 死锁？

有问题的代码sn-p如下所示：

net.sf.ehcache.store.compound.Segment.put(Segment.java:427) 

423 Element put(Object key, int hash, Element element, boolean onlyIfAbsent) { 
424    boolean installed = false; 
425    Object encoded = create(key, element); 
426 
427    writeLock().lock(); 
428    try { 
429       // ensure capacity 
430       if (count + 1 > threshold) { 

我可以访问encoded 对象，但看起来writeLock() 已经被获取，因此整个线程被卡住了。这就是我的权力结束的地方，因为我对 Ehcache Segment 的内部知识知之甚少。

谁能提供有关如何进一步调试的任何提示？不幸的是，创建一个小的、自洽的测试用例不是一种选择。

这也发布在Ehcache forums page。

提前致谢。

Answer 1

回答我自己的问题，以防万一其他人在此问题上滑倒，Ehcache 论坛中的帖子将消失。

原因：
死锁的原因来自同一个线程，在该线程中尝试定位缓存中的对象。在堆栈的底部之一，Ehcache 在同一个锁对象上执行readLock().lock() 和writeLock().lock()。这显然是一个禁忌。

为什么会这样？ 发生这种情况是因为缓存加载另一个对象作为副作用（另一个大禁忌）并且两个对象都以相同的内存段结束（因此共享相同的ReentrantLock）。提示：我使用相同的缓存区域，因为我不想为数百种不同的实体类型指定容量。

为什么会这样？ 由于我的 Hibernate 映射，无意中加载了缓存键查找。该对象（正在查找）有一个复合键，指向另一个对象。该复合键的一部分已在 equals 方法中使用，并导致该负载。巧合的是，加载的对象也被尝试放置在同一个缓存段中 - 并导致死锁。

经验教训
格外小心您的 Hibernate 映射。如果您有复合键，切勿使用<key-many-to-one，因为这会导致不可预知的结果。我想很多人没有意识到这一点只是因为他们将不同类型的对象放入了不同的缓存区域，但无意的加载仍然是邪恶的。

感谢来自 Terracotta 论坛的 Alex 帮助我找到了这一点。

Answer 2

您可以使用JProfiler（有一个功能齐全的评估版）来查看当前的锁定图。它支持 java.util.concurrent 锁，并会告诉你谁拥有锁以及它是在哪里获得的。有了这些信息，就可以更轻松地分析问题。

免责声明：我公司开发JProfiler