2 Replies Latest reply on Sep 28, 2015 7:54 AM by stephenklau

    InvocationContextInterceptor error

    stephenklau

      Hi,

       

      We are planning to adjust our logging for the org.infinispan.interceptors.InvocationContextInterceptor (please see the error below) so that this Error is not present in our logs.  This error occurs occasionally under heavy load.


      As we perceive this to be an optimistic lock failure. Is there any reason that this would be a bad idea?   Are we incorrect in our assessment of what this means?


      Thanks,


      - Stephen



       

      2015/09/25-13:05:47,116 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (Thread-9 (HornetQ-client-global-threads-371428664)) ISPN000136: Execution error: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from QA2-JCM-2-24352, see cause for remote stack trace

              at org.infinispan.remoting.transport.AbstractTransport.checkResponse(AbstractTransport.java:44) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.processSingleCall(CommandAwareRpcDispatcher.java:364) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommand(CommandAwareRpcDispatcher.java:165) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:563) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:290) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.distribution.VersionedDistributionInterceptor.prepareOnAffectedNodes(VersionedDistributionInterceptor.java:35) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitPrepareCommand(TxDistributionInterceptor.java:198) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.CacheWriterInterceptor.visitPrepareCommand(CacheWriterInterceptor.java:103) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:103) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.VersionedEntryWrappingInterceptor.visitPrepareCommand(VersionedEntryWrappingInterceptor.java:51) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:78) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:87) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:36) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:132) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:119) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:103) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitPrepareCommand(TransactionSynchronizerInterceptor.java:42) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

        at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:244) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.statetransfer.StateTransferInterceptor.handleTxCommand(StateTransferInterceptor.java:171) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.statetransfer.StateTransferInterceptor.visitPrepareCommand(StateTransferInterceptor.java:99) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:103) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:103) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:104) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:73) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:103) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:122) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:104) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.transaction.xa.TransactionXaAdapter.prepare(TransactionXaAdapter.java:92) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:213)

              at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2522)

              at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2489)

              at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2066)

              at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1481)

              at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98)

              at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)

              at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189)

              at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)

              at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)

              at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:72) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]

              at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source) [:1.7.0_80]

              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_80]

              at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_80]

              at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]

              at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]

              at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]

              at com.sun.proxy.$Proxy181.afterDelivery(Unknown Source)

              at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:337)

              at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:1117)

              at org.hornetq.core.client.impl.ClientConsumerImpl.access$500(ClientConsumerImpl.java:57)

              at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1252)

              at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:105)

              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_80]

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_80]

              at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_80]

      Caused by: org.infinispan.transaction.WriteSkewException: Write skew detected on key 9f097996-6cd6-4852-980a-bfe8f997ad49 for transaction null

              at org.infinispan.transaction.WriteSkewHelper.performWriteSkewCheckAndReturnNewVersions(WriteSkewHelper.java:53) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.clusteredCreateNewVersionsAndCheckForWriteSkews(ClusteringDependentLogic.java:148) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.createNewVersionsAndCheckForWriteSkews(ClusteringDependentLogic.java:89) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.VersionedEntryWrappingInterceptor.visitPrepareCommand(VersionedEntryWrappingInterceptor.java:53) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:78) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:87) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]

              at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:125) [infinispan-core-6.2.1.Final-redhat-2.jar:6.2.1.Final-redhat-2]