直接写入tikv时，有一个节点leader降到0，频繁报：peer is not leader for region xxxx, leader may None

🛸 其他技术问题 rawkv/纯kv
1

【TiDB 使用环境】生产环境
【TiDB 版本】v6.5.3
我们有一个单纯的tikv集群，用作kv数据存储，用spark调用tikv-client-java包往里写数据时，有一个节点的leader会突然降到0

QQ_1751616581993
QQ_1751616581993655×370 28.8 KB

tikv日志：

[2025/07/04 16:10:00.666 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for region 274942, leader may Some(id: 274944 store_id: 10)\" not_leader { region_id: 274942 leader { id: 274944 store_id: 10 } }))))))"] [tag=raw_put] [thread_id=89]
[2025/07/04 16:10:00.667 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for region 226633, leader may Some(id: 226636 store_id: 10)\" not_leader { region_id: 226633 leader { id: 226636 store_id: 10 } }))))))"] [tag=raw_put] [thread_id=93]
[2025/07/04 16:10:00.667 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for region 289116, leader may Some(id: 289118 store_id: 2)\" not_leader { region_id: 289116 leader { id: 289118 store_id: 2 } }))))))"] [tag=raw_put] [thread_id=93]

tikv配置如下：

QQ_1751616471360
QQ_1751616471360667×286 7.62 KB

最终任务会失败，日志为：

QQ_1751616680300
QQ_17516166803001269×343 12.2 KB

2

最好能提供一个完整的tikv日志。这个info信息看不出来什么。

你看看这个类似的，含有

peer is not leader

这段字符的issue。

https://github.com/tikv/tikv/issues/18005

处理的也是error报错。

3

完整的太大了传不上来。

