[infinispan-issues] [JBoss JIRA] (ISPN-2727) Transactional put failed after master node with enabled InfinispanIndexManager is killed

[Galder Zamarreño (JIRA)]

    [ https://issues.jboss.org/browse/ISPN-2727?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12751616#comment-12751616 ] 

Galder Zamarreño edited comment on ISPN-2727 at 1/31/13 10:50 AM:
------------------------------------------------------------------

The issue appears before any nodes have been killed. The problem seems related to ordering in which Hibernate and Infinispan synchronizations are executing. The actual exception is:

{code}2013-01-31 16:22:49,868 11797 DEBUG [org.infinispan.util.concurrent.locks.LockManagerImpl] 
(Hibernate Search: Index updates queue processor for index person-1:LuceneIndexesLocking) 
Failed to acquire lock write.lock|M|person, owner is GlobalTransaction:<null>:49:local{code}

So, when the first put is executed, org.infinispan.transaction.synchronization.SynchronizationAdapter is executed before org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization, and that leads to "write.lock|M|person" being correctly unlocked. The processor kicked off by Hibernate Search's synchronization can then acquire the lock on "write.lock|M|person" without probs.

Second time though, org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization is executed before org.infinispan.transaction.synchronization.SynchronizationAdapter, so the lock on "write.lock|M|person" is not released and the processing thread fails to acquire the lock as shown above.

Log snippets can be found in showing what I mentioned above:
https://gist.github.com/77207522649b79c814e0

IIRC, I've seen that before and AFAIK, JTA provides no guarantees in the order in which multiple synchronizations are executed. I tried disabling Infinispan's use of synchronization and the test then passes fine.

This needs some further debugging, but the solution could be here to not allow synchronization for indexed caches.
                
      was (Author: galder.zamarreno):
    The issue appears before any nodes have been killed. The problem seems related to ordering in which Hibernate and Infinispan synchronizations are executing. The actual exception is:

{code}2013-01-31 16:22:49,868 11797 DEBUG [org.infinispan.util.concurrent.locks.LockManagerImpl] (Hibernate Search: Index updates queue processor for index person-1:LuceneIndexesLocking) Failed to acquire lock write.lock|M|person, owner is GlobalTransaction:<null>:49:local{code}

So, when the first put is executed, org.infinispan.transaction.synchronization.SynchronizationAdapter is executed before org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization, and that leads to "write.lock|M|person" being correctly unlocked. The processor kicked off by Hibernate Search's synchronization can then acquire the lock on "write.lock|M|person" without probs.

Second time though, org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization is executed before org.infinispan.transaction.synchronization.SynchronizationAdapter, so the lock on "write.lock|M|person" is not released and the processing thread fails to acquire the lock as shown above.

Log snippets can be found in showing what I mentioned above:
https://gist.github.com/77207522649b79c814e0

IIRC, I've seen that before and AFAIK, JTA provides no guarantees in the order in which multiple synchronizations are executed. I tried disabling Infinispan's use of synchronization and the test then passes fine.

This needs some further debugging, but the solution could be here to not allow synchronization for indexed caches.
                  
> Transactional put failed after master node with enabled InfinispanIndexManager is killed 
> -----------------------------------------------------------------------------------------
>
>                 Key: ISPN-2727
>                 URL: https://issues.jboss.org/browse/ISPN-2727
>             Project: Infinispan
>          Issue Type: Bug
>          Components: Querying
>            Reporter: Anna Manukyan
>            Assignee: Galder Zamarreño
>             Fix For: 5.2.0.Final
>
>         Attachments: MultiNodeDistributedTest.java, MultiNodeLocalTest.java, MultiNodeLocalTxTest.java, MultiNodeReplicatedTest.java, MultiNodeReplicatedTxTest.java
>
>
> I've added new test, which uses the following Infinispan configuration: REPL_SYNC clustering mode, with transaction enabled, as well as enabled indexing with InfinispanIndexManager.
> The test adds several nodes with the described configuration, adds entries to different nodes, and checks that the query for the entries returns the same result for all nodes. 
> Then master node is killed, and then again new data is inserted and checked on all nodes. (Similiar test to https://github.com/infinispan/infinispan/blob/master/query/src/test/java/org/infinispan/query/distributed/MultiNodeReplicatedTest.java but with enabled transaction).
> When the test tries to insert new entry to one of the caches, after the master node kill, the following exception appears:
> {code}
> testIndexingWorkDistribution(org.infinispan.query.distributed.MultiNodeReplicatedTxTest)  Time elapsed: 1.656 sec  <<< FAILURE!
> javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
> 	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1177)
> 	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117)
> 	at org.infinispan.query.distributed.MultiNodeDistributedTest.storeOn(MultiNodeDistributedTest.java:78)
> 	at org.infinispan.query.distributed.MultiNodeDistributedTest.testIndexingWorkDistribution(MultiNodeDistributedTest.java:102)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:601)
> 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:80)
> 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:715)
> 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:907)
> 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1237)
> 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
> 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
> 	at org.testng.TestRunner.privateRun(TestRunner.java:767)
> 	at org.testng.TestRunner.run(TestRunner.java:617)
> 	at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
> 	at org.testng.SuiteRunner.access$000(SuiteRunner.java:37)
> 	at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:368)
> 	at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> 	at java.lang.Thread.run(Thread.java:722)
> Caused by: org.infinispan.CacheException: Could not prepare. 
> 	at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:70)
> 	at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
> 	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
> 	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
> 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:164)
> 	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165)
> 	... 24 more
> Caused by: javax.transaction.xa.XAException
> 	at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:161)
> 	at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:123)
> 	at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:68)
> 	... 29 more
> {code}
> You can find the test attached. The test which fails is MultiNodeReplicatedTxTest.java . The rest are the tests which are the parents and a bit modified compared to the version in infinispan repo.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira