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

Inconsistent data after transaction rollback (with success on originator)

XMLWordPrintable

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

      Scenario
      Nodes edg-perf[10-13], partition handling on

      1.Transaction is started on edg-perf10

      10:24:48,228 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (DefaultStressor-6) start called on tx GlobalTransaction:<edg-perf10-20667>:38910:local
      

      2. Value of key_000000000000065B is updated within the transaction

      10:24:48,405 TRACE [org.radargun.service.InfinispanOperations$Cache] (DefaultStressor-6) PUT cache=testCache key=key_000000000000065B value=[6 #15: 296, 501, 1109, 1119, 1459, 1544, 1999, 2083, 2130, 2257, 2298, 2784, 2941, 3009, 3147, ]
      

      3. Transaction is successfully prepared on edg-perf11 & edg-perf12

      10:24:48,559 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-6) Responses: [sender=edg-perf11-61837, received=true, suspected=false]
      [sender=edg-perf12-7305, received=true, suspected=false] 
      

      4. Transaction commit is issued

      10:24:48,562 TRACE [org.infinispan.transaction.TransactionCoordinator] (DefaultStressor-6) Committing transaction GlobalTransaction:<edg-perf10-20667>:38910:local
      

      5. Other participating nodes (edg-perf11 & edg-perf12) are suspected...

      10:24:52,705 TRACE [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (DefaultStressor-6) Target node edg-perf11-61837 left during remote call, ignoring
      10:24:52,716 TRACE [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (DefaultStressor-6) Target node edg-perf12-7305 left during remote call, ignoring
      

      ... as they received a new view (without edg-perf10) meanwhile.

      10:24:48,547 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-1,edg-perf12-7305) ISPN000093: Received new, MERGED cluster view: MergeView::[edg-perf12-7305|20] (3) [edg-perf12-7305, edg-perf11-61837, edg-perf13-25187], 2 subgroups: [edg-perf13-25187|8] (1) [edg-perf13-25187], [edg-perf13-25187|19] (1) [edg-perf13-25187]
      

      Still, the transaction is commited on edg-perf10 & updated entry is stored locally

      10:24:52,894 TRACE [org.infinispan.statetransfer.CommitManager] (DefaultStressor-6) Trying to commit. Key=key_000000000000065B. Operation Flag=null, L1 invalidation=false
      10:24:52,896 TRACE [org.infinispan.statetransfer.CommitManager] (DefaultStressor-6) Committing key=key_000000000000065B. It is a L1 invalidation or a normal put and no tracking is enabled!
      10:24:52,908 TRACE [org.infinispan.container.DefaultDataContainer] (DefaultStressor-6) Creating new ICE for writing. Existing=ImmortalCacheEntry{key=key_000000000000065B, value=[6 #14: 296, 501, 1109, 1119, 1459, 1544, 1999, 2083, 2130, 2257, 2298, 2784, 2941, 3009, ]}, metadata=EmbeddedMetadata{version=null}, new value=[6 #15: 296, 501, 1109, 1119, 1459, 1544, 1999, 2083, 2130, 2257, 2298, 2784, 2941, 3009, 3147, ]
      

      6. Other nodes rollback the transaction

      10:24:50,376 DEBUG [org.infinispan.transaction.TransactionTable] (transport-thread-10) Rolling back transaction GlobalTransaction:<edg-perf10-20667>:38910:remote because originator edg-perf10-20667 left the cluster
      

      7. edg-perf10 receives a new view, containing nodes edg-perf[10,11,13]. Incoming state transfer overwrites the updated value

      10:25:09,614 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-2,edg-perf10-20667) ISPN000093: Received new, MERGED cluster view: MergeView::[edg-perf10-20667|22] (3) [edg-perf10-20667, edg-perf11-61837, edg-perf13-25187], 4 subgroups: [edg-perf10-20667|15] (2) [edg-perf10-20667, edg-perf11-61837], [edg-perf10-20667|19] (3) [edg-perf10-20667, edg-perf12-7305, edg-perf11-61837], [edg-perf10-20667|18] (1) [edg-perf10-20667], [edg-perf10-20667|21] (2) [edg-perf10-20667, edg-perf13-25187]
      

      8. get operation returns outdated value

      10:26:21,020 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-6) Response(s) to ClusteredGetCommand{key=key_000000000000065B, flags=null} is {edg-perf12-7305=SuccessfulResponse{responseValue=ImmortalCacheValue {value=[6 #14: 296, 501, 1109, 1119, 1459, 1544, 1999, 2083, 2130, 2257, 2298, 2784, 2941, 3009, ]}} }
      

      From client perspective, this behavior is not transparent. Provided the transaction ended up successfully, presence of the updated entry can be assumed.

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

                Created:
                Updated:
                Resolved: