Docker source reports 404s on closed containers that were started before it.

[Hoverbear]

Starting a Vector (0.10 or master) with the following config works fine normally:

[sources.foo]
  type = "docker" # required

[sinks.my_sink_id]
  type = "console" # required
  inputs = ["foo"] # required
  encoding = "json"

Outputs:

ana@autonoma:~/git/timberio/vector$ docker run -i -p 5000:5000 -v $PWD/vector.toml:/etc/vector/vector.toml:ro  -v /var/run/docker.sock:/var/run/docker.sock timberio/vector:latest-alpine -vvv
Nov 04 17:43:51.402  INFO vector: Log level "trace" is enabled.
Nov 04 17:43:51.431  INFO vector: Loading configs. path=["/etc/vector/vector.toml"]
Nov 04 17:43:51.431 TRACE vector: Parsing config. path="/etc/vector/vector.toml"
Nov 04 17:43:51.432  INFO vector: Vector is starting. version="0.10.0" git_version="v0.9.0-377-g0f0311a" released="Wed, 22 Jul 2020 20:01:29 +0000" arch="x86_64"
Nov 04 17:43:51.432  INFO vector::sources::docker: Capturing logs from now on now=2020-11-04T17:43:51.432219100+00:00
Nov 04 17:43:51.432  INFO vector::sources::docker: Listening docker events
Nov 04 17:43:51.432  INFO vector::topology: Running healthchecks.
Nov 04 17:43:51.432  INFO vector::topology: Starting source "foo"
Nov 04 17:43:51.432  INFO vector::topology: Starting sink "my_sink_id"
Nov 04 17:43:51.432  INFO vector::topology::builder: Healthcheck: Passed.
Nov 04 17:43:51.432 TRACE sink{name=my_sink_id type=console}: vector::sinks::util::sink: Acking events. acking_num=0
Nov 04 17:43:51.434 TRACE source{name=foo type=docker}: vector::sources::docker: Found already running container id=470cecb91b137bdb204f4af6b86145a4a15c6e128bd21b92038e8909211576fb names=["/quirky_joliot"]
Nov 04 17:43:51.434  INFO source{name=foo type=docker}: vector::sources::docker: Detected self container id="470cecb91b137bdb204f4af6b86145a4a15c6e128bd21b92038e8909211576fb"

From here you can run and exit containers in another shell without causing issues:

ana@autonoma:~/git/timberio/vector$ docker run --log-driver json-file -p 5001:5001  -v /var/run/docker.sock:/var/run/docker.sock  -it --rm --entrypoint /bin/bash ubuntu
root@9a2754cfd44a:/# exit
ana@autonoma:~/git/timberio/vector$ 

However, if you spawn a Docker container prior to starting Vector:

ana@autonoma:~/git/timberio/vector$ docker run --log-driver json-file -p 5001:5001  -v /var/run/docker.sock:/var/run/docker.sock  -it --rm --entrypoint /bin/bash ubuntu
root@c5cec9e5269d:/# 

And run Vector:

ana@autonoma:~/git/timberio/vector$ docker run -i -p 5000:5000 -v $PWD/vector.toml:/etc/vector/vector.toml:ro  -v /var/run/docker.sock:/var/run/docker.sock timberio/vector:latest-alpine -vvv
Nov 04 17:45:47.183  INFO vector: Log level "trace" is enabled.
Nov 04 17:45:47.205  INFO vector: Loading configs. path=["/etc/vector/vector.toml"]
Nov 04 17:45:47.205 TRACE vector: Parsing config. path="/etc/vector/vector.toml"
Nov 04 17:45:47.207  INFO vector: Vector is starting. version="0.10.0" git_version="v0.9.0-377-g0f0311a" released="Wed, 22 Jul 2020 20:01:29 +0000" arch="x86_64"
Nov 04 17:45:47.207  INFO vector::sources::docker: Capturing logs from now on now=2020-11-04T17:45:47.207265900+00:00
Nov 04 17:45:47.207  INFO vector::sources::docker: Listening docker events
Nov 04 17:45:47.208  INFO vector::topology: Running healthchecks.
Nov 04 17:45:47.208  INFO vector::topology: Starting source "foo"
Nov 04 17:45:47.208  INFO vector::topology: Starting sink "my_sink_id"
Nov 04 17:45:47.208  INFO vector::topology::builder: Healthcheck: Passed.
Nov 04 17:45:47.208 TRACE sink{name=my_sink_id type=console}: vector::sinks::util::sink: Acking events. acking_num=0
Nov 04 17:45:47.210 TRACE source{name=foo type=docker}: vector::sources::docker: Found already running container id=e70db9306726a4170181c680b7c2bcc519e2a2334e55010df31944de68956ce1 names=["/ecstatic_noether"]
Nov 04 17:45:47.210  INFO source{name=foo type=docker}: vector::sources::docker: Detected self container id="e70db9306726a4170181c680b7c2bcc519e2a2334e55010df31944de68956ce1"
Nov 04 17:45:47.210 TRACE source{name=foo type=docker}: vector::sources::docker: Found already running container id=c5cec9e5269d42cea6298f4d0c766cf84844669650a0c98a29558b014bb5515d names=["/dreamy_mirzakhani"]
Nov 04 17:45:47.212  INFO vector::sources::docker: Started listening logs on docker container id=c5cec9e5269d42cea6298f4d0c766cf84844669650a0c98a29558b014bb5515d

