ReplicaStateMachine should consider ReplicaDeletionStarted/ReplicaDeletionSuccessful as a valid previous state

[wuchong]

Search before asking

• I searched in the issues and found nothing similar.

Fluss version

0.6.0 (latest release)

Please describe the bug 🐞

com.alibaba.fluss.server.coordinator.TableManagerITCase#testPartitionedTableManagement has many ERROR logs that reporting

5015 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Replica state for TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} should be in the [NewReplica, OnlineReplica, OfflineReplica] before moving to state OfflineReplica, but the current state is ReplicaDeletionStarted.
5016 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Fail to change state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} from ReplicaDeletionStarted to OfflineReplica.
5017 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Replica state for TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} should be in the [NewReplica, OnlineReplica, OfflineReplica] before moving to state OfflineReplica, but the current state is ReplicaDeletionStarted.

Solution

No response

Are you willing to submit a PR?

• I'm willing to submit a PR!

[caozhen1937]

Hi @wuchong , How can I reproduce these ERRORs?

[wuchong]

@caozhen1937 you can see the ERROR logs when you enable logs configuration fluss-server/src/test/resources/log4j2-test.properties

[gyang94]

@wuchong I made a PR to add this: #795
I tried to understand why the replica state could change from ReplicaDeletionStarted to OfflineReplica:

1. It looks that when dropping a table, we will delete all zk nodes under the table path.
2. When coordinator received NotifyLeaderAndIsrResponseReceivedEvent event, it failed to get table info from zk and throw StorageException.
3. Then coordinator will mark this replica offline.

[wuchong]

@gyang94 this is not a simple fix to add ReplicaDeletionStarted/ReplicaDeletionSuccessful to previous valid state of ReplicaOfflineState.

We need to figure out whether it's a valid previous state of ReplicaOfflineState or not. If yes, then how to handle the state transition (what should coordinator/tabletserver do). If not, then is it proper to print the ERROR log? (ERROR log means there is something wrong in the system).

You can get the full log when enable the debug log for the test TableManagerITCase#testPartitionedTableManagement (logging code see 9c9929b).

3712 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.TestLoggerExtension [] - 
================================================================================
Test com.alibaba.fluss.server.coordinator.TableManagerITCase.testPartitionedTableManagement[[1] YEAR] is running.
--------------------------------------------------------------------------------
3799 [fluss-netty-server-worker-thread-2] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered database db1
3800 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1)
3859 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables)
3869 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR)
3871 [periodic-auto-partition-manager-thread-1] INFO  com.alibaba.fluss.server.coordinator.AutoPartitionManager [] - Start auto partitioning for 0 tables at 2025-04-27T07:13:23.207Z.
3874 [fluss-netty-server-worker-thread-2] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered new schema version 1 for table db1.tb1_YEAR.
3874 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR/schemas)
3875 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR/schemas/1)
3896 [fluss-netty-server-worker-thread-2] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered table tb1_YEAR for database db1
3897 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CHANGED event (path: /metadata/databases/db1/tables/tb1_YEAR)
3907 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - New table: db1.tb1_YEAR with id 0, new table bucket assignment {}.
3909 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - New table buckets: [] for table db1.tb1_YEAR.
3919 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.AutoPartitionManager [] - Added auto partition table [db1.tb1_YEAR] (id=0) into scheduler
3921 [periodic-auto-partition-manager-thread-1] INFO  com.alibaba.fluss.server.coordinator.AutoPartitionManager [] - Start auto partitioning for 1 tables at 2025-04-27T07:13:23.263Z.
3967 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR/partitions)
3967 [periodic-auto-partition-manager-thread-1] INFO  com.alibaba.fluss.server.coordinator.MetadataManager [] - Register partition 2025 to zookeeper for table [db1.tb1_YEAR].
3968 [periodic-auto-partition-manager-thread-1] INFO  com.alibaba.fluss.server.coordinator.AutoPartitionManager [] - Auto partitioning created partition dt=2025 for table [db1.tb1_YEAR].
3968 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR/partitions/2025)
3972 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - New partition 2025 with partition id 0 and assignment {0=[0], 1=[1], 2=[2]} for table db1.tb1_YEAR.
3974 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - New table buckets: [TableBucket{tableId=0, partitionId=0, bucket=2}, TableBucket{tableId=0, partitionId=0, bucket=1}, TableBucket{tableId=0, partitionId=0, bucket=0}] for table db1.tb1_YEAR.
3975 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=2, tablePath=db1.tb1_YEAR, partition=2025} from NonExistentBucket to NewBucket.
3975 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=1, tablePath=db1.tb1_YEAR, partition=2025} from NonExistentBucket to NewBucket.
3975 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=0, tablePath=db1.tb1_YEAR, partition=2025} from NonExistentBucket to NewBucket.
3979 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from NonExistentReplica to NewReplica.
3980 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} from NonExistentReplica to NewReplica.
3980 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=db1.tb1_YEAR, partition=2025} from NonExistentReplica to NewReplica.
3998 [coordinator-event-thread] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered LeaderAndIsr{leader=2, leaderEpoch=0, isr=[2], coordinatorEpoch=0, bucketEpoch=0} for bucket TableBucket{tableId=0, partitionId=0, bucket=2} in Zookeeper.
4001 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4008 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=2, tablePath=db1.tb1_YEAR, partition=2025} from NewBucket to OnlineBucket.
4008 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4010 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4012 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4013 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4013 [fluss-netty-server-worker-thread-2] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Deleted table db1.tb1_YEAR.
4021 [coordinator-event-thread] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered LeaderAndIsr{leader=1, leaderEpoch=0, isr=[1], coordinatorEpoch=0, bucketEpoch=0} for bucket TableBucket{tableId=0, partitionId=0, bucket=1} in Zookeeper.
4022 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=1, tablePath=db1.tb1_YEAR, partition=2025} from NewBucket to OnlineBucket.
4035 [coordinator-event-thread] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered LeaderAndIsr{leader=0, leaderEpoch=0, isr=[0], coordinatorEpoch=0, bucketEpoch=0} for bucket TableBucket{tableId=0, partitionId=0, bucket=0} in Zookeeper.
4035 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=0, tablePath=db1.tb1_YEAR, partition=2025} from NewBucket to OnlineBucket.
4037 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR)
4043 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from NewReplica to OnlineReplica.
4060 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} from NewReplica to OnlineReplica.
4061 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR/schemas)
4064 [fluss-netty-server-worker-thread-2] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered new schema version 1 for table db1.tb1_YEAR.
4077 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=db1.tb1_YEAR, partition=2025} from NewReplica to OnlineReplica.
4077 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CREATED event (path: /metadata/databases/db1/tables/tb1_YEAR/schemas/1)
4091 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=2, tablePath=db1.tb1_YEAR, partition=2025} from OnlineBucket to OfflineBucket.
4098 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=1, tablePath=db1.tb1_YEAR, partition=2025} from OnlineBucket to OfflineBucket.
4099 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=0, tablePath=db1.tb1_YEAR, partition=2025} from OnlineBucket to OfflineBucket.
4106 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=2, tablePath=db1.tb1_YEAR, partition=2025} from OfflineBucket to NonExistentBucket.
4115 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=1, tablePath=db1.tb1_YEAR, partition=2025} from OfflineBucket to NonExistentBucket.
4116 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.TableBucketStateMachine [] - Successfully changed state for table bucket TableBucket{tableId=0, partitionId=0, bucket=0, tablePath=db1.tb1_YEAR, partition=2025} from OfflineBucket to NonExistentBucket.
4105 [fluss-netty-server-worker-thread-3] ERROR com.alibaba.fluss.server.replica.ReplicaManager [] - Error while checking and creating replica
java.io.UncheckedIOException: java.io.IOException: No content to map due to end-of-input.
	at com.alibaba.fluss.utils.json.JsonSerdeUtils.readValue(JsonSerdeUtils.java:71) ~[classes/:?]
	at com.alibaba.fluss.server.zk.data.ZkData$TableZNode.decode(ZkData.java:121) ~[classes/:?]
	at java.util.Optional.map(Optional.java:215) ~[?:1.8.0_341]
	at com.alibaba.fluss.server.zk.ZooKeeperClient.getTable(ZooKeeperClient.java:353) ~[classes/:?]
	at com.alibaba.fluss.server.TabletManagerBase.getTableInfo(TabletManagerBase.java:214) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.maybeCreateReplica(ReplicaManager.java:1451) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.validateAndGetIsBecomeLeader(ReplicaManager.java:1291) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.lambda$becomeLeaderOrFollower$4(ReplicaManager.java:345) ~[classes/:?]
	at com.alibaba.fluss.utils.concurrent.LockUtils.inLock(LockUtils.java:31) [classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.becomeLeaderOrFollower(ReplicaManager.java:334) [classes/:?]
	at com.alibaba.fluss.server.tablet.TabletService.notifyLeaderAndIsr(TabletService.java:279) [classes/:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_341]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_341]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_341]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_341]
	at com.alibaba.fluss.rpc.netty.server.FlussRequestHandler.processRequest(FlussRequestHandler.java:62) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.FlussRequestHandler.processRequest(FlussRequestHandler.java:33) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.RequestProcessor.processRequest(RequestProcessor.java:97) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.RequestProcessor.run(RequestProcessor.java:69) [classes/:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_341]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_341]
	at java.lang.Thread.run(Thread.java:750) [?:1.8.0_341]
Caused by: java.io.IOException: No content to map due to end-of-input.
	at com.alibaba.fluss.utils.json.JsonSerdeUtils.readValue(JsonSerdeUtils.java:67) ~[classes/:?]
	... 21 more
4105 [fluss-netty-server-worker-thread-1] ERROR com.alibaba.fluss.server.replica.ReplicaManager [] - Error while checking and creating replica
java.io.UncheckedIOException: java.io.IOException: No content to map due to end-of-input.
	at com.alibaba.fluss.utils.json.JsonSerdeUtils.readValue(JsonSerdeUtils.java:71) ~[classes/:?]
	at com.alibaba.fluss.server.zk.data.ZkData$TableZNode.decode(ZkData.java:121) ~[classes/:?]
	at java.util.Optional.map(Optional.java:215) ~[?:1.8.0_341]
	at com.alibaba.fluss.server.zk.ZooKeeperClient.getTable(ZooKeeperClient.java:353) ~[classes/:?]
	at com.alibaba.fluss.server.TabletManagerBase.getTableInfo(TabletManagerBase.java:214) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.maybeCreateReplica(ReplicaManager.java:1451) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.validateAndGetIsBecomeLeader(ReplicaManager.java:1291) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.lambda$becomeLeaderOrFollower$4(ReplicaManager.java:345) ~[classes/:?]
	at com.alibaba.fluss.utils.concurrent.LockUtils.inLock(LockUtils.java:31) [classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.becomeLeaderOrFollower(ReplicaManager.java:334) [classes/:?]
	at com.alibaba.fluss.server.tablet.TabletService.notifyLeaderAndIsr(TabletService.java:279) [classes/:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_341]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_341]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_341]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_341]
	at com.alibaba.fluss.rpc.netty.server.FlussRequestHandler.processRequest(FlussRequestHandler.java:62) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.FlussRequestHandler.processRequest(FlussRequestHandler.java:33) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.RequestProcessor.processRequest(RequestProcessor.java:97) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.RequestProcessor.run(RequestProcessor.java:69) [classes/:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_341]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_341]
	at java.lang.Thread.run(Thread.java:750) [?:1.8.0_341]
Caused by: java.io.IOException: No content to map due to end-of-input.
	at com.alibaba.fluss.utils.json.JsonSerdeUtils.readValue(JsonSerdeUtils.java:67) ~[classes/:?]
	... 21 more
