tidb 版本 4.0.13
业务反馈今天18:40左右业务报了一波超时,查看监控定位到有个tikv上的所有leader都切了一下,但是很快就恢复,查看pd leader日志再18:38:56开始刷了大量的leader change的日志,查看一场tikv节点也可以看到很多 not leader的日志,但是都没找到明确的原因。
pd leader的日志
[2025/04/22 16:45:10.168 +08:00] [INFO] [cluster.go:545] ["region Version changed"] [region-id=96] [detail="StartKey Changed:{7480000000000000FF335F729A91284870FF8012130000000000FA} -> {7480000000000000FF335F729A91D749F3FFC012450000000000FA}, EndKey:{7480000000000000FF3500000000000000F8}"] [old-version=2424] [new-version=2425]
[2025/04/22 16:49:19.197 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457500356552687616]
[2025/04/22 16:51:01.546 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457500356552687616]
[2025/04/22 16:59:19.201 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457500513839087616]
[2025/04/22 17:01:01.547 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457500513839087616]
[2025/04/22 17:09:19.198 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457500671125487616]
[2025/04/22 17:11:01.319 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457500671125487616]
[2025/04/22 17:19:19.192 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457500828411887616]
[2025/04/22 17:21:01.343 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457500828411887616]
[2025/04/22 17:22:31.315 +08:00] [INFO] [periodic.go:135] ["starting auto periodic compaction"] [revision=207241647] [compact-period=1h0m0s]
[2025/04/22 17:22:31.316 +08:00] [INFO] [index.go:189] ["compact tree index"] [revision=207241647]
[2025/04/22 17:22:31.316 +08:00] [INFO] [periodic.go:146] ["completed auto periodic compaction"] [revision=207241647] [compact-period=1h0m0s] [took=1h0m0.002146155s]
[2025/04/22 17:22:31.429 +08:00] [INFO] [kvstore_compaction.go:55] ["finished scheduled compaction"] [compact-revision=207241647] [took=113.235568ms]
[2025/04/22 17:29:19.213 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457500985698287616]
[2025/04/22 17:31:01.367 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457500985698287616]
[2025/04/22 17:39:19.200 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457501142984687616]
[2025/04/22 17:41:01.458 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457501142984687616]
[2025/04/22 17:49:19.197 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457501300271087616]
[2025/04/22 17:51:01.460 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457501300271087616]
[2025/04/22 17:59:19.195 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457501457557487616]
[2025/04/22 18:01:01.488 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457501457557487616]
[2025/04/22 18:09:19.197 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457501614843887616]
[2025/04/22 18:11:01.378 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457501614843887616]
[2025/04/22 18:19:19.198 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457501772130287616]
[2025/04/22 18:21:01.540 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457501772130287616]
[2025/04/22 18:22:31.317 +08:00] [INFO] [periodic.go:135] ["starting auto periodic compaction"] [revision=207249793] [compact-period=1h0m0s]
[2025/04/22 18:22:31.318 +08:00] [INFO] [index.go:189] ["compact tree index"] [revision=207249793]
[2025/04/22 18:22:31.318 +08:00] [INFO] [periodic.go:146] ["completed auto periodic compaction"] [revision=207249793] [compact-period=1h0m0s] [took=1h0m0.001967415s]
[2025/04/22 18:22:31.421 +08:00] [INFO] [kvstore_compaction.go:55] ["finished scheduled compaction"] [compact-revision=207249793] [took=102.797908ms]
[2025/04/22 18:29:19.199 +08:00] [INFO] [grpc_service.go:815] ["update service GC safe point"] [service-id=gc_worker] [expire-at=9223372036854775807] [safepoint=457501929416687616]
[2025/04/22 18:31:01.530 +08:00] [INFO] [grpc_service.go:760] ["updated gc safe point"] [safe-point=457501929416687616]
[2025/04/22 18:38:56.839 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=912] [from=156469] [to=41493]
[2025/04/22 18:38:56.839 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=53051] [from=156469] [to=41493]
[2025/04/22 18:38:56.842 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=75804] [from=156469] [to=41493]
[2025/04/22 18:38:57.342 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=18852] [from=156469] [to=26987]
[2025/04/22 18:38:57.364 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=78486] [from=156469] [to=41493]
[2025/04/22 18:38:57.364 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=17512] [from=156469] [to=41493]
[2025/04/22 18:38:57.365 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=122701] [from=156469] [to=41493]
[2025/04/22 18:38:57.379 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=792] [from=156469] [to=26987]
[2025/04/22 18:38:57.504 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=17184] [from=156469] [to=26987]
[2025/04/22 18:38:57.513 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=73635] [from=156469] [to=88524]
[2025/04/22 18:38:57.519 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=13692] [from=156469] [to=88524]
[2025/04/22 18:38:57.520 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=116561] [from=156469] [to=88524]
[2025/04/22 18:38:57.549 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=120229] [from=156469] [to=88524]
[2025/04/22 18:38:57.556 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=131258] [from=156469] [to=88524]
[2025/04/22 18:38:57.558 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=179870] [from=156469] [to=88524]
[2025/04/22 18:38:57.584 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=123337] [from=156469] [to=41493]
[2025/04/22 18:38:57.593 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=26873] [from=156469] [to=41493]
[2025/04/22 18:38:57.594 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=11120] [from=156469] [to=41493]
[2025/04/22 18:38:57.730 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=115258] [from=156469] [to=26987]
[2025/04/22 18:38:57.731 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=75814] [from=156469] [to=26987]
[2025/04/22 18:38:57.732 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=7600] [from=156469] [to=26987]
[2025/04/22 18:38:57.733 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=63693] [from=156469] [to=26987]
[2025/04/22 18:38:57.733 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=180661] [from=156469] [to=26987]
[2025/04/22 18:38:57.760 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=8512] [from=156469] [to=41493]
[2025/04/22 18:38:57.804 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=644] [from=156469] [to=41493]
[2025/04/22 18:38:57.808 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=120657] [from=156469] [to=41493]
[2025/04/22 18:38:57.808 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=78052] [from=156469] [to=41493]
[2025/04/22 18:38:57.808 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=77868] [from=156469] [to=41493]
[2025/04/22 18:38:57.808 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=59937] [from=156469] [to=41493]
[2025/04/22 18:38:57.810 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=171082] [from=156469] [to=41493]
[2025/04/22 18:38:57.832 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=5400] [from=156469] [to=41493]
[2025/04/22 18:38:57.838 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=62268] [from=156469] [to=41493]
[2025/04/22 18:38:57.838 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=74163] [from=156469] [to=41493]
[2025/04/22 18:38:57.839 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=54162] [from=156469] [to=41493]
[2025/04/22 18:38:57.839 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=4148] [from=156469] [to=41493]
[2025/04/22 18:38:57.839 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=58055] [from=156469] [to=41493]
[2025/04/22 18:38:57.840 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=17544] [from=156469] [to=41493]
[2025/04/22 18:38:57.862 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=11676] [from=156469] [to=88524]
[2025/04/22 18:38:57.862 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=169273] [from=156469] [to=88524]
[2025/04/22 18:38:57.862 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=25513] [from=156469] [to=88524]
[2025/04/22 18:38:57.862 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=53011] [from=156469] [to=88524]
[2025/04/22 18:38:57.865 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=180502] [from=156469] [to=88524]
[2025/04/22 18:38:57.866 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=67404] [from=156469] [to=88524]
[2025/04/22 18:38:57.867 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=11056] [from=156469] [to=88524]
[2025/04/22 18:38:57.890 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=176532] [from=156469] [to=88524]
[2025/04/22 18:38:57.899 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=26341] [from=156469] [to=41493]
[2025/04/22 18:38:57.900 +08:00] [INFO] [cluster.go:566] ["leader changed"] [region-id=169949] [from=156469] [to=41493]
异常节点tikv的同期日志
[2025/04/22 18:24:58.524 +08:00] [INFO] [util.rs:226] ["heartbeat sender and receiver are stale, refreshing ..."]
[2025/04/22 18:24:58.538 +08:00] [WARN] [util.rs:244] ["updating PD client done"] [spend=16.336023ms]
[2025/04/22 18:24:58.538 +08:00] [INFO] [client.rs:433] ["cancel region heartbeat sender"]
[2025/04/22 18:29:14.561 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F7295B663CE2A401204 lock_version: 457524577439318041 key: 7480000000000000375F7295B663CE2A401204 lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:30:10.339 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F72929D5A5AACC00012 lock_version: 457524592066953238 key: 7480000000000000375F72929D5A5AACC00012 lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:31:12.832 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F729367650F74400817 lock_version: 457524608450953230 key: 7480000000000000375F729367650F74400817 lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:31:15.406 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F7290B79A571280000A lock_version: 457524609119420445 key: 7480000000000000375F7290B79A571280000A lock_ttl: 3001 txn_size: 1"]
[2025/04/22 18:31:35.315 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F7298AEA0C029801207 lock_version: 457524614336348215 key: 7480000000000000375F7298AEA0C029801207 lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:31:55.705 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F698000000000000001016F662D52336A6D5AFF6A4A6964706B6A65FF3673726C32396C6BFF6A69794D00000000FB038000000000000067038000000000000001 lock_version: 457524619683823643 key: 7480000000000000375F698000000000000001016F662D523
36A6D5AFF6A4A6964706B6A65FF3673726C32396C6BFF6A69794D00000000FB038000000000000067038000000000000001 lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:32:00.280 +08:00] [INFO] [gc_manager.rs:416] ["gc_worker: start auto gc"] [safe_point=457501929416687616]
[2025/04/22 18:33:47.759 +08:00] [INFO] [gc_manager.rs:456] ["gc_worker: finished auto gc"] [processed_regions=4449]
[2025/04/22 18:33:54.051 +08:00] [INFO] [compact.rs:123] ["compact range finished"] [time_takes=6.288605571s] [cf=default] [range_end=7A7480000000000000FF3D5F728000000023FFF54D3A0000000000FA] [range_start=7A7480000000000000FF3D5F728000000023FFF375C40000000000FA]
[2025/04/22 18:34:22.798 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F729A5D989DD040044C lock_version: 457524658245206046 key: 7480000000000000375F729A5D989DD040044C lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:34:23.695 +08:00] [INFO] [compact.rs:123] ["compact range finished"] [time_takes=29.643884836s] [cf=write] [range_end=7A7480000000000000FF3D5F728000000023FFF54D3A0000000000FA] [range_start=7A7480000000000000FF3D5F728000000023FFF375C40000000000FA]
[2025/04/22 18:34:23.695 +08:00] [WARN] [mod.rs:89] ["handle task CheckAndCompact { cf_names: [\"default\", \"write\"], ranges: (Some(7A7480000000000000FF3D5F728000000023FFAD31AA0000000000FA), Some(7A7480000000000000FF3D5F728000000024FFBB6EB80000000000FA)), tombstones_num_threshold: 10000, tombstones_percent_threshold: 30 }"] [takes=35933]
[2025/04/22 18:34:47.446 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F729341EDA23C40001A lock_version: 457524664707055647 key: 7480000000000000375F729341EDA23C40001A lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:34:58.539 +08:00] [INFO] [util.rs:463] ["connecting to PD endpoint"] [endpoints=http://192.168.1.109:13126]
[2025/04/22 18:34:58.539 +08:00] [INFO] [<unknown>] ["New connected subchannel at 0x7f9794c3bec0 for subchannel 0x7f9794c973c0"]
[2025/04/22 18:34:58.540 +08:00] [INFO] [util.rs:463] ["connecting to PD endpoint"] [endpoints=http://192.168.1.100:13126]
[2025/04/22 18:34:58.541 +08:00] [INFO] [util.rs:528] ["connected to PD leader"] [endpoints=http://192.168.1.100:13126]
[2025/04/22 18:34:58.541 +08:00] [INFO] [util.rs:226] ["heartbeat sender and receiver are stale, refreshing ..."]
[2025/04/22 18:34:58.560 +08:00] [WARN] [util.rs:244] ["updating PD client done"] [spend=21.23789ms]
[2025/04/22 18:34:58.560 +08:00] [INFO] [client.rs:433] ["cancel region heartbeat sender"]
[2025/04/22 18:36:06.567 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F72910EA6D8B9000011 lock_version: 457524685442646082 key: 7480000000000000375F72910EA6D8B9000011 lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:38:04.423 +08:00] [WARN] [endpoint.rs:537] [error-response] [err="Key is locked (will clean up) primary_lock: 7480000000000000375F7292EB4D6A8F400012 lock_version: 457524716349423627 key: 7480000000000000375F7292EB4D6A8F400012 lock_ttl: 3000 txn_size: 1"]
[2025/04/22 18:38:51.680 +08:00] [WARN] [process.rs:190] ["[region 3348] scheduler handle command: prewrite, ts: 457524728132796449"] [takes=2081]
[2025/04/22 18:38:52.975 +08:00] [WARN] [process.rs:190] ["[region 3348] scheduler handle command: prewrite, ts: 457524728145903621"] [takes=2081]
[2025/04/22 18:38:54.703 +08:00] [ERROR] [<unknown>] ["ipv4:192.168.4.896:43572: Keepalive watchdog fired. Closing transport."]
[2025/04/22 18:38:55.305 +08:00] [INFO] [tracker.rs:241] [slow-query] [perf_stats.internal_delete_skipped_count=0] [perf_stats.internal_key_skipped_count=0] [perf_stats.block_read_byte=0] [perf_stats.block_read_count=0] [perf_stats.block_cache_hit_count=11] [scan.range.first="Some(start: 7480000000000000375F729113677512800014 end: 7480000000000000375F729113677512800015)"] [scan.ranges=1] [scan.total=1] [scan.processed=1] [scan.is_desc=false] [tag=select] [table_id=55] [txn_start_ts=457524728145903618] [total_suspend_time=0ns] [total_process_time=4.021s] [handler_build_time=173ms] [wait_time.snapshot=23ms] [wait_time.schedule=0ns] [wait_time=23ms] [total_lifetime=4.32s] [remote_host=ipv4:192.168.64.16:32970] [region_id=4912]
[2025/04/22 18:38:56.933 +08:00] [WARN] [store.rs:645] ["[store 156469] handle 174 pending peers include 168 ready, 0 entries, 396 messages and 0 snapshots"] [takes=7240]
[2025/04/22 18:38:57.075 +08:00] [WARN] [store.rs:645] ["[store 156469] handle 257 pending peers include 169 ready, 2 entries, 358 messages and 0 snapshots"] [takes=7378]
[2025/04/22 18:38:57.194 +08:00] [INFO] [raft.rs:971] ["[logterm: 12, index: 18, vote: 159568] ignored vote from 115042 [logterm: 12, index: 18]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=10] [term=12] [msg_index=18] [msg_term=12] [from=115042] [vote=159568] [log_index=18] [log_term=12] [raft_id=159568] [region_id=59705]
[2025/04/22 18:38:57.310 +08:00] [INFO] [raft.rs:971] ["[logterm: 14, index: 3244593, vote: 159671] ignored vote from 74873 [logterm: 14, index: 3244593]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=2] [term=14] [msg_index=3244593] [msg_term=14] [from=74873] [vote=159671] [log_index=3244593] [log_term=14] [raft_id=159671] [region_id=74870]
[2025/04/22 18:38:57.555 +08:00] [INFO] [raft.rs:1003] ["received a message with higher term from 153305"] ["msg type"=MsgAppendResponse] [message_term=26] [term=25] [from=153305] [raft_id=157102] [region_id=912]
[2025/04/22 18:38:57.936 +08:00] [INFO] [raft.rs:783] ["became follower at term 26"] [term=26] [raft_id=157102] [region_id=912]
[2025/04/22 18:38:58.564 +08:00] [INFO] [raft.rs:1192] ["[logterm: 25, index: 1878081, vote: 0] cast vote for 107933 [logterm: 25, index: 1878081] at term 26"] ["msg type"=MsgRequestPreVote] [term=26] [msg_index=1878081] [msg_term=25] [from=107933] [vote=0] [log_index=1878081] [log_term=25] [raft_id=157102] [region_id=912]
[2025/04/22 18:38:59.381 +08:00] [INFO] [raft.rs:1192] ["[logterm: 25, index: 1878081, vote: 0] cast vote for 107933 [logterm: 25, index: 1878081] at term 26"] ["msg type"=MsgRequestVote] [term=26] [msg_index=1878081] [msg_term=25] [from=107933] [vote=0] [log_index=1878081] [log_term=25] [raft_id=157102] [region_id=912]
[2025/04/22 18:39:00.364 +08:00] [INFO] [raft.rs:1003] ["received a message with higher term from 186972"] ["msg type"=MsgAppendResponse] [message_term=14] [term=13] [from=186972] [raft_id=156544] [region_id=53051]
[2025/04/22 18:39:01.680 +08:00] [INFO] [raft.rs:783] ["became follower at term 14"] [term=14] [raft_id=156544] [region_id=53051]
[2025/04/22 18:39:02.247 +08:00] [INFO] [raft.rs:1192] ["[logterm: 13, index: 35, vote: 0] cast vote for 53054 [logterm: 13, index: 35] at term 14"] ["msg type"=MsgRequestPreVote] [term=14] [msg_index=35] [msg_term=13] [from=53054] [vote=0] [log_index=35] [log_term=13] [raft_id=156544] [region_id=53051]
[2025/04/22 18:39:02.747 +08:00] [INFO] [raft.rs:1192] ["[logterm: 13, index: 35, vote: 0] cast vote for 53054 [logterm: 13, index: 35] at term 14"] ["msg type"=MsgRequestVote] [term=14] [msg_index=35] [msg_term=13] [from=53054] [vote=0] [log_index=35] [log_term=13] [raft_id=156544] [region_id=53051]
[2025/04/22 18:39:03.904 +08:00] [INFO] [raft.rs:971] ["[logterm: 14, index: 32, vote: 157273] ignored vote from 51056 [logterm: 14, index: 32]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=10] [term=14] [msg_index=32] [msg_term=14] [from=51056] [vote=157273] [log_index=32] [log_term=14] [raft_id=157273] [region_id=51053]
[2025/04/22 18:39:04.963 +08:00] [WARN] [apply.rs:546] ["[store 156469] handle ready 1 committed entries"] [takes=1001]
[2025/04/22 18:39:06.256 +08:00] [WARN] [process.rs:190] ["[region 3348] scheduler handle command: prewrite, ts: 457524728578441220"] [takes=2566]
[2025/04/22 18:39:08.721 +08:00] [INFO] [tracker.rs:241] [slow-query] [perf_stats.internal_delete_skipped_count=0] [perf_stats.internal_key_skipped_count=2] [perf_stats.block_read_byte=0] [perf_stats.block_read_count=0] [perf_stats.block_cache_hit_count=10] [scan.range.first="Some(start: 7480000000000000375F69800000000000000203806BFD3954C24E00 end: 7480000000000000375F69800000000000000203806BFD3954C24E01)"] [scan.ranges=1] [scan.total=3] [scan.processed=2] [scan.is_desc=false] [tag=index] [table_id=55] [txn_start_ts=457524728224546822] [total_suspend_time=0ns] [total_process_time=4.194s] [handler_build_time=94ms] [wait_time.snapshot=262ms] [wait_time.schedule=0ns] [wait_time=262ms] [total_lifetime=4.641s] [remote_host=ipv4:192.168.4.89:47098] [region_id=3072]
[2025/04/22 18:39:08.729 +08:00] [ERROR] [<unknown>] ["ipv4:192.168.4.89:47096: Keepalive watchdog fired. Closing transport."]
[2025/04/22 18:39:08.769 +08:00] [INFO] [raft.rs:971] ["[logterm: 17, index: 648150, vote: 157573] ignored vote from 101113 [logterm: 17, index: 648150]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=4] [term=17] [msg_index=648150] [msg_term=17] [from=101113] [vote=157573] [log_index=648150] [log_term=17] [raft_id=157573] [region_id=77188]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:971] ["[logterm: 6, index: 6, vote: 169165] ignored vote from 169164 [logterm: 6, index: 6]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=2] [term=6] [msg_index=6] [msg_term=6] [from=169164] [vote=169165] [log_index=6] [log_term=6] [raft_id=169165] [region_id=169163]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:971] ["[logterm: 6, index: 6, vote: 169165] ignored vote from 169164 [logterm: 6, index: 6]: lease is not expired"] ["msg type"=MsgRequestVote] ["remaining ticks"=2] [term=6] [msg_index=6] [msg_term=6] [from=169164] [vote=169165] [log_index=6] [log_term=6] [raft_id=169165] [region_id=169163]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:1003] ["received a message with higher term from 169164"] ["msg type"=MsgAppend] [message_term=7] [term=6] [from=169164] [raft_id=169165] [region_id=169163]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:783] ["became follower at term 7"] [term=7] [raft_id=169165] [region_id=169163]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:971] ["[logterm: 10, index: 4970022, vote: 157679] ignored vote from 103264 [logterm: 10, index: 4970022]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=10] [term=10] [msg_index=4970022] [msg_term=10] [from=103264] [vote=157679] [log_index=4970022] [log_term=10] [raft_id=157679] [region_id=69524]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:971] ["[logterm: 10, index: 4970022, vote: 157679] ignored vote from 103264 [logterm: 10, index: 4970022]: lease is not expired"] ["msg type"=MsgRequestVote] ["remaining ticks"=10] [term=10] [msg_index=4970022] [msg_term=10] [from=103264] [vote=157679] [log_index=4970022] [log_term=10] [raft_id=157679] [region_id=69524]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:1003] ["received a message with higher term from 103264"] ["msg type"=MsgAppend] [message_term=11] [term=10] [from=103264] [raft_id=157679] [region_id=69524]
[2025/04/22 18:39:08.770 +08:00] [INFO] [raft.rs:783] ["became follower at term 11"] [term=11] [raft_id=157679] [region_id=69524]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:971] ["[logterm: 16, index: 3985828, vote: 157909] ignored vote from 91839 [logterm: 16, index: 3985828]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=4] [term=16] [msg_index=3985828] [msg_term=16] [from=91839] [vote=157909] [log_index=3985828] [log_term=16] [raft_id=157909] [region_id=60239]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:971] ["[logterm: 16, index: 3985828, vote: 157909] ignored vote from 91839 [logterm: 16, index: 3985828]: lease is not expired"] ["msg type"=MsgRequestVote] ["remaining ticks"=4] [term=16] [msg_index=3985828] [msg_term=16] [from=91839] [vote=157909] [log_index=3985828] [log_term=16] [raft_id=157909] [region_id=60239]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:1003] ["received a message with higher term from 91839"] ["msg type"=MsgAppend] [message_term=17] [term=16] [from=91839] [raft_id=157909] [region_id=60239]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:783] ["became follower at term 17"] [term=17] [raft_id=157909] [region_id=60239]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:971] ["[logterm: 14, index: 576972, vote: 159582] ignored vote from 98580 [logterm: 14, index: 576972]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=5] [term=14] [msg_index=576972] [msg_term=14] [from=98580] [vote=159582] [log_index=576972] [log_term=14] [raft_id=159582] [region_id=77306]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:971] ["[logterm: 14, index: 576972, vote: 159582] ignored vote from 98580 [logterm: 14, index: 576972]: lease is not expired"] ["msg type"=MsgRequestVote] ["remaining ticks"=5] [term=14] [msg_index=576972] [msg_term=14] [from=98580] [vote=159582] [log_index=576972] [log_term=14] [raft_id=159582] [region_id=77306]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:1003] ["received a message with higher term from 98580"] ["msg type"=MsgAppend] [message_term=15] [term=14] [from=98580] [raft_id=159582] [region_id=77306]
[2025/04/22 18:39:08.782 +08:00] [INFO] [raft.rs:783] ["became follower at term 15"] [term=15] [raft_id=159582] [region_id=77306]
[2025/04/22 18:39:08.784 +08:00] [INFO] [raft.rs:971] ["[logterm: 10, index: 23, vote: 159429] ignored vote from 131976 [logterm: 10, index: 23]: lease is not expired"] ["msg type"=MsgRequestPreVote] ["remaining ticks"=1] [term=10] [msg_index=23] [msg_term=10] [from=131976] [vote=159429] [log_index=23] [log_term=10] [raft_id=159429] [region_id=131975]
[2025/04/22 18:39:08.784 +08:00] [INFO] [raft.rs:971] ["[logterm: 10, index: 23, vote: 159429] ignored vote from 131976 [logterm: 10, index: 23]: lease is not expired"] ["msg type"=MsgRequestVote] ["remaining ticks"=1] [term=10] [msg_index=23] [msg_term=10] [from=131976] [vote=159429] [log_index=23] [log_term=10] [raft_id=159429] [region_id=131975]
[2025/04/22 18:39:08.784 +08:00] [INFO] [raft.rs:1003] ["received a message with higher term from 131976"] ["msg type"=MsgAppend] [message_term=11] [term=10] [from=131976] [raft_id=159429] [region_id=131975]
[2025/04/22 18:39:08.784 +08:00] [INFO] [raft.rs:783] ["became follower at term 11"] [term=11] [raft_id=159429] [region_id=131975]
: