Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-14762

Concurrency issue with "ISPN000482: Cannot create remote transaction GlobalTx:xx:xx, already completed"

    XMLWordPrintable

Details

    Description

      The globalMaxPrunedTxId value is updated by the scheduled thread[1].

      [1]
      "timeout-thread--p12-t1" #161 daemon prio=5 os_prio=0 tid=0x000055a324a6c800 nid=0x2017 at breakpoint[0x00007f4a87af2000]
         java.lang.Thread.State: RUNNABLE
      	at org.infinispan.transaction.impl.TransactionTable$CompletedTransactionsInfo.updateLastPrunedTxId(TransactionTable.java:832) ---------- [2]
      	at org.infinispan.transaction.impl.TransactionTable$CompletedTransactionsInfo.cleanupCompletedTransactions(TransactionTable.java:806)
      	at org.infinispan.transaction.impl.TransactionTable.lambda$start$0(TransactionTable.java:151)
      	at org.infinispan.transaction.impl.TransactionTable$$Lambda$924/1335696931.run(Unknown Source)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
      	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
      	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
      	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)
      
      [2] org.infinispan.transaction.impl.TransactionTable$CompletedTransactionsInfo.updateLastPrunedTxId(TransactionTable.java:832)
      830      private void updateLastPrunedTxId(final long txId, Address address) {
      831         if (txId > globalMaxPrunedTxId) {
      -> 832            globalMaxPrunedTxId = txId;
      833         }
      834         nodeMaxPrunedTxIds.compute(address, (a, nodeMaxPrunedTxId) -> {
      835            if (nodeMaxPrunedTxId != null && txId <= nodeMaxPrunedTxId) {
      836               return nodeMaxPrunedTxId;
      837            }
      838            return txId;
      839         });
      840      }
      

      If it is updated just before the evaluation of line 745 below[3], it will be determined that the transaction has already been completed and an exception will be output[4].

      [3] org.infinispan.transaction.impl.TransactionTable$CompletedTransactionsInfo
      737      boolean isTransactionCompleted(GlobalTransaction gtx) {
      738         if (completedTransactions.containsKey(gtx))
      739            return true;
      740
      741         // Transaction ids are allocated in sequence, so any transaction with a smaller id must have been started
      742         // before a transaction that was already removed from the completed transactions map because it was too old.
      743         // We assume that the transaction was either committed, or it was rolled back (e.g. because the prepare
      744         // RPC timed out.
      745         // Note: We must check the id *after* verifying that the tx doesn't exist in the map.
      -> 746         if (gtx.getId() > globalMaxPrunedTxId)
      747            return false;
      748         Long nodeMaxPrunedTxId = nodeMaxPrunedTxIds.get(gtx.getAddress());
      749         return nodeMaxPrunedTxId != null && gtx.getId() <= nodeMaxPrunedTxId;
      750      }
      
      [4]
      17:52:20,275 WARN  [org.infinispan.remoting.inboundhandler.NonTotalOrderTxPerCacheInboundInvocationHandler] (remote-thread--p5-t4) ISPN000071: Caught exception when handling command PrepareCommand {modifications=[PutKeyValueCommand{key=Se
      ssionCreationMetaDataKey(Q_GV2hvhBEK92kbV0VUrkDQyXZmFp9PR603LsYFv), value=org.wildfly.clustering.web.cache.session.SessionCreationMetaDataEntry@defbefa, flags=[FORCE_SYNCHRONOUS], commandInvocationId=CommandInvocation:local:0, putIfAbsent
      =true, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=null}, successful=true, topologyId=5}, PutKeyValueCommand{key=SessionAccessMetaDataKey(Q_GV2hvhBEK92kbV0VUrkDQyXZmFp9PR603LsYFv), value=
      org.wildfly.clustering.web.cache.session.SimpleSessionAccessMetaData@1a73f08f, flags=[IGNORE_RETURN_VALUES], commandInvocationId=CommandInvocation:local:0, putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedExpirableMetadata{l
      ifespan=-1, maxIdle=-1, version=null}, successful=true, topologyId=5}, PutKeyValueCommand{key=SessionAttributesKey(Q_GV2hvhBEK92kbV0VUrkDQyXZmFp9PR603LsYFv), value=[B@75e4ae75, flags=[IGNORE_RETURN_VALUES], commandInvocationId=CommandInvo
      cation:local:0, putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=null}, successful=true, topologyId=5}], onePhaseCommit=true, retried=false, gtx=GlobalTx:node1:2, cacheName=
      'test.war', topologyId=5}: org.infinispan.commons.CacheException: ISPN000482: Cannot create remote transaction GlobalTx:node1:2, already completed                                                                                           
              at org.infinispan.transaction.impl.TransactionTable.lambda$getOrCreateRemoteTransaction$1(TransactionTable.java:385)
              at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
              at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:378)
              at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:358)
              at org.infinispan.commands.tx.PrepareCommand.createContext(PrepareCommand.java:121)
              at org.infinispan.commands.tx.PrepareCommand.invokeAsync(PrepareCommand.java:102)
              at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:126)
              at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
              at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
              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 org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
              at java.lang.Thread.run(Thread.java:748)
      

      Attachments

        Issue Links

          Activity

            People

              spyrkob Bartosz Spyrko-Smietanko
              pferraro@redhat.com Paul Ferraro
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: