Upgrade to 20.10 breaks log tailing: unexpected EOF errors #41820

PandarinDev · 2020-12-18T15:20:30Z

Description

Our E2E test suite uses testcontainers-java to run our microservices and their dependencies in containers for the duration of our tests. All of the tests were passing with 19.03.14 until we updated our build nodes to Docker 20.10.1, at which point we started repeatedly getting STDOUT: $Error grabbing logs: unexpected EOF errors, and our Wait.forLogMessage calls started timing out.

Note however, that this issue seems sporadic as about 1 out of 10 builds still passes. After we reverted to Docker 19.03.14 the issue went away. We're using the latest version of Testcontainers (1.15.1 at the time of reporting the issue).

After contacting the developers I was told this is most likely a Docker issue.

Steps to reproduce the issue:
Unfortunately our projects are not OSS, so I cannot give you the exact containers used. I'll try to describe a matching scenario.

Set up a project that uses the latest version of testcontainers-java (1.15.1).
Set up a docker image that produces a lot of standard output.
Start the image using testcontainers-java and wait for a log message using Wait.forLogMessage().
A huge percentage of the times this will result in the error message STDOUT: $Error grabbing logs: unexpected EOF errors and the wait policy will not trigger even though the messages are present in the log.

Describe the results you received:
Error message: STDOUT: $Error grabbing logs: unexpected EOF errors, wait policy for log message not triggering even though the message was present in the log.

Describe the results you expected:
No EOF error, wait policy for log message working.

Additional information you deem important (e.g. issue happens only occasionally):
As mentioned in the description the issue seems sporadic, but it happens in about 80+% of our CI runs.

Output of docker version:
Previous version where the tests were passing:

Client: Docker Engine - Community
 Version:           19.03.14
 API version:       1.40
 Go version:        go1.13.15
 Git commit:        5eb3275d40
 Built:             Tue Dec  1 19:20:26 2020
 OS/Arch:           linux/amd64
 Experimental:      false

Server: Docker Engine - Community
 Engine:
  Version:          19.03.14
  API version:      1.40 (minimum version 1.12)
  Go version:       go1.13.15
  Git commit:       5eb3275d40
  Built:            Tue Dec  1 19:18:53 2020
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.3.9
  GitCommit:        ea765aba0d05254012b0b9e595e995c09186427f
 runc:
  Version:          1.0.0-rc10
  GitCommit:        dc9208a3303feef5b3839f4323d9beb36df0a9dd
 docker-init:
  Version:          0.18.0
  GitCommit:        fec3683

Current version where the issue is present:

Client:
 Version:           20.10.1
 API version:       1.41
 Go version:        go1.15.6
 Git commit:        831ebeae96
 Built:             Tue Dec 15 22:25:01 2020
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server:
 Engine:
  Version:          20.10.1
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.15.6
  Git commit:       f0014860c1
  Built:            Tue Dec 15 22:24:28 2020
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          v1.4.3
  GitCommit:        269548fa27e0089a8b8278fc4fc781d7f65a939b.m
 runc:
  Version:          1.0.0-rc92
  GitCommit:        ff819c7e9184c13b7c2607fe6c30ae19403a7aff
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

Output of docker info:

Previous version where the tests were passing:

Client:
 Debug Mode: false

Server:
 Containers: 0
  Running: 0
  Paused: 0
  Stopped: 0
 Images: 92
 Server Version: 19.03.14
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: true
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: ea765aba0d05254012b0b9e595e995c09186427f
 runc version: dc9208a3303feef5b3839f4323d9beb36df0a9dd
 init version: fec3683
 Security Options:
  apparmor
  seccomp
   Profile: default
 Kernel Version: 5.4.0-58-generic
 Operating System: Ubuntu 20.04.1 LTS
 OSType: linux
 Architecture: x86_64
 CPUs: 3
 Total Memory: 15.64GiB
 Name: build1
 ID: QWYR:EE5C:DWTE:MY65:MQ7Y:FERG:F7J2:IDTT:7LVR:VHSE:REFY:6AQH
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: No swap limit support

Current version where the issue is present:

Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Build with BuildKit (Docker Inc., v0.5.1-tp-docker)

Server:
 Containers: 134
  Running: 8
  Paused: 0
  Stopped: 126
 Images: 1390
 Server Version: 20.10.1
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 269548fa27e0089a8b8278fc4fc781d7f65a939b.m
 runc version: ff819c7e9184c13b7c2607fe6c30ae19403a7aff
 init version: de40ad0
 Security Options:
  seccomp
   Profile: default
 Kernel Version: 5.9.14-arch1-1
 Operating System: Arch Linux
 OSType: linux
 Architecture: x86_64
 CPUs: 8
 Total Memory: 31.24GiB
 Name: RE02WL03
 ID: YC3H:JCWA:APFN:VOQ7:CWPG:B4VO:5FYW:UPVL:2H5B:PO4H:SXO7:LSGH
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: No blkio weight support
WARNING: No blkio weight_device support

The current version and info parts were copied from an Arch box, while the previous version and info parts were copied from an Ubuntu box, but we could also reproduce the issue on Ubuntu after upgrading to 20.10.

Additional environment details (AWS, VirtualBox, physical, etc.):

Could reproduce using both Ubuntu 20.10 and Arch Linux.

The text was updated successfully, but these errors were encountered:

tiborvass · 2020-12-19T00:26:24Z

Related docker/for-mac#5145

sorinvisan89 · 2021-01-05T05:26:39Z

I also can confirm this is happening. Worked fine before upgrade of docker engine from 19 to 20.

I have multiple containers(about 7 running), 3 of them produce generous output.

Usually, for one or two containers the logging fails with the EOF error during integration testing.

docker info
Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Build with BuildKit (Docker Inc., v0.4.2-docker)
  scan: Docker Scan (Docker Inc., v0.5.0)

Server:
 Containers: 7
  Running: 7
  Paused: 0
  Stopped: 0
 Images: 20
 Server Version: 20.10.0
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: true
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 269548fa27e0089a8b8278fc4fc781d7f65a939b
 runc version: ff819c7e9184c13b7c2607fe6c30ae19403a7aff
 init version: de40ad0
 Security Options:
  seccomp
   Profile: default
 Kernel Version: 4.19.121-linuxkit
 Operating System: Docker Desktop
 OSType: linux
 Architecture: x86_64
 CPUs: 6
 Total Memory: 4.825GiB
 Name: docker-desktop
 ID: QDG2:L34D:MF6P:RWBK:ULT5:CTNT:GNSN:UCNB:K2EU:U4GP:ZVE6:VIA7
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 HTTP Proxy: gateway.docker.internal:3128
 HTTPS Proxy: gateway.docker.internal:3129
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

Logs in the dockerd are filled with the following:

2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.781629156Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6765
2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.781650830Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6766
2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.781666688Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6767
2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.782293790Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6768
2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.782321359Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6769
2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.782337211Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6770
2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.782352359Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6771
2021-01-04T17:58:55Z dockerd time="2021-01-04T17:58:55.782382550Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=6772

Best regards,
Sorin

lindycoder · 2021-01-06T21:41:56Z

Hello!

This issue is also affecting docker-for-mac version 3.0.3 me with a very verbose container

$ docker info
Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Build with BuildKit (Docker Inc., v0.4.2-docker)
  scan: Docker Scan (Docker Inc., v0.5.0)

Server:
 Containers: 1
  Running: 0
  Paused: 0
  Stopped: 1
 Images: 206
 Server Version: 20.10.0
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: true
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 269548fa27e0089a8b8278fc4fc781d7f65a939b
 runc version: ff819c7e9184c13b7c2607fe6c30ae19403a7aff
 init version: de40ad0
 Security Options:
  seccomp
   Profile: default
 Kernel Version: 4.19.121-linuxkit
 Operating System: Docker Desktop
 OSType: linux
 Architecture: x86_64
 CPUs: 4
 Total Memory: 1.942GiB
 Name: docker-desktop
 ID: HOTY:MO5N:FHBP:X5XL:ATD5:FECJ:TO4C:77OU:DAI2:KQJR:DATW:R4KO
 Docker Root Dir: /var/lib/docker
 Debug Mode: true
  File Descriptors: 41
  Goroutines: 46
  System Time: 2021-01-06T21:36:10.251766204Z
  EventsListeners: 3
 HTTP Proxy: gateway.docker.internal:3128
 HTTPS Proxy: gateway.docker.internal:3129
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false
 Product License: Community Engine

Seeing the same error logs as other reports in ~/Library/Containers/com.docker.docker/Data/log/vm/dockerd.log

2021-01-06T19:59:40Z dockerd time="2021-01-06T19:59:40.627461991Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=19995
2021-01-06T19:59:40Z dockerd time="2021-01-06T19:59:40.627484481Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=19996
2021-01-06T19:59:40Z dockerd time="2021-01-06T19:59:40.627534667Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=19997
2021-01-06T19:59:40Z dockerd time="2021-01-06T19:59:40.627550573Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=19998
2021-01-06T19:59:40Z dockerd time="2021-01-06T19:59:40.627568544Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=19999
2021-01-06T19:59:40Z dockerd time="2021-01-06T19:59:40.627916644Z" level=error msg="Error streaming logs: unexpected EOF" container=fb0dea1014da664d46c72b1cd3ced88fb7ecc3c7b2abf7f10fd0f43898b373bb method="(*Daemon).ContainerLogs" module=daemon
2021-01-06T19:59:40Z dockerd time="2021-01-06T19:59:40.628082325Z" level=debug msg="end logs (<nil>)" container=fb0dea1014da664d46c72b1cd3ced88fb7ecc3c7b2abf7f10fd0f43898b373bb method="(*Daemon).ContainerLogs" module=daemon

I can currently reproduce consistantly, so if there's extra information i can provide just ask me!

Thank you,
Martin

cpuguy83 · 2021-01-06T23:25:34Z

Any chance we can get a sample of the log file in question? This would be under /var/lib/docker/containers/<id>/<id>-log.json

lindycoder · 2021-01-07T15:25:55Z

Good morning @cpuguy83

I tried to isolate a sample of the file where the error happens, but it's always a different part and i got the -log.json out and loaded every lines with JSON and they're all fine. Which means the content being written to this file is probably not the cause.

My very wild guess is that there is a race condition between the writer and the reader of this file/stream, but that's just a guess.

I noticed in the dockerd.log that i periodically get a single line like

2021-01-07T13:53:40Z dockerd time="2021-01-07T13:53:40.593422800Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=0

I can't really tell if it's the same container that gives the problem, but this is there alone and not causing any problem.

This leaves me to believe that there is a resilient mechanism for handling the race condition, if that's the problem.

But sometimes it just goes in a loop and retries up to 20000 times. This whole process takes ~2 seconds during which the container still produce logs.

Here's the output of one failure from the docker logs -f:

2021-01-07 15:17:24.114 UTC [562] LOG:  duration: 0.207 ms  statement: SELECT table_a.setting AS table_a_setting, table_a.id AS table_a_id
error from daemon in stream: Error grabbing logs: unexpected EOF

And here's the corresponding lines in the -log.json

{"log":"2021-01-07 15:17:24.114 UTC [562] LOG:  duration: 0.207 ms  statement: SELECT table_a.setting AS table_a_setting, table_a.id AS table_a_id \n","stream":"stderr","time":"2021-01-07T15:17:24.1158133Z"}
{"log":"\u0009FROM table_a JOIN apps ON table_a.id = apps.id \n","stream":"stderr","time":"2021-01-07T15:17:24.1158641Z"}

At the time of this failure, the -log.json file was 35 Mb long

cpuguy83 · 2021-01-07T18:48:16Z

Indeed we do handle the case where there can be a race between reading/writing a json entry.
It seems like we have messed up the byte stream somehow.

Working on getting more debugging in here (at least adding container ID to these error logs from the daemon).

Do you have log rotation or anything else enabled?
I have not been able to reproduce this trying in a few different ways.

cpuguy83 · 2021-01-07T18:52:30Z

Also, is this while following logs or just tailing existing ones?

lindycoder · 2021-01-07T19:29:24Z

@cpuguy83 I'm currently using docker-for-mac, following logs docker logs --follow <name>, it's the default install without any special considerations, so the vm dunning docker server is pristine. The -json.log is not rotated.

It usually takes a couple minutes before triggering. This only affect a single container producing massive logging. It's actually a postgres container logging all the queries while running a big suite of tests. Couple MBs of logs every test run.

I've managed to get it to occur more if there are more containers around with several docker logs --follow. Our setup launches containers and --follow them printing in a file. The stack i use to reproduce is running a dozen containers.

So that's a dozen docker logs --follow running concurrently, but the only container triggering the error is the postgres one, which produces the most logs, by far.

SvenDowideit · 2021-01-13T02:45:36Z

I'm getting this very often - I'm running on Ubuntu - and it happens whenever I'm tailing (docker logs -f <caddy>) the logs of a very active proxy (both caddy and goproxies) that have lots of log lines

cpuguy83 · 2021-01-13T03:40:10Z

@SvenDowideit Is there any chance you could provide and image that repros it?
I have been unable to through a variety of tests.

SvenDowideit · 2021-01-13T04:25:06Z

yup

I'm using a more complicated version of:

	docker run -dit \
  		--port 8081:8081 \
  		--restart always \
		--name goproxy \
		--network cirri_proxy \
		--label "virtual.port=8081" \
		-v goproxy_cache:/go \
			goproxy/goproxy

docker logs -f goproxy

and then building something non-trivial with GOPROXY=http://localhost:8081

i don't think it happened the first time, while its filling its cache, but after that, I get it every time.

The extra complexity is that I don't have the --port part, and am instead using a caddyserver hooked up to the cirri_network that has a reverse proxy config generated from the virtual.port label - no stinking --port mapping for us :D

wendigo · 2021-01-13T09:32:53Z

We've hit the same bug in the https://github.com/trinodb/trino while running our product tests (testcontainers based). When Trino is starting, it generates a lot of logs. During the startup, 20% of runs fail with EOF.

It's pretty straightforward to reproduce it locally:

git clone https://github.com/trinodb/trino
cd trino
./mvnw clean install -DskipTests
./testing/trino-product-tests-launcher/bin/run-launcher test run --no-bind --environment  multinode-tls-kerberos -- -t io.trino.tests.cli.TestTrinoCli

pidzama · 2021-01-21T20:46:56Z

I have the same issue when starting docker compose with ~10 Wildfly services, each generating rather normal amount of logs during WAR/EAR deployment.

instantlinux · 2021-01-24T18:33:05Z

I have a local gitlab instance running. The problem happened right away when I upgraded. That's a great way to generate many megabytes per hour of logs, for anyone who needs to reproduce this.

pete-woods · 2021-01-27T11:31:36Z

We are also seeing this issue in some integration tests that run against Docker that read logs from containers using the Go Docker API.

pete-woods · 2021-01-27T11:46:32Z

Okay, I have come up with an easy way to reproduce it:

docker run -d --rm --name teh-logs ubuntu seq 10000000
docker logs -f teh-logs > logs.txt

In my case, I get the output:

% docker run -d --rm --name teh-logs ubuntu seq 10000000
14cabbd7f8515e5e0631a39c29535177bfaeba8c97e76269e5318f49c3b306e6
% docker logs -f teh-logs > logs.txt
error from daemon in stream: Error grabbing logs: unexpected EOF

pete-woods · 2021-01-27T16:48:44Z

I have found running more than one copy of this at once (with -2, -3 appended to the name of the container names) helps make it reproduce more frequently.

cpuguy83 · 2021-01-27T19:42:21Z

@pete-woods Anything special about the environment? I can't repro with this either :(

