[
https://issues.apache.org/jira/browse/IGNITE-20996?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Denis Chudov updated IGNITE-20996:
----------------------------------
Reviewer: Kirill Gusakov
> Rebalance can be considered as successful while actual data replication failed
> ------------------------------------------------------------------------------
>
> Key: IGNITE-20996
> URL: https://issues.apache.org/jira/browse/IGNITE-20996
> Project: Ignite
> Issue Type: Bug
> Reporter: Denis Chudov
> Assignee: Denis Chudov
> Priority: Major
> Labels: ignite-3
>
> The successful rebalance happens after successful raft configuration change
> and invoke to meta storage with replacing stable assignments with pending
> ones. Also there is the following line in the log:
>
> {code:java}
> [2023-11-30T09:20:25,028][INFO
> ][%iinrt_tcg_0%rebalance-scheduler-1][RebalanceRaftGroupEventsListener]
> Rebalance finished [tablePartitionId=9_part_1, appliedPeers=[Assignment
> [consistentId=iinrt_tcg_0, isPeer=true], Assignment
> [consistentId=iinrt_tcg_1, isPeer=true], Assignment
> [consistentId=iinrt_tcg_2, isPeer=true], Assignment
> [consistentId=iinrt_tcg_3, isPeer=true]]]{code}
>
> But in case when there were errors on FSM on replication, the result of the
> rebalance looks the same, in spite the data was not actually replicated.
> Probably there are some problems in raft that allow triggering the
> configuration change event in spite of errors in state machine.
> *Update*:
> The issue can be reproduced as:
> - Unmute testCfgGap test
> - Change NodeOptions.catchupMargin to any value smaller than 100 (because
> actually this tests write and check the replication of 100 rows)
> - Run the test
> Expected result:
> - Catchup phas of rebalance failed
> Actual result:
> {code}
> [2023-12-08T17:24:41,738][INFO
> ][%iinrt_tcg_1%JRaft-Common-Executor-2][NodeImpl] Catch up for
> peer=iinrt_tcg_3 was finished
> [2023-12-08T17:24:41,739][INFO
> ][%iinrt_tcg_1%JRaft-Common-Executor-2][NodeImpl] Catch up phase to change
> peers from=[iinrt_tcg_2, iinrt_tcg_1, iinrt_tcg_0] to=[iinrt_tcg_3,
> iinrt_tcg_0, iinrt_tcg_1, iinrt_tcg_2] was successfully finished
> [2023-12-08T17:24:41,743][INFO
> ][%iinrt_tcg_1%JRaft-FSMCaller-Disruptor-_stripe_5-0][StateMachineAdapter]
> onConfigurationCommitted: iinrt_tcg_3,iinrt_tcg_0,iinrt_tcg_1,iinrt_tcg_2.
> [2023-12-08T17:24:41,744][INFO
> ][%iinrt_tcg_2%JRaft-FSMCaller-Disruptor-_stripe_4-0][StateMachineAdapter]
> onConfigurationCommitted: iinrt_tcg_3,iinrt_tcg_0,iinrt_tcg_1,iinrt_tcg_2.
> [2023-12-08T17:24:41,744][INFO
> ][%iinrt_tcg_0%JRaft-FSMCaller-Disruptor-_stripe_6-0][StateMachineAdapter]
> onConfigurationCommitted: iinrt_tcg_3,iinrt_tcg_0,iinrt_tcg_1,iinrt_tcg_2.
> [2023-12-08T17:24:41,745][WARN
> ][%iinrt_tcg_1%JRaft-Common-Executor-1][RpcRequestClosure] A response:
> ChangePeersAsyncResponseImpl [newLearnersList=ArrayList [],
> newPeersList=ArrayList [iinrt_tcg_3, iinrt_tcg_0, iinrt_tcg_1, iinrt_tcg_2],
> oldLearnersList=ArrayList [], oldPeersList=ArrayList [iinrt_tcg_2,
> iinrt_tcg_1, iinrt_tcg_0]] sent repeatedly!
> [2023-12-08T17:24:41,745][ERROR][%iinrt_tcg_3%JRaft-FSMCaller-Disruptor-_stripe_3-0][PartitionListener]
> Unknown error while processing command [commandIndex=2, commandTerm=2,
> command=UpdateAllCommandImpl [full=false, messageRowsToUpdate=HashMap
> {1ed55656-1c13-4382-b4d2-c68c2106bef7=TimedBinaryRowMessageImpl
> [binaryRowMessage=BinaryRowMessageImpl
> [binaryTuple=java.nio.HeapByteBuffer[pos=0 lim=9 cap=9], schemaVersion=1],
> timestamp=0]}, requiredCatalogVersion=5, safeTimeLong=111545252503945221,
> tablePartitionId=TablePartitionIdMessageImpl [partitionId=0, tableId=9],
> txCoordinatorId=aecb6e7e-4b5c-41b4-aaa5-17b8568c67b1,
> txId=018c49d0-e9fc-0000-0000-0000dc9ad69a]]
> java.lang.AssertionError: T2 part 0
> at
> org.apache.ignite.internal.table.IndexWrapper$HashIndexWrapper.getStorage(IndexWrapper.java:106)
> ~[ignite-table-3.0.0-SNAPSHOT.jar:?]
> at org.apache.ignite.internal.table.TableImpl$1.get(TableImpl.java:211)
> ~[ignite-table-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.internal.table.distributed.index.IndexUpdateHandler.waitIndexes(IndexUpdateHandler.java:151)
> ~[ignite-table-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.internal.table.distributed.StorageUpdateHandler.handleUpdateAll(StorageUpdateHandler.java:158)
> ~[ignite-table-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.internal.table.distributed.raft.PartitionListener.handleUpdateAllCommand(PartitionListener.java:293)
> ~[ignite-table-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.internal.table.distributed.raft.PartitionListener.lambda$onWrite$1(PartitionListener.java:199)
> ~[ignite-table-3.0.0-SNAPSHOT.jar:?]
> at java.util.Iterator.forEachRemaining(Iterator.java:133) [?:?]
> at
> org.apache.ignite.internal.table.distributed.raft.PartitionListener.onWrite(PartitionListener.java:159)
> [ignite-table-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.internal.raft.server.impl.JraftServerImpl$DelegatingStateMachine.onApply(JraftServerImpl.java:659)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.raft.jraft.core.FSMCallerImpl.doApplyTasks(FSMCallerImpl.java:557)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.raft.jraft.core.FSMCallerImpl.doCommitted(FSMCallerImpl.java:525)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.raft.jraft.core.FSMCallerImpl.runApplyTask(FSMCallerImpl.java:444)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:136)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:130)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:226)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:191)
> [ignite-raft-3.0.0-SNAPSHOT.jar:?]
> at
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:137)
> [disruptor-3.3.7.jar:?]
> at java.lang.Thread.run(Thread.java:834) [?:?]
> {code}
> So, according to the logs we can't replicate even the first message to the
> new node, but the catchup phase is done successfully. *That's the main
> problem, which should be investigated*. What about rebalance itself - it can
> be finished successfully anyway, because majority of the nodes (3/4) is
> applied configuration entry successfully.
> Also, the test itself is green, but it shouldn't. The last check
> {code}
> checkTableWithData(newNode, "t2");
> {code}
> supposed to check the data replication to the newNode (so, it can't be
> successfull), but it looks like it checks the data on primary replica
> instead. So, test must be updated to the real 1-node data check after the fix
> https://issues.apache.org/jira/browse/IGNITE-19712
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
