Inconsistent Index Handles

translator_bot · June 22, 2024, 7:06pm

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

Original topic: inconsistent index handles

| username: Mingdr

[TiDB Usage Environment] Production Environment
[TiDB Version] 3.0.11

[Encountered Problem: This error log issue has been persistent. Initially, I thought it was an index problem, so I deleted and rebuilt the index, but the error still occurs.

Executed admin check table and check index, both returned ok, but the error still appears in the logs.

Table Structure:

CREATE TABLE `sum_merch` (
  `SUMMARY_ID` int(11) NOT NULL AUTO_INCREMENT,
  `MERCH_ID` int(11) NOT NULL COMMENT 'Ordinary Merchant or Main Merchant ID',
  `SUB_MERCH_ID` int(11) DEFAULT NULL COMMENT 'Sub Merchant ID',
  `CHAN_CODE` char(1) NOT NULL COMMENT 'Payment Channel',
  `SUB_CHAN_CODE` char(1) DEFAULT NULL,
  `SUMMARY_DATE` date NOT NULL COMMENT 'Summary Date',
  `SCENE` char(1) NOT NULL COMMENT 'Business Scene Code'
  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='Merchant Transaction Summary'

[Resource Configuration] 3pd 3server 5kv

translator_bot · June 22, 2024, 7:06pm

| username: xfworld | Original post link

It feels like the index creation is not completed yet…
Indexes are also stored through regions, so check if all the index regions are fully built…

At first, I thought it was a length issue, but after looking at the index key, it was relatively short, so I gave up on that idea.

Additionally, the 3.X version is quite old, so you might want to consider upgrading to a newer version.

translator_bot · June 22, 2024, 7:06pm

| username: Mingdr | Original post link

How do you check the index region?
Our version is too old, so we are planning to deploy version 6.x directly when the server expires.

translator_bot · June 22, 2024, 7:06pm

| username: Billmay表妹 | Original post link

You can upgrade it, the current version is too low and may have some issues that have already been fixed.

translator_bot · June 22, 2024, 7:06pm

| username: xfworld | Original post link

You can check through the metadata records of TiKV.

Specific operations:

After obtaining the index region, use the TiKV CLI to verify each region.

translator_bot · June 22, 2024, 7:06pm

| username: Mingdr | Original post link

I looked at them one by one and found that one of the regions is a bit strange, missing middle_key_by_approximate_size.

Region 79107

translator_bot · June 22, 2024, 7:06pm

| username: Mingdr | Original post link

Found some logs of this region on TiKV 4:

[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:

translator_bot · June 22, 2024, 7:06pm

| username: xfworld | Original post link

These are all info and are normal.

It’s not that there’s no way to handle this, but the cost is too high because even after handling it, it might still occur.

I suggest you consider upgrading…
Two options:

Upgrade to 3.1.X
The version gap is not too big, but the upgrade might still impact the business, so you need to prepare backup and rollback plans.
Upgrade to 6.5.X
The version gap is too large, so it’s recommended to set up a new environment and directly migrate the data…

translator_bot · June 22, 2024, 7:06pm

| username: Mingdr | Original post link

Okay, this is not a core business. Let’s upgrade to 6.x next time. Thanks~

translator_bot · June 22, 2024, 7:06pm

| username: system | Original post link

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.