java.lang.IllegalStateException: there is already a writer h

[mindflyer]

I have problem with JBossCache 1.4.1.SP3 (and JBoss 4.0.5.ga with hibernate 3.2.2.ga)

I configured optimistic mode and catched exception:

DEBUG [org.jboss.cache.interceptors.OptimisticLockingInterceptor] Caught exception attempting to lock nodes
java.lang.IllegalStateException: there is already a writer holding the lock: GlobalTransaction:<null>:2311
 at org.jboss.cache.lock.LockMap.setWriterIfNotNull(LockMap.java:96)
 at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:208)
 at org.jboss.cache.Node.acquireWriteLock(Node.java:529)
 at org.jboss.cache.Node.acquire(Node.java:476)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.lockNodes(OptimisticLockingInterceptor.java:153)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:80)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
 at org.jboss.cache.interceptors.TxInterceptor.runPreparePhase(TxInterceptor.java:873)
 at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(TxInterceptor.java:1138)
 at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:75)
 at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1491)
 at org.jboss.tm.TransactionImpl.beforePrepare(TransactionImpl.java:1110)
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:324)
 at org.jboss.tm.TxManager.commit(TxManager.java:240)
 at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:369)
 at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
 at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:157)
 at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5863)
 at org.jboss.cache.TreeCache.put(TreeCache.java:3833)
 at org.jboss.cache.TreeCache.put(TreeCache.java:3507)
 at org.hibernate.cache.OptimisticTreeCache.writeLoad(OptimisticTreeCache.java:84)
 at org.hibernate.cache.TransactionalCache.put(TransactionalCache.java:55)
 at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:156)
 at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:842)
 at org.hibernate.loader.Loader.doQuery(Loader.java:717)
 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
 at org.hibernate.loader.Loader.doList(Loader.java:2211)
 at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2127)
 at org.hibernate.loader.Loader.list(Loader.java:2087)
 at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:375)
 at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
 at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
 at net.uk.topdog.td2.common.dao.server.PersistentUnTypedEmfDAO.getCollection(PersistentUnTypedEmfDAO.java:316)

I found similar problem http://jira.jboss.com/jira/browse/JBCACHE-740
and see Fix Version/s: 2.0.0.BETA1.
The page http://labs.jboss.com/portal/jbosscache/compatibility/index.html tells that JBossCache2 is compatible only with JBoss5. Is it true?
I can't use JBoss5 now and want to use optimistic locking very much :)
Does anyone know if this problem is gonna be fixed in version 1.4.x?

[manik]

Have you tried the teast case attached in JBCACHE-740? (You may need tomodify this a bit since 740 was contributed by someone using JOTM)

[mindflyer]

Have you tried the teast case attached in JBCACHE-740? (You may need tomodify this a bit since 740 was contributed by someone using JOTM)

Firstly, I added logging to MultithreadedTxTest.Worker.run into catch section:

catch (Exception e)
 {
 exception = e;
 log.error("exception", e);
 try
 {
 tx.rollback();
 }
 catch (Exception e1)
 {
 rollbackException = e1;
 log.error("rollbackException", e1);
 }
 }

started test and test passed, but log contains many errors:

11:28:34,484 ERROR [DummyTransaction] beforeCompletion() failed for tx=org.jboss.cache.transaction.DummyTransaction@10f11b8, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:168, tx=org.jboss.cache.transaction.DummyTransaction@10f11b8)]
java.lang.RuntimeException:
 at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(TxInterceptor.java:1163)
 at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:75)
 at org.jboss.cache.transaction.DummyTransaction.notifyBeforeCompletion(DummyTransaction.java:247)
 at org.jboss.cache.transaction.DummyTransaction.commit(DummyTransaction.java:54)
 at net.uk.topdog.td2.common.server.statistics.MultithreadedTxTest$Worker.run(MultithreadedTxTest.java:144)
Caused by: org.jboss.cache.optimistic.DataVersioningException: Tx attempted to create /path/node anew. It has already been created since this tx started by another (possibly remote) tx.
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.simpleValidate(OptimisticValidatorInterceptor.java:139)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateNodes(OptimisticValidatorInterceptor.java:113)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:78)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:99)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
 at org.jboss.cache.interceptors.TxInterceptor.runPreparePhase(TxInterceptor.java:873)
 at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(TxInterceptor.java:1138)
 ... 4 more
