I am testing Hibernate version 3.2 CR 1 with JBossCache 1.3 CR 1, using OptimisticTreeCacheProvider. For treecache.xml, I am using JBC 1.3's hibernate-recommended-config.xml with the only modification being the addition of an eviction policy. Using a cluster environment with our web app under load, some nodes operate fine without exception. However, other nodes begin with an exception like the following:
Code:
156000 [PoolThread-48] WARN org.jboss.cache.interceptors.TxInterceptor - Rolling back, exception encountered
java.lang.RuntimeException:
at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(TxInterceptor.java:1033)
at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:72)
at org.objectweb.jotm.SubCoordinator.doBeforeCompletion(SubCoordinator.java:1443)
at org.objectweb.jotm.SubCoordinator.commit_one_phase(SubCoordinator.java:407)
at org.objectweb.jotm.TransactionImpl.commit(TransactionImpl.java:224)
at org.objectweb.jotm.Current.commit(Current.java:475)
at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:325)
.....
Caused by: org.jboss.cache.CacheException: unable to validate nodes
at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateNodes(OptimisticValidatorInterceptor.java:109)
at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:64)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:67)
at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:87)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:67)
at org.jboss.cache.interceptors.InvalidationInterceptor.invoke(InvalidationInterceptor.java:54)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:67)
at org.jboss.cache.interceptors.TxInterceptor.runPreparePhase(TxInterceptor.java:753)
at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(TxInterceptor.java:1011)
... 49 more
followed immediately by many write lock exceptions similar to the following:
Code:
171000 [PoolThread-49] ERROR org.jboss.cache.lock.IdentityLock - write lock for /com/inventive/altona/orm/School could not be acquired after 15000 ms. Locks: Read lock owners: {}
Write lock owner: GlobalTransaction:<10.40.58.21:3438>:1199
(caller=GlobalTransaction:<10.40.58.21:3438>:1207, lock info: write owner=GlobalTransaction:<10.40.58.21:3438>:1199 (activeReaders=0, activeWriter=PoolThread-48, waitingReaders=0, waitingWriters=1, waitingUpgrader=0))
171000 [PoolThread-49] WARN org.jboss.cache.interceptors.TxInterceptor - Rolling back, exception e
ncountered
java.lang.RuntimeException:
at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(TxInterceptor.java:1033)
at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:72)
at org.objectweb.jotm.SubCoordinator.doBeforeCompletion(SubCoordinator.java:1443)
at org.objectweb.jotm.SubCoordinator.commit_one_phase(SubCoordinator.java:407)
at org.objectweb.jotm.TransactionImpl.commit(TransactionImpl.java:224)
at org.objectweb.jotm.Current.commit(Current.java:475)
at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:325)
at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:136)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:67)
at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:153)
at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:4786)
at org.jboss.cache.TreeCache.put(TreeCache.java:3224)
at org.jboss.cache.TreeCache.put(TreeCache.java:2919)
at org.hibernate.cache.OptimisticTreeCache.writeLoad(OptimisticTreeCache.java:95)
.....
Caused by: org.jboss.cache.lock.TimeoutException: write lock for /com/inventive/altona/orm/School co
uld not be acquired after 15000 ms. Locks: Read lock owners: {}
Write lock owner: GlobalTransaction:<10.40.58.21:3438>:1199
(caller=GlobalTransaction:<10.40.58.21:3438>:1207, lock info: write owner=GlobalTransaction:<10.40.58.21:3438>:1199 (activeReaders=0, activeWriter=PoolThread-48, waitingReaders=0, waitingWriters=1, waitingUpgra
der=0))
at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:185)
at org.jboss.cache.Node.acquireWriteLock(Node.java:557)
at org.jboss.cache.Node.acquire(Node.java:517)
at org.jboss.cache.interceptors.OptimisticLockingInterceptor.lockNodes(OptimisticLockingInterceptor.java:141)
at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:68)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:67)
at org.jboss.cache.interceptors.InvalidationInterceptor.invoke(InvalidationInterceptor.java:54)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:67)
at org.jboss.cache.interceptors.TxInterceptor.runPreparePhase(TxInterceptor.java:753)
at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(TxInterceptor.java:1011)
... 49 more
Does anyone have any suggestions for other configuration parameters to try or other techniques that can be used to help debug this and/or find a reasonable solution?
Thanks in advance!
Aaron