TiKV may failed to generate snapshot when it is compacting log
Nobody has claimed this yet.
- Dominant language
- C++
- Stars
- 1k
- Forks
- 423
- Avg merge
- 1d 15h
- Merged PRs (30d)
- 24
Description
Bug Report
Please answer these questions before submitting your issue. Thanks!
This will lead to regenerating the snapshot, so TiFlash will lag behind when waiting the new snapshot.
This requires enhancement from TiKV. However, we have this issue so we can easily do triage.
The peer is created at 23:55:12, with its snapshot comes at 01:10
[2023/11/04 23:55:12.213 +08:00] [INFO] [[peer.rs:321](http://peer.rs:321/)] ["replicate peer"] [peer_id=396150] [region_id=396146]
[2023/11/04 23:55:12.213 +08:00] [INFO] [[raft.rs:2663](http://raft.rs:2663/)] ["switched to configuration"] [config="Configuration { voters: Configuration { incoming: Configuration { voters: {} }, outgoing: Configuration { voters: {} } }, learners: {}, learners_next: {}, auto_leave: false }"] [raft_id=396150] [region_id=396146]
[2023/11/04 23:55:12.213 +08:00] [INFO] [[raft.rs:1127](http://raft.rs:1127/)] ["became follower at term 0"] [term=0] [raft_id=396150] [region_id=396146]
[2023/11/04 23:55:12.213 +08:00] [INFO] [[raft.rs:388](http://raft.rs:388/)] [newRaft] [peers="Configuration { incoming: Configuration { voters: {} }, outgoing: Configuration { voters: {} } }"] ["last term"=0] ["last index"=0] [applied=0] [commit=0] [term=0] [raft_id=396150] [region_id=396146]
[2023/11/04 23:55:12.213 +08:00] [INFO] [[raw_node.rs:315](http://raw_node.rs:315/)] ["RawNode created with id 396150."] [id=396150] [raft_id=396150] [region_id=396146]
[2023/11/04 23:55:12.213 +08:00] [INFO] [[raft.rs:1371](http://raft.rs:1371/)] ["received a message with higher term from 396148"] ["msg type"=MsgHeartbeat] [message_term=6] [term=0] [from=396148] [raft_id=396150] [region_id=396146]
[2023/11/04 23:55:12.213 +08:00] [INFO] [[raft.rs:1127](http://raft.rs:1127/)] ["became follower at term 6"] [term=6] [raft_id=396150] [region_id=396146]
[2023/11/04 23:55:12.213 +08:00] [INFO] [[region.rs:103](http://region.rs:103/)] [" 17:396146 396150, peer created"] [is_replicated=true] [role=Follower] [leader_id=396148] [region_id=396146]
[2023/11/05 01:10:04.097 +08:00] [INFO] [[snap.rs:293](http://snap.rs:293/)] ["saving snapshot file"] [file=/data0/proxy/snap/rev_396146_6_7_(default|lock|write).sst] [snap_key=396146_6_7]
[2023/11/05 01:10:04.137 +08:00] [INFO] [[snap.rs:301](http://snap.rs:301/)] ["saving all snapshot files"] [takes=764.803238ms] [snap_key=396146_6_7]
[2023/11/05 01:10:04.154 +08:00] [INFO] [[raft_log.rs:627](http://raft_log.rs:627/)] ["log [committed=0, persisted=0, applied=0, unstable.offset=1, unstable.entries.len()=0] starts to restore snapshot [index: 7, term: 6]"] [snapshot_term=6] [snapshot_index=7] [log="committed=0, persisted=0, applied=0, unstable.offset=1, unstable.entries.len()=0"] [raft_id=396150] [region_id=396146]
[2023/11/05 01:10:04.154 +08:00] [INFO] [[raft.rs:2663](http://raft.rs:2663/)] ["switched to configuration"] [config="Configuration { voters: Configuration { incoming: Configuration { voters: {396148, 396149, 396147} }, outgoing: Configuration { voters: {} } }, learners: {404561, 396150, 396151}, learners_next: {}, auto_leave: false }"] [raft_id=396150] [region_id=396146]
[2023/11/05 01:10:04.154 +08:00] [INFO] [[raft.rs:2647](http://raft.rs:2647/)] ["restored snapshot"] [snapshot_term=6] [snapshot_index=7] [last_term=6] [last_index=7] [commit=7] [raft_id=396150] [region_id=396146]
[2023/11/05 01:10:04.154 +08:00] [INFO] [[raft.rs:2528](http://raft.rs:2528/)] ["[commit: 7, term: 6] restored snapshot [index: 7, term: 6]"] [snapshot_term=6] [snapshot_index=7] [commit=7] [term=6] [raft_id=396150] [region_id=396146]
[2023/11/05 01:10:04.154 +08:00] [INFO] [[peer_storage.rs:605](http://peer_storage.rs:605/)] ["begin to apply snapshot"] [peer_id=396150] [region_id=396146]
[2023/11/05 01:10:04.154 +08:00] [INFO] [[peer_storage.rs:688](http://peer_storage.rs:688/)] ["apply snapshot with state ok"] [for_witness=false] [state="applied_index: 7 truncated_state { index: 7 term: 6 }"] [region="id: 396146 start_key: 7480000000000000FF6F5F728000000012FF1DE53A0000000000FA end_key: 7480000000000000FF6F5F728000000012FF1EB7CD0000000000FA region_epoch { conf_ver: 14 version: 1648 } peers { id: 396147 store_id: 1 } peers { id: 396148 store_id: 6 } peers { id: 396149 store_id: 8 } peers { id: 396150 store_id: 17 role: Learner } peers { id: 396151 store_id: 5 role: Learner } peers { id: 404561 store_id: 4 role: Learner }"] [peer_id=396150] [region_id=396146]
There are many logs in tikv leader
[2023/11/05 00:29:28.268 +08:00] [WARN] [[peer_storage.rs:515](http://peer_storage.rs:515/)] ["failed to try generating snapshot"] [request_peer=396151] [times=1] [peer_id=396148] [region_id=396146] [thread_id=0x5]
1. Minimal reproduce step (Required)
2. What did you expect to see? (Required)
3. What did you see instead (Required)
4. What is your TiFlash version? (Required)
Contributor guide
No contributing guide indexed for this repository
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start at the peer_storage.rs:515 warning and compare it with the snap.rs:293-301 and raft_log.rs:627 log entries. Investigate whether snapshot generation fails while TiKV is compacting its log, then determine whether the behavior can be reproduced or needs a TiKV enhancement. Done means documenting an actionable cause or triage result; no implementation scope or test is named.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp, rust
- Domain
- distributed-systems
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100