4105 [fluss-netty-server-worker-thread-1] ERROR com.alibaba.fluss.server.replica.ReplicaManager [] - Error while checking and creating replica
java.io.UncheckedIOException: java.io.IOException: No content to map due to end-of-input.
	at com.alibaba.fluss.utils.json.JsonSerdeUtils.readValue(JsonSerdeUtils.java:71) ~[classes/:?]
	at com.alibaba.fluss.server.zk.data.ZkData$TableZNode.decode(ZkData.java:121) ~[classes/:?]
	at java.util.Optional.map(Optional.java:215) ~[?:1.8.0_341]
	at com.alibaba.fluss.server.zk.ZooKeeperClient.getTable(ZooKeeperClient.java:353) ~[classes/:?]
	at com.alibaba.fluss.server.TabletManagerBase.getTableInfo(TabletManagerBase.java:214) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.maybeCreateReplica(ReplicaManager.java:1451) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.validateAndGetIsBecomeLeader(ReplicaManager.java:1291) ~[classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.lambda$becomeLeaderOrFollower$4(ReplicaManager.java:345) ~[classes/:?]
	at com.alibaba.fluss.utils.concurrent.LockUtils.inLock(LockUtils.java:31) [classes/:?]
	at com.alibaba.fluss.server.replica.ReplicaManager.becomeLeaderOrFollower(ReplicaManager.java:334) [classes/:?]
	at com.alibaba.fluss.server.tablet.TabletService.notifyLeaderAndIsr(TabletService.java:279) [classes/:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_341]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_341]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_341]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_341]
	at com.alibaba.fluss.rpc.netty.server.FlussRequestHandler.processRequest(FlussRequestHandler.java:62) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.FlussRequestHandler.processRequest(FlussRequestHandler.java:33) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.RequestProcessor.processRequest(RequestProcessor.java:97) [classes/:?]
	at com.alibaba.fluss.rpc.netty.server.RequestProcessor.run(RequestProcessor.java:69) [classes/:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_341]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_341]
	at java.lang.Thread.run(Thread.java:750) [?:1.8.0_341]
Caused by: java.io.IOException: No content to map due to end-of-input.
	at com.alibaba.fluss.utils.json.JsonSerdeUtils.readValue(JsonSerdeUtils.java:67) ~[classes/:?]
	... 21 more
