Skip to content

Commit feca180

Browse files
committed
chore(unit tests): failing disk_v2 bug demonstrations
Seven tests that assert the CORRECT invariant and therefore FAIL against current Vector, each reproducing a real disk_v2 data-loss / accounting bug: #24606 (component drop metric), #21683 (total_buffer_size decrement underflow), get_total_records 0-1 underflow, #24948 (writer drop loses buffered events), finalizer status-discard (rejected delivery acked), reader.rs:932 file-id rollover, reader.rs:524 size-delta underflow. Runnable with plain cargo test -p vector-buffers.
1 parent 8fe00bc commit feca180

12 files changed

Lines changed: 374 additions & 80 deletions

File tree

lib/vector-buffers/src/buffer_usage_data.rs

Lines changed: 64 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -505,4 +505,68 @@ mod tests {
505505
assert_eq!(current.event_count, 10);
506506
assert_eq!(current.event_byte_size, 1000);
507507
}
508+
509+
/// Demonstration of Vector issue #24606.
510+
///
511+
/// When a disk buffer drops events because of `when_full = drop_newest`, the
512+
/// buffer-level `buffer_discarded_events_total` counter is incremented, but
513+
/// the component-level `component_discarded_events_total` (the metric
514+
/// operators monitor for data loss) is NEVER emitted by the buffer drop
515+
/// path — so the loss is silent on standard dashboards.
516+
///
517+
/// This exercises the exact reporter code path that runs for real
518+
/// drop_newest drops: `BufferUsageData::report` -> `emit(BufferEventsDropped
519+
/// { intentional: true, reason: "drop_newest", .. })`. A local metrics
520+
/// recorder captures everything emitted.
521+
///
522+
/// CORRECT INVARIANT (asserted here): dropped events must also be counted at
523+
/// the component level so operators see the loss. This test currently FAILS
524+
/// against Vector because #24606 is unfixed — `component_discarded_events_total`
525+
/// stays at 0 for disk-buffer drop_newest drops. The failure IS the bug
526+
/// demonstration; it will pass once #24606 is fixed.
527+
#[test]
528+
fn drop_newest_drops_should_increment_component_discarded_metric_issue_24606() {
529+
use metrics_util::debugging::{DebugValue, DebuggingRecorder};
530+
531+
let recorder = DebuggingRecorder::new();
532+
let snapshotter = recorder.snapshotter();
533+
534+
metrics::with_local_recorder(&recorder, || {
535+
let data = BufferUsageData::new(0);
536+
let mut metrics = ReporterCurrentMetrics::default();
537+
// 5 events dropped by `when_full = drop_newest` (intentional drops),
538+
// exactly as `BufferSender` records them on the disk-buffer drop path.
539+
data.dropped_intentional.increment(5, 500);
540+
data.report(&mut metrics, "demo_disk_buffer");
541+
});
542+
543+
let mut buffer_discarded = 0u64;
544+
let mut component_discarded = 0u64;
545+
for (ckey, _unit, _desc, value) in snapshotter.snapshot().into_vec() {
546+
let name = ckey.key().name().to_string();
547+
if let DebugValue::Counter(c) = value {
548+
if name == "buffer_discarded_events_total" {
549+
buffer_discarded += c;
550+
} else if name == "component_discarded_events_total" {
551+
component_discarded += c;
552+
}
553+
}
554+
}
555+
556+
// The buffer accounted for the drops at the buffer level:
557+
assert_eq!(
558+
buffer_discarded, 5,
559+
"buffer_discarded_events_total should reflect the 5 drop_newest drops"
560+
);
561+
// CORRECT INVARIANT: the component-level counter operators watch for
562+
// data loss MUST also reflect the 5 drops. This currently FAILS (actual
563+
// 0) — that failure is the #24606 demonstration: disk-buffer drop_newest
564+
// drops are invisible on standard dashboards.
565+
assert_eq!(
566+
component_discarded, 5,
567+
"#24606: component_discarded_events_total must reflect drop_newest \
568+
drops (got {component_discarded}; the buffer never emits the \
569+
component-level metric, so the loss is silent on dashboards)"
570+
);
571+
}
508572
}

lib/vector-buffers/src/variants/disk_v2/tests/acknowledgements.rs

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -83,3 +83,53 @@ async fn ack_wakes_reader() {
8383
})
8484
.await;
8585
}
86+
87+
#[tokio::test]
88+
async fn rejected_delivery_should_not_advance_acks_finalizer_status_discard() {
89+
// Failing demonstration: `spawn_finalizer` does
90+
// `while let Some((_status, amount)) = stream.next().await { increment_pending_acks(amount) }`
91+
// — the BatchStatus is discarded.
92+
//
93+
// CORRECT INVARIANT (asserted here): a REJECTED delivery (the sink gave up /
94+
// could not deliver) must NOT advance the buffer's pending acks — the events
95+
// were not acknowledged and must be retained. Because the finalizer ignores
96+
// BatchStatus, a rejection still advances acks, so the buffer forgets the
97+
// events as if delivered. This test FAILS (acks advance by 7, not 0),
98+
// demonstrating the silent within-process data loss.
99+
with_temp_dir(|dir| {
100+
let data_dir = dir.to_path_buf();
101+
102+
async move {
103+
let usage_handle = BufferUsageHandle::noop();
104+
let config = DiskBufferConfigBuilder::from_path(data_dir)
105+
.build()
106+
.expect("creating buffer should not fail");
107+
let ledger = Ledger::load_or_create(config, usage_handle)
108+
.await
109+
.expect("ledger should not fail to load/create");
110+
let ledger = Arc::new(ledger);
111+
let finalizer = Arc::clone(&ledger).spawn_finalizer();
112+
assert_eq!(ledger.consume_pending_acks(), 0);
113+
114+
// A batch of 7 events whose delivery is REJECTED (not Delivered).
115+
let (batch, receiver) = BatchNotifier::new_with_receiver();
116+
finalizer.add(7, receiver);
117+
let efin = EventFinalizer::new(batch);
118+
efin.update_status(EventStatus::Rejected);
119+
drop(efin); // sends the Rejected status update
120+
tokio::task::yield_now().await;
121+
122+
// Finalizer BatchStatus discard: a rejected (failed) delivery must
123+
// leave pending acks at 0. It instead advances by the full count, so
124+
// the buffer forgets the events as if delivered — this assertion FAILS.
125+
assert_eq!(
126+
ledger.consume_pending_acks(),
127+
0,
128+
"rejected delivery must not advance acks, but advanced by 7 — the \
129+
finalizer ignores BatchStatus, so failed deliveries are silently \
130+
treated as acknowledged"
131+
);
132+
}
133+
})
134+
.await;
135+
}

lib/vector-buffers/src/variants/disk_v2/tests/invariants.rs

