Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-5386

Tx succeeds on coord, while being rollbacked on other participants due to Tx pruning

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Major
    • 7.2.0.Final
    • None
    • Core
    • None

    Description

      All participants of transaction share the same topology. TX gets successfully prepared & commited on coordinator.

      03:49:27,759 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-1,edg-perf08-48196) New view accepted: [edg-perf08-48196|18] (5) [edg-perf08-48196, edg-perf01-23632, edg-perf02-34805, edg-perf03-16232, edg-perf04-41106]
      03:49:41,051 TRACE [org.infinispan.statetransfer.StateTransferManagerImpl] (transport-thread-9) Installing new cache topology CacheTopology{id=53, rebalanceId=19, currentCH=DefaultConsistentHash{ns = 512, owners = (5)[edg-perf08-48196: 103+101, edg-perf01-23632: 102+103, edg-perf02-34805: 102+103, edg-perf03-16232: 102+103, edg-perf04-41106: 103+102]}, pendingCH=null, unionCH=null, actualMembers=[edg-perf08-48196, edg-perf01-23632, edg-perf02-34805, edg-perf03-16232, edg-perf04-41106]} on cache testCache
      ...
      03:51:34,005 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-1) edg-perf08-48196 invoking PrepareCommand { ... gtx=GlobalTransaction:<edg-perf08-48196>:13330:local, cacheName='testCache', topologyId=53} to recipient list [edg-perf03-16232, edg-perf08-48196, edg-perf02-34805, edg-perf04-41106, edg-perf01-23632]
      03:51:36,329 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-1) Responses: [sender=edg-perf03-16232,received=true, suspected=false] [sender=edg-perf02-34805, received=true, suspected=false] [sender=edg-perf04-41106, received=true, suspected=false] [sender=edg-perf01-23632, received=true, suspected=false]
      03:51:36,342 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-1) edg-perf08-48196 invoking CommitCommand {gtx=GlobalTransaction:<edg-perf08-48196>:13330:local, cacheName='testCache', topologyId=53} to recipient list [edg-perf03-16232, edg-perf08-48196, edg-perf02-34805, edg-perf04-41106, edg-perf01-23632] with options RpcOptions{timeout=60000, unit=MILLISECONDS, fifoOrder=false, totalOrder=false, responseFilter=null, responseMode=SYNCHRONOUS_IGNORE_LEAVERS, skipReplicationQueue=false}
      03:51:36,703 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-1) Responses: [sender=edg-perf03-16232, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false] [sender=edg-perf02-34805, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false] [sender=edg-perf04-41106, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false] [sender=edg-perf01-23632, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false]
      

      The problem is, that other participating nodes rollback it, as TX with higher id was completed before. Successfull response is returned for both prepare & commit commands.

      03:49:58,190 TRACE [org.infinispan.transaction.TransactionTable] (remote-thread-499) Marking transaction GlobalTransaction:<edg-perf08-48196>:13337:local as completed
      ...
      03:51:34,122 TRACE [org.infinispan.transaction.TransactionTable] (remote-thread-593) Created and registered remote transaction RemoteTransaction{ ...  lookedUpEntries={}, lockedKeys=null, backupKeyLocks=null, lookedUpEntriesTopology=2147483647, isMarkedForRollback=false, tx=GlobalTransaction:<edg-perf08-48196>:13330:remote, state=null}
      03:51:34,073 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-593) Calling perform() on PrepareCommand { ... gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
      03:51:34,342 TRACE [org.infinispan.interceptors.TxInterceptor] (remote-thread-593) Rolling back remote transaction GlobalTransaction:<edg-perf08-48196>:13330:remote because either already completed (true) or originator no longer in the cluster (false).
      03:51:34,639 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-593) About to send back response null for command PrepareCommand { ... gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
      03:51:36,355 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-589) Calling perform() on CommitCommand {gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
      03:51:36,355 TRACE [org.infinispan.commands.tx.AbstractTransactionBoundaryCommand] (remote-thread-589) Did not find a RemoteTransaction for GlobalTransaction:<edg-perf08-48196>:13330:remote
      03:51:36,355 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-589) About to send back response SuccessfulResponse{responseValue=null}  for command CommitCommand {gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
      

      Exception response should be returned instead to avoid incorrect assumptions about presence of updated entry in the cache.

      dberinde@redhat.com spotted lastPrunedTxId modifications are not logged, let's make sure they are.

      Attachments

        Activity

          People

            dberinde@redhat.com Dan Berindei (Inactive)
            mcimbora_jira Matej Čimbora (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: