inconsistent index handles

[Mingdr (会飞的猫)]

【 TiDB 使用环境】生产环境
【 TiDB 版本】3.0.11

【遇到的问题：一直有这个错误日志问题，一开始以为是索引问题，就删除这个索引然后重建，依旧报这个错。

执行过admin check table 和 check index 都正常返回ok，但是日志依旧出现这种错误

表结构：

CREATE TABLE `sum_merch` (
  `SUMMARY_ID` int(11) NOT NULL AUTO_INCREMENT,
  `MERCH_ID` int(11) NOT NULL COMMENT '普通商户或主商户ID',
  `SUB_MERCH_ID` int(11) DEFAULT NULL COMMENT '子商户ID',
  `CHAN_CODE` char(1) NOT NULL COMMENT '支付渠道',
  `SUB_CHAN_CODE` char(1) DEFAULT NULL,
  `SUMMARY_DATE` date NOT NULL COMMENT '汇总日期',
  `SCENE` char(1) NOT NULL COMMENT '业务场景编码'
  PRIMARY KEY (`SUMMARY_ID`),
  KEY `INDEX_SUMMARY_DATE` (`SUMMARY_DATE`),
  KEY `INDEX_MERCH_SUMMARY_DATE_NEW` (`MERCH_ID`,`SUMMARY_DATE`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin AUTO_INCREMENT=7860001 COMMENT='商户交易汇总'

【资源配置】3pd 3server 5kv

[xfworld (魔幻之翼)]

感觉是索引新建之后，回填没完成…
索引也是通过 region 来存放的，看看能不能检查下 index region 是否全部建设完成了…

---

我开始以为是长度问题，看了下index 的key，这个长度比较短，就放弃了

另外 3.X 的版本比较旧了，可以考虑 升级版本了

[Mingdr (会飞的猫)]

@xfworld

检查下 index region

怎么 检查 index region 呢
我们版本太低了 准备等服务器到期直接部署6.x的版本

[Billmay表妹 (表妹)]

可以升级下，版本太低了~可能会出现一些已经被修复国的问题~

[xfworld (魔幻之翼)]

可以通过 tikv 的元数据记录去查看

具体操作：
https://docs.pingcap.com/zh/tidb/v3.0/sql-statement-show-table-regions

index region 获取后，通过 tikv cli 来对每个region 进行校对

https://docs.pingcap.com/zh/tidb/v3.0/tikv-control#打印-region-的-properties-信息

[Mingdr (会飞的猫)]

我一个个看了一下，发现其中有个region有点奇怪 缺失 middle_key_by_approximate_size

79107那个region

[Mingdr (会飞的猫)]

在4这台tikv上发现了这个region的一些日志

[2023/01/17 17:25:01.234 +08:00] [INFO] [peer.rs:175] [“replicate peer”] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:01.234 +08:00] [INFO] [raft.rs:723] [“[region 79107] 407315 became follower at term 0”]
[2023/01/17 17:25:01.234 +08:00] [INFO] [raft.rs:295] [“[region 79107] 407315 newRaft [peers: , term: 0, commit: 0, applied: 0, last_index: 0, last_term: 0]”]
[2023/01/17 17:25:01.234 +08:00] [INFO] [raft.rs:723] [“[region 79107] 407315 became follower at term 1”]
[2023/01/17 17:25:01.234 +08:00] [INFO] [raft.rs:924] [“[region 79107] 407315 [term: 1] received a MsgHeartbeat message with higher term from 163121 [term: 12]”]
[2023/01/17 17:25:01.234 +08:00] [INFO] [raft.rs:723] [“[region 79107] 407315 became follower at term 12”]
[2023/01/17 17:25:02.588 +08:00] [INFO] [snap.rs:223] [“saving snapshot file”] [file=/data/tidb/deploy/data/snap/rev_79107_12_3735427_(default|lock|write).sst] [snap_key=79107_12_3735427]
[2023/01/17 17:25:02.592 +08:00] [INFO] [raft.rs:1829] [“[region 79107] 407315 [commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 3735427, term: 12]”]
[2023/01/17 17:25:02.592 +08:00] [INFO] [raft.rs:1853] [“[region 79107] 407315 restored progress of 163121 [Some(Progress { matched: 0, next_idx: 1, state: Probe, paused: false, pending_snapshot: 0, recent_active: false, ins: Inflights { start: 0, count: 0, buffer: }, is_learner: false })]”]
[2023/01/17 17:25:02.592 +08:00] [INFO] [raft.rs:1853] [“[region 79107] 407315 restored progress of 406813 [Some(Progress { matched: 0, next_idx: 1, state: Probe, paused: false, pending_snapshot: 0, recent_active: false, ins: Inflights { start: 0, count: 0, buffer: }, is_learner: false })]”]
[2023/01/17 17:25:02.592 +08:00] [INFO] [raft.rs:1853] [“[region 79107] 407315 restored progress of 407314 [Some(Progress { matched: 0, next_idx: 1, state: Probe, paused: false, pending_snapshot: 0, recent_active: false, ins: Inflights { start: 0, count: 0, buffer: }, is_learner: false })]”]
[2023/01/17 17:25:02.592 +08:00] [INFO] [raft.rs:1853] [“[region 79107] 407315 restored progress of 407315 [Some(Progress { matched: 0, next_idx: 1, state: Probe, paused: false, pending_snapshot: 0, recent_active: false, ins: Inflights { start: 0, count: 0, buffer: }, is_learner: true })]”]
[2023/01/17 17:25:02.592 +08:00] [INFO] [raft_log.rs:474] [“[region 79107] 407315 log [committed=0, applied=0, unstable.offset=1, unstable.entries.len()=0] starts to restore snapshot [index: 3735427, term: 12]”]
[2023/01/17 17:25:02.592 +08:00] [INFO] [raft.rs:1773] [“[region 79107] 407315 [commit: 3735427] restored snapshot [index: 3735427, term: 12]”]
[2023/01/17 17:25:02.592 +08:00] [INFO] [peer_storage.rs:901] [“begin to apply snapshot”] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:02.592 +08:00] [INFO] [peer_storage.rs:941] [“apply snapshot with state ok”] [state=“applied_index: 3735427 truncated_state { index: 3735427 term: 12 }”] [region=“id: 79107 start_key: 7480000000000006FF535F698000000000FF0000050380000000FF000014CA0419A6D6FF0000000000038000FF00000033770B0000FD end_key: 7480000000000006FF535F728000000000FF0087230000000000FA region_epoch { conf_ver: 288 version: 1333 } peers { id: 163121 store_id: 144610 } peers { id: 406813 store_id: 1 } peers { id: 407314 store_id: 255992 } peers { id: 407315 store_id: 4 is_learner: true }”] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:02.616 +08:00] [INFO] [peer.rs:2001] [“snapshot is applied”] [region=“id: 79107 start_key: 7480000000000006FF535F698000000000FF0000050380000000FF000014CA0419A6D6FF0000000000038000FF00000033770B0000FD end_key: 7480000000000006FF535F728000000000FF0087230000000000FA region_epoch { conf_ver: 288 version: 1333 } peers { id: 163121 store_id: 144610 } peers { id: 406813 store_id: 1 } peers { id: 407314 store_id: 255992 } peers { id: 407315 store_id: 4 is_learner: true }”] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:02.616 +08:00] [INFO] [region.rs:277] [“begin apply snap data”] [region_id=79107]
[2023/01/17 17:25:03.189 +08:00] [INFO] [region.rs:346] [“apply new data”] [time_takes=567.683346ms] [region_id=79107]
[2023/01/17 17:25:03.448 +08:00] [INFO] [apply.rs:1067] [“execute admin command”] [command=“cmd_type: ChangePeer change_peer { peer { id: 407315 store_id: 4 } }”] [index=3735826] [term=12] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:03.448 +08:00] [INFO] [apply.rs:1391] [“exec ConfChange”] [epoch=“conf_ver: 288 version: 1333”] [type=AddNode] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:03.448 +08:00] [INFO] [apply.rs:1446] [“add peer successfully”] [region=“id: 79107 start_key: 7480000000000006FF535F698000000000FF0000050380000000FF000014CA0419A6D6FF0000000000038000FF00000033770B0000FD end_key: 7480000000000006FF535F728000000000FF0087230000000000FA region_epoch { conf_ver: 288 version: 1333 } peers { id: 163121 store_id: 144610 } peers { id: 406813 store_id: 1 } peers { id: 407314 store_id: 255992 } peers { id: 407315 store_id: 4 is_learner: true }”] [peer=“id: 407315 store_id: 4”] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:03.449 +08:00] [INFO] [apply.rs:1067] [“execute admin command”] [command=“cmd_type: ChangePeer change_peer { change_type: RemoveNode peer { id: 406813 store_id: 1 } }”] [index=3735829] [term=12] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:03.449 +08:00] [INFO] [apply.rs:1391] [“exec ConfChange”] [epoch=“conf_ver: 289 version: 1333”] [type=RemoveNode] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:03.449 +08:00] [INFO] [apply.rs:1499] [“remove peer successfully”] [region=“id: 79107 start_key: 7480000000000006FF535F698000000000FF0000050380000000FF000014CA0419A6D6FF0000000000038000FF00000033770B0000FD end_key: 7480000000000006FF535F728000000000FF0087230000000000FA region_epoch { conf_ver: 289 version: 1333 } peers { id: 163121 store_id: 144610 } peers { id: 406813 store_id: 1 } peers { id: 407314 store_id: 255992 } peers { id: 407315 store_id: 4 }”] [peer=“id: 406813 store_id: 1”] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:05.629 +08:00] [INFO] [raft.rs:1662] [“[region 79107] 407315 [term 12] received MsgTimeoutNow from 163121 and starts an election to get leadership.”]
[2023/01/17 17:25:05.629 +08:00] [INFO] [raft.rs:1094] [“[region 79107] 407315 is starting a new election at term 12”]
[2023/01/17 17:25:05.629 +08:00] [INFO] [raft.rs:743] [“[region 79107] 407315 became candidate at term 13”]
[2023/01/17 17:25:05.629 +08:00] [INFO] [raft.rs:858] [“[region 79107] 407315 received MsgRequestVoteResponse from 407315 at term 13”]
[2023/01/17 17:25:05.629 +08:00] [INFO] [raft.rs:832] [“[region 79107] 407315 [logterm: 12, index: 3736279] sent MsgRequestVote request to 407314 at term 13”]
[2023/01/17 17:25:05.629 +08:00] [INFO] [raft.rs:832] [“[region 79107] 407315 [logterm: 12, index: 3736279] sent MsgRequestVote request to 163121 at term 13”]
[2023/01/17 17:25:05.630 +08:00] [INFO] [raft.rs:858] [“[region 79107] 407315 received MsgRequestVoteResponse from 407314 at term 13”]
[2023/01/17 17:25:05.630 +08:00] [INFO] [raft.rs:1587] [“[region 79107] 407315 [quorum:2] has received 2 MsgRequestVoteResponse votes and 0 vote rejections”]
[2023/01/17 17:25:05.630 +08:00] [INFO] [raft.rs:793] [“[region 79107] 407315 became leader at term 13”]
[2023/01/17 17:25:05.643 +08:00] [INFO] [raft.rs:924] [“[region 83787] 407152 [term: 3358] received a MsgRequestVote message with higher term from 407106 [term: 3359]”]
[2023/01/17 17:25:05.643 +08:00] [INFO] [raft.rs:723] [“[region 83787] 407152 became follower at term 3359”]
[2023/01/17 17:25:05.643 +08:00] [INFO] [raft.rs:1108] [“[region 83787] 407152 [logterm: 3358, index: 5618503936, vote: 0] cast MsgRequestVote for 407106 [logterm: 3358, index: 5618503936] at term 3359”]
[2023/01/17 17:25:05.645 +08:00] [INFO] [process.rs:175] [“get snapshot failed”] [err=“Request(message: "peer is not leader for region 83787, leader may Some(id: 407106 store_id: 1)" not_leader { region_id: 83787 leader { id: 407106 store_id: 1 } })”] [cid=1394805065]
[2023/01/17 17:25:05.645 +08:00] [INFO] [process.rs:175] [“get snapshot failed”] [err=“Request(message: "peer is not leader for region 83787, leader may Some(id: 407106 store_id: 1)" not_leader { region_id: 83787 leader { id: 407106 store_id: 1 } })”] [cid=1394805066]
[2023/01/17 17:25:05.653 +08:00] [INFO] [apply.rs:1067] [“execute admin command”] [command=“cmd_type: ChangePeer change_peer { change_type: AddLearnerNode peer { id: 407316 store_id: 255992 is_learner: true } }”] [index=5618503939] [term=3359] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:05.653 +08:00] [INFO] [apply.rs:1391] [“exec ConfChange”] [epoch=“conf_ver: 11603 version: 7891”] [type=AddLearner] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:05.653 +08:00] [INFO] [apply.rs:1531] [“add learner successfully”] [region=“id: 83787 start_key: 7480000000000028FF1B5F7280000000D2FFC798150000000000FA end_key: 7480000000000028FF1E5F698000000000FF0000010380000000FF0000034603800000FF0000001A08000000FC region_epoch { conf_ver: 11603 version: 7891 } peers { id: 407106 store_id: 1 } peers { id: 407124 store_id: 164975 } peers { id: 407152 store_id: 4 }”] [peer=“id: 407316 store_id: 255992 is_learner: true”] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.437 +08:00] [INFO] [apply.rs:1067] [“execute admin command”] [command=“cmd_type: ChangePeer change_peer { peer { id: 407316 store_id: 255992 } }”] [index=5618504263] [term=3359] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.437 +08:00] [INFO] [apply.rs:1391] [“exec ConfChange”] [epoch=“conf_ver: 11604 version: 7891”] [type=AddNode] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.437 +08:00] [INFO] [apply.rs:1446] [“add peer successfully”] [region=“id: 83787 start_key: 7480000000000028FF1B5F7280000000D2FFC798150000000000FA end_key: 7480000000000028FF1E5F698000000000FF0000010380000000FF0000034603800000FF0000001A08000000FC region_epoch { conf_ver: 11604 version: 7891 } peers { id: 407106 store_id: 1 } peers { id: 407124 store_id: 164975 } peers { id: 407152 store_id: 4 } peers { id: 407316 store_id: 255992 is_learner: true }”] [peer=“id: 407316 store_id: 255992”] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.437 +08:00] [INFO] [apply.rs:1067] [“execute admin command”] [command=“cmd_type: ChangePeer change_peer { change_type: RemoveNode peer { id: 407152 store_id: 4 } }”] [index=5618504265] [term=3359] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.437 +08:00] [INFO] [apply.rs:1391] [“exec ConfChange”] [epoch=“conf_ver: 11605 version: 7891”] [type=RemoveNode] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.437 +08:00] [INFO] [apply.rs:1499] [“remove peer successfully”] [region=“id: 83787 start_key: 7480000000000028FF1B5F7280000000D2FFC798150000000000FA end_key: 7480000000000028FF1E5F698000000000FF0000010380000000FF0000034603800000FF0000001A08000000FC region_epoch { conf_ver: 11605 version: 7891 } peers { id: 407106 store_id: 1 } peers { id: 407124 store_id: 164975 } peers { id: 407152 store_id: 4 } peers { id: 407316 store_id: 255992 }”] [peer=“id: 407152 store_id: 4”] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.437 +08:00] [INFO] [router.rs:245] [“[region 83787] shutdown mailbox”]
[2023/01/17 17:25:07.438 +08:00] [INFO] [apply.rs:2802] [“target region is not found, drop messages”] [region_id=83787]
[2023/01/17 17:25:07.438 +08:00] [INFO] [peer.rs:1289] [“starts destroy”] [merged_by_target=false] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.438 +08:00] [INFO] [peer.rs:527] [“begin to destroy”] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.441 +08:00] [INFO] [peer_storage.rs:1325] [“finish clear peer meta”] [takes=3.203294ms] [raft_logs=1062] [raft_key=1] [apply_key=1] [meta_key=1] [region_id=83787]
[2023/01/17 17:25:07.442 +08:00] [INFO] [peer.rs:574] [“peer destroy itself”] [takes=4.545237ms] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:07.442 +08:00] [INFO] [router.rs:245] [“[region 83787] shutdown mailbox”]
[2023/01/17 17:25:07.442 +08:00] [INFO] [region.rs:457] [“register deleting data in range”] [end_key=7A7480000000000028FF1E5F698000000000FF0000010380000000FF0000034603800000FF0000001A08000000FC] [start_key=7A7480000000000028FF1B5F7280000000D2FFC798150000000000FA] [region_id=83787]
[2023/01/17 17:25:08.181 +08:00] [INFO] [peer.rs:450] [“deleting applied snap file”] [snap_file=79107_12_3735427] [peer_id=407315] [region_id=79107]
[2023/01/17 17:25:08.188 +08:00] [INFO] [peer.rs:660] [“failed to schedule peer tick”] [err=“sending on a disconnected channel”] [tick=RAFT] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:11.978 +08:00] [INFO] [peer.rs:660] [“failed to schedule peer tick”] [err=“sending on a disconnected channel”] [tick=RAFT_LOG_GC] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:11.978 +08:00] [INFO] [peer.rs:660] [“failed to schedule peer tick”] [err=“sending on a disconnected channel”] [tick=SPLIT_REGION_CHECK] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:39.085 +08:00] [INFO] [compact.rs:118] [“compact range finished”] [time_takes=262.903609ms] [cf=lock] [range_end=None] [range_start=None]
[2023/01/17 17:25:39.844 +08:00] [INFO] [peer.rs:660] [“failed to schedule peer tick”] [err=“sending on a disconnected channel”] [tick=PD_HEARTBEAT] [peer_id=407152] [region_id=83787]
[2023/01/17 17:25:52.509 +08:00] [INFO] [peer.rs:175] [“replicate peer”] [peer_id=407318] [region_id=407292]

[xfworld (魔幻之翼)]

这些都是info，都是正常的

处理这个也不是没办法，但是代价太大了，因为处理好之后，可能还会出现

---

---

我建议你考虑升级算了…
两种选择

• 升到 3.1.X
  版本跨度不太大，但是升级也有可能会对业务有影响，需要做好备份和回滚方案

• 升到 6.5.X
  版本跨度太大了，建议搭建新的环境，直接迁移数据…

[Mingdr (会飞的猫)]

好的，这个不是什么核心业务，等下次直接升级到6.x好了，感谢~