I'm assuming this is all happening in real envs and not Docker Desktop specifically?

pete-woods · 2021-01-27T19:44:15Z

I have reproduced with this technique now on Docker for Mac, and in a Vagrant Ubuntu 18.04 VM.

It definitely took more poking in the VMs than the Mac to reproduce, though. Running two copies of the Ubuntu seq container and tailing the logs from both did it fairly reliably for me.

pete-woods · 2021-01-27T19:45:32Z

The other environment we're reproducing in is a GCP VM running Ubuntu 20.04 in our integration tests. (GCP is where CircleCI runs its VMs).

instantlinux · 2021-01-27T19:51:18Z

My environment is a quad-core bare-metal Ubuntu 20.04 with 16GB RAM (half of it in avail state, and another 5GB in buff/cache state), running about 2 dozen containers. Load average usually about 0.80 - 1.50.

aeriksson · 2021-02-03T19:55:33Z

I wasn't able to reproduce using @pete-woods's approach either, but it always seems to happen in a few seconds if I run

docker run -it --name foo ubuntu sh -c "apt-get update && apt-get install -y nyancat && nyancat"

in one terminal window, and then

docker logs -f foo

in a separate terminal window.

For what it's worth, it also happens if I tail the logs over Docker's HTTP API.

Running Docker 20.10.2 on MacOS on a Macbook Pro.

tobiasstadler · 2021-03-01T17:52:24Z

@cpuguy83 did you run ˋdocker logs -fˋ? Do you use the json-file logging?

instantlinux · 2021-03-01T17:53:13Z

Can you run a heavy mixed load on the worker and repeat the nyancat test?

cclafferty · 2021-03-01T17:54:49Z

It breaks within 10 or so seconds for me as soon as you start requesting logs.

PandarinDev · 2021-03-01T17:55:38Z

+1 to @tobiasstadler 's last comment, the issue is only present if you run docker logs -f on an already running container.

cpuguy83 · 2021-03-01T17:56:38Z

@tobiasstadler Yes and yes.

Looking at your suggested change.
There is something fishy here and this is related to the commit I had in mind.

cpuguy83 · 2021-03-01T20:01:06Z

@tobiasstadler

re: #41820 (comment)

Yes, I think that's the culprit.
I haven't been able to reproduce with a real docker client, however I wrote a unit test to simulate the condition.

cpuguy83 · 2021-03-01T22:02:25Z

#42104 should take care of this, but will need to be backported after it is merged.

emulanob · 2021-03-15T16:16:05Z

I don't know if my case contributes to the resolution at all, but all clients in our Nomad cluster are flooding the syslog with these error messages, just like @sorinvisan89 and @lindycoder reported. I'm still able to retrieve logs both via docker logs and nomad logs commands, though.

The issue was noticed because our elasticsearch cluster alerted low disk space.

For reference:

$ docker version
Client: Docker Engine - Community
 Version:           20.10.3
 API version:       1.41
 Go version:        go1.13.15
 Git commit:        48d30b5
 Built:             Fri Jan 29 14:33:21 2021
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.3
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.13.15
  Git commit:       46229ca
  Built:            Fri Jan 29 14:31:32 2021
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.4.3
  GitCommit:        269548fa27e0089a8b8278fc4fc781d7f65a939b
 runc:
  Version:          1.0.0-rc92
  GitCommit:        ff819c7e9184c13b7c2607fe6c30ae19403a7aff
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

anodyne-canvas · 2021-04-01T23:09:26Z

Thanks for the fix, when will this be included in a release?

pete-woods · 2021-04-02T07:02:02Z

I can't see it in the 20.10.6 milestone, where I think a lot of us would hope to.

anodyne-canvas · 2021-04-07T14:50:26Z

It actually is in the 20.10.6 milestone:
https://github.com/moby/moby/milestone/93?closed=1
#42174

rbreejen · 2021-05-21T16:26:22Z

I am still encountering these errors, while running the latest docker version: 20.10.6. Can somebody else confirm?

