tikv error when demote follower to learner #11463

dbsid · 2021-11-24T06:43:33Z

Bug Report

What version of TiKV are you using?

[root@tikv-1-0 bin]# ./tikv-server -V
TiKV
Release Version:   5.3.0
Edition:           Community
Git Commit Hash:   2bba8cce69b1da1cfb1181ed4630b084ad7a542b
Git Commit Branch: heads/refs/tags/v5.2.3
UTC Build Time:    2021-11-20 04:29:29
Rust Version:      rustc 1.56.0-nightly (2faabf579 2021-07-27)
Enable Features:   jemalloc mem-profiling portable sse protobuf-codec test-engines-rocksdb cloud-aws cloud-gcp
Profile:           dist_release

What operating system and CPU are you using?

x86 linux

Steps to reproduce

disable balance pd-ctl config set region-schedule-limit 0
enable placement rules pd-ctl config placement-rules enable
prepared rules.json

  {
    "group_id": "pd",
    "rules": [
      {
        "group_id": "pd",
        "id": "default",
        "start_key": "",
        "end_key": "",
        "role": "voter",
        "count": 1
      },
      {
        "group_id": "pd",
        "id": "learner",
        "start_key": "",
        "end_key": "",
        "role": "learner",
        "count": 2,
        "location_labels": [ "zone", "host"]
      }
    ]
  }
]

apply the rules pd-ctl config placement-rules rule-bundle save --in="rules.json"

What did you expect?

followers demoted to learner

What did happened?

no learners from the pd monitor panel.
pd error observed

"fix-demote-voter {demote peer: store [2]} (kind:leader, region:27297(575,5), createAt:2021-11-24 14:13:03.029484698 +0800 CST m=+1723.126547708, startAt:2021-11-24 14:13:03.02956604 +0800 CST m=+1723.126629057, currentStep:1, steps:[transfer leader from store 2 to store 1, demote follower peer 27299 on store 2 to learner]) timeout",
  "fix-demote-voter {demote peer: store [2]} (kind:leader, region:27241(575,5), createAt:2021-11-24 14:13:03.026463593 +0800 CST m=+1723.123526603, startAt:2021-11-24 14:13:03.026487511 +0800 CST m=+1723.123550523, currentStep:1, steps:[transfer leader from store 2 to store 1, demote follower peer 27243 on store 2 to learner]) timeout",
  "fix-demote-voter {demote peer: store [2]} (kind:unknown, region:28201(531,5), createAt:2021-11-24 14:13:03.083497632 +0800 CST m=+1723.180560641, startAt:2021-11-24 14:13:03.083519035 +0800 CST m=+1723.180582046, currentStep:0, steps:[demote follower peer 28203 on store 2 to learner]) timeout",
  "fix-demote-voter {demote peer: store [2]} (kind:unknown, region:29229(470,5), createAt:2021-11-24 14:13:03.123877868 +0800 CST m=+1723.220940885, startAt:2021-11-24 14:13:03.123914335 +0800 CST m=+1723.220977375, currentStep:0, steps:[demote follower peer 29231 on store 2 to learner]) timeout",
  "fix-demote-voter {demote peer: store [2]} (kind:unknown, region:29541(580,5), createAt:2021-11-24 14:13:03.138161506 +0800 CST m=+1723.235224516, startAt:2021-11-24 14:13:03.138180225 +0800 CST m=+1723.235243236, currentStep:0, steps:[demote follower peer 29543 on store 2 to learner]) timeout"

tikv error observed