Then stop the container:

root@9a2754cfd44a:/# exit

The Vector will output as such:

ana@autonoma:~/git/timberio/vector$ docker run -i -p 5000:5000 -v $PWD/vector.toml:/etc/vector/vector.toml:ro  -v /var/run/docker.sock:/var/run/docker.sock timberio/vector:latest-alpine
Nov 04 16:54:51.893  INFO vector: Log level "info" is enabled.
Nov 04 16:54:51.919  INFO vector: Loading configs. path=["/etc/vector/vector.toml"]
Nov 04 16:54:51.920  INFO vector: Vector is starting. version="0.10.0" git_version="v0.9.0-377-g0f0311a" released="Wed, 22 Jul 2020 20:01:29 +0000" arch="x86_64"
Nov 04 16:54:51.921  INFO vector::sources::docker: Capturing logs from now on now=2020-11-04T16:54:51.921369200+00:00
Nov 04 16:54:51.921  INFO vector::sources::docker: Listening docker events
Nov 04 16:54:51.921  INFO vector::topology: Running healthchecks.
Nov 04 16:54:51.921  INFO vector::topology: Starting source "foo"
Nov 04 16:54:51.921  INFO vector::topology: Starting sink "my_sink_id"
Nov 04 16:54:51.921  INFO vector::topology::builder: Healthcheck: Passed.
Nov 04 16:54:51.923  INFO source{name=foo type=docker}: vector::sources::docker: Detected self container id="e2d57a2b9ca3801265a2e98484a52dd484dfa6022d8680b9c3f65aa88a25960e"
Nov 04 16:54:51.925  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:52.860  INFO vector::sources::docker: Stoped listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:52.860  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.067  INFO vector::sources::docker: Stoped listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.067  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.068 ERROR vector::sources::docker: docker API container logging error error=API responded with a 404 not found: {"message":"No such container: 96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2"}

Nov 04 16:54:53.068  INFO vector::sources::docker: Stoped listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.069  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.069 ERROR vector::sources::docker: docker API container logging error error=API responded with a 404 not found: {"message":"No such container: 96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2"}

Nov 04 16:54:53.069  INFO vector::sources::docker: Stoped listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.069  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.071 ERROR vector::sources::docker: docker API container logging error error=API responded with a 404 not found: {"message":"No such container: 96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2"}

Nov 04 16:54:53.071  INFO vector::sources::docker: Stoped listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.071  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.072 ERROR vector::sources::docker: docker API container logging error error=API responded with a 404 not found: {"message":"No such container: 96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2"}

Nov 04 16:54:53.072  INFO vector::sources::docker: Stoped listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.072  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.073 ERROR vector::sources::docker: docker API container logging error error=API responded with a 404 not found: {"message":"No such container: 96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2"}

Nov 04 16:54:53.073  INFO vector::sources::docker: Stoped listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.073  INFO vector::sources::docker: Started listening logs on docker container id=96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2
Nov 04 16:54:53.074 ERROR vector::sources::docker: docker API container logging error error=API responded with a 404 not found: {"message":"No such container: 96634cb0d7838fea87167cd7082e2397e7dfd5c13440995ddc649411a43516f2"}

This will continue indefinitely.

[ktff]

The 404s aren't surprising. It seams the source didn't register that the container was stopped so it's retrying to fetch it's logs.

[Hoverbear]

Is there a way for us to recognize we've seen a bunch of 404s and should make sure the container does in fact exist?

[ktff]

Probably, but we should have been notified that the container was stopped so this is some bug on our side in tracking the state of containers that we picked up on start.

[StephenWakely]

I can no longer reproduce this, so it looks like it has been fixed.