Vector stale buffer file bug and analysis
One morning, a vector log aggregator in production stopped moving logs. CPU was near idle, the disk buffer was well under its cap, and there were no errors in the logs which were set to info and higher. Reboot did not fix the issue. It stayed that way for about 15 hours until we found the cause: one 128 MiB data file in a Vector disk buffer, left behind months earlier by an unplanned node reboot.
Once we knew what to look for, we found the same leftover file on several other production clusters. Some had already stalled. One was caught with months to spare.
How a Vector disk buffer works
A Vector disk buffer (v2) is a ring of data files, each up to 128 MiB. The writer appends to its current file. The reader follows behind and deletes each file once all its events are delivered. A small ledger, buffer.db, records which file the writer and reader are on, as 16-bit file IDs, so the ring wraps after about 65,000 files.
The bug lives in the gap between two writes.
Two writes, only one of them durable
When the reader finishes a file, it deletes it and then advances the reader position in the ledger, which is memory-mapped and msynced. The delete has no fsync on the directory, so after that sequence, the ledger update is on disk garanteed but the delete may not be.
If the node loses power or reboots hard at that moment, the ledger survives and the delete does not. The file comes back on disk, and the ledger has already moved past it. On startup Vector only cleans up files between the reader and writer positions, so nothing will ever read or delete it.
We reproduced this on a dev cluster by triggering an immediate reboot with echo b > /proc/sysrq-trigger right after a file delete. A clean stop or a SIGKILL leaves nothing behind. It takes an unclean node reboot.
Why it waits months
Nothing happens right away. The writer works through the rest of the ID space while the stale file sits there. Depending on traffic, getting all the way around can take weeks or months, and in our case the file survived pod restarts the whole time.
When the writer finally needs that file ID, the file exists and isn’t empty, so the writer waits for the reader to delete it. The reader never will. The buffer stops accepting writes, and there’s no warning or error.
Why one stuck sink stopped everything
Our aggregator sends each event to two sinks, each with its own disk buffer. When one sink’s buffer stops accepting writes, backpressure reaches the shared source, so the healthy sink drains and goes idle too. Upstream agents time out, and the aggregator starts discarding events.
Get Abhilasha Gupta’s stories in your inbox
Join Medium for free to get updates from this writer.
Restarting the pod doesn’t help, because the file is still there.
Detecting it before it bites
The stale file leaves one clear sign in Vector’s buffer metrics. On startup, buffer bytes count every data file on disk, but buffer events count only unread records. A buffer with a stale file never drops below about 128 MiB, even when it’s essentially empty:
min_over_time(vector_buffer_byte_size[1d]) > 120 * 1024 * 1024
and
min_over_time(vector_buffer_events[1d]) < 1000Newer Vector releases also expose these as vector_buffer_size_bytes and vector_buffer_size_events.
Bytes staying high for a whole day while events stay near zero almost always means a stale file. Run against a few months of our history, this flagged exactly the known cases with no false positives. The signal was in our metrics the whole time, but nothing was watching for it.
Two other alerts were worth adding: one for a source that stops sending for more than about ten minutes, which catches the stall itself, and one for an aggregator Prometheus can’t scrape. Alerts that read the pod’s own metrics go quiet when the pod does.
The fix
On Vector 0.58 and later, Vector checks once a second for data files outside the reader-to-writer window and deletes them, so a stale file is gone about a second after startup (vector#25845). We checked this by running the upstream tests plus two of our own, one shaped like the reproduced case and one that wraps around the ring.
On older versions, read the ledger, delete only the data file outside the reader-to-writer range, and restart. Don’t wipe the whole buffer directory. That throws away every buffered event and the evidence along with it. Until we can upgrade, we run the same check in an init container, so a restart is enough to clear it.
Takeaways
- If you run Vector disk buffers on nodes that can reboot without draining, you are exposed. Upgrade to 0.58+ or add the cleanup check.
- Alert on buffer bytes versus events, not on throughput dropping to zero. Ours trickled just above zero, so a zero-throughput alert never fired.
- When the same alert fires repeatedly across clusters, treat the repeats as one problem.
The upstream discussion is in vector#19759.