[2021/11/24 14:28:32.985 +08:00] [INFO] [apply.rs:1755] ["exec ConfChange"] [epoch="conf_ver: 5 version: 363"] [type=AddLearner] [peer_id=26238] [region_id=26237]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1248] ["execute raft command"] [err_code=KV:Raftstore:Unknown] [err="Other(\"[components/raftstore/src/store/fsm/apply.rs:1884]: can't add duplicated learner id: 26223 store_id: 2 role: Learner to region id: 26221 start_key: 7480000000000000FF415F728000000000FF1F9C1A0000000000FA end_key: 7480000000000000FF415F728000000000FF25FD970000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26222 store_id: 1 } peers { id: 26223 store_id: 2 } peers { id: 26224 store_id: 5 }\")"] [peer_id=26222] [region_id=26221]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1877] ["can't add duplicated learner"] [region="id: 26237 start_key: 7480000000000000FF415F728000000000FF394C840000000000FA end_key: 7480000000000000FF415F728000000000FF3FB3090000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26238 store_id: 1 } peers { id: 26239 store_id: 2 } peers { id: 26240 store_id: 5 }"] [peer="id: 26239 store_id: 2 role: Learner"] [peer_id=26238] [region_id=26237]
[2021/11/24 14:28:32.985 +08:00] [INFO] [apply.rs:1383] ["execute admin command"] [command="cmd_type: ChangePeer change_peer { change_type: AddLearnerNode peer { id: 26283 store_id: 2 role: Learner } }"] [index=933] [term=29] [peer_id=26282] [region_id=26281]
[2021/11/24 14:28:32.985 +08:00] [INFO] [apply.rs:1755] ["exec ConfChange"] [epoch="conf_ver: 5 version: 363"] [type=AddLearner] [peer_id=26282] [region_id=26281]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1877] ["can't add duplicated learner"] [region="id: 26281 start_key: 7480000000000000FF415F728000000000FF7FA3860000000000FA end_key: 7480000000000000FF415F728000000000FF8602350000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26282 store_id: 1 } peers { id: 26283 store_id: 2 } peers { id: 26284 store_id: 5 }"] [peer="id: 26283 store_id: 2 role: Learner"] [peer_id=26282] [region_id=26281]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1248] ["execute raft command"] [err_code=KV:Raftstore:Unknown] [err="Other(\"[components/raftstore/src/store/fsm/apply.rs:1884]: can't add duplicated learner id: 26239 store_id: 2 role: Learner to region id: 26237 start_key: 7480000000000000FF415F728000000000FF394C840000000000FA end_key: 7480000000000000FF415F728000000000FF3FB3090000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26238 store_id: 1 } peers { id: 26239 store_id: 2 } peers { id: 26240 store_id: 5 }\")"] [peer_id=26238] [region_id=26237]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1248] ["execute raft command"] [err_code=KV:Raftstore:Unknown] [err="Other(\"[components/raftstore/src/store/fsm/apply.rs:1884]: can't add duplicated learner id: 26283 store_id: 2 role: Learner to region id: 26281 start_key: 7480000000000000FF415F728000000000FF7FA3860000000000FA end_key: 7480000000000000FF415F728000000000FF8602350000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26282 store_id: 1 } peers { id: 26283 store_id: 2 } peers { id: 26284 store_id: 5 }\")"] [peer_id=26282] [region_id=26281]
[2021/11/24 14:28:32.985 +08:00] [INFO] [apply.rs:1383] ["execute admin command"] [command="cmd_type: ChangePeer change_peer { change_type: AddLearnerNode peer { id: 26503 store_id: 2 role: Learner } }"] [index=904] [term=23] [peer_id=26502] [region_id=26501]
[2021/11/24 14:28:32.985 +08:00] [INFO] [apply.rs:1755] ["exec ConfChange"] [epoch="conf_ver: 5 version: 363"] [type=AddLearner] [peer_id=26502] [region_id=26501]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1877] ["can't add duplicated learner"] [region="id: 26501 start_key: 7480000000000000FF4B5F728000000000FF2C6AC20000000000FA end_key: 7480000000000000FF4B5F728000000000FF32DDE10000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26502 store_id: 1 } peers { id: 26503 store_id: 2 } peers { id: 26504 store_id: 5 }"] [peer="id: 26503 store_id: 2 role: Learner"] [peer_id=26502] [region_id=26501]
[2021/11/24 14:28:32.985 +08:00] [INFO] [apply.rs:1383] ["execute admin command"] [command="cmd_type: ChangePeer change_peer { change_type: AddLearnerNode peer { id: 26495 store_id: 2 role: Learner } }"] [index=920] [term=27] [peer_id=26494] [region_id=26493]
[2021/11/24 14:28:32.985 +08:00] [INFO] [apply.rs:1755] ["exec ConfChange"] [epoch="conf_ver: 5 version: 363"] [type=AddLearner] [peer_id=26494] [region_id=26493]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1877] ["can't add duplicated learner"] [region="id: 26493 start_key: 7480000000000000FF4B5F728000000000FF1FA3EC0000000000FA end_key: 7480000000000000FF4B5F728000000000FF2610740000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26494 store_id: 1 } peers { id: 26495 store_id: 2 } peers { id: 26496 store_id: 5 }"] [peer="id: 26495 store_id: 2 role: Learner"] [peer_id=26494] [region_id=26493]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1248] ["execute raft command"] [err_code=KV:Raftstore:Unknown] [err="Other(\"[components/raftstore/src/store/fsm/apply.rs:1884]: can't add duplicated learner id: 26503 store_id: 2 role: Learner to region id: 26501 start_key: 7480000000000000FF4B5F728000000000FF2C6AC20000000000FA end_key: 7480000000000000FF4B5F728000000000FF32DDE10000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26502 store_id: 1 } peers { id: 26503 store_id: 2 } peers { id: 26504 store_id: 5 }\")"] [peer_id=26502] [region_id=26501]
[2021/11/24 14:28:32.985 +08:00] [ERROR] [apply.rs:1248] ["execute raft command"] [err_code=KV:Raftstore:Unknown] [err="Other(\"[components/raftstore/src/store/fsm/apply.rs:1884]: can't add duplicated learner id: 26495 store_id: 2 role: Learner to region id: 26493 start_key: 7480000000000000FF4B5F728000000000FF1FA3EC0000000000FA end_key: 7480000000000000FF4B5F728000000000FF2610740000000000FA region_epoch { conf_ver: 5 version: 363 } peers { id: 26494 store_id: 1 } peers { id: 26495 store_id: 2 } peers { id: 26496 store_id: 5 }\")"] [peer_id=26494] [region_id=26493]

