IllegalStateException during the prepare phase of transaction
suenda Feb 11, 2019 3:59 AMI am running an Infinispan cluster (version 9.0.1) composed of two nodes (let's call them node A and B). I have a transaction in which I update several caches. Recently, I have been having problem with some transaction commit. It seems during the prepare phase of the transaction, a RPC is made to the other node (node B) that terminates with an IllegalStateException and which causes the transaction to fail and rollback. The problem seems to occur only for few specific keys arbitrarily and with this particular node (node B) during RPC. For instance, if I change the originating node from A to B, meaning the RPC is made from B to A, the transaction succeeds without any issue.
The exception thrown on node B is as follows:
java.lang.IllegalStateException: Entries cannot have null versions! at org.infinispan.container.entries.VersionedRepeatableReadEntry.getCurrentEntryVersion(VersionedRepeatableReadEntry.java:92) at org.infinispan.container.entries.VersionedRepeatableReadEntry.performWriteSkewCheck(VersionedRepeatableReadEntry.java:53) at org.infinispan.transaction.impl.WriteSkewHelper.performWriteSkewCheckAndReturnNewVersions(WriteSkewHelper.java:57) at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.clusteredCreateNewVersionsAndCheckForWriteSkews(ClusteringDependentLogic.java:317) at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.createNewVersionsAndCheckForWriteSkews(ClusteringDependentLogic.java:177) at org.infinispan.interceptors.impl.VersionedEntryWrappingInterceptor.lambda$visitPrepareCommand$0(VersionedEntryWrappingInterceptor.java:63) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:84) at org.infinispan.interceptors.impl.VersionedEntryWrappingInterceptor.visitPrepareCommand(VersionedEntryWrappingInterceptor.java:57) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.impl.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:44) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:45) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:186) at org.infinispan.interceptors.impl.TxInterceptor.handlePrepareCommand(TxInterceptor.java:147) at org.infinispan.interceptors.impl.TxInterceptor.visitPrepareCommand(TxInterceptor.java:136) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.partitionhandling.impl.PartitionHandlingInterceptor.visitPrepareCommand(PartitionHandlingInterceptor.java:181) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.BaseAsyncInterceptor.lambda$new$0(BaseAsyncInterceptor.java:20) at org.infinispan.interceptors.InvocationSuccessFunction.apply(InvocationSuccessFunction.java:21) at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:67) at org.infinispan.interceptors.InvocationStage.thenApply(InvocationStage.java:24) at org.infinispan.interceptors.BaseAsyncInterceptor.asyncInvokeNext(BaseAsyncInterceptor.java:227) at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:46) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:188) at org.infinispan.statetransfer.StateTransferInterceptor.handleTxCommand(StateTransferInterceptor.java:180) at org.infinispan.statetransfer.StateTransferInterceptor.visitPrepareCommand(StateTransferInterceptor.java:66) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:53) at org.infinispan.interceptors.DDAsyncInterceptor.visitPrepareCommand(DDAsyncInterceptor.java:127) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:126) at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:94) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:59) at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:53) at org.infinispan.interceptors.DDAsyncInterceptor.visitPrepareCommand(DDAsyncInterceptor.java:127) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:49) at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234) at org.infinispan.commands.tx.PrepareCommand.invokeAsync(PrepareCommand.java:100) at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:90) at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:90) at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:68) at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
The stacktrace on node A is as follows :
[WARN ] (XAResourceRecord:234) ARJUNA016041: prepare on < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a089c85:da7d:5c5dae66:4849, node_name=1, branch_uid=0:ffff0a089c85:da7d:5c5dae66:484d, subordinatenodename=null, eis_name=0 > (TransactionXaAdapter{localTransaction=LocalXaTransaction{xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a089c85:da7d:5c5dae66:4849, node_name=1, branch_uid=0:ffff0a089c85:da7d:5c5dae66:484d, subordinatenodename=null, eis_name=0 >} LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, lockedKeys=[], backupKeyLocks=[], topologyId=3, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@1284}) failed with exception XAException.XA_RBROLLBACK javax.transaction.xa.XAException at org.infinispan.transaction.impl.TransactionCoordinator.prepare(TransactionCoordinator.java:150) at org.infinispan.transaction.impl.TransactionCoordinator.prepare(TransactionCoordinator.java:113) at org.infinispan.transaction.xa.XaTransactionTable.prepare(XaTransactionTable.java:110) at org.infinispan.transaction.xa.TransactionXaAdapter.prepare(TransactionXaAdapter.java:60) at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:217) at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2627) at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2577) at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2131) at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1515) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) at com.sncf.gaia.infinispan.InfinispanEntityStore.store(InfinispanEntityStore.java:161) at com.sncf.gaia.gestion.data.access.GaiaEntityStore.store(GaiaEntityStore.java:91) at com.sncf.gaia.ws.method.impl.PutImpl.put(PutImpl.java:50) at com.sncf.gaia.ws.RestEntityService.putData(RestEntityService.java:74) at rff.services.Service.putData(Service.java:149) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:180) at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96) at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:189) at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:99) at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:262) at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:180) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:299) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPut(AbstractHTTPServlet.java:235) at javax.servlet.http.HttpServlet.service(HttpServlet.java:651) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:274) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:108) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:620) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:349) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1110) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1425) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Caused by: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from P70SDEMVKYR-55942, see cause for remote stack trace at org.infinispan.remoting.transport.AbstractTransport.checkResponse(AbstractTransport.java:44) at org.infinispan.remoting.transport.jgroups.JGroupsTransport.checkRsp(JGroupsTransport.java:918) at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$3(JGroupsTransport.java:687) at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602) at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) at org.infinispan.remoting.transport.jgroups.RspListFuture.requestDone(RspListFuture.java:53) at org.infinispan.remoting.transport.jgroups.RspListFuture.accept(RspListFuture.java:48) at org.infinispan.remoting.transport.jgroups.RspListFuture.accept(RspListFuture.java:19) at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760) at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736) at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) at org.jgroups.blocks.GroupRequest.receiveResponse(GroupRequest.java:106) at org.infinispan.remoting.transport.jgroups.CustomRequestCorrelator.handleResponse(CustomRequestCorrelator.java:50) at org.jgroups.blocks.RequestCorrelator.dispatch(RequestCorrelator.java:363) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:307) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:579) at org.jgroups.JChannel.up(JChannel.java:792) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:893) at org.jgroups.protocols.FRAG3.up(FRAG3.java:171) at org.jgroups.protocols.FlowControl.up(FlowControl.java:345) at org.jgroups.protocols.FlowControl.up(FlowControl.java:345) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:867) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:240) at org.jgroups.protocols.UNICAST3.deliverMessage(UNICAST3.java:1061) at org.jgroups.protocols.UNICAST3.handleDataReceived(UNICAST3.java:787) at org.jgroups.protocols.UNICAST3.up(UNICAST3.java:440) at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:598) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:129) at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:197) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:252) at org.jgroups.protocols.MERGE3.up(MERGE3.java:277) at org.jgroups.protocols.Discovery.up(Discovery.java:262) at org.jgroups.protocols.TP.passMessageUp(TP.java:1203) at org.jgroups.util.SubmitToThreadPool$SingleMessageHandler.run(SubmitToThreadPool.java:87) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ... 1 more Caused by: java.lang.IllegalStateException: Entries cannot have null versions! at org.infinispan.container.entries.VersionedRepeatableReadEntry.getCurrentEntryVersion(VersionedRepeatableReadEntry.java:92) at org.infinispan.container.entries.VersionedRepeatableReadEntry.performWriteSkewCheck(VersionedRepeatableReadEntry.java:53) at org.infinispan.transaction.impl.WriteSkewHelper.performWriteSkewCheckAndReturnNewVersions(WriteSkewHelper.java:57) at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.clusteredCreateNewVersionsAndCheckForWriteSkews(ClusteringDependentLogic.java:317) at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.createNewVersionsAndCheckForWriteSkews(ClusteringDependentLogic.java:177) at org.infinispan.interceptors.impl.VersionedEntryWrappingInterceptor.lambda$visitPrepareCommand$0(VersionedEntryWrappingInterceptor.java:63) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:84) at org.infinispan.interceptors.impl.VersionedEntryWrappingInterceptor.visitPrepareCommand(VersionedEntryWrappingInterceptor.java:57) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.impl.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:44) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:45) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:186) at org.infinispan.interceptors.impl.TxInterceptor.handlePrepareCommand(TxInterceptor.java:147) at org.infinispan.interceptors.impl.TxInterceptor.visitPrepareCommand(TxInterceptor.java:136) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.partitionhandling.impl.PartitionHandlingInterceptor.visitPrepareCommand(PartitionHandlingInterceptor.java:181) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.BaseAsyncInterceptor.lambda$new$0(BaseAsyncInterceptor.java:20) at org.infinispan.interceptors.InvocationSuccessFunction.apply(InvocationSuccessFunction.java:21) at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:67) at org.infinispan.interceptors.InvocationStage.thenApply(InvocationStage.java:24) at org.infinispan.interceptors.BaseAsyncInterceptor.asyncInvokeNext(BaseAsyncInterceptor.java:227) at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:46) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:188) at org.infinispan.statetransfer.StateTransferInterceptor.handleTxCommand(StateTransferInterceptor.java:180) at org.infinispan.statetransfer.StateTransferInterceptor.visitPrepareCommand(StateTransferInterceptor.java:66) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:57) at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:53) at org.infinispan.interceptors.DDAsyncInterceptor.visitPrepareCommand(DDAsyncInterceptor.java:127) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:126) at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:94) at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:59) at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:53) at org.infinispan.interceptors.DDAsyncInterceptor.visitPrepareCommand(DDAsyncInterceptor.java:127) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:176) at org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:49) at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234) at org.infinispan.commands.tx.PrepareCommand.invokeAsync(PrepareCommand.java:100) at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:90) at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:90) at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:68) at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40) ... 3 more
Thanks in advance for any pointers.