11:28:34,484 ERROR [MultithreadedTxTest] exception
javax.transaction.RollbackException: outcome is false status: 1
 at org.jboss.cache.transaction.DummyTransaction.commit(DummyTransaction.java:67)
 at net.uk.topdog.td2.common.server.statistics.MultithreadedTxTest$Worker.run(MultithreadedTxTest.java:144)

Is it all right?

Secondly, I set TransactionManagerLookupClass = "org.jboss.cache.JBossTransactionManagerLookup" and ran test under the running JBoss. I see:

11:48:12,187 INFO [InterceptorChainFactory] interceptor chain is:
class org.jboss.cache.interceptors.CallInterceptor
class org.jboss.cache.interceptors.OptimisticNodeInterceptor
class org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor
class org.jboss.cache.interceptors.OptimisticValidatorInterceptor
class org.jboss.cache.interceptors.OptimisticLockingInterceptor
class org.jboss.cache.interceptors.TxInterceptor
class org.jboss.cache.interceptors.CacheMgmtInterceptor
11:48:12,218 INFO [STDOUT] >> testing simultaneous writes with 2 threads...
11:48:12,250 ERROR [MultithreadedTxTest] exception
org.jboss.tm.JBossRollbackException: Unable to commit, tx=TransactionImpl:XidImp
l[FormatId=257, GlobalId=SI/28, BranchQual=, localId=28] status=STATUS_NO_TRANSA
CTION; - nested throwable: (java.lang.RuntimeException: )
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:372)
 at net.uk.topdog.td2.common.server.statistics.MultithreadedTxTest$Worker
.run(MultithreadedTxTest.java:144)
Caused by: java.lang.RuntimeException:
 at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandle
r.beforeCompletion(TxInterceptor.java:1163)
 at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeComp
letion(OrderedSynchronizationHandler.java:75)
 at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:
1491)
 at org.jboss.tm.TransactionImpl.beforePrepare(TransactionImpl.java:1110)

 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:324)
 ... 1 more
Caused by: org.jboss.cache.optimistic.DataVersioningException: Tx attempted to c
reate /path anew. It has already been created since this tx started by another
(possibly remote) tx.
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.simpleVal
idate(OptimisticValidatorInterceptor.java:139)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateN
odes(OptimisticValidatorInterceptor.java:113)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(Op
timisticValidatorInterceptor.java:78)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(Opti
misticLockingInterceptor.java:99)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
 at org.jboss.cache.interceptors.TxInterceptor.runPreparePhase(TxIntercep
tor.java:873)
 at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandle
r.beforeCompletion(TxInterceptor.java:1138)
 ... 5 more
11:48:12,250 ERROR [MultithreadedTxTest] rollbackException
java.lang.IllegalStateException: Transaction has terminated TransactionImpl:XidI
mpl[FormatId=257, GlobalId=SI/28, BranchQual=, localId=28]
 at org.jboss.tm.TransactionImpl.lock(TransactionImpl.java:834)
 at org.jboss.tm.TransactionImpl.rollback(TransactionImpl.java:395)
 at net.uk.topdog.td2.common.server.statistics.MultithreadedTxTest$Worker
.run(MultithreadedTxTest.java:153)
11:48:12,250 ERROR [MultithreadedTxTest] Failed test
junit.framework.AssertionFailedError: rollback failed
 at junit.framework.Assert.fail(Assert.java:47)
 at junit.framework.Assert.assertTrue(Assert.java:20)
 at junit.framework.Assert.assertNull(Assert.java:233)
 at net.uk.topdog.td2.common.server.statistics.MultithreadedTxTest.testSi
multanWrite(MultithreadedTxTest.java:74)
 at net.uk.topdog.td2.common.server.statistics.MultithreadedTxTest.testSi
multanWrite(MultithreadedTxTest.java:44)
 at net.uk.topdog.td2.common.server.statistics.MultithreadedTxTest.myStar
tTest(MultithreadedTxTest.java:177)