[JBoss JIRA] (ISPN-5275) Verify that eager near cache doesn't obtain existing entries upon connecting
by Vojtech Juranek (JIRA)
Vojtech Juranek created ISPN-5275:
-------------------------------------
Summary: Verify that eager near cache doesn't obtain existing entries upon connecting
Key: ISPN-5275
URL: https://issues.jboss.org/browse/ISPN-5275
Project: Infinispan
Issue Type: Task
Components: Test Suite - Core
Reporter: Vojtech Juranek
Assignee: Vojtech Juranek
Implement test which would verify that eager near cache obtains only entries created after client has been connected to the server, entries created prior connecting client to server are obtained only upon request.
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
11 years, 1 month
[JBoss JIRA] (ISPN-5166) During ST, previously removed entry was revived
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5166?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration commented on ISPN-5166:
-----------------------------------------------
Matej Čimbora <mcimbora(a)redhat.com> changed the Status of [bug 1184373|https://bugzilla.redhat.com/show_bug.cgi?id=1184373] from ON_QA to VERIFIED
> During ST, previously removed entry was revived
> -----------------------------------------------
>
> Key: ISPN-5166
> URL: https://issues.jboss.org/browse/ISPN-5166
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 7.1.0.Beta1
> Reporter: Radim Vansa
> Assignee: Dan Berindei
> Priority: Critical
> Fix For: 7.2.0.Alpha1, 7.2.0.Final
>
> Attachments: cluster.txt, topo.txt
>
>
> In transactional mode, entry was removed (transaction succeeded and the entry was removed from data container), but later, when StateResponseCommand arrives, the entry is revived with the old value.
> Here is how the remove is executed on edg-perf01:
> {code}
> 07:50:08,276 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-5) Replication task sending PrepareCommand {modifications=[RemoveCommand{key=key_000000000000050E, value=null, flags=null, valueMatcher=MATCH_ALWAYS}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf01-21525>:95726:local, cacheName='testCache', topologyId=89} to single recipient edg-perf03-24234 with response mode GET_ALL
> 07:50:08,368 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-5) Response(s) to PrepareCommand {modifications=[RemoveCommand{key=key_000000000000050E, value=null, flags=null, valueMatcher=MATCH_ALWAYS}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf01-21525>:95726:local, cacheName='testCache', topologyId=89} is {edg-perf03-24234=null}
> 07:50:08,369 TRACE [org.infinispan.statetransfer.StateTransferManagerImpl] (DefaultStressor-5) Forwarding command PrepareCommand {modifications=[RemoveCommand{key=key_000000000000050E, value=null, flags=null, valueMatcher=MATCH_ALWAYS}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf01-21525>:95726:local, cacheName='testCache', topologyId=90} to new targets [edg-perf03-24234]
> 07:50:08,369 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-5) edg-perf01-21525 invoking PrepareCommand {modifications=[RemoveCommand{key=key_000000000000050E, value=null, flags=null, valueMatcher=MATCH_ALWAYS}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf01-21525>:95726:local, cacheName='testCache', topologyId=90} to recipient list [edg-perf03-24234] with options RpcOptions{timeout=60000, unit=MILLISECONDS, fifoOrder=false, totalOrder=false, responseFilter=null, responseMode=SYNCHRONOUS, skipReplicationQueue=false}
> 07:50:08,527 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-5) Response(s) to PrepareCommand {modifications=[RemoveCommand{key=key_000000000000050E, value=null, flags=null, valueMatcher=MATCH_ALWAYS}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf01-21525>:95726:local, cacheName='testCache', topologyId=90} is {edg-perf03-24234=null}
> 07:50:08,529 TRACE [org.infinispan.transaction.LocalTransaction] (DefaultStressor-5) getCommitNodes recipients=[edg-perf01-21525, edg-perf03-24234], currentTopologyId=90, members=[edg-perf03-24234, edg-perf01-21525, edg-perf04-55497], txTopologyId=88
> 07:50:08,531 TRACE [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (DefaultStressor-5) dests=[edg-perf01-21525, edg-perf03-24234], command=CommitCommand {gtx=GlobalTransaction:<edg-perf01-21525>:957
> 26:local, cacheName='testCache', topologyId=90}, mode=SYNCHRONOUS_IGNORE_LEAVERS, timeout=60000
> 07:50:08,531 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-5) Replication task sending CommitCommand {gtx=GlobalTransaction:<edg-perf01-21525>:95726:local, cacheNam
> e='testCache', topologyId=90} to addresses [edg-perf03-24234] with response mode GET_ALL
> 07:50:08,555 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-5) Responses: [sender=edg-perf03-24234, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false]
> 07:50:08,555 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (DefaultStressor-5) About to commit entry ReadCommittedEntry(49e1fe5d){key=key_000000000000050E, value=[5 #19: 380, 431, 453, 459, 467, 650, 851, 1209, 1405, 1893, 2080, 2353, 2353, 2685, 2950, 3702, 3936, 4188, 4973, ], oldValue=null, isCreated=false, isChanged=true, isRemoved=true, isValid=false, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
> 07:50:08,561 TRACE [org.infinispan.container.entries.ReadCommittedEntry] (DefaultStressor-5) Updating entry (key=key_000000000000050E removed=true valid=false changed=true created=false loaded=false value=[5 #19: 380, 431, 453, 459, 467, 650, 851, 1209, 1405, 1893, 2080, 2353, 2353, 2685, 2950, 3702, 3936, 4188, 4973, ] metadata=EmbeddedMetadata{version=null}, providedMetadata=null)
> 07:50:08,561 TRACE [org.infinispan.statetransfer.CommitManager] (DefaultStressor-5) Committed key=key_000000000000050E. Old discard policy=null. New discard policy=DiscardPolicy{discardStateTransfer=true, discardXSiteStateTransfer=false}
> {code}
> The commit command on edg-perf03 is executed only after the StateResponseCommand is sent (and received on edg-perf01):
> {code}
> 07:50:10,736 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (remote-thread-254) Invoked with command PutKeyValueCommand{key=key_000000000000050E, value=[5 #19: 380, 431, 453, 459, 467, 650, 851, 1209, 1405, 1893, 2080, 2353, 2353, 2685, 2950, 3702, 3936, 4188, 4973, ], flags=[CACHE_MODE_LOCAL, SKIP_REMOTE_LOOKUP, PUT_FOR_STATE_TRANSFER, SKIP_SHARED_CACHE_STORE, SKIP_OWNERSHIP_CHECK, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@3e54512]
> 07:50:10,747 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (remote-thread-254) start called on tx GlobalTransaction:<edg-perf01-21525>:95972:local
> 07:50:10,758 TRACE [org.infinispan.transaction.LocalTransaction] (remote-thread-254) Adding modification PutKeyValueCommand{key=key_000000000000050E, value=[5 #19: 380, 431, 453, 459, 467, 650, 851, 1209, 1405, 1893, 2080, 2353, 2353, 2685, 2950, 3702, 3936, 4188, 4973, ], flags=[CACHE_MODE_LOCAL, SKIP_REMOTE_LOOKUP, PUT_FOR_STATE_TRANSFER, SKIP_SHARED_CACHE_STORE, SKIP_OWNERSHIP_CHECK, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}. Mod list is null
> 07:50:10,763 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (remote-thread-254) end called on tx GlobalTransaction:<edg-perf01-21525>:95972:local(testCache)
> 07:50:10,763 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (remote-thread-254) Invoked with command PrepareCommand {modifications=null, onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf01-21525>:95972:local, cacheName='testCache', topologyId=-1} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@3df73149]
> 07:50:10,779 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (remote-thread-254) About to commit entry ReadCommittedEntry(206acaec){key=key_000000000000050E, value=[5 #19: 380, 431, 453, 459, 467, 650, 851, 1209, 1405, 1893, 2080, 2353, 2353, 2685, 2950, 3702, 3936, 4188, 4973, ], oldValue=null, isCreated=true, isChanged=true, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
> 07:50:10,779 TRACE [org.infinispan.statetransfer.CommitManager] (remote-thread-254) Trying to commit. Key=key_000000000000050E. Operation Flag=PUT_FOR_STATE_TRANSFER, L1 invalidation=false
> 07:50:10,782 TRACE [org.infinispan.container.DefaultDataContainer] (remote-thread-254) Store ImmortalCacheEntry{key=key_000000000000050E, value=[5 #19: 380, 431, 453, 459, 467, 650, 851, 1209, 1405, 1893, 2080, 2353, 2353, 2685, 2950, 3702, 3936, 4188, 4973, ]} in container
> {code}
> Later, I can see that the value was really writen to the container (further read retrieves it):
> {code}
> 07:53:26,778 TRACE [org.infinispan.container.EntryFactoryImpl] (DefaultStressor-5) Retrieved from container ImmortalCacheEntry{key=key_000000000000050E, value=[5 #19: 380, 431, 453, 459, 467, 650, 851, 1209, 1405, 1893, 2080, 2353, 2353, 2685, 2950, 3702, 3936, 4188, 4973, ]} (forceFetch=false, isLocal=true)
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
11 years, 1 month
[JBoss JIRA] (ISPN-5274) Inconsistent data after transaction rollback (with success on originator)
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5274?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration updated ISPN-5274:
------------------------------------------
Bugzilla References: https://bugzilla.redhat.com/show_bug.cgi?id=1199490, https://bugzilla.redhat.com/show_bug.cgi?id=1180680 (was: https://bugzilla.redhat.com/show_bug.cgi?id=1199490)
> Inconsistent data after transaction rollback (with success on originator)
> -------------------------------------------------------------------------
>
> Key: ISPN-5274
> URL: https://issues.jboss.org/browse/ISPN-5274
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Reporter: Matej Čimbora
> Assignee: Dan Berindei
>
> Scenario
> Nodes edg-perf[10-13], partition handling on
> 1.Transaction is started on edg-perf10
> {code}
> 10:24:48,228 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (DefaultStressor-6) start called on tx GlobalTransaction:<edg-perf10-20667>:38910:local
> {code}
> 2. Value of key_000000000000065B is updated within the transaction
> {code}
> 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, ]
> {code}
> 3. Transaction is successfully prepared on edg-perf11 & edg-perf12
> {code}
> 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]
> {code}
> 4. Transaction commit is issued
> {code}
> 10:24:48,562 TRACE [org.infinispan.transaction.TransactionCoordinator] (DefaultStressor-6) Committing transaction GlobalTransaction:<edg-perf10-20667>:38910:local
> {code}
> 5. Other participating nodes (edg-perf11 & edg-perf12) are suspected...
> {code}
> 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
> {code}
> ... as they received a new view (without edg-perf10) meanwhile.
> {code}
> 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]
> {code}
> Still, the transaction is commited on edg-perf10 & updated entry is stored locally
> {code}
> 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, ]
> {code}
> 6. Other nodes rollback the transaction
> {code}
> 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
> {code}
> 7. edg-perf10 receives a new view, containing nodes edg-perf[10,11,13]. Incoming state transfer overwrites the updated value
> {code}
> 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]
> {code}
> 8. get operation returns outdated value
> {code}
> 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, ]}} }
> {code}
> From client perspective, this behavior is not transparent. Provided the transaction ended up successfully, presence of the updated entry can be assumed.
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
11 years, 1 month
[JBoss JIRA] (ISPN-5137) Transaction from new topology rolled back (but succeeds on originator)
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5137?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration commented on ISPN-5137:
-----------------------------------------------
Matej Čimbora <mcimbora(a)redhat.com> changed the Status of [bug 1180680|https://bugzilla.redhat.com/show_bug.cgi?id=1180680] from ON_QA to ASSIGNED
> Transaction from new topology rolled back (but succeeds on originator)
> ----------------------------------------------------------------------
>
> Key: ISPN-5137
> URL: https://issues.jboss.org/browse/ISPN-5137
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 7.1.0.Alpha1, 7.0.3.Final
> Reporter: Radim Vansa
> Assignee: Dan Berindei
> Priority: Critical
> Fix For: 7.1.0.CR2
>
>
> During a merge of (edg-perf01, edg-perf02, edg-perf03) + (edg-perf04), transaction executed on edg-perf04 in latest topology is silently rolled back and commit command is ignored since the topology has not arrived yet.
> Topologies on edg-perf04
> {code}
> 09:06:38,233 DEBUG [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread-23) Updating cluster-wide current topology for cache testCache, topology = CacheTopology{id=51, rebalanceId=12, currentCH
> =DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=null, unionCH=null, actualMembers=[edg-perf03-18534, edg-perf02-60481, e
> dg-perf01-19198]}, availability mode = AVAILABLE
> 09:06:38,248 TRACE [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread-21) Attempting to execute command on self: CacheTopologyControlCommand{cache=testCache, type=CH_UPDATE, sender=edg-perf04
> -59142, joinInfo=null, topologyId=51, rebalanceId=12, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=null, ava
> ilabilityMode=AVAILABLE, actualMembers=[edg-perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19}
> 09:06:38,413 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (transport-thread-23) Replication task sending CacheTopologyControlCommand{cache=testCache, type=CH_UPDATE, sender=edg-per
> f04-59142, joinInfo=null, topologyId=52, rebalanceId=12, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=null,
> availabilityMode=AVAILABLE, actualMembers=[edg-perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19} to addresses null with response mode GET_NONE
> 09:06:38,415 TRACE [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread-10) Attempting to execute command on self: CacheTopologyControlCommand{cache=testCache, type=CH_UPDATE, sender=edg-perf04
> -59142, joinInfo=null, topologyId=52, rebalanceId=12, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=null, ava
> ilabilityMode=AVAILABLE, actualMembers=[edg-perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19}
> 09:06:38,451 TRACE [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread-8) Attempting to execute command on self: CacheTopologyControlCommand{cache=testCache, type=REBALANCE_START, sender=edg-p
> erf04-59142, joinInfo=null, topologyId=53, rebalanceId=13, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=Defa
> ultConsistentHash{ns = 512, owners = (4)[edg-perf04-59142: 128+128, edg-perf03-18534: 128+128, edg-perf02-60481: 128+128, edg-perf01-19198: 128+128]}, availabilityMode=null, actualMembers=[edg-perf04-59142, edg-
> perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19}
> {code}
> Transaction on edg-perf04 can be executed, since all owners are in current topology, though this node itself is degraded yet:
> {code}
> 09:06:38,545 TRACE [org.infinispan.partionhandling.impl.PartitionHandlingManagerImpl] (DefaultStressor-5) Checking availability for key=key_00000000000022CF, status=DEGRADED_MODE
> 09:06:38,545 TRACE [org.infinispan.partionhandling.impl.PartitionHandlingManagerImpl] (DefaultStressor-5) Key key_00000000000022CF is available.
> 09:06:38,549 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-5) edg-perf04-59142 invoking PrepareCommand {modifications=[PutKeyValueCommand{key=key_00000000000022CF, value=[35 #4: 197, 314, 331, 1101, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf04-59142>:23898:local, cacheName='testCache', topologyId=51} to recipient list [edg-perf01-19198, edg-perf02-60481] with options RpcOptions{timeout=60000, unit=MILLISECONDS, fifoOrder=true, totalOrder=false, responseFilter=null, responseMode=SYNCHRONOUS, skipReplicationQueue=false}
> 09:06:38,780 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-5) Responses: [sender=edg-perf01-19198, received=true, suspected=false]
> [sender=edg-perf02-60481, received=true, suspected=false]
> 09:06:38,788 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-5) edg-perf04-59142 invoking CommitCommand {gtx=GlobalTransaction:<edg-perf04-59142>:23898:local, cacheName='testCache', topologyId=51} to recipient list [edg-perf01-19198, edg-perf02-60481] with options RpcOptions{timeout=60000, unit=MILLISECONDS, fifoOrder=false, totalOrder=false, responseFilter=null, responseMode=SYNCHRONOUS_IGNORE_LEAVERS, skipReplicationQueue=false}
> 09:06:39,080 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-5) Responses: [sender=edg-perf01-19198, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false]
> [sender=edg-perf02-60481, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false]
> {code}
> These are topologies on edg-perf02:
> {code}
> 09:06:38,417 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (remote-thread-55) Attempting to execute non-CacheRpcCommand command: CacheTopologyControlCommand{cache=testCache, type=CH_UPDATE, sender=edg-perf04-59142, joinInfo=null, topologyId=51, rebalanceId=12, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=null, availabilityMode=AVAILABLE, actualMembers=[edg-perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19} [sender=edg-perf04-59142]
> 09:06:38,467 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (remote-thread-56) Attempting to execute non-CacheRpcCommand command: CacheTopologyControlCommand{cache=testCache, type=CH_UPDATE, sender=edg-perf04-59142, joinInfo=null, topologyId=52, rebalanceId=12, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=null, availabilityMode=AVAILABLE, actualMembers=[edg-perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19} [sender=edg-perf04-59142]
> 09:06:38,577 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (remote-thread-52) Attempting to execute non-CacheRpcCommand command: CacheTopologyControlCommand{cache=testCache, type=REBALANCE_START, sender=edg-perf04-59142, joinInfo=null, topologyId=53, rebalanceId=13, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=DefaultConsistentHash{ns = 512, owners = (4)[edg-perf04-59142: 128+128, edg-perf03-18534: 128+128, edg-perf02-60481: 128+128, edg-perf01-19198: 128+128]}, availabilityMode=null, actualMembers=[edg-perf04-59142, edg-perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19} [sender=edg-perf04-59142]
> {code}
> The transaction is successfully prepared on edg-perf02 (even twice as the prepare command is resent from edg-perf01)
> {code}
> 09:06:38,613 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-64) Calling perform() on PrepareCommand {modifications=[PutKeyValueCommand{key=key_00000000000022CF, value=[35 #4: 197, 314, 331, 1101, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf04-59142>:23898:remote, cacheName='testCache', topologyId=51}
> 09:06:38,620 TRACE [org.infinispan.util.concurrent.locks.LockManagerImpl] (remote-thread-64) Successfully acquired lock key_00000000000022CF!
> 09:06:38,626 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-64) About to send back response null for command PrepareCommand {modifications=[PutKeyValueCommand{key=key_00000000000022CF, value=[35 #4: 197, 314, 331, 1101, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf04-59142>:23898:remote, cacheName='testCache', topologyId=51}
> 09:06:38,670 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-64) Calling perform() on PrepareCommand {modifications=[PutKeyValueCommand{key=key_00000000000022CF, value=[35 #4: 197, 314, 331, 1101, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false,
> gtx=GlobalTransaction:<edg-perf04-59142>:23898:remote, cacheName='testCache', topologyId=52} // resent from edg-perf01
> 09:06:38,672 TRACE [org.infinispan.util.concurrent.locks.LockManagerImpl] (remote-thread-64) Already own lock for entry
> 09:06:38,675 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-64) About to send back response null for command PrepareCommand {modifications=[PutKeyValueCommand{key=key_00000000000022CF, value=[35 #4: 197, 314, 331, 1101, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf04-59142>:23898:remote, cacheName='testCache', topologyId=52}
> {code}
> However, as topology 53 is installed, this transaction is rolled back:
> {code}
> 09:06:38,577 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (remote-thread-52) Attempting to execute non-CacheRpcCommand command: CacheTopologyControlCommand{cache=testCache, type=RE
> BALANCE_START, sender=edg-perf04-59142, joinInfo=null, topologyId=53, rebalanceId=13, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198
> : 170+171]}, pendingCH=DefaultConsistentHash{ns = 512, owners = (4)[edg-perf04-59142: 128+128, edg-perf03-18534: 128+128, edg-perf02-60481: 128+128, edg-perf01-19198: 128+128]}, availabilityMode=null, actualMemb
> ers=[edg-perf04-59142, edg-perf03-18534, edg-perf02-60481, edg-perf01-19198], throwable=null, viewId=19} [sender=edg-perf04-59142]
> 09:06:38,658 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (remote-thread-52) Installing fake cache topology CacheTopology{id=52, rebalanceId=12, currentCH=DefaultConsistentHash{ns = 512, owners = (3)[edg-perf03-18534: 171+171, edg-perf02-60481: 171+170, edg-perf01-19198: 170+171]}, pendingCH=null, unionCH=null, actualMembers=null} for cache testCache
> 09:06:38,670 DEBUG [org.infinispan.transaction.TransactionTable] (remote-thread-52) The originating node left the cluster for 6 remote transactions
> 09:06:38,675 DEBUG [org.infinispan.transaction.TransactionTable] (remote-thread-52) Rolling back transaction GlobalTransaction:<edg-perf04-59142>:23898:remote because originator edg-perf04-59142 left the cluster
> 09:06:38,675 TRACE [org.infinispan.commands.tx.AbstractTransactionBoundaryCommand] (remote-thread-52) About to execute tx command RollbackCommand {gtx=GlobalTransaction:<edg-perf04-59142>:23898:remote, cacheName
> ='testCache', topologyId=-1}
> {code}
> But even after that, the CommitCommand still suceeds:
> {code}
> 09:06:38,811 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-56) Calling perform() on CommitCommand {gtx=GlobalTransaction:<edg-perf04-59142>:23898:remote, cacheName='testCache', topologyId=51}
> 09:06:38,812 TRACE [org.infinispan.commands.tx.AbstractTransactionBoundaryCommand] (remote-thread-56) Did not find a RemoteTransaction for GlobalTransaction:<edg-perf04-59142>:23898:remote
> 09:06:38,812 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-56) About to send back response SuccessfulResponse{responseValue=null} for command CommitCommand {gtx=GlobalTransaction:<edg-perf04-59142>:23898:remote, cacheName='testCache', topologyId=51}
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
11 years, 1 month
[JBoss JIRA] (ISPN-5158) Transaction rolled back but returns successful response
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5158?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration commented on ISPN-5158:
-----------------------------------------------
Matej Čimbora <mcimbora(a)redhat.com> changed the Status of [bug 1180680|https://bugzilla.redhat.com/show_bug.cgi?id=1180680] from ON_QA to ASSIGNED
> Transaction rolled back but returns successful response
> -------------------------------------------------------
>
> Key: ISPN-5158
> URL: https://issues.jboss.org/browse/ISPN-5158
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 7.1.0.Beta1
> Reporter: Radim Vansa
> Assignee: Dan Berindei
> Priority: Critical
> Fix For: 7.2.0.Alpha1, 7.2.0.Final
>
> Attachments: tx.txt, views.txt
>
>
> When the cluster is merging, it is possible that a node is removed from the view although it is still responsive. Eventually the cluster is merged correctly, but since the node is reported as missing from the view, transaction originating from this node is rolled back.
> {code}
> 10:01:36,116 TRACE [org.infinispan.interceptors.TxInterceptor] (remote-thread-151) Rolling back remote transaction GlobalTransaction:<edg-perf02-39415>:28106:remote because either already completed(false) or originator no longer in the cluster(true).
> {code}
> However, even after this a successful response is sent to the originator:
> {code}
> 10:01:36,119 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-151) About to send back response null for command PrepareCommand {modifications=[PutKeyValueCommand{key=key_0000000000001318, value=[19 #1: 1195, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf02-39415>:28106:remote, cacheName='testCache', topologyId=47}
> {code}
> Originator then expects that the transaction was successfully prepared:
> {code}
> 10:01:36,124 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-9) Responses: [sender=edg-perf01-36235, received=true, suspected=false]
> [sender=edg-perf03-24110, received=true, suspected=false]
> 10:01:36,135 TRACE [org.infinispan.transaction.TransactionCoordinator] (DefaultStressor-9) Committing transaction GlobalTransaction:<edg-perf02-39415>:28106:local
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
11 years, 1 month
[JBoss JIRA] (ISPN-5274) Inconsistent data after transaction rollback (with success on originator)
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5274?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration commented on ISPN-5274:
-----------------------------------------------
Matej Čimbora <mcimbora(a)redhat.com> changed the Status of [bug 1180680|https://bugzilla.redhat.com/show_bug.cgi?id=1180680] from ON_QA to ASSIGNED
> Inconsistent data after transaction rollback (with success on originator)
> -------------------------------------------------------------------------
>
> Key: ISPN-5274
> URL: https://issues.jboss.org/browse/ISPN-5274
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Reporter: Matej Čimbora
> Assignee: Dan Berindei
>
> Scenario
> Nodes edg-perf[10-13], partition handling on
> 1.Transaction is started on edg-perf10
> {code}
> 10:24:48,228 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (DefaultStressor-6) start called on tx GlobalTransaction:<edg-perf10-20667>:38910:local
> {code}
> 2. Value of key_000000000000065B is updated within the transaction
> {code}
> 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, ]
> {code}
> 3. Transaction is successfully prepared on edg-perf11 & edg-perf12
> {code}
> 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]
> {code}
> 4. Transaction commit is issued
> {code}
> 10:24:48,562 TRACE [org.infinispan.transaction.TransactionCoordinator] (DefaultStressor-6) Committing transaction GlobalTransaction:<edg-perf10-20667>:38910:local
> {code}
> 5. Other participating nodes (edg-perf11 & edg-perf12) are suspected...
> {code}
> 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
> {code}
> ... as they received a new view (without edg-perf10) meanwhile.
> {code}
> 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]
> {code}
> Still, the transaction is commited on edg-perf10 & updated entry is stored locally
> {code}
> 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, ]
> {code}
> 6. Other nodes rollback the transaction
> {code}
> 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
> {code}
> 7. edg-perf10 receives a new view, containing nodes edg-perf[10,11,13]. Incoming state transfer overwrites the updated value
> {code}
> 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]
> {code}
> 8. get operation returns outdated value
> {code}
> 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, ]}} }
> {code}
> From client perspective, this behavior is not transparent. Provided the transaction ended up successfully, presence of the updated entry can be assumed.
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
11 years, 1 month
[JBoss JIRA] (ISPN-5274) Inconsistent data after transaction rollback (with success on originator)
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5274?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration updated ISPN-5274:
------------------------------------------
Bugzilla Update: Perform
Bugzilla References: https://bugzilla.redhat.com/show_bug.cgi?id=1199490
> Inconsistent data after transaction rollback (with success on originator)
> -------------------------------------------------------------------------
>
> Key: ISPN-5274
> URL: https://issues.jboss.org/browse/ISPN-5274
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Reporter: Matej Čimbora
> Assignee: Dan Berindei
>
> Scenario
> Nodes edg-perf[10-13], partition handling on
> 1.Transaction is started on edg-perf10
> {code}
> 10:24:48,228 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (DefaultStressor-6) start called on tx GlobalTransaction:<edg-perf10-20667>:38910:local
> {code}
> 2. Value of key_000000000000065B is updated within the transaction
> {code}
> 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, ]
> {code}
> 3. Transaction is successfully prepared on edg-perf11 & edg-perf12
> {code}
> 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]
> {code}
> 4. Transaction commit is issued
> {code}
> 10:24:48,562 TRACE [org.infinispan.transaction.TransactionCoordinator] (DefaultStressor-6) Committing transaction GlobalTransaction:<edg-perf10-20667>:38910:local
> {code}
> 5. Other participating nodes (edg-perf11 & edg-perf12) are suspected...
> {code}
> 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
> {code}
> ... as they received a new view (without edg-perf10) meanwhile.
> {code}
> 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]
> {code}
> Still, the transaction is commited on edg-perf10 & updated entry is stored locally
> {code}
> 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, ]
> {code}
> 6. Other nodes rollback the transaction
> {code}
> 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
> {code}
> 7. edg-perf10 receives a new view, containing nodes edg-perf[10,11,13]. Incoming state transfer overwrites the updated value
> {code}
> 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]
> {code}
> 8. get operation returns outdated value
> {code}
> 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, ]}} }
> {code}
> From client perspective, this behavior is not transparent. Provided the transaction ended up successfully, presence of the updated entry can be assumed.
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
11 years, 1 month