[2025/07/07 13:50:59.111 +08:00] [INFO] [raft.rs:1944] ["[term 17] starts to transfer leadership to 289638"] [lead_transferee=289638] [term=17] [raft_id=2740
55] [region_id=274052] [thread_id=247]
[2025/07/07 13:50:59.111 +08:00] [INFO] [raft.rs:1957] ["sends MsgTimeoutNow to 289638 immediately as 289638 already has up-to-date log"] [lead_transferee=28
9638] [raft_id=274055] [region_id=274052] [thread_id=247]
[2025/07/07 13:50:59.111 +08:00] [INFO] [peer.rs:3946] ["transfer leader"] [peer="id: 294400 store_id: 19"] [peer_id=294402] [region_id=294399] [thread_id=24
7]
[2025/07/07 13:50:59.111 +08:00] [INFO] [raft.rs:1944] ["[term 10] starts to transfer leadership to 294400"] [lead_transferee=294400] [term=10] [raft_id=2944
02] [region_id=294399] [thread_id=247]
[2025/07/07 13:50:59.111 +08:00] [INFO] [raft.rs:1957] ["sends MsgTimeoutNow to 294400 immediately as 294400 already has up-to-date log"] [lead_transferee=29
4400] [raft_id=294402] [region_id=294399] [thread_id=247]
[2025/07/07 13:50:59.112 +08:00] [INFO] [peer.rs:3946] ["transfer leader"] [peer="id: 7609 store_id: 2"] [peer_id=276006] [region_id=7607] [thread_id=247]
[2025/07/07 13:50:59.112 +08:00] [INFO] [raft.rs:1944] ["[term 17] starts to transfer leadership to 7609"] [lead_transferee=7609] [term=17] [raft_id=276006] 
[region_id=7607] [thread_id=247]
[2025/07/07 13:50:59.112 +08:00] [INFO] [raft.rs:1957] ["sends MsgTimeoutNow to 7609 immediately as 7609 already has up-to-date log"] [lead_transferee=7609] 
[raft_id=276006] [region_id=7607] [thread_id=247]
[2025/07/07 13:50:59.112 +08:00] [INFO] [raft.rs:1386] ["received a message with higher term from 294400"] ["msg type"=MsgRequestVote] [message_term=11] [ter
m=10] [from=294400] [raft_id=294402] [region_id=294399] [thread_id=246]
[2025/07/07 13:50:59.112 +08:00] [INFO] [raft.rs:1151] ["became follower at term 11"] [term=11] [raft_id=294402] [region_id=294399] [thread_id=246]
[2025/07/07 13:50:59.112 +08:00] [INFO] [raft.rs:1605] ["[logterm: 10, index: 12204, vote: 0] cast vote for 294400 [logterm: 10, index: 12204] at term 11"] [
"msg type"=MsgRequestVote] [term=11] [msg_index=12204] [msg_term=10] [from=294400] [vote=0] [log_index=12204] [log_term=10] [raft_id=294402] [region_id=29439
9] [thread_id=246]
[2025/07/07 13:50:59.112 +08:00] [INFO] [endpoint.rs:784] ["deregister observe region"] [observe_id=ObserveId(3684)] [region_id=294399] [store_id=Some(3)] [t
hread_id=205]
[2025/07/07 13:50:59.113 +08:00] [INFO] [raft.rs:1386] ["received a message with higher term from 289638"] ["msg type"=MsgRequestVote] [message_term=18] [ter
m=17] [from=289638] [raft_id=274055] [region_id=274052] [thread_id=246]
[2025/07/07 13:50:59.113 +08:00] [INFO] [raft.rs:1151] ["became follower at term 18"] [term=18] [raft_id=274055] [region_id=274052] [thread_id=246]
[2025/07/07 13:50:59.113 +08:00] [INFO] [raft.rs:1605] ["[logterm: 17, index: 21084, vote: 0] cast vote for 289638 [logterm: 17, index: 21084] at term 18"] [
"msg type"=MsgRequestVote] [term=18] [msg_index=21084] [msg_term=17] [from=289638] [vote=0] [log_index=21084] [log_term=17] [raft_id=274055] [region_id=27405
2] [thread_id=246]
[2025/07/07 13:50:59.113 +08:00] [INFO] [endpoint.rs:784] ["deregister observe region"] [observe_id=ObserveId(2326)] [region_id=274052] [store_id=Some(3)] [t
hread_id=205]
[2025/07/07 13:50:59.115 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for re
gion 44071, leader may Some(id: 277215 store_id: 1)\" not_leader { region_id: 44071 leader { id: 277215 store_id: 1 } }))))))"] [tag=raw_put] [thread_id=91]
[2025/07/07 13:50:59.119 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for re
gion 304307, leader may Some(id: 304309 store_id: 10)\" not_leader { region_id: 304307 leader { id: 304309 store_id: 10 } }))))))"] [tag=raw_put] [thread_id=
87]
[2025/07/07 13:50:59.120 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for re
gion 23232, leader may Some(id: 23235 store_id: 10)\" not_leader { region_id: 23232 leader { id: 23235 store_id: 10 } }))))))"] [tag=raw_put] [thread_id=89]
[2025/07/07 13:50:59.121 +08:00] [INFO] [pd.rs:1526] ["try to transfer leader"] [to_peers="[id: 297503 store_id: 1, id: 287041 store_id: 2]"] [to_peer="id: 2
87041 store_id: 2"] [from_peer="id: 287043 store_id: 3"] [region_id=287040] [thread_id=40]
[2025/07/07 13:50:59.121 +08:00] [INFO] [pd.rs:1526] ["try to transfer leader"] [to_peers="[id: 293234 store_id: 2, id: 293233 store_id: 19]"] [to_peer="id: 
293233 store_id: 19"] [from_peer="id: 293235 store_id: 3"] [region_id=293232] [thread_id=40]
[2025/07/07 13:50:59.121 +08:00] [INFO] [pd.rs:1526] ["try to transfer leader"] [to_peers="[id: 301331 store_id: 1, id: 301329 store_id: 2]"] [to_peer="id: 3
01329 store_id: 2"] [from_peer="id: 301330 store_id: 3"] [region_id=301328] [thread_id=40]
[2025/07/07 13:50:59.122 +08:00] [INFO] [peer.rs:3946] ["transfer leader"] [peer="id: 297503 store_id: 1"] [peer_id=287043] [region_id=287040] [thread_id=246
]
[2025/07/07 13:50:59.122 +08:00] [INFO] [raft.rs:1944] ["[term 13] starts to transfer leadership to 297503"] [lead_transferee=297503] [term=13] [raft_id=2870
43] [region_id=287040] [thread_id=246]
[2025/07/07 13:50:59.122 +08:00] [INFO] [raft.rs:1957] ["sends MsgTimeoutNow to 297503 immediately as 297503 already has up-to-date log"] [lead_transferee=29
7503] [raft_id=287043] [region_id=287040] [thread_id=246]
[2025/07/07 13:50:59.122 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for re
gion 299198, leader may Some(id: 299199 store_id: 19)\" not_leader { region_id: 299198 leader { id: 299199 store_id: 19 } }))))))"] [tag=raw_put] [thread_id=
89]
[2025/07/07 13:50:59.123 +08:00] [INFO] [peer.rs:3946] ["transfer leader"] [peer="id: 293233 store_id: 19"] [peer_id=293235] [region_id=293232] [thread_id=24
7]
[2025/07/07 13:50:59.123 +08:00] [INFO] [raft.rs:1944] ["[term 10] starts to transfer leadership to 293233"] [lead_transferee=293233] [term=10] [raft_id=2932
35] [region_id=293232] [thread_id=247]
[2025/07/07 13:50:59.123 +08:00] [INFO] [raft.rs:1957] ["sends MsgTimeoutNow to 293233 immediately as 293233 already has up-to-date log"] [lead_transferee=29
3233] [raft_id=293235] [region_id=293232] [thread_id=247]
[2025/07/07 13:50:59.123 +08:00] [INFO] [mod.rs:2271] ["get snapshot failed"] [err="Error(Txn(Error(Engine(Error(Request(message: \"peer is not leader for re
gion 22770, leader may Some(id: 22772 store_id: 2)\" not_leader { region_id: 22770 leader { id: 22772 store_id: 2 } }))))))"] [tag=raw_put] [thread_id=91]
[2025/07/07 13:50:59.123 +08:00] [INFO] [peer.rs:3946] ["transfer leader"] [peer="id: 301331 store_id: 1"] [peer_id=301330] [region_id=301328] [thread_id=246
]
[2025/07/07 13:50:59.123 +08:00] [INFO] [raft.rs:1944] ["[term 7] starts to transfer leadership to 301331"] [lead_transferee=301331] [term=7] [raft_id=301330
] [region_id=301328] [thread_id=246]
[2025/07/07 13:50:59.123 +08:00] [INFO] [raft.rs:1957] ["sends MsgTimeoutNow to 301331 immediately as 301331 already has up-to-date log"] [lead_transferee=30
1331] [raft_id=301330] [region_id=301328] [thread_id=246]
[2025/07/07 13:50:59.124 +08:00] [INFO] [raft.rs:1386] ["received a message with higher term from 293233"] ["msg type"=MsgRequestVote] [message_term=11] [ter
m=10] [from=293233] [raft_id=293235] [region_id=293232] [thread_id=247]
[2025/07/07 13:50:59.124 +08:00] [INFO] [raft.rs:1151] ["became follower at term 11"] [term=11] [raft_id=293235] [region_id=293232] [thread_id=247]
[2025/07/07 13:50:59.124 +08:00] [INFO] [raft.rs:1605] ["[logterm: 10, index: 55991, vote: 0] cast vote for 293233 [logterm: 10, index: 55991] at term 11"] [
"msg type"=MsgRequestVote] [term=11] [msg_index=55991] [msg_term=10] [from=293233] [vote=0] [log_index=55991] [log_term=10] [raft_id=293235] [region_id=29323
2] [thread_id=247]
[2025/07/07 13:50:59.124 +08:00] [INFO] [endpoint.rs:784] ["deregister observe region"] [observe_id=ObserveId(2108)] [region_id=293232] [store_id=Some(3)] [t
hread_id=205]
[2025/07/07 13:50:59.124 +08:00] [INFO] [raft.rs:1386] ["received a message with higher term from 297503"] ["msg type"=MsgRequestVote] [message_term=14] [ter
m=13] [from=297503] [raft_id=287043] [region_id=287040] [thread_id=247]
[2025/07/07 13:50:59.124 +08:00] [INFO] [raft.rs:1151] ["became follower at term 14"] [term=14] [raft_id=287043] [region_id=287040] [thread_id=247]
[2025/07/07 13:50:59.124 +08:00] [INFO] [raft.rs:1605] ["[logterm: 13, index: 10997, vote: 0] cast vote for 297503 [logterm: 13, index: 10997] at term 14"] [
"msg type"=MsgRequestVote] [term=14] [msg_index=10997] [msg_term=13] [from=297503] [vote=0] [log_index=10997] [log_term=13] [raft_id=287043] [region_id=28704
0] [thread_id=247]
[2025/07/07 13:50:59.124 +08:00] [INFO] [endpoint.rs:784] ["deregister observe region"] [observe_id=ObserveId(4011)] [region_id=287040] [store_id=Some(3)] [t
hread_id=205]
4

[2025/07/07 13:50:59.112 +08:00] [INFO] [raft.rs:1151] [“became follower at term 11”] [term=11] [raft_id=294402] [region_id=294399] [thread_id=246]

[2025/07/07 13:50:59.123 +08:00] [INFO] [raft.rs:1944] [“[term 7] starts to transfer leadership to 301331”] [lead_transferee=301331] [term=7] [raft_id=301330
] [region_id=301328] [thread_id=246]

这个日志看起来没什么问题，类似上面这种transfer leader的情况很多，所以会有peer is not leader一点也不奇怪。

要硬说的话，java-client应该能自己处理这个错误，从pd更新对应region的信息并放入缓存，然后自己重试访问正确的tikv才对。不应该直接报错抛出异常。最起码之前看go-client应该就是这么处理的。

我个人感觉更像是java-client的bug，或者java-client的版本的问题。从tikv侧，我觉得没啥问题。

https://github.com/tikv/client-java/issues/687

这个是个类似的问题，报错的调用堆栈和你上面的差不多，就是行数不太一样。

5

但是很奇怪啊，某个节点的leader会突然降到0

1 个赞
6

你提醒我了，你说的对。我忘了有一个tikv leader都掉0了。这个肯定不正常。

把transfer leader很多和有一个tikv leader掉0结合一起来看的话，建议查查带宽是不是被打满了。

之前碰到过，rawkv写入太猛，导致带宽被打满了。
然后就各种奇怪的问题，查了半天。 :rofl:

7

查看下该tikv节点状态是否正常，以及网络带宽是否满了，还有写热点问题

8

节点状态正常，带宽没满

1 个赞
9

如果tikv的日志上看不到什么问题，还有个思路就是查查pd为什么要这么调度。

看看pd Scheduler相关的监控找找看。

10

QQ_1751957782789
QQ_1751957782789952×734 135 KB

QQ_1751957914361
QQ_17519579143611908×672 161 KB

11

我的系统盘性能很低，虽然系统盘和tikv数据盘是独立的两个盘。观察到写入tikv时，当某一tikv leader 降到0的时候，系统盘 io 也是打满的。

1 个赞
12

1752036477271
17520364772713718×511 97.1 KB

找找看是不是那个leader掉0的这个slow store score比较高？看看故障时间段的监控。

13

QQ_1752038980519
QQ_1752038980519650×306 39.1 KB

image
image602×330 25 KB

好像不太一样啊，61 和 62 都很高，但只有62的leader降到了0

14

但只有62的leader降到了0

这个是符合预期的，因为如果2个tikv的leader都evict，那某些raft组的多数派就没办法维持了。所以2个都高的情况下只能evict一个。

这么看的话leader掉0的主要原因，就是evict slow store。如果确定你的盘很慢，我感觉可以考虑去掉evict slow store 这个scheduler。

你可以看看这个帖子，里面对于slow store的讨论是比较全面的。从判断机制，到解决方法。

以往掉0，我会第一时间感觉是slow store的问题。这次我没有第一时间怀疑是slow store，主要是以往碰到的都是瞬间掉下去，很快又回来。你这个leader掉0持续10几分钟的，比较少见。你后面不提一句盘性能不行，我真没往这个方向上想过。 :sweat_smile:

15

QQ_1752045571221
QQ_1752045571221824×653 54.2 KB

QQ_1752045650121
QQ_1752045650121919×654 56.7 KB

QQ_1752045688201
QQ_1752045688201410×293 13.3 KB

QQ_1752045702984
QQ_1752045702984434×320 14.9 KB

QQ_1752045725753
QQ_1752045725753674×297 8.69 KB

刚才说错了，系统盘io不高，是其它服务的盘io很高，但是这个曲线的确能对的上，难道pd调度的时候还会检测其它非tikv盘的io情况吗

1 个赞
16

你注意翻我发的那个帖子。

里面讲的比较清楚的，判断机制是，readpool的排队时间上升，grpc的RPS（每秒请求数）下降。当这2个事件同时发生，就认为这个store是slow store。

换句话说，不管你怎么看io，这个store一定是grpc请求也下滑了，排队时间也上升了。才会导致被evict leader。