[ https://issues.jboss.org/browse/JBCACHE-1613?page=com.atlassian.jira.plug... ] Dennis Reed updated JBCACHE-1613: --------------------------------- Description: After switching to JTS for transactions, "random" lock timeouts occur: org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/foo] after [15000] milliseconds for requestor [GlobalTransaction:<10.1.2.3:12345>:5]! Lock held by [null] at org.jboss.cache.mvcc.MVCCNodeHelper.acquireLock(MVCCNodeHelper.java:157) The actual cause is only logged at TRACE level: TRACE [org.jboss.cache.lock.MVCCLockManager] (RequestProcessor-97) Attempting to unlock /foo TRACE [org.jboss.cache.lock.MVCCLockManager] (RequestProcessor-97) Caught exception and ignoring. java.lang.IllegalMonitorStateException: org.jboss.cache.util.concurrent.locks.OwnableReentrantLock@4d93ddfa[State = 1, empty queue][Locked by GlobalTransaction:<10.1.2.3:12345>:4] at org.jboss.cache.util.concurrent.locks.OwnableReentrantLock.tryRelease(OwnableReentrantLock.java:139) at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1239) at org.jboss.cache.util.concurrent.locks.OwnableReentrantLock.unlock(OwnableReentrantLock.java:105) at org.jboss.cache.util.concurrent.locks.PerElementLockContainer.releaseLock(PerElementLockContainer.java:112) at org.jboss.cache.lock.MVCCLockManager.unlock(MVCCLockManager.java:147) at org.jboss.cache.interceptors.MVCCLockingInterceptor.cleanupLocks(MVCCLockingInterceptor.java:375) at org.jboss.cache.interceptors.MVCCLockingInterceptor.transactionalCleanup(MVCCLockingInterceptor.java:400) at org.jboss.cache.interceptors.MVCCLockingInterceptor.handlePrepareCommand(MVCCLockingInterceptor.java:332) ... The root cause is that JTS commits transactions in a different thread than the one calling commit. Under load, it even uses different threads for each call during the same transaction commit (beforeCompletion/afterCompletion). JBoss Cache stores some data in ThreadLocals, and when different threads call beforeCompletion and afterCompletion for the same transaction, it causes it to mix the data between the transactions causing data corruption. Particularly the "ctx = invocationContextContainer.get();" calls in org.jboss.cache.interceptors.TxInterceptor beforeCompletion and afterCompletion. was: After switching to JTS for transactions, "random" lock timeouts occur: org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/foo] after [15000] milliseconds for requestor [GlobalTransaction:<10.1.2.3:12345>:5]! Lock held by [null] at org.jboss.cache.mvcc.MVCCNodeHelper.acquireLock(MVCCNodeHelper.java:157) The actual cause is only logged at TRACE level: TRACE [org.jboss.cache.lock.MVCCLockManager] (RequestProcessor-97) Attempting to unlock /foo TRACE [org.jboss.cache.lock.MVCCLockManager] (RequestProcessor-97) Caught exception and ignoring. java.lang.IllegalMonitorStateException: org.jboss.cache.util.concurrent.locks.OwnableReentrantLock@4d93ddfa[State = 1, empty queue][Locked by GlobalTransaction:<10.1.2.3:12345>:4] at org.jboss.cache.util.concurrent.locks.OwnableReentrantLock.tryRelease(OwnableReentrantLock.java:139) at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1239) at org.jboss.cache.util.concurrent.locks.OwnableReentrantLock.unlock(OwnableReentrantLock.java:105) at org.jboss.cache.util.concurrent.locks.PerElementLockContainer.releaseLock(PerElementLockContainer.java:112) at org.jboss.cache.lock.MVCCLockManager.unlock(MVCCLockManager.java:147) at org.jboss.cache.interceptors.MVCCLockingInterceptor.cleanupLocks(MVCCLockingInterceptor.java:375) at org.jboss.cache.interceptors.MVCCLockingInterceptor.transactionalCleanup(MVCCLockingInterceptor.java:400) at org.jboss.cache.interceptors.MVCCLockingInterceptor.handlePrepareCommand(MVCCLockingInterceptor.java:332) ... The root cause is that JTS commits transactions in a different thread than the one calling commit. Under load, it even uses different threads for each call during the same transaction commit (beforeCompletion/afterCompletion). JBoss Cache stores some data in ThreadLocals, and when different threads call beforeCompletion and afterCompletion for the same transaction, it causes it to mix the data between the transactions causing data corruption. Steps to Reproduce: Enable JTS: cd $JBOSS_HOME/docs/examples/transactions modify target.server.dir in build.xml to point to the correct profile ant jts Configure a cache using transactions, MVCC, and REPL_ASYNC (could not reproduce with LOCAL, possibly just because of timing). Start two nodes in a cluster. In multiple threads, run the following in a loop: tm.begin (); cache.put ( "/foo/bar", "foo", "bar" ); tm.commit (); (I was able to reproduce the issue multiple times with 2 threads running 100 iterations each). Expected result: No errors Actual result: org.jboss.cache.lock.TimeoutException errors Possibly other errors, such as "ERROR [TxInterceptor] Transaction has a null transaction entry - beforeCompletion() will fail." was: Enable JTS: cd $JBOSS_HOME/docs/examples/transactions # modify target.server.dir in build.xml to point to the correct profile ant jts Configure a cache using transactions, MVCC, and REPL_ASYNC (could not reproduce with LOCAL, possibly just because of timing). Start two nodes in a cluster. In multiple threads, run the following in a loop: tm.begin (); cache.put ( "/foo/bar", "foo", "bar" ); tm.commit (); (I was able to reproduce the issue multiple times with 2 threads running 100 iterations each). Expected result: No errors Actual result: org.jboss.cache.lock.TimeoutException errors Possibly other errors, such as "ERROR [TxInterceptor] Transaction has a null transaction entry - beforeCompletion() will fail." -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://issues.jboss.org/browse/JBCACHE-1613?page=com.atlassian.jira.plug... ] Dennis Reed updated JBCACHE-1613: --------------------------------- Steps to Reproduce: Enable JTS: cd $JBOSS_HOME/docs/examples/transactions modify target.server.dir in build.xml to point to the correct profile ant jts Configure a cache using transactions, MVCC, and REPL_ASYNC (I could not reproduce with LOCAL, possibly just because of timing, and didn't try REPL_SYNC). For instance, using the "timestamps-cache" after adding the following: <property name="transactionManagerLookupClass">org.jboss.cache.transaction.GenericTransactionManagerLookup</property> Start two nodes in a cluster. In multiple threads, run the following in a loop: tm.begin (); cache.put ( "/foo/bar", "foo", "bar" ); tm.commit (); See attached JTSCache for a test case: new JTSCache().test(); (I was able to reproduce the issue multiple times with 2 threads running 100 iterations each). Expected result: No errors Actual result: org.jboss.cache.lock.TimeoutException errors Possibly other errors, such as "ERROR [TxInterceptor] Transaction has a null transaction entry - beforeCompletion() will fail." was: Enable JTS: cd $JBOSS_HOME/docs/examples/transactions modify target.server.dir in build.xml to point to the correct profile ant jts Configure a cache using transactions, MVCC, and REPL_ASYNC (could not reproduce with LOCAL, possibly just because of timing). Start two nodes in a cluster. In multiple threads, run the following in a loop: tm.begin (); cache.put ( "/foo/bar", "foo", "bar" ); tm.commit (); (I was able to reproduce the issue multiple times with 2 threads running 100 iterations each). Expected result: No errors Actual result: org.jboss.cache.lock.TimeoutException errors Possibly other errors, such as "ERROR [TxInterceptor] Transaction has a null transaction entry - beforeCompletion() will fail." -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://issues.jboss.org/browse/JBCACHE-1613?page=com.atlassian.jira.plug... ] Work on JBCACHE-1613 started by Dennis Reed. -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://issues.jboss.org/browse/JBCACHE-1613?page=com.atlassian.jira.plug... ] Dennis Reed updated JBCACHE-1613: --------------------------------- Steps to Reproduce: Enable JTS: cd $JBOSS_HOME/docs/examples/transactions modify target.server.dir in build.xml to point to the correct profile ant jts Configure a cache using transactions, MVCC, and REPL_ASYNC (I have not tested whether modes other than REPL_ASYNC also trigger it) For instance, using the "timestamps-cache" after adding the following: <property name="transactionManagerLookupClass">org.jboss.cache.transaction.GenericTransactionManagerLookup</property> In multiple threads, run the following in a loop: tm.begin (); cache.put ( "/foo/bar", "foo", "bar" ); tm.commit (); See attached JTSCache for a test case: new JTSCache().test(); (I was able to reproduce the issue multiple times with 2 threads running 100 iterations each). Expected result: No errors Actual result: org.jboss.cache.lock.TimeoutException errors Possibly other errors, such as "ERROR [TxInterceptor] Transaction has a null transaction entry - beforeCompletion() will fail." was: Enable JTS: cd $JBOSS_HOME/docs/examples/transactions modify target.server.dir in build.xml to point to the correct profile ant jts Configure a cache using transactions, MVCC, and REPL_ASYNC (I could not reproduce with LOCAL, possibly just because of timing, and didn't try REPL_SYNC). For instance, using the "timestamps-cache" after adding the following: <property name="transactionManagerLookupClass">org.jboss.cache.transaction.GenericTransactionManagerLookup</property> Start two nodes in a cluster. In multiple threads, run the following in a loop: tm.begin (); cache.put ( "/foo/bar", "foo", "bar" ); tm.commit (); See attached JTSCache for a test case: new JTSCache().test(); (I was able to reproduce the issue multiple times with 2 threads running 100 iterations each). Expected result: No errors Actual result: org.jboss.cache.lock.TimeoutException errors Possibly other errors, such as "ERROR [TxInterceptor] Transaction has a null transaction entry - beforeCompletion() will fail." -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa For more information on JIRA, see: http://www.atlassian.com/software/jira