Some regions still in flashback state after flashback cluster done

[seiya-annie]

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

HA test for multi-valued index
loop inject pd-latency/tikv-latency/pd-timeoff failure during following steps:
1.add multi-valued index in table
2.flashback to the time before add index

2. What did you expect to see? (Required)

add index successfully
flashback successfully

3. What did you see instead (Required)

report tidb status abnormal during tikv-latency case:
in log we found:

[2023/05/30 18:48:12.466 +00:00] [INFO] [ddl_worker.go:601] ["[ddl] finish DDL job"] [worker="worker 3, tp general"] [job="ID:297, Type:drop index, State:synced, SchemaState:none, SchemaID:91, TableID:242, RowCount:0, ArgLen:4, start time: 2023-05-30 18:48:12.147 +0000 UTC, Err:<nil>, ErrCount:0, SnapshotVersion:0"]
[2023/05/30 18:48:12.645 +00:00] [INFO] [handle.go:1411] ["[stats] incrementally update modifyCount"] [tableID=243] [curModifyCnt=0] [results.BaseModifyCnt=0] [modifyCount=0]
[2023/05/30 18:48:12.645 +00:00] [INFO] [handle.go:1433] ["[stats] directly update count"] [tableID=243] [results.Count=1000000] [count=1000000]
[2023/05/30 18:48:12.650 +00:00] [WARN] [session.go:2239] ["run statement failed"] [schemaVersion=233] [error="region 94 is in flashback progress, FlashbackStartTS is 441836495043821576"] [session="{\n  \"currDBName\": \"\",\n  \"id\": 0,\n  \"status\": 3,\n  \"strictMode\": true,\n  \"txn\": \"441836501099347969\",\n  \"user\": null\n}"]
[2023/05/30 18:48:12.650 +00:00] [ERROR] [analyze.go:322] ["save table stats to storage failed"] [error="region 94 is in flashback progress, FlashbackStartTS is 441836495043821576"] [tableID=243]
[2023/05/30 18:48:12.653 +00:00] [INFO] [analyze.go:590] ["analyze table `test`.`user_data1` has failed"] [partition=] ["job info"="auto analyze table all columns with 256 buckets, 500 topn, 0.11 samplerate"] ["start time"=2023/05/30 18:48:10.259 +00:00] ["end time"=2023/05/30 18:48:12.650 +00:00] [cost=2.391293318s]
[2023/05/30 18:48:12.653 +00:00] [INFO] [tidb.go:285] ["rollbackTxn called due to ddl/autocommit failure"]
[2023/05/30 18:48:12.653 +00:00] [WARN] [session.go:2239] ["run statement failed"] [schemaVersion=226] [error="region 94 is in flashback progress, FlashbackStartTS is 441836495043821576"] [session="{\n  \"currDBName\": \"\",\n  \"id\": 622910720530448387,\n  \"status\": 2,\n  \"strictMode\": true,\n  \"user\": null\n}"]
[2023/05/30 18:48:12.653 +00:00] [ERROR] [update.go:1307] ["[stats] auto analyze failed"] [sql="analyze table `test`.`user_data1` index `j2`"] [cost_time=2.415044361s] [error="region 94 is in flashback progress, FlashbackStartTS is 441836495043821576"]
[2023/05/30 18:48:12.655 +00:00] [INFO] [domain.go:2023] ["HistoricalStatsWorker exited."]
[2023/05/30 18:48:12.655 +00:00] [INFO] [wait_group_wrapper.go:137] ["background process exited"] [source=domain] [process=HistoricalStatsWorker]
[2023/05/30 18:48:14.546 +00:00] [INFO] [cpuprofile.go:113] ["parallel cpu profiler started"]
[2023/05/30 18:48:14.546 +00:00] [INFO] [sem.go:78] ["tidb-server is operating with security enhanced mode (SEM) enabled"]
[2023/05/30 18:48:14.546 +00:00] [INFO] [printer.go:48] ["Welcome to TiDB."] ["Release Version"=v7.1.0] [Edition=Community] ["Git Commit Hash"=635a4362235e8a3c0043542e629532e3c7bb2756] ["Git Branch"=heads/refs/tags/v7.1.0] ["UTC Build Time"="2023-05-30 10:58:57"] [GoVersion=go1.20.3] ["Race Enabled"=false] ["Check Table Before Drop"=false] ["TiKV Min Version"=6.2.0-alpha]

4. What is your TiDB version? (Required)

v7.1.0

[seiya-annie]

tidb-0.log.gz
tidb-1.log.gz

[Defined2014]

After flashback cluster, some regions still in flashback state. Because TiKV receives a FlashbackCmd before FlashbackPrepare completes and returns a not prepare error to TiDB, TiDB will ignore it for some expected reasons.

tidb/ddl/cluster.go

Lines 555 to 557 in 3a489e4

	if err.Error() != fmt.Sprintf("region %d is not prepared for the flashback", loc.Region.GetID()) {
	return taskStat, err
	}

TiKV should not return before FlashbackPrepare is actually executed.

[Defined2014]

fixed by tikv/tikv#14859