How to reproduce (tested on Ubuntu 20.04.2 LTS & MacOS):
Terminal 1: docker run -it --name foo ubuntu sh -c "apt-get update && apt-get install -y nyancat && nyancat"
Terminal 2: docker logs -f foo (expect the same "You have nyaned for x seconds" screen as in terminal 1)
Terminal 3 (Ubuntu): journalctl -u docker -f
Terminal 3 (MacOS): tail -f ~/Library/Containers/com.docker.docker/Data/log/vm/dockerd.log
Terminal 3 (other OS): see https://stackoverflow.com/a/30970134/9103163 how to view the logs of the docker daemon process on your OS.

The error is showing up immediately.

aleon1220 · 2021-06-15T05:03:29Z

Docker Engine Error json-file: fix sporadic unexpected EOF errors
I had spent sometime researching and trying to find errors in the docker
logs.
There is a bug in docker engine 20.10.5 which is the version running in docker. A Github PR fixes this. #42104
I found the error while running

$ journalctl -u docker.service

level=warning msg="got error while decoding json" error="unexpected EOF" retries=19999

Docker driver for logs has a bug and it won't handle some log formatting. The bug then floods the system's log with retries messages. This situation generates a very annoying CPU load.

Docker engine latest is 20.10.7. The issue has been fixed in release Docker engine 20.10.6 https://docs.docker.com/engine/release-notes/#20106

emulanob · 2021-06-15T11:53:16Z

I checked a few of my instances at random and they are running version 20.10.6 where the bug should be fixed, but instead I still see lots of warning messages when journalctl -afu docker.service is executed:

level=warning msg="got error while decoding json" error="unexpected EOF" retries=X

Maybe there's something else causing it too?

1it · 2021-08-19T09:19:28Z

I've upgraded the docker version on a test machine and still have the same warnings:

Aug 19 09:13:44 test-docker-0 dockerd[17267]: time="2021-08-19T09:13:44.285053897Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=0

Client: Docker Engine - Community
 Version:           v20.10.8
 API version:       1.41
 Go version:        go1.16.6
 Git commit:        aa949f2ad
 Built:             Thu Aug 12 15:10:34 2021
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          v20.10.8
  API version:      1.42 (minimum version 1.12)
  Go version:       go1.16.6
  Git commit:       91dc595e96
  Built:            Thu Aug 12 15:10:34 2021
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.4.9
  GitCommit:        e25210fe30a0a703442421b0f60afac609f950a3
 runc:
  Version:          1.0.1
  GitCommit:        v1.0.1-0-g4144b63
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

dragos-dgp · 2022-04-28T12:21:29Z

Hello, we upgraded the engine to the latest and we are still flooded with that error message @cpuguy83 :

gbolo · 2022-05-02T19:54:31Z

I can also confirm this flooding. Using Server Version: 20.10.11. Also running nomad

schemmerling · 2022-05-31T18:39:55Z

ditto: I can also confirm this flooding. Using Server Version: 20.10.11. Also running nomad

oren-nonamesecurity · 2022-10-30T07:12:03Z

Same here, docker 20.10.10 still flooding

cpuguy83 added kind/bug Bugs are bugs. The cause may or may not be known at triage time so debugging may be needed. area/logging version/20.10 labels Dec 18, 2020

cpuguy83 mentioned this issue Jan 4, 2021

Fix log tail with empty logs #36305

Merged

thaJeztah added this to Needs triage in 20.10.x bugs/regressions via automation Jan 5, 2021

stephen-turner mentioned this issue Jan 5, 2021

docker logs -f -t fails with Error grabbing logs: unexpected EOF after about 30m docker/for-mac#5145

Closed

wendigo mentioned this issue Jan 12, 2021

product test test run should fail fast when one of the containers fails to start or exists trinodb/trino#6565

Open

PandarinDev mentioned this issue Jan 22, 2021

Error waiting for log message with Docker 20.10.1 testcontainers/testcontainers-java#3613

Open

cpuguy83 mentioned this issue Mar 1, 2021

Fix handling for json-file io.UnexpectedEOF #42104

Merged

thaJeztah moved this from Needs triage to High priority in 20.10.x bugs/regressions Mar 4, 2021

cpuguy83 closed this as completed in #42104 Mar 18, 2021

20.10.x bugs/regressions automation moved this from High priority to Closed Mar 18, 2021

thaJeztah mentioned this issue Mar 19, 2021

[20.10 backport] Fix handling for json-file io.UnexpectedEOF #42174

Merged

craig-willis added a commit to whole-tale/terraform_deployment that referenced this issue Mar 24, 2021

Pin docker version (moby/moby#41820)

f3a93d0

craig-willis added a commit to whole-tale/terraform_deployment that referenced this issue Mar 24, 2021

Pin docker version (moby/moby#41820)

c204c46

xanimo mentioned this issue Apr 6, 2021

$Error grabbing logs: unexpected EOF rosetta-dogecoin/rosetta-dogecoin#21

Closed

SylvainJuge mentioned this issue Apr 12, 2021

Put memory limits on test docker containers elastic/apm-agent-java#1748

Merged

This was referenced Jan 16, 2023

[20.10 backport] daemon/logger: read the length header correctly #43165

Merged

dockerd: high memory usage docker/for-linux#848

Closed

Upgrade to 20.10 breaks log tailing: unexpected EOF errors #41820

Upgrade to 20.10 breaks log tailing: unexpected EOF errors #41820

Comments

PandarinDev commented Dec 18, 2020 • edited

tiborvass commented Dec 19, 2020

sorinvisan89 commented Jan 5, 2021

lindycoder commented Jan 6, 2021 • edited

cpuguy83 commented Jan 6, 2021

lindycoder commented Jan 7, 2021 • edited

cpuguy83 commented Jan 7, 2021

cpuguy83 commented Jan 7, 2021

lindycoder commented Jan 7, 2021

SvenDowideit commented Jan 13, 2021 • edited

cpuguy83 commented Jan 13, 2021

SvenDowideit commented Jan 13, 2021

wendigo commented Jan 13, 2021 • edited

pidzama commented Jan 21, 2021

instantlinux commented Jan 24, 2021

pete-woods commented Jan 27, 2021

pete-woods commented Jan 27, 2021 • edited

pete-woods commented Jan 27, 2021

cpuguy83 commented Jan 27, 2021

pete-woods commented Jan 27, 2021 • edited

pete-woods commented Jan 27, 2021

instantlinux commented Jan 27, 2021

aeriksson commented Feb 3, 2021 • edited

tobiasstadler commented Mar 1, 2021

instantlinux commented Mar 1, 2021

cclafferty commented Mar 1, 2021

PandarinDev commented Mar 1, 2021

cpuguy83 commented Mar 1, 2021

cpuguy83 commented Mar 1, 2021

cpuguy83 commented Mar 1, 2021

emulanob commented Mar 15, 2021

anodyne-canvas commented Apr 1, 2021

pete-woods commented Apr 2, 2021

anodyne-canvas commented Apr 7, 2021

rbreejen commented May 21, 2021 • edited

aleon1220 commented Jun 15, 2021

emulanob commented Jun 15, 2021

1it commented Aug 19, 2021

dragos-dgp commented Apr 28, 2022

gbolo commented May 2, 2022

schemmerling commented May 31, 2022 • edited

oren-nonamesecurity commented Oct 30, 2022

PandarinDev commented Dec 18, 2020 •

edited

lindycoder commented Jan 6, 2021 •

edited

lindycoder commented Jan 7, 2021 •

edited

SvenDowideit commented Jan 13, 2021 •

edited

wendigo commented Jan 13, 2021 •

edited

pete-woods commented Jan 27, 2021 •

edited

pete-woods commented Jan 27, 2021 •

edited

aeriksson commented Feb 3, 2021 •

edited

rbreejen commented May 21, 2021 •

edited

schemmerling commented May 31, 2022 •

edited