[
https://issues.jboss.org/browse/ISPN-4426?page=com.atlassian.jira.plugin....
]
Dan Berindei commented on ISPN-4426:
------------------------------------
I found a little more information in the log: the CommitCommand is actually executed 3
times, because both the originator and and the old owners forward the command to the new
owners in the write CH (including the old owners):
{noformat}
10:07:31,964 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl]
(remote-thread-5) Calling perform() on CommitCommand
{gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=41}
10:07:31,968 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl]
(remote-thread-23) Calling perform() on CommitCommand
{gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=41}
10:07:32,408 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl]
(remote-thread-23) Calling perform() on CommitCommand
{gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=41}
{noformat}
The problem seems to be caused by the ISPN-4137 fix, as the transaction is now only marked
as completed in TxInterceptor. The first thread (remote-thread-5) decides to replay the
PrepareCommand and updates the {{lookedUpEntriesTopology}} to the new topology. Then the
second thread (remote-thread-23) sees that it doesn't need to replay the
PrepareCommand and tries to execute the CommitCommand directly. The modifications list is
empty, however, so nothing is committed, but the transaction is marked as completed, which
then prevents remote-thread-5 (and again remote-thread-23) from doing anything else:
{noformat}
10:07:31,974 DEBUG [org.infinispan.statetransfer.StateTransferInterceptor]
(remote-thread-5) Replaying the transactions received as a result of state transfer
PrepareCommand {modifications=[PutKeyValueCommand{key=key_0000000000001531, value=[21 #21:
246, 320, 846, 1083, 1256, 1398, 1526, 1667, 1816, 2533, 2557, 2724, 2804, 2840, 2921,
3492, 3613, 3659, 4413, 4677, 5760, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP],
putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null},
successful=true}, ... onePhaseCommit=false,
gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=-1}
10:07:31,974 TRACE [org.infinispan.commands.tx.PrepareCommand] (remote-thread-5) Invoking
remotely originated prepare: PrepareCommand
{modifications=[PutKeyValueCommand{key=key_0000000000001531, value=[21 #21: 246, 320, 846,
1083, 1256, 1398, 1526, 1667, 1816, 2533, 2557, 2724, 2804, 2840, 2921, 3492, 3613, 3659,
4413, 4677, 5760, ], flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], putIfAbsent=false,
valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}, ...
], onePhaseCommit=false, gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=-1} with invocation context:
org.infinispan.context.impl.RemoteTxInvocationContext@7a5688e0
10:07:31,976 DEBUG [org.infinispan.statetransfer.StateTransferInterceptor]
(remote-thread-23) handleTopologyAffectedCommand for command CommitCommand
{gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=41}, origin edg-perf03-58446
10:07:31,980 DEBUG [org.infinispan.interceptors.EntryWrappingInterceptor]
(remote-thread-23) Commiting CommitCommand
10:07:31,980 DEBUG [org.infinispan.statetransfer.StateTransferInterceptor]
(remote-thread-23) handled command CommitCommand
{gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=41}, origin edg-perf03-58446
10:07:32,013 DEBUG [org.infinispan.statetransfer.StateTransferInterceptor]
(remote-thread-5) Prepare command replayed
10:07:32,013 DEBUG [org.infinispan.statetransfer.StateTransferInterceptor]
(remote-thread-5) handleTopologyAffectedCommand for command CommitCommand
{gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=41}, origin edg-perf03-58446
10:07:32,014 DEBUG [org.infinispan.statetransfer.StateTransferInterceptor]
(remote-thread-5) handled command CommitCommand
{gtx=GlobalTransaction:<edg-perf03-58446>:23655:remote,
cacheName='testCache', topologyId=41}, origin edg-perf03-58446
10:07:32,408 TRACE [org.infinispan.commands.tx.AbstractTransactionBoundaryCommand]
(remote-thread-23) Did not find a RemoteTransaction for
GlobalTransaction:<edg-perf03-58446>:23655:remote
{noformat}
Transaction replayed but not committed
--------------------------------------
Key: ISPN-4426
URL:
https://issues.jboss.org/browse/ISPN-4426
Project: Infinispan
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: State Transfer
Affects Versions: 7.0.0.Alpha4
Reporter: Radim Vansa
Assignee: Dan Berindei
Priority: Critical
Labels: 63gablocker
Dist TX cache, node C is joining. In previous topology, entry is owned by A (primary) and
B (backup). In new topology, primary ownership is transferred to C, B stays backup.
1. TX is prepared in old topology and is being committed, when topology changes
2. on C (the new owner), the TX info is received and later even the old entry
3. C receives the CommitCommand, therefore, it correctly replays the PrepareCommand.
4. When the entries are about to be committed, in TxInterceptor the transaction is found
to be already completed as it has lower TxID.
Result: the transaction is not being executed and stale data stay on the node (with my
algortihm it eventually led to complete entry loss).
--
This message was sent by Atlassian JIRA
(v6.2.6#6264)