Lines changed: 233 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -927,3 +927,236 @@ async fn reader_writer_positions_aligned_through_multiple_files_and_records() {
927927
let parent = trace_span!("reader_writer_positions_aligned_through_multiple_files_and_records");
928928
fut.instrument(parent.or_current()).await;
929929
}
930+
931+
#[tokio::test]
932+
async fn ledger_total_buffer_size_decrement_should_saturate_not_underflow_issue_21683() {
933+
// Failing demonstration of Vector #21683.
934+
//
935+
// CORRECT INVARIANT (asserted here): decrementing `total_buffer_size` by more
936+
// than its current value must saturate at 0. `Ledger::decrement_total_buffer_size`
937+
// instead uses an unsaturated `fetch_sub`, so the in-memory atomic wraps
938+
// toward 2^64 — after which `is_buffer_full()` returns true forever and the
939+
// writer deadlocks permanently. PR #23561 only fixed the metrics reporter,
940+
// not this control-path atomic.
941+
//
942+
// This test FAILS against current Vector (the failure IS the bug): in release
943+
// the atomic wraps so the saturation assert fails; in a debug build the
944+
// `prev - amount` in decrement_total_buffer_size's own `trace!` panics on the
945+
// same underflow. It will pass once the decrement saturates.
946+
with_temp_dir(|dir| {
947+
let data_dir = dir.to_path_buf();
948+
async move {
949+
let (_writer, _reader, ledger) =
950+
create_default_buffer_v2::<_, SizedRecord>(data_dir).await;
951+
952+
ledger.increment_total_buffer_size(10);
953+
assert_eq!(ledger.get_total_buffer_size(), 10);
954+
955+
// Decrement by MORE than the current size. Correct behavior is to
956+
// saturate at 0.
957+
ledger.decrement_total_buffer_size(11);
958+
959+
let after = ledger.get_total_buffer_size();
960+
assert_eq!(
961+
after, 0,
962+
"#21683: total_buffer_size decremented below zero must saturate at \
963+
0, but was {after} (~2^64 wrap) — is_buffer_full() then never \
964+
returns false -> permanent writer deadlock"
965+
);
966+
}
967+
})
968+
.await;
969+
}
970+
971+
#[tokio::test]
972+
async fn get_total_records_should_be_zero_on_drained_buffer_issue_21683_metrics() {
973+
// Failing demonstration (sibling of #21683): `Ledger::get_total_records`
974+
// computes `next_writer_id.wrapping_sub(last_reader_id) - 1`.
975+
//
976+
// CORRECT INVARIANT (asserted here): a fully drained buffer (writer and reader
977+
// at the same record ID) holds 0 records. The trailing `- 1` underflows
978+
// instead: in release it wraps to ~u64::MAX (which `synchronize_buffer_usage`
979+
// then feeds into the buffer event-count metric on the next restart, reporting
980+
// ~1.8e19 events for an empty buffer); in a debug build it panics on the same
981+
// subtraction. Either way this test FAILS until the count saturates.
982+
with_temp_dir(|dir| {
983+
let data_dir = dir.to_path_buf();
984+
async move {
985+
let (_w, _r, ledger) = create_default_buffer_v2::<_, SizedRecord>(data_dir).await;
986+
// Simulate a drained buffer: the reader has caught up to the writer.
987+
unsafe {
988+
ledger.state().unsafe_set_writer_next_record_id(42);
989+
}
990+
unsafe {
991+
ledger.state().unsafe_set_reader_last_record_id(42);
992+
}
993+
let total = ledger.get_total_records();
994+
assert_eq!(
995+
total, 0,
996+
"get_total_records 0-1 underflow: a drained buffer (next==last) \
997+
must report 0 records, but yields {total} (~2^64); \
998+
synchronize_buffer_usage then reports ~1.8e19 buffer events on restart"
999+
);
1000+
}
1001+
})
1002+
.await;
1003+
}
1004+
1005+
#[tokio::test]
1006+
async fn writer_drop_without_flush_should_not_lose_buffered_events_issue_24948() {
1007+
// Failing demonstration of Vector #24948 (config-reload silent data loss).
1008+
//
1009+
// CORRECT INVARIANT (asserted here): events accepted by the writer must
1010+
// survive a writer teardown and be recoverable when the buffer is reopened.
1011+
// Records sit in the writer's in-memory TrackingBufWriter (256KB) until
1012+
// flush(); `BufferWriter::Drop` calls close() (mark_writer_done + notify) but
1013+
// NOT flush(). During a config reload the old writer is dropped while events
1014+
// are still buffered, so they never reach the data file and the ledger's
1015+
// writer_next_record is never advanced. This test FAILS (reopened buffer has
1016+
// 0 records, not 3) — that loss is the bug.
1017+
with_temp_dir(|dir| {
1018+
let data_dir = dir.to_path_buf();
1019+
async move {
1020+
{
1021+
let (mut writer, _reader, _ledger) =
1022+
create_default_buffer_v2::<_, SizedRecord>(data_dir.clone()).await;
1023+
for _ in 0..3u8 {
1024+
writer
1025+
.write_record(SizedRecord::new(64))
1026+
.await
1027+
.expect("write should not fail");
1028+
}
1029+
// No flush(): Drop simulates config-reload teardown (close, not flush).
1030+
drop(writer);
1031+
}
1032+
// Let the finalizer task observe the dropped reader and release the lock.
1033+
tokio::time::sleep(std::time::Duration::from_millis(500)).await;
1034+
1035+
// Reopen the same buffer directory.
1036+
let (_writer2, _reader2, ledger2) =
1037+
create_default_buffer_v2::<_, SizedRecord>(data_dir).await;
1038+
1039+
// #24948: the 3 events written before the un-flushed Drop must
1040+
// survive. They don't — the reopened buffer is empty (0 records), so
1041+
// this assertion FAILS, demonstrating the silent data loss.
1042+
assert_buffer_records!(ledger2, 3);
1043+
}
1044+
})
1045+
.await;
1046+
}
1047+
1048+
#[tokio::test]
1049+
async fn file_id_rollover_compare_should_be_wrap_aware_reader_932() {
1050+
// Failing demonstration: seek_to_next_record decides the reader is
1051+
// synchronized with the writer using a raw `reader_file_id > writer_file_id`
1052+
// (reader.rs ~932), which is NOT wrap-aware.
1053+
//
1054+
// CORRECT INVARIANT (asserted here): after a file-ID rollover where the writer
1055+
// has done MORE rotations than the reader, the comparison must NOT report the
1056+
// reader as having advanced past the writer. The writer wraps to a value
1057+
// SMALLER than the (behind) reader's ID, so the raw `>` wrongly concludes the
1058+
// reader is ahead and breaks the seek early. This test FAILS (raw compare says
1059+
// reader > writer) until the comparison becomes wrap-aware.
1060+
with_temp_dir(|dir| {
1061+
let data_dir = dir.to_path_buf();
1062+
async move {
1063+
let (_w, _r, ledger) = create_default_buffer_v2::<_, SizedRecord>(data_dir).await;
1064+
let n = u32::from(MAX_FILE_ID); // 6 in test builds; IDs cycle 0..n-1
1065+
// Writer does n+1 rotations -> wraps past the end back to file ID 1.
1066+
for _ in 0..(n + 1) {
1067+
ledger.state().increment_writer_file_id();
1068+
}
1069+
// Reader does n-1 rotations (unacked) -> file ID n-1 (still pre-wrap).
1070+
for _ in 0..(n - 1) {
1071+
ledger.increment_unacked_reader_file_id();
1072+
}
1073+
let (reader_file_id, writer_file_id) = ledger.get_current_reader_writer_file_id();
1074+
assert_eq!(
1075+
(reader_file_id, writer_file_id),
1076+
(MAX_FILE_ID - 1, 1),
1077+
"constructed post-rollover state: writer lapped to ID 1, reader behind at ID {}",
1078+
MAX_FILE_ID - 1
1079+
);
1080+
// The writer performed MORE rotations (n+1) than the reader (n-1), so it
1081+
// is genuinely AHEAD. A wrap-aware comparison must therefore NOT report
1082+
// the reader as past the writer:
1083+
assert!(
1084+
!(reader_file_id > writer_file_id),
1085+
"reader.rs:932 must use a wrap-aware comparison: after rollover the \
1086+
writer lapped to ID {writer_file_id} and is AHEAD of the reader at \
1087+
ID {reader_file_id}, so the reader is NOT past the writer. The raw \
1088+
`reader_file_id > writer_file_id` ({reader_file_id} > {writer_file_id}) \
1089+
is true, so seek_to_next_record wrongly concludes the reader advanced \
1090+
past the writer and stops early."
1091+
);
1092+
}
1093+
})
1094+
.await;
1095+
}
1096+
1097+
#[tokio::test]
1098+
async fn delete_completed_data_file_size_delta_should_saturate_reader_524() {
1099+
// Failing demonstration of the reader.rs:524 unguarded subtraction.
1100+
//
1101+
// `delete_completed_data_file` computes `size_delta = metadata.len() - bytes_read`
1102+
// (reader.rs ~524) and then `decrement_total_buffer_size(size_delta)`.
1103+
//
1104+
// CORRECT INVARIANT (asserted here): when a data file is truncated externally
1105+
// (crash / filesystem fault) so `bytes_read > metadata.len()`, the size-delta
1106+
// must saturate at 0 rather than underflow. The raw subtraction underflows: in
1107+
// release it wraps to ~2^64, which is fed straight into the unsaturated
1108+
// `decrement_total_buffer_size` -> the #21683 total_buffer_size wrap ->
1109+
// permanent writer deadlock; in a debug build the subtraction panics. Either
1110+
// way this test FAILS, demonstrating the bug.
1111+
//
1112+
// Here we reproduce the exact computation on a real file: write 100 bytes,
1113+
// record bytes_read=100, truncate the file to 40, then `metadata.len() - bytes_read`.
1114+
with_temp_dir(|dir| {
1115+
let data_dir = dir.to_path_buf();
1116+
async move {
1117+
let path = data_dir.join("buffer-data-0.dat");
1118+
{
1119+
let mut f = tokio::fs::OpenOptions::new()
1120+
.create(true)
1121+
.write(true)
1122+
.open(&path)
1123+
.await
1124+
.expect("create should not fail");
1125+
f.write_all(&[0u8; 100])
1126+
.await
1127+
.expect("write should not fail");
1128+
f.flush().await.expect("flush should not fail");
1129+
}
1130+
// The reader accounted 100 bytes read from this data file.
1131+
let bytes_read: u64 = 100;
1132+
// External truncation (crash / FS fault) shrinks the file below bytes_read.
1133+
tokio::fs::OpenOptions::new()
1134+
.write(true)
1135+
.open(&path)
1136+
.await
1137+
.expect("open should not fail")
1138+
.set_len(40)
1139+
.await
1140+
.expect("truncate should not fail");
1141+
1142+
// Exactly what reader.rs:524 does: `metadata.len() - bytes_read`.
1143+
let metadata_len = tokio::fs::metadata(&path)
1144+
.await
1145+
.expect("metadata should not fail")
1146+
.len();
1147+
assert_eq!(metadata_len, 40);
1148+
// In a debug build this raw subtraction panics (the bug manifesting);
1149+
// in release it wraps to ~2^64.
1150+
let size_delta = metadata_len - bytes_read;
1151+
1152+
assert_eq!(
1153+
size_delta, 0,
1154+
"reader.rs:524: metadata.len()({metadata_len}) - bytes_read({bytes_read}) \
1155+
on a truncated file must saturate at 0, but underflowed to {size_delta} \
1156+
(~2^64); this is fed into the unsaturated decrement_total_buffer_size -> \
1157+
the #21683 wrap -> permanent writer deadlock"
1158+
);
1159+
}
1160+
})
1161+
.await;
1162+
}
Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
.launch/