4200 [fluss-netty-server-worker-thread-2] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Registered table tb1_YEAR for database db1
4203 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_CHANGED event (path: /metadata/databases/db1/tables/tb1_YEAR)
4213 [coordinator-event-thread] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Updated LeaderAndIsr{leader=-1, leaderEpoch=0, isr=[2], coordinatorEpoch=0, bucketEpoch=1} for bucket TableBucket{tableId=0, partitionId=0, bucket=2} in Zookeeper.
4221 [coordinator-event-thread] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Updated LeaderAndIsr{leader=-1, leaderEpoch=0, isr=[1], coordinatorEpoch=0, bucketEpoch=1} for bucket TableBucket{tableId=0, partitionId=0, bucket=1} in Zookeeper.
4223 [coordinator-event-thread] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Updated LeaderAndIsr{leader=-1, leaderEpoch=0, isr=[0], coordinatorEpoch=0, bucketEpoch=1} for bucket TableBucket{tableId=0, partitionId=0, bucket=0} in Zookeeper.
4224 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from OnlineReplica to OfflineReplica.
4226 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} from OnlineReplica to OfflineReplica.
4227 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=db1.tb1_YEAR, partition=2025} from OnlineReplica to OfflineReplica.
4249 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from OfflineReplica to ReplicaDeletionStarted.
4250 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} from OfflineReplica to ReplicaDeletionStarted.
4250 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=db1.tb1_YEAR, partition=2025} from OfflineReplica to ReplicaDeletionStarted.
4268 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.CommonTestUtils [] - Attempt failed, sleeping for 1 ms, and then retrying.
4283 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.AutoPartitionManager [] - Removed auto partition table [db1.tb1_YEAR] (id=0) from scheduler
4283 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.CommonTestUtils [] - Attempt failed, sleeping for 2 ms, and then retrying.
4286 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - New table: db1.tb1_YEAR with id 1, new table bucket assignment {}.
4286 [fluss-netty-server-worker-thread-3] DEBUG com.alibaba.fluss.utils.concurrent.FlussScheduler [] - Scheduling task highWatermark-checkpoint with initial delay 0 ms and period 5000 ms.
4286 [fluss-netty-server-worker-thread-1] DEBUG com.alibaba.fluss.utils.concurrent.FlussScheduler [] - Scheduling task highWatermark-checkpoint with initial delay 0 ms and period 5000 ms.
4286 [fluss-netty-server-worker-thread-1] DEBUG com.alibaba.fluss.utils.concurrent.FlussScheduler [] - Scheduling task highWatermark-checkpoint with initial delay 0 ms and period 5000 ms.
4287 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - New table buckets: [] for table db1.tb1_YEAR.
4306 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.CommonTestUtils [] - Attempt failed, sleeping for 4 ms, and then retrying.
4318 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.CoordinatorEventProcessor [] - The replica [TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0}] become offline.
4334 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Replica state for TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=db1.tb1_YEAR, partition=2025} should be in the [NewReplica, OnlineReplica, OfflineReplica] before moving to state OfflineReplica, but the current state is ReplicaDeletionStarted.
4334 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.CommonTestUtils [] - Attempt failed, sleeping for 8 ms, and then retrying.
4337 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Fail to change state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=db1.tb1_YEAR, partition=2025} from ReplicaDeletionStarted to OfflineReplica.
4338 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.CoordinatorEventProcessor [] - The replica [TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1}] become offline.
4339 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Replica state for TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} should be in the [NewReplica, OnlineReplica, OfflineReplica] before moving to state OfflineReplica, but the current state is ReplicaDeletionStarted.
4339 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Fail to change state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=db1.tb1_YEAR, partition=2025} from ReplicaDeletionStarted to OfflineReplica.
4339 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.CoordinatorEventProcessor [] - The replica [TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2}] become offline.
4340 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Replica state for TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} should be in the [NewReplica, OnlineReplica, OfflineReplica] before moving to state OfflineReplica, but the current state is ReplicaDeletionStarted.
4340 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Fail to change state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from ReplicaDeletionStarted to OfflineReplica.
4342 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=db1.tb1_YEAR, partition=2025} from ReplicaDeletionStarted to ReplicaDeletionSuccessful.
4363 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.CommonTestUtils [] - Attempt failed, sleeping for 16 ms, and then retrying.
4384 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - Deletion of table with id 0 successfully completed.
4395 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=null, partition=2025} from ReplicaDeletionStarted to ReplicaDeletionSuccessful.
4396 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.CommonTestUtils [] - Attempt failed, sleeping for 32 ms, and then retrying.
4396 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=null, partition=2025} from ReplicaDeletionStarted to ReplicaDeletionSuccessful.
4396 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=null, partition=2025} from ReplicaDeletionSuccessful to null.
4398 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=1}, replica=1, tablePath=null, partition=2025} from ReplicaDeletionSuccessful to null.
4403 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=0}, replica=0, tablePath=null, partition=2025} from ReplicaDeletionSuccessful to null.
4438 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.CommonTestUtils [] - Attempt failed, sleeping for 64 ms, and then retrying.
4439 [coordinator-event-thread] INFO  com.alibaba.fluss.server.zk.ZooKeeperClient [] - Deleted table assignment for partition id 0.
4441 [coordinator-event-thread] INFO  com.alibaba.fluss.server.coordinator.TableManager [] - Deletion of partition TablePartition{tableId=0, partitionId=0} successfully completed.
4538 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4539 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4540 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4543 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4543 [Curator-SafeNotifyService-0] DEBUG com.alibaba.fluss.server.coordinator.event.watcher.TableChangeWatcher [] - Received NODE_DELETED event
4556 [ForkJoinPool-1-worker-9] INFO  com.alibaba.fluss.testutils.common.TestLoggerExtension [] - 
--------------------------------------------------------------------------------
Test com.alibaba.fluss.server.coordinator.TableManagerITCase.testPartitionedTableManagement[[1] YEAR] successfully run.
================================================================================

