Skip to content

Commit 4f01070

Browse files
committed
[#268] fix: WAL torn write 시 recovery가 실패하던 문제 수정
- used_wal_bytes가 truncated frame header/body를 에러 대신 (유효 경계, torn 이유)로 반환하도록 변경 - newest 세그먼트의 torn tail은 uncommitted 기록으로 간주해 경고 로그와 함께 버리고 복구 계속 (PostgreSQL/SQLite 관례) - 중간 세그먼트는 기존대로 에러 유지 (strict) - write_entry에서 body를 먼저 쓰고 length header를 마지막에 패치해 frame_len을 commit marker로 동작하게 변경 - frame_len 유효 + body 잘림 / 부분 header 재현 테스트 추가
1 parent d169445 commit 4f01070

2 files changed

Lines changed: 163 additions & 10 deletions

File tree

src/engine/wal/manager/builder.rs

Lines changed: 36 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -93,10 +93,26 @@ impl<'a> WALBuilder<'a> {
9393
let content = self.file_system.read(&path).await.map_err(|e| {
9494
WALError::wrap(format!("failed to read log file {:?}: {}", path, e))
9595
})?;
96-
let used_bytes = used_wal_bytes(&content).map_err(|e| {
96+
let (used_bytes, torn) = used_wal_bytes(&content).map_err(|e| {
9797
WALError::wrap(format!("failed to inspect log file {:?}: {}", path, e))
9898
})?;
99-
let entries: Vec<WALEntry> = decoder.decode(&content).map_err(|e| {
99+
100+
if let Some(reason) = torn {
101+
if sequence != max_sequence {
102+
return Err(WALError::wrap(format!(
103+
"corrupt intermediate segment {:?}: {}",
104+
path, reason
105+
)));
106+
}
107+
// #268: a torn write (partial header or truncated frame body)
108+
// in the newest segment is an uncommitted record, not file
109+
// corruption. Discard it and recover only the complete frames
110+
// before it, following the PostgreSQL/SQLite recovery
111+
// convention.
112+
log::warn!("discarding torn WAL tail in {:?}: {}", path, reason);
113+
}
114+
115+
let entries: Vec<WALEntry> = decoder.decode(&content[..used_bytes]).map_err(|e| {
100116
WALError::wrap(format!("failed to decode log file {:?}: {}", path, e))
101117
})?;
102118

@@ -124,16 +140,25 @@ impl<'a> WALBuilder<'a> {
124140
}
125141
}
126142

127-
fn used_wal_bytes(content: &[u8]) -> errors::Result<usize> {
143+
/// Walks the frames of a WAL segment and returns the byte offset of the last
144+
/// complete frame boundary, along with the reason the tail after it is torn
145+
/// (`None` when the segment ends on a clean frame boundary or zero padding).
146+
///
147+
/// #268: a torn write leaves a frame whose length header is valid but whose
148+
/// body never fully landed (or a header that was only partially written).
149+
/// That is an *uncommitted* record, not corruption, so the truncation is
150+
/// reported instead of being an error; the caller decides whether discarding
151+
/// the tail is acceptable (newest segment) or not (intermediate segment).
152+
fn used_wal_bytes(content: &[u8]) -> errors::Result<(usize, Option<String>)> {
128153
let mut offset = 0;
129154

130155
while offset < content.len() {
131156
if content.len() - offset < size_of::<u32>() {
132157
if content[offset..].iter().all(|byte| *byte == 0) {
133-
return Ok(offset);
158+
return Ok((offset, None));
134159
}
135160

136-
return Err(WALError::wrap("truncated wal frame header".to_string()));
161+
return Ok((offset, Some("truncated wal frame header".to_string())));
137162
}
138163

139164
let frame_len = u32::from_le_bytes(
@@ -143,17 +168,20 @@ fn used_wal_bytes(content: &[u8]) -> errors::Result<usize> {
143168
) as usize;
144169

145170
if frame_len == 0 {
146-
return Ok(offset);
171+
return Ok((offset, None));
147172
}
148173

149174
offset += size_of::<u32>();
150175

151176
if content.len() - offset < frame_len {
152-
return Err(WALError::wrap("truncated wal frame body".to_string()));
177+
return Ok((
178+
offset - size_of::<u32>(),
179+
Some("truncated wal frame body".to_string()),
180+
));
153181
}
154182

155183
offset += frame_len;
156184
}
157185

158-
Ok(offset)
186+
Ok((offset, None))
159187
}

src/engine/wal/manager/mod.rs

Lines changed: 127 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -120,7 +120,19 @@ where
120120
frame[..size_of::<u32>()].copy_from_slice(&frame_len.to_le_bytes());
121121

122122
self.rotate_if_needed(frame.len()).await?;
123-
self.append_frame_to_mmap(&frame).await?;
123+
124+
// #268: write the body first and patch the length header last. The
125+
// length then acts as a commit marker: if a crash interrupts the
126+
// memcpy, the on-disk frame either has len == 0 (unwritten) or a
127+
// truncated body under a valid len — both are discarded on recovery.
128+
let header_offset = self.current_offset;
129+
let header = &frame[..size_of::<u32>()];
130+
// Reserve the header slot first (as zeros = "not committed"), then
131+
// write the body, then patch the header last (see #268).
132+
self.append_frame_to_mmap(header).await?;
133+
let body = &frame[size_of::<u32>()..];
134+
self.append_frame_to_mmap(body).await?;
135+
self.patch_frame_header_at(header_offset, header).await?;
124136

125137
self.unsynced_bytes += frame.len();
126138
if self.unsynced_bytes >= GROUP_COMMIT_THRESHOLD_BYTES {
@@ -178,6 +190,33 @@ where
178190
Ok(())
179191
}
180192

193+
/// Overwrites the length header of the frame just written, at the
194+
/// absolute offset its slot occupies. Used by `write_entry` to patch the
195+
/// 4-byte length header *after* the body (see #268).
196+
async fn patch_frame_header_at(
197+
&mut self,
198+
header_offset: usize,
199+
header: &[u8],
200+
) -> errors::Result<()> {
201+
self.open_current_segment_if_needed().await?;
202+
203+
let segment = self
204+
.current_segment
205+
.as_mut()
206+
.ok_or_else(|| WALError::wrap("wal segment is not open".to_string()))?;
207+
208+
// The slot was reserved by the body write; patching it must not move
209+
// the segment offset.
210+
debug_assert!(
211+
header_offset + header.len() <= segment.offset,
212+
"header slot must lie within the already-written frame"
213+
);
214+
215+
segment.mmap[header_offset..header_offset + header.len()].copy_from_slice(header);
216+
217+
Ok(())
218+
}
219+
181220
async fn open_current_segment_if_needed(&mut self) -> errors::Result<()> {
182221
if self.current_segment.is_some() {
183222
return Ok(());
@@ -612,6 +651,89 @@ mod tests {
612651
);
613652
}
614653

654+
/// #268: a torn write (valid frame_len, truncated body) at the end of the
655+
/// newest segment is an *uncommitted* record, not corruption — it must be
656+
/// discarded and recovery must proceed with the complete entries before
657+
/// it, instead of failing startup.
658+
#[tokio::test]
659+
async fn test_build_discards_torn_tail_of_newest_segment() {
660+
let wal_dir = setup_test_wal_dir("torn_tail_newest_segment").await;
661+
let config = get_test_config(&wal_dir);
662+
write_wal_file(
663+
&config,
664+
1,
665+
&vec![
666+
create_entry(EntryType::Insert, Some("complete-1")),
667+
create_entry(EntryType::Set, Some("complete-2")),
668+
],
669+
)
670+
.await;
671+
672+
// Simulate a torn write: the frame_len header says 8, but only 3
673+
// body bytes landed before the crash.
674+
let path = wal_dir.join(format!("00000001.{}", config.wal_extension));
675+
let mut file = tokio::fs::OpenOptions::new()
676+
.append(true)
677+
.open(&path)
678+
.await
679+
.unwrap();
680+
file.write_all(&8u32.to_le_bytes()).await.unwrap();
681+
file.write_all(&[1, 2, 3]).await.unwrap();
682+
drop(file);
683+
684+
let wal_manager = WALBuilder::new(&config)
685+
.build(BincodeDecoder::new(), BincodeEncoder::new())
686+
.await
687+
.expect("a torn tail must not prevent startup");
688+
689+
let payloads: Vec<_> = wal_manager
690+
.pending_entries()
691+
.iter()
692+
.map(|entry| entry.data.clone().unwrap())
693+
.collect();
694+
assert_eq!(
695+
payloads,
696+
vec![b"complete-1".to_vec(), b"complete-2".to_vec()],
697+
"the complete entries before the torn frame must be replayed, the torn one discarded"
698+
);
699+
}
700+
701+
/// #268: a partially written frame header (fewer than 4 non-zero bytes
702+
/// landed) in the newest segment is likewise an uncommitted write and
703+
/// must be discarded rather than failing startup.
704+
#[tokio::test]
705+
async fn test_build_discards_partial_frame_header_of_newest_segment() {
706+
let wal_dir = setup_test_wal_dir("partial_header_newest_segment").await;
707+
let config = get_test_config(&wal_dir);
708+
write_wal_file(
709+
&config,
710+
1,
711+
&vec![create_entry(EntryType::Insert, Some("complete"))],
712+
)
713+
.await;
714+
715+
let path = wal_dir.join(format!("00000001.{}", config.wal_extension));
716+
let mut file = tokio::fs::OpenOptions::new()
717+
.append(true)
718+
.open(&path)
719+
.await
720+
.unwrap();
721+
file.write_all(&[0xAB, 0xCD]).await.unwrap();
722+
drop(file);
723+
724+
let wal_manager = WALBuilder::new(&config)
725+
.build(BincodeDecoder::new(), BincodeEncoder::new())
726+
.await
727+
.expect("a partial frame header must not prevent startup");
728+
729+
let payloads: Vec<_> = wal_manager
730+
.pending_entries()
731+
.iter()
732+
.map(|entry| entry.data.clone().unwrap())
733+
.collect();
734+
assert_eq!(payloads, vec![b"complete".to_vec()]);
735+
}
736+
615737
#[tokio::test]
616738
async fn test_build_rejects_corrupt_intermediate_segment() {
617739
let wal_dir = setup_test_wal_dir("corrupt_intermediate_segment").await;
@@ -772,7 +894,10 @@ mod tests {
772894
.build(BincodeDecoder::new(), BincodeEncoder::new())
773895
.await
774896
.unwrap_or_else(|error| {
775-
panic!("current behaviour: cut={} was expected to be accepted, got {}", cut, error)
897+
panic!(
898+
"current behaviour: cut={} was expected to be accepted, got {}",
899+
cut, error
900+
)
776901
});
777902
assert_eq!(
778903
reopened.pending_entries().len(),

0 commit comments

Comments
 (0)