The text was updated successfully, but these errors were encountered:

dbsid · 2021-11-24T06:47:17Z

/assign NingLin-P

NingLin-P · 2021-11-24T08:11:47Z

When demoting a voter to a learner with simple confchange, the following check will fail because L1876 only checks whether the current region peer list contains the incoming learner peer id but not whether its role is the requested role.

Previously there are no such schedule (demoting a voter to a learner with simple confchange) but it is supported recently by PD and hence lead to this issue.

tikv/components/raftstore/src/store/fsm/apply.rs

Lines 1871 to 1899 in 6a0792a

    
           ConfChangeType::AddLearnerNode => { 
        
               PEER_ADMIN_CMD_COUNTER_VEC 
        
                   .with_label_values(&["add_learner", "all"]) 
        
                   .inc(); 
        
               if util::find_peer(&region, store_id).is_some() { 
        
                   error!( 
        
                       "can't add duplicated learner"; 
        
                       "region_id" => self.region_id(), 
        
                       "peer_id" => self.id(), 
        
                       "peer" => ?peer, 
        
                       "region" => ?&self.region 
        
                   ); 
        
                   return Err(box_err!( 
        
                       "can't add duplicated learner {:?} to region {:?}", 
        
                       peer, 
        
                       self.region 
        
                   )); 
        
               } 
        
               region.mut_peers().push(peer.clone()); 
        
               PEER_ADMIN_CMD_COUNTER_VEC 
        
                   .with_label_values(&["add_learner", "success"]) 
        
                   .inc(); 
        
               info!( 
        
                   "add learner successfully"; 
        
                   "region_id" => self.region_id(), 
        
                   "peer_id" => self.id(), 
        
                   "peer" => ?peer,

BusyJay · 2021-11-24T11:10:54Z

Why PD wants to demote follower to learner with single step?

HunDunDM · 2021-12-03T07:51:55Z

After PD enables joint consensus, joint consensus will not be used for changes that only have a single demote. But PD did not produce such scheduling before. DemoteFollower must be used as recorded in pd#4140, which is supported in v5.3.0.

HunDunDM · 2021-12-03T07:53:10Z

DemoteFollower was tested when joint consensus was introduced in v5.0.0.

w41ter · 2021-12-06T08:54:28Z

@BusyJay @NingLin-P
Do you have any suggestions for fixing this problem? It seems that may cause incompatibility or even insecurity if modify the logic in apply.rs directly.

w41ter · 2021-12-06T09:21:41Z

HeartbeatResponse::change_peer_v2 would demoting a voter directly, how about use change_peer_v2 instead of change_peer to demote a voter to learner?

BusyJay · 2021-12-06T09:38:54Z

Isn't just rejecting the proposal should be enough?

Lily2025 · 2021-12-06T10:18:10Z

/type bug

BusyJay · 2021-12-07T12:50:49Z

HeartbeatResponse::change_peer_v2 would demoting a voter directly, how about use change_peer_v2 instead of change_peer to demote a voter to learner?

I see your question. It feels good to me. /cc @NingLin-P

w41ter · 2021-12-09T08:31:15Z

@HunDunDM I have submit a PR to solve this problem, would you like to help me review the code?

NingLin-P · 2021-12-14T07:04:59Z

HeartbeatResponse::change_peer_v2 would demoting a voter directly, how about use change_peer_v2 instead of change_peer to demote a voter to learner?

lgtm

HunDunDM · 2022-01-06T04:20:05Z

fixed by tikv/pd#4534

ti-chi-bot assigned NingLin-P Nov 24, 2021

HunDunDM mentioned this issue Dec 3, 2021

server/schedule: prevent removing voters directly in 2 replica raft group tikv/pd#4412

Closed

ti-chi-bot added the type/bug The issue is confirmed as a bug. label Dec 6, 2021

This was referenced Dec 9, 2021

Demoting single voter directly isn't working tikv/pd#4444

Closed

server/schedule: use ChangePeerV2 to demote single voter directly tikv/pd#4445

Closed

jebter added the severity/major label Dec 15, 2021

lcwangchao mentioned this issue Dec 30, 2021

Learner peers cannot be scheduled using placement settings pingcap/tidb#31173

Closed

HunDunDM mentioned this issue Jan 6, 2022

operator: remove empty JointConsensus steps and fix single voter demote bug tikv/pd#4534

Merged

NingLin-P closed this as completed Jan 10, 2022

jebter added the affects-5.3 This bug affects 5.3.x versions. label Jan 18, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

tikv error when demote follower to learner #11463

tikv error when demote follower to learner #11463

dbsid commented Nov 24, 2021 •

edited

Loading

dbsid commented Nov 24, 2021

NingLin-P commented Nov 24, 2021 •

edited

Loading

BusyJay commented Nov 24, 2021

HunDunDM commented Dec 3, 2021

HunDunDM commented Dec 3, 2021

w41ter commented Dec 6, 2021

w41ter commented Dec 6, 2021

BusyJay commented Dec 6, 2021

Lily2025 commented Dec 6, 2021

BusyJay commented Dec 7, 2021

w41ter commented Dec 9, 2021

NingLin-P commented Dec 14, 2021

HunDunDM commented Jan 6, 2022

tikv error when demote follower to learner #11463

tikv error when demote follower to learner #11463

Comments

dbsid commented Nov 24, 2021 • edited Loading

Bug Report

What version of TiKV are you using?

What operating system and CPU are you using?

Steps to reproduce

What did you expect?

What did happened?

dbsid commented Nov 24, 2021

NingLin-P commented Nov 24, 2021 • edited Loading

BusyJay commented Nov 24, 2021

HunDunDM commented Dec 3, 2021

HunDunDM commented Dec 3, 2021

w41ter commented Dec 6, 2021

w41ter commented Dec 6, 2021

BusyJay commented Dec 6, 2021

Lily2025 commented Dec 6, 2021

BusyJay commented Dec 7, 2021

w41ter commented Dec 9, 2021

NingLin-P commented Dec 14, 2021

HunDunDM commented Jan 6, 2022

dbsid commented Nov 24, 2021 •

edited

Loading

NingLin-P commented Nov 24, 2021 •

edited

Loading