You can see the state of TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} changes in the following steps:

// table is just created and notify tablet server to online the replica
3979 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from NonExistentReplica to NewReplica.
4043 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from NewReplica to OnlineReplica.

// table is dropped, move to offline and start to delete it
4224 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from OnlineReplica to OfflineReplica.
4249 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from OfflineReplica to ReplicaDeletionStarted.

// tablet server start the repica failed because of IOException (see above log), and report offline for it, but it was in deleting state, the state change is ignored 
4340 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Replica state for TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} should be in the [NewReplica, OnlineReplica, OfflineReplica] before moving to state OfflineReplica, but the current state is ReplicaDeletionStarted.
4340 [coordinator-event-thread] ERROR com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Fail to change state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=db1.tb1_YEAR, partition=2025} from ReplicaDeletionStarted to OfflineReplica.

// // tablet server remove the replica successfully, and change the replica state to ReplicaDeletionSuccessful
4396 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=null, partition=2025} from ReplicaDeletionStarted to ReplicaDeletionSuccessful.

// complete the table deletion, remove the state tracking for the table
4396 [coordinator-event-thread] DEBUG com.alibaba.fluss.server.coordinator.statemachine.ReplicaStateMachine [] - Successfully changed state for table bucket replica TableBucketReplica{tableBucket=TableBucket{tableId=0, partitionId=0, bucket=2}, replica=2, tablePath=null, partition=2025} from ReplicaDeletionSuccessful to null.

Therefore, it seems all the state transition works as expected, including the failed transition from ReplicaDeletionStarted -> OfflineReplica. But we should consider to change the log level from ERROR to WARN as there is nothing wrong in the system. But not sure, whether it's ok to change the log level, because we may still need to ERROR level for other cases.

cc @swuferhong , please take a look for this issue which may indicate a problem in our system.

[gyang94]

@wuchong Thanks for detailed explanation. Yes, the state transition is good. And I am going to share what I found last time about why the state will change from ReplicaDeletionStarted to OfflineReplica:

1. The CoordinatorEventProcessor received a NotifyLeaderAndIsrResponseReceivedEvent . In this event there is an Api.Error with StorageException. Then the processor marks the replica to be offline in CoordinatorEventProcessor.onReplicaBecomeOffline().
2. There StorageException was thrown in ReplicaManager.validateAndGetIsBecomeLeader(). It it because in ReplicaManager.maybeCreateReplica() function, it failed to get table info from zookeeper getTableInfo(zkClient, tablePath). The schema info does not exists in zookeeper.

Since we have dropped table and delete all zk nodes under the table path (in MetadataManager.dropTable), it should be expected that in ReplicaManager cannot find schema info in zookeeper.

In my option, we don't have to switch the state from ReplicaDeletionStarted back to OfflineReplica, just ignore this transition would be fine. This transition is not valid, but we don't need treat it as an error and log error on it.

I suggest to add a couldBeIgnoredTransition() function in ReplicaStateMachine

if (isValidReplicaStateTransition(curState, targetState)) {
    return true;
} else if (couldBeIgnoredTransition(curState, targetState)) {
    // do something for ignored invalid transition
    // e.g. log.warn()
    return false;
} else  {
    logInvalidTransition(replica, curState, targetState);
    logFailedSateChange(replica, curState, targetState);
    return false;
}

[wuchong]

@gyang94 Yes, the reasons you analyzed are correct.

Regarding the logging, I'm still wondering whether we should treat them as WARN or ERROR. Because, another fixing way is resolve the StorageException in ReplicaManager side.