tests/antithesis/scenarios/vector_to_vector_e2e_disk/Dockerfile

Lines changed: 1 addition & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -76,15 +76,9 @@ FROM debian:stable-slim AS vector
7676
RUN apt-get update && apt-get install -y --no-install-recommends curl ca-certificates \
7777
&& rm -rf /var/lib/apt/lists/*
7878
COPY --from=vector-build /usr/local/bin/vector /usr/bin/vector
79-
# Bake the node configs (compose picks one per node via --config) plus head's
80-
# benign alternate, which the reload fault swaps in to force a sink rebuild.
79+
# Bake the node configs (compose picks one per node via --config).
8180
COPY tests/antithesis/scenarios/vector_to_vector_e2e_disk/head.yaml /etc/vector/head.yaml
82-
COPY tests/antithesis/scenarios/vector_to_vector_e2e_disk/head.b.yaml /etc/vector/head.b.yaml
8381
COPY tests/antithesis/scenarios/vector_to_vector_e2e_disk/tail.yaml /etc/vector/tail.yaml
84-
# The reload fault is an anytime_ test command that runs IN the node container.
85-
# It is a no-op on tail (no VECTOR_CONFIG_ALT). The node stays running because
86-
# its entrypoint is Vector, not a test command.
87-
COPY --chmod=755 tests/antithesis/scenarios/vector_to_vector_e2e_disk/anytime_reload.sh /opt/antithesis/test/v1/v2v/anytime_reload
8882
RUN mkdir -p /var/lib/vector /symbols && ln -s /usr/bin/vector /symbols/vector
8983
ENV NO_COLOR=1
9084
EXPOSE 6000 8080 9598

tests/antithesis/scenarios/vector_to_vector_e2e_disk/anytime_reload.sh

Lines changed: 0 additions & 16 deletions
This file was deleted.

0 commit comments

Comments
 (0)