vectordotdev / vectordotdev/vector

docker_logs: a transient stream error replays every record since the Vector process started

Open
#26,023 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Rust
Stars
22.6k
Forks
2.3k
Avg merge
1d 7h
Merged PRs (30d)
146

Description

Problem

When a docker_logs log-follow stream ends with a transient error, the source does not resume
from the last delivered record — it resumes from the Vector process start time and re-emits
every line the container has logged since Vector booted.

The result is that a single recoverable stream blip re-delivers a container's entire history, and
the amount re-delivered grows with collector uptime. In our environment a proxy in front of the
Docker socket cut idle log-follow streams on a fixed 10-minute cadence; each cut produced a full
replay. Measured re-delivery factors, grouping received records by exact timeUnixNano:

container window records distinct factor
low-volume cache service 95 min 128 13 9.8x
idle buildkit container ~3 days 71,151 264 269x

No records were lost and the receiver never applied backpressure — every duplicate was accepted.
The 9.8x case is exactly one replay of all 13 records per 10-minute cut.

The code path

In src/sources/docker_logs/mod.rs (v0.56.0), a container's resume position lives in
ContainerLogInfo, which is owned by the running stream task.

A clean stream end returns it, so the state survives:

let result = match (result, error) {
    (Ok(()), None) => Ok(info),                                  // info preserved
    (Err(()), _)   => Err((info.id, ErrorPersistence::Permanent)),
    (_, Some(occurrence)) => Err((info.id, occurrence)),          // info DROPPED
};

The main loop resumes the clean case with restart, which reuses the existing info:

Some(Ok(info)) => {
    let state = self.containers.get_mut(&info.id).expect(...);
    if state.return_info(info) { self.esb.restart(state); }
}

But the transient-error case only carries the ContainerId forward, so it goes through start:

ErrorPersistence::Transient => if state.is_running() {
    let backoff = Some(self.backoff_duration);
    self.containers.insert(id.clone(), self.esb.start(id, backoff));
}

and start builds a brand new ContainerLogInfo seeded with the source's now_timestamp:

let info = ContainerLogInfo::new(id, metadata, this.core.now_timestamp);

now_timestamp is captured once when the source is created, so it is the Vector process start
time. last_log is now None, and log_since() therefore returns the process start rather than
the last delivered record:

fn log_since(&self) -> i64 {
    self.last_log.as_ref().map(|(d, _)| d.timestamp())
        .unwrap_or_else(|| self.created.timestamp()) - 1
}

That value is passed straight to the Docker API:

.since(info.log_since() as i32)

The duplicate guard in new_event cannot help, because with last_log: None it takes the
first-run branch, which admits everything after created:

None => {
    if self.created < timestamp.with_timezone(&Utc) {
        // Noop - first log to process.
    }
}

So every record since the process started is re-emitted.

Reproduction

Minimal setup: a container that logs a handful of lines and then goes quiet, watched through a
proxy that closes idle streams. Scaling the proxy's idle timeout to 30s and observing for 150s
(five cut intervals), against timberio/vector@sha256:93b072b4... (0.56.0):

proxy behaviour records delivered distinct factor Error in communication with Docker daemon
cuts idle streams at 30s 65 13 5.0x 4
does not cut idle streams 13 13 1.0x 0

Five cuts, five replays of all 13 records. The count tracks the number of stream errors exactly.

Suggested fix

run_event_stream still owns info at the point it builds the error result, so the resume state
is available and is simply discarded. Carrying it through the transient path — e.g. returning
Err((info, ErrorPersistence::Transient)) and having the main loop re-arm the existing
ContainerState rather than calling start — would make a transient error resume from
last_log like the clean path already does.

A narrower fix would be to have start accept an optional previous ContainerLogInfo. Either way
the goal is that a recoverable error costs at most the bounded one-record overlap the
second-granularity since already implies, instead of the whole history since process start.

Related

Existing issues describe the watch churn itself but not this re-delivery consequence:
#23847 (stops watching after a Docker daemon communication error), #20028 and #11056
(Started/Stopped watching loops). Checkpointing requests #7358, #20121 and #24869 would also
address this, but the behaviour above looks like a straightforward bug in the existing resume
logic rather than a missing feature: the state is already in hand and is thrown away.

Version

vector 0.56.0 (aarch64-unknown-linux-gnu 6817c02 2026-06-03)

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start in src/sources/docker_logs/mod.rs, reading run_event_stream, ContainerLogInfo, and the main loop handling transient errors. Trace how the clean path preserves info while the transient path calls start, then verify the resume state remains available across a recoverable stream error. Done means a transient Docker stream interruption resumes from last_log rather than replaying the container history.

Written by the indexing model from the issue text.

Assessment

Tech stack
rust
Domain
observability-sre, stream-processing
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Active
Clarity
Clearly specified
Newbie friendliness
76/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.