Error grabbing logs: invalid character '\x00' looking for beginning of value

[sabrine2020]

• [x] This is a bug report
• [ ] This is a feature request
• [x] I searched existing issues before opening this one

Expected behavior

reading logs from docker containers

Actual behavior

Can't read logs using:

docker-compose logs -f myservice

nor with:

docker logs -f 6f454c73ff9c

I am getting this error:

error from daemon in stream: Error grabbing logs: invalid character '\x00' looking for beginning of value

Steps to reproduce the behavior

After some hours I can't read logs from my containers

Output of docker version:

Client:
 Version:      17.09.0-ce
 API version:  1.32
 Go version:   go1.8.3
 Git commit:   afdb6d4
 Built:        Tue Sep 26 22:42:18 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.09.0-ce
 API version:  1.32 (minimum version 1.12)
 Go version:   go1.8.3
 Git commit:   afdb6d4
 Built:        Tue Sep 26 22:40:56 2017
 OS/Arch:      linux/amd64
 Experimental: false

Output of docker info:

Containers: 11
 Running: 11
 Paused: 0
 Stopped: 0
Images: 8
Server Version: 17.09.0-ce
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 76
 Dirperm1 Supported: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 06b9cb35161009dcb7123345749fef02f7cea8e0
runc version: 3f2f8b84a77f73d38244dd690525642a72156c64
init version: 949e6fa
Security Options:
 apparmor
 seccomp
  Profile: default
Kernel Version: 4.4.0-97-generic
Operating System: Ubuntu 16.04.3 LTS
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 7.695GiB
Name: egmintel-desktop
ID: VB22:IXWI:GY6D:QPM4:SPHX:HYUP:OQN7:ZM55:LLKE:P3UU:XK7F:26TH
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

WARNING: No swap limit support

My docker-compose version: docker-compose version 1.16.1, build 6d1ac21

[thaJeztah]

Are you getting the same error for any container, or just a specific one? What's running in the container, and how is it started (what options are set for the container?)

[mrvautin]

Also receiving this issue from time to time on OSX. Can only fix by rebuilding.

[ghost]

I'd just like to let you know that this does seem to be a real issue and It has affected us as well, we solved it by manually removing the null "\x00" characters from the offending logs found with the grep below.

grep -P '\x00' /var/lib/docker/containers/**/*json.log

I'll link the two issues that we were having before we found that real cause is this. gliderlabs/logspout#246 moby/moby#29511

[mevatron]

@thaJeztah I can confirm @WBad suggested fix does get my logs back after manually plucking out the corrupted line in the log file.

I'm running the following docker version:

Client:
 Version:      17.05.0-ce
 API version:  1.29
 Go version:   go1.7.5
 Git commit:   89658be
 Built:        Thu May  4 22:10:54 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.05.0-ce
 API version:  1.29 (minimum version 1.12)
 Go version:   go1.7.5
 Git commit:   89658be
 Built:        Thu May  4 22:10:54 2017
 OS/Arch:      linux/amd64
 Experimental: false

[codejanovic]

Glad i found this one. I have got the same problem on Docker for Windows with Hyper-V. Looks like docker is kind of dying after this issue in my case, because i am unable to access my containerized web applications after hitting it.

[TelpeNight]

Facing the same issue on Ubuntu after hard reboot of the server.

lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 14.04.5 LTS
Release:        14.04
Codename:       trusty

uname -r
4.4.0-109-generic

docker version
Client:
 Version:      17.05.0-ce
 API version:  1.29
 Go version:   go1.7.5
 Git commit:   89658be
 Built:        Thu May  4 22:06:06 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.05.0-ce
 API version:  1.29 (minimum version 1.12)
 Go version:   go1.7.5
 Git commit:   89658be
 Built:        Thu May  4 22:06:06 2017
 OS/Arch:      linux/amd64
 Experimental: false

[rhuddleston]

After hard reboot having the same issue with 17.09 but this time getting:

Jan 25 22:27:58 dockerd[1218]: time="2018-01-25T22:27:58.979480120Z" level=error msg="Error streaming logs: invalid character 'l' after object key:value pair" container=3b65284c435e method="(Daemon).ContainerLogs" module=daemon Jan 25 22:27:59 dockerd[1218]: time="2018-01-25T22:27:59.712920995Z" level=error msg="Error streaming logs: invalid character 'l' after object key:value pair" container=3b65284c435e method="(Daemon).ContainerLogs" module=daemon Jan 25 22:28:00 dockerd[1218]: time="2018-01-25T22:28:00.439213542Z" level=error msg="Error streaming logs: invalid character 'l' after object key:value pair" container=3b65284c435e method="(*Daemon).ContainerLogs" module=daemon

[thaJeztah]

If someone is able to share a sample log-file with the \x00 (of course, "sanitised" if it contains sensible information); that could be useful to reproduce and fix the issue.

[ppiccolo]

@thaJeztah 7148d42670fea7606e53befaef93f7782c86b5080cac1f096610be4b0b53907f-json.log.1.zip

[henkeberggren]

While having the same issue. I use a workaround with--tail=10 flag (or whatever number you like) to only get the lines after the "invalid" character.

[YakDriver]

@thaJeztah I debugged this issue in a different project. For me, the cause was an initialized buffer having a starting size. When you Write() to the buffer, it appends everything to the \x00 characters at the beginning -- not what I expected. Lots of things don't like \x00, like encoding/json.Unmarshal() which gives: error invalid character '\x00' looking for beginning of value.

Change the 50 to 0 and the problem goes away.

output := bytes.NewBuffer(make([]byte, 50, 1024))
output.Write([]byte("{ \"Number\": 1 }"))
resp := &jFormat{}
err := json.Unmarshal(output.Bytes(), resp)

Go playground

[jbehrends]

Docker version 18.09.2, build 6247962 CentOS 7.6.1810

This is happening in my environment as well. I only found it because my Logstash instances are throwing tons of errors when trying to json parse these logs.

I can easily tell this is happening by looking at the log file encoding. Problematic logs are showing up as having a binary encoding:

$ file -i *.log*
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log:             application/octet-stream; charset=binary
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.1:           text/plain; charset=utf-8
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.2:           application/octet-stream; charset=binary
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.3:           application/octet-stream; charset=binary
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.4:           text/plain; charset=utf-8
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.5:           application/octet-stream; charset=binary
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.6:           application/octet-stream; charset=binary
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.7:           application/octet-stream; charset=binary
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.8:           text/plain; charset=utf-8
9ea960b82438faac9e0339425a37a5655735465cac5a00e7de074d6ce6f275f7-json.log.9:           application/octet-stream; charset=binary

journalctl also shows a bunch of errors while viewing logs through the "docker logs" command:

Mar 13 14:36:03 myhostname.domain dockerd[4191]: time="2019-03-13T14:36:02.841619856-07:00" level=warning msg="got error while decoding json" error="invalid character '\\x00' looking for beginning of value" retries=2497
Mar 13 14:36:03 myhostname.domain dockerd[4191]: time="2019-03-13T14:36:02.841631120-07:00" level=warning msg="got error while decoding json" error="invalid character '\\x00' looking for beginning of value" retries=2498
Mar 13 14:36:03 myhostname.domain dockerd[4191]: time="2019-03-13T14:36:02.841642228-07:00" level=warning msg="got error while decoding json" error="invalid character '\\x00' looking for beginning of value" retries=2499
Mar 13 14:36:03 myhostname.domain dockerd[4191]: time="2019-03-13T14:36:02.841653011-07:00" level=warning msg="got error while decoding json" error="invalid character '\\x00' looking for beginning of value" retries=2500

[jbehrends]

To follow up on my previous comment. I did some testing, and this only happens when I have docker perform it's own log rotation. If I add the following flags to my docker daemon this issue happens fairly consistently on newly created logs after rotation:

--log-opt max-size=10m --log-opt max-file=10

When I remove those flags and use logrotate.d for log rotation I no longer have this issue. So I'm convinced this has something to do with docker rotating it's own logs.

[wk8]

Tried reproducing with Docker version 18.09.2, build 6247962 on CentOS 7.6.1810 with:

• d run --log-opt max-size=1m --log-opt max-file=100 ubuntu bash -c 'cat /dev/urandom'
• the same, with docker compose
• a container running a small C program outputting null bytes and UTF8 strings randomly

Wasn't able to get a repro.

@jbehrends : would you be able to share the compose file with which you obtained this? Thanks!

[jbehrends]

I'm not using compose, these are settings I'm using globally for the docker daemon's config located in "/etc/sysconfig/docker" on all of my systems that run docker. So any container that gets launched will get these logging options. I've had this happen on Kubernetes hosts, and on hosts where I'm manually running containers via "docker run ...."

[0x53A]

I don't know if it's the same issue, but the invalid character '\x00' looking for beginning of value. part is similar.

---

When I run

docker run -it --isolation=process mcr.microsoft.com/windows/nanoserver:1809 cmd

on an unpatched windows 10 1809, I get a bluescreen TERMINAL SERVER DRIVER MADE INCORRECT MEMORY REFERENCE. (This seems to be a known, already patched issue: https://techcommunity.microsoft.com/t5/Windows-Server-Insiders/Problem-running-microsoft-nanoserver-insider-10-0-17074-1000/td-p/146104)

Afterwards, docker is kaputt:

docker run -it --isolation=process mcr.microsoft.com/windows/nanoserver:1809 cmd
docker: Error response from daemon: Failed to unmarshall layerchain json - invalid character '\x00' looking for beginning of value.
See 'docker run --help'.

I only got it back working by completely uninstalling and reinstalling it.

[degerrit]

We are hitting this too, on pretty much ALL our hosts in a Kubernetes environment, but also on hosts not running Kubernetes.

• Docker version 18.09.6 (client) 18.09.2 (engine) on Ubuntu 16.04.6 LTS kernel 4.15.0-1041-azure
• Same config on all hosts /etc/docker/daemon.json:

  
  {
  "live-restore": true,
  "log-driver": "json-file",
  "log-opts":  {
   "max-size": "50m",
   "max-file": "5"
  }
  }

Here's where the \x00 bits are, always at the beginning of the file:

cat /var/lib/docker/containers/4f2ec4b99328f8da0f153760886f3e88696f529984f2e89ed1ad296c55cce752/4f2ec4b99328f8da0f153760886f3e88696f529984f2e89ed1ad296c55cce752-json.log |\ hexdump -C |\ grep "00 00" -B3 -A5 00000000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| * 017be550 00 00 00 00 00 00 00 00 00 00 00 00 7b 22 6c 6f |............{"lo| 017be560 67 22 3a 22 49 30 37 32 32 20 30 36 3a 32 35 3a |g":"I0722 06:25:| 017be570 30 39 2e 35 39 34 39 31 39 20 20 20 20 20 20 20 |09.594919 | 017be580 31 20 74 72 61 63 65 2e 67 6f 3a 37 36 5d 20 54 |1 trace.go:76] T| 017be590 72 61 63 65 5b 31 34 35 33 37 36 31 38 36 32 5d |race[1453761862]| 017be5a0 3a 20 5c 22 47 75 61 72 61 6e 74 65 65 64 55 70 |: \"GuaranteedUp|

00000000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| * 0153ae10 00 7b 22 6c 6f 67 22 3a 22 32 30 31 39 2d 30 37 |.{"log":"2019-07| 0153ae20 2d 31 39 20 30 36 3a 32 35 3a 30 35 2e 34 30 32 |-19 06:25:05.402| 0153ae30 20 5b 49 4e 46 4f 5d 5b 32 30 30 37 33 5d 20 69 | [INFO][20073] i| 0153ae40 6e 74 5f 64 61 74 61 70 6c 61 6e 65 2e 67 6f 20 |nt_dataplane.go |

00000000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| * 01197b90 00 00 00 00 7b 22 6c 6f 67 22 3a 22 32 30 31 39 |....{"log":"2019| 01197ba0 2d 30 37 2d 31 37 20 30 36 3a 32 35 3a 30 37 2e |-07-17 06:25:07.| 01197bb0 36 37 35 20 5b 49 4e 46 4f 5d 5b 32 30 30 37 33 |675 [INFO][20073| 01197bc0 5d 20 68 65 61 6c 74 68 2e 67 6f 20 31 35 30 3a |] health.go 150:| 01197bd0 20 4f 76 65 72 61 6c 6c 20 68 65 61 6c 74 68 20 | Overall health |

The fact that we are seeing this only at the beginning of a json log file makes me suspect @jbehrends 's guess about docker log rotation is the root cause.

Related to that we are having issues shipping the docker logs through Elasticsearch, but those problems may not be 100% correlated, since I have found hosts /with/ the docker log \x00 issue which /don't/ show our most common the ELK filebeat issue:
> write error: data size (79748532 bytes) is greater than the max file size (10485760 bytes)

(although filebeat would obviously *also* be trying to ship the \x00-affected files, and presumably fail to parse the json also).

[alejandromicheloud]

---

Error grabbing logs, my personal FIX

---

1. docker-compose ps
2. docker inspect CONTAINER_NAME | grep log
3. cd LOG_FOLDER
4. file -i .log The files type: "application/octet-stream; charset=binary" have errors, can be RENAMED/REMOVED/UPDATED for fix.

[chinglinwen]

This issue happened to me too, what's the fix ( without losing logs )

          |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f 10 11 12 13 14 15 16 17 |                                    
 0bbe3258 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe3270 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe3288 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe32a0 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe32b8 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe32d0 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe32e8 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe3300 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe3318 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe3330 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe3348 | 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 | ........................ |         
 0bbe3360 | 00 00 00 00 00 00 00 00 00 00 00 00 00 7b 22 6c 6f 67 22 3a 22 32 30 32 | .............{"log":"202 |         
 0bbe3378 | 30 2d 30 35 2d 30 34 20 31 39 3a 35 36 3a 30 35 2e 39 33 32 20 32 34 32 | 0-05-04 19:56:05.932 242 |         
 0bbe3390 | 34 20 44 45 42 55 47 20 6f 73 6c 6f 5f 73 65 72 76 69 63 65 2e 70 65 72 | 4 DEBUG oslo_service.per |         
 0bbe33a8 | 69 6f 64 69 63 5f 74 61 73 6b 20 5b 72 65 71 2d 62 36 62 66 38 33 37 33 | iodic_task [req-b6bf8373 |         
 0bbe33c0 | 2d 31 61 33 30 2d 34 39 37 63 2d 62 32 37 61 2d 35 30 31 62 37 30 66 39 | -1a30-497c-b27a-501b70f9 |         
 0bbe33d8 | 32 61 34 66 20 2d 20 2d 20 2d 20 2d 20 2d 5d 20 52 75 6e 6e 69 6e 67 20 | 2a4f - - - - -] Running  |         
 0bbe33f0 | 70 65 72 69 6f 64 69 63 20 74 61 73 6b 20 43 6f 6d 70 75 74 65 4d 61 6e | periodic task ComputeMan |         
 0bbe3408 | 61 67 65 72 2e 5f 69 6e 73 74 61 6e 63 65 5f 75 73 61 67 65 5f 61 75 64 | ager._instance_usage_aud |         
 0bbe3420 | 69 74 20 72 75 6e 5f 70 65 72 69 6f 64 69 63 5f 74 61 73 6b 73 20 2f 75 | it run_periodic_tasks /u |         
 0bbe3438 | 73 72 2f 6c 69 62 2f 70 79 74 68 6f 6e 32 2e 37 2f 73 69 74 65 2d 70 61 | sr/lib/python2.7/site-pa |         
 0bbe3450 | 63 6b 61 67 65 73 2f 6f 73 6c 6f 5f 73 65 72 76 69 63 65 2f 70 65 72 69 | ckages/oslo_service/peri |         
 0bbe3468 | 6f 64 69 63 5f 74 61 73 6b 2e 70 79 3a 32 31 37 5c 75 30 30 31 62 5b 30 | odic_task.py:217\u001b[0 # 

k8s version: 1.17.2

docker version

Server: Docker Engine - Community
 Engine:
  Version:          19.03.5
  API version:      1.40 (minimum version 1.12)
  Go version:       go1.12.12
  Git commit:       633a0ea
  Built:            Wed Nov 13 07:24:18 2019
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.2.10
  GitCommit:        b34a5c8af56e510852c35414db4c1f4fa6172339
 runc:
  Version:          1.0.0-rc8+dev
  GitCommit:        3e425f80a8c931f88e6d94a8c831b9d5aa481657
 docker-init:
  Version:          0.18.0
  GitCommit:        fec3683

[chinglinwen]

According to this line: https://sourcegraph.com/github.com/docker/docker-ce@05bbb382e1bf56c66a0711b8d14f8360e3e39acb/-/blob/components/engine/daemon/logger/jsonfilelog/jsonfilelog.go#L103:2

the buffer is empty initialized, no default \x00 prefix I think. @YakDriver

buf := bytes.NewBuffer(nil)

Relate code here, https://sourcegraph.com/github.com/docker/docker-ce@05bbb382e1bf56c66a0711b8d14f8360e3e39acb/-/blob/components/engine/daemon/logger/jsonfilelog/jsonlog/jsonlogbytes.go#L85

does any one know, the real cause, maybe some bug there?

func ffjsonWriteJSONBytesAsString(buf *bytes.Buffer, s []byte) {
    const hex = "0123456789abcdef"

    buf.WriteByte('"')
    start := 0
    for i := 0; i < len(s); {
        if b := s[i]; b < utf8.RuneSelf {
            if 0x20 <= b && b != '\\' && b != '"' && b != '<' && b != '>' && b != '&' {
                i++
                continue
            }
            if start < i {
                buf.Write(s[start:i])
            }
            switch b {
            case '\\', '"':
                buf.WriteByte('\\')
                buf.WriteByte(b)
            case '\n':
                buf.WriteByte('\\')
                buf.WriteByte('n')
            case '\r':
                buf.WriteByte('\\')
                buf.WriteByte('r')
            default:

                buf.WriteString(`\u00`)
                buf.WriteByte(hex[b>>4])
                buf.WriteByte(hex[b&0xF])
            }
            i++
            start = i
            continue
        }
        c, size := utf8.DecodeRune(s[i:])
        if c == utf8.RuneError && size == 1 {
            if start < i {
                buf.Write(s[start:i])
            }
            buf.WriteString(`\ufffd`)
            i += size
            start = i
            continue
        }

        if c == '\u2028' || c == '\u2029' {
            if start < i {
                buf.Write(s[start:i])
            }
            buf.WriteString(`\u202`)
            buf.WriteByte(hex[c&0xF])
            i += size
            start = i
            continue
        }
        i += size
    }
    if start < len(s) {
        buf.Write(s[start:])
    }
    buf.WriteByte('"')
}

[chinglinwen]

To fix the corrupt logs (adapt to your docker data-root)

grep -P '\x00' /da1/docker/containers/**/*.log* | awk '{ print $3 }' 
grep -P '\x00' /da1/docker/containers/**/*.log* | awk '{ print $3 }' | xargs sed -i 's/\x0//g'

edited: the above fix if the log file does not have number suffix, it may cause docker logs to stop receive new logs

At first I think, it may relate to that I changed docker data-root ( without move docker directory to new path, date: 2020-5-4 )

But recent logs (it's the in use logs, not rotated log) show, it still happens at about 2020-5-8, both of corrupt log at 14:09, though don't know why.

[root@nt9 ~]# grep -P '\x00' /da1/docker/containers/**/*.log* | awk '{ print $3 }' 
/da1/docker/containers/8b988e1d18e571ff6eb376930ad86ff466769149d4afbd9d690d6515297b1817/8b988e1d18e571ff6eb376930ad86ff466769149d4afbd9d690d6515297b1817-json.log
/da1/docker/containers/9df878d3e54f23432fd51c4e34ad6c0bd7b36dc0ee3a38a4f4a79af667254097/9df878d3e54f23432fd51c4e34ad6c0bd7b36dc0ee3a38a4f4a79af667254097-json.log

[root@nt9 ~]# cat /da1/docker/containers/8b988e1d18e571ff6eb376930ad86ff466769149d4afbd9d690d6515297b1817/8b988e1d18e571ff6eb376930ad86ff466769149d4afbd9d690d6515297b1817-json.log |\
>  hexdump -C |\
>  grep "00 00" -B3 -A5
00000000  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
*
020ab240  00 00 00 00 00 00 00 00  00 00 7b 22 6c 6f 67 22  |..........{"log"|
020ab250  3a 22 32 30 32 30 2d 30  35 2d 30 38 20 31 34 3a  |:"2020-05-08 14:|
020ab260  30 39 3a 31 37 2e 34 37  31 20 34 33 31 30 38 20  |09:17.471 43108 |
020ab270  44 45 42 55 47 20 6f 73  6c 6f 5f 73 65 72 76 69  |DEBUG oslo_servi|
020ab280  63 65 2e 70 65 72 69 6f  64 69 63 5f 74 61 73 6b  |ce.periodic_task|
020ab290  20 5b 72 65 71 2d 36 38  61 61 35 39 39 61 2d 62  | [req-68aa599a-b|
[root@nt9 ~]# uptime 
 14:18:23 up 13 days, 20:10,  8 users,  load average: 2.44, 1.96, 1.87
[root@nt9 ~]# cat /da1/docker/containers/9df878d3e54f23432fd51c4e34ad6c0bd7b36dc0ee3a38a4f4a79af667254097/9df878d3e54f23432fd51c4e34ad6c0bd7b36dc0ee3a38a4f4a79af667254097-json.log | hexdump -C | grep "00 00" -B3 -A5
00000000  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
*
031d4aa0  00 00 00 00 00 00 00 00  7b 22 6c 6f 67 22 3a 22  |........{"log":"|
031d4ab0  32 30 32 30 2d 30 35 2d  30 38 20 30 36 3a 30 39  |2020-05-08 06:09|
031d4ac0  3a 31 33 2e 37 36 38 2b  30 30 30 30 3a 20 33 35  |:13.768+0000: 35|
031d4ad0  34 3a 20 69 6e 66 6f 20  3a 20 76 69 72 45 76 65  |4: info : virEve|
031d4ae0  6e 74 50 6f 6c 6c 44 69  73 70 61 74 63 68 54 69  |ntPollDispatchTi|
031d4af0  6d 65 6f 75 74 73 3a 34  35 35 20 3a 20 45 56 45  |meouts:455 : EVE|
[root@nt9 ~]#

[Jonatha1983]

Hi all Any news about this issue ?

[chinglinwen]

this issue is a big problem for us even at now time, for docker 19.03.5.

imagine, if you can't enable docker container logs(rotate, setting log-opts) , how to deal with the log growing issue?

[Jonatha1983]

We had the same issue and I added the following layer in the base image we are using:

ENV LANG C.UTF-8

And since then we do not see the invalid charts: 'X00'

[zamog]

After a closer look it seems like a race condition - it will only happens when the container is very chatty ( ~ under 100ms between logs) and some external process (like log rotate) truncate the log file. Steps to reproduce the behavior with k8s and docker run the following pod

apiVersion: v1
kind: Pod
metadata:
  name: counter
spec:
  containers:
  - name: count
    image: busybox
    args: [/bin/sh, -c,
            'i=0; while true; do echo "$(date) INFO $i: Testing logging problems!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!"; i=$((i+1)); sleep 0.01; done']

Use docker inspect to find the log file and run the truncate command:

cp e504410aaf83394f3359d7ebec2461ff1674e0296bf4087685f64ab6abfa9750-json.log 1.log && truncate -s0 e504410aaf83394f3359d7ebec2461ff1674e0296bf4087685f64ab6abfa9750-json.log

Can also watch the offset with lsof:

$lsof +d /var/lib/docker/containers/e504410aaf83394f3359d7ebec2461ff1674e0296bf4087685f64ab6abfa9750                                                                                                                                             

COMMAND    PID USER   FD   TYPE DEVICE SIZE/OFF      NODE NAME
dockerd   4137 root  127w   REG  253,1  2473782 142528918 /var/lib/docker/containers/e504410aaf83394f3359d7ebec2461ff1674e0296bf4087685f64ab6abfa9750/e504410aaf83394f3359d7ebec2461ff1674e0296bf4087685f64ab6abfa9750-json.log

Workaround
Find and disable all process that truncate the log file (usually logrotate) / use only docker builtin logrotate More info https://superuser.com/questions/881777/what-happens-when-i-truncate-a-file-that-is-in-use https://stackoverflow.com/questions/43345474/behavior-when-opening-file-in-truncate-mode

[chris-coelho]

I faced a similar issue when starting of docker daemon on win10 and I fixed it with: https://success.docker.com/article/warning-error-loading-configjson

[djgalloway]

I solved this by deleting the scheduler-state.json file. It lived on a Ceph cluster that my docker registry suddenly lost access to and must have corrupted the file.

[rajtpd]

We are also seeing this issue when logs rotate and container is very busy logging. Anyone looking at how to fix this?

[ivenxu]

any update on this?

[BrodyStone21]

Currently getting some weird system freezes on Ubuntu Server 20.04.3 LTS and came across this in the logs. Any ideas?

Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.891908772Z" level=warning msg="got error while decoding json" error="invalid character '\\x00' looking for beginning of value" retries=0
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.891988392Z" level=warning msg="got error while decoding json" error="invalid character '\\x00' looking for beginning of value" retries=1
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892019270Z" level=warning msg="got error while decoding json" error="invalid character '\\x00' looking for beginning of value" retries=2
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892042974Z" level=warning msg="got error while decoding json" error="invalid character ':' looking for beginning of value" retries=3
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892069093Z" level=warning msg="got error while decoding json" error="invalid character '.' looking for beginning of value" retries=4
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892091585Z" level=warning msg="got error while decoding json" error="invalid character 'v' looking for beginning of value" retries=5
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892111573Z" level=warning msg="got error while decoding json" error="invalid character 'p' looking for beginning of value" retries=6
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892132782Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=7
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892155275Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=8
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892175583Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=9
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892193897Z" level=warning msg="got error while decoding json" error="invalid character '}' looking for beginning of value" retries=10
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892213444Z" level=warning msg="got error while decoding json" error="invalid character 'e' looking for beginning of value" retries=11
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892232149Z" level=warning msg="got error while decoding json" error="invalid character 's' looking for beginning of value" retries=12
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892250754Z" level=warning msg="got error while decoding json" error="invalid character 'c' looking for beginning of value" retries=13
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892270340Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=14
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892289807Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=15
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892307810Z" level=warning msg="got error while decoding json" error="invalid character 'o' looking for beginning of value" retries=16
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892326475Z" level=warning msg="got error while decoding json" error="invalid character 'g' looking for beginning of value" retries=17
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892349148Z" level=warning msg="got error while decoding json" error="invalid character ':' looking for beginning of value" retries=18
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892367753Z" level=warning msg="got error while decoding json" error="invalid character 'i' looking for beginning of value" retries=19
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892388993Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=20
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892407327Z" level=warning msg="got error while decoding json" error="invalid character ':' looking for beginning of value" retries=21
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892429939Z" level=warning msg="got error while decoding json" error="invalid character '\\\\' looking for beginning of value" retries=22
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892457411Z" level=warning msg="got error while decoding json" error="invalid character 'e' looking for beginning of value" retries=23
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892485243Z" level=warning msg="got error while decoding json" error="invalid character 'e' looking for beginning of value" retries=24
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892516832Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=25
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892544675Z" level=warning msg="got error while decoding json" error="invalid character 'Z' looking for beginning of value" retries=26
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892578558Z" level=warning msg="got error while decoding json" error="invalid character 'e' looking for beginning of value" retries=27
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892609927Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=28
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892639623Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=29
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892657987Z" level=warning msg="got error while decoding json" error="invalid character 'T' looking for beginning of value" retries=30
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892678555Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=31
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892698453Z" level=warning msg="got error while decoding json" error="invalid character 'Z' looking for beginning of value" retries=32
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892718180Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=33
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892737346Z" level=warning msg="got error while decoding json" error="invalid character '\\\\' looking for beginning of value" retries=34
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892756582Z" level=warning msg="got error while decoding json" error="invalid character 'a' looking for beginning of value" retries=35
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892776459Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=36
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892796146Z" level=warning msg="got error while decoding json" error="invalid character 'c' looking for beginning of value" retries=37
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892815652Z" level=warning msg="got error while decoding json" error="json: cannot unmarshal number into Go value of type jsonlog.JSONLog" retries=38
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892834167Z" level=warning msg="got error while decoding json" error="invalid character ':' looking for beginning of value" retries=39
Dec 12 14:11:26 ubuntu dockerd[1178]: time="2021-12-12T14:11:26.892853944Z" level=warning msg="got error while decoding json" error="invalid character ' ' in literal null (expecting 'u')" retries=40

[xitox97]

I also having this issue. Any solutions for this?

[fourseven]

For what it's worth we had this with under our logging config in our docker-compose.yml used for elastic beanstalk docker with AL2:

      options:
        max-size: "100m"
        max-file: "5"

Which clashed with the default setup of beanstalk which also had logrotate config specified for the container logs - so we removed the above and so far the errors haven't shown up again. If that fails we'll go back to the docker rotate and work out how to disable the beanstalk config (found under /etc/logrotate.elasticbeanstalk.hourly/*)

[PeeBeerBeach]

Just experienced the same error in Jellyfin Docker today. I deleted all logs and the error was gone.

[pimsdsigd]

Hello, same with nginx today and docker 23.0.0

172.20.0.6 - - [07/Feb/2023:19:08:42 +0000] "GET /stub_status HTTP/1.1" 200 106 "-" "NGINX-Prometheus-Exporter/v0.11.0" "xFor=-" "host=nginx" "hHost=nginx:8080" http"pHost=- upAddr=- xForHost=-"
error from daemon in stream: Error grabbing logs: invalid character '\x00' looking for beginning of value

[thaJeztah]

The error message itself may be an indication that a file in the log driver's storage for that container got corrupted. This can happen either if an unclean shutdown happened, or (e.g.) in situations where the host ran out of space.

Also make sure you don't have other software that interacts with these files (e.g. truncating, rotating, like https://github.com/docker/for-linux/issues/140#issuecomment-1319495126); all files under /var/lib/docker are designed to be exclusively accessed by the daemon. Interacting with those files (more so while the daemon is running), can result in failures happening or corruption of those files.

Also see the warning about this in the documentation; https://docs.docker.com/config/containers/logging/json-file/

Warning

The json-file logging driver uses file-based storage. These files are designed to be exclusively accessed by the Docker daemon. Interacting with these files with external tools may interfere with Docker’s logging system and result in unexpected behavior, and should be avoided.

[Gurubux]

I had the same issue. I was logged in via SSH. Other user logged in from other system, he could view the logs, without this error. I signed out-signed in and logs was visible again.

[bobpaul]

The error message itself may be an indication that a file in the log driver's storage for that container got corrupted. This can happen either if an unclean shutdown happened, or (e.g.) in situations where the host ran out of space.

Some of the comments above show how to remove the offending characters with awk, etc. But another solution, if you don't care about the log history on the machine (which I don't due to remote syslog) is to just truncate the logs.

for cont in $(docker container ps | cut -f1 -d\ | grep -v CONTAINER); do 
  sudo truncate -s0 $(docker container inspect  --format='{{.LogPath}}' $cont); 
done

Is there a more correct way to one-time clear the log files without touching the files directly?

[01005591-tp]

I'd just like to let you know that this does seem to be a real issue and It has affected us as well, we solved it by manually removing the null "\x00" characters from the offending logs found with the grep below.

grep -P '\x00' /var/lib/docker/containers/**/*json.log

Using this regex I found nothing, but when added -a flag (--text) to grep, I found a some lines looking like this ^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@.

So the grep I used is actually

grep -Pa '\x00' /var/lib/docker/containers/**/*json.log

Removing those lines manually resolved the issue for me.

I've recently had a disk failure and these lines seem to have been added at the time of that failure.

[benjivm]

The error message itself may be an indication that a file in the log driver's storage for that container got corrupted. This can happen either if an unclean shutdown happened, or (e.g.) in situations where the host ran out of space.

Some of the comments above show how to remove the offending characters with awk, etc. But another solution, if you don't care about the log history on the machine (which I don't due to remote syslog) is to just truncate the logs.

for cont in $(docker container ps | cut -f1 -d\ | grep -v CONTAINER); do 
  sudo truncate -s0 $(docker container inspect  --format='{{.LogPath}}' $cont); 
done

Is there a more correct way to one-time clear the log files without touching the files directly?

How/where do I run this on Docker Desktop for Windows? There is no /var/lib/docker in WSL2.

Edit: Sorry, just realized I am in the for Linux only repo, but this is the only thread I found on this issue that matches my problem with a specific mysql container.

[Sleuthing]

The error message itself may be an indication that a file in the log driver's storage for that container got corrupted. This can happen either if an unclean shutdown happened, or (e.g.) in situations where the host ran out of space.

Some of the comments above show how to remove the offending characters with awk, etc. But another solution, if you don't care about the log history on the machine (which I don't due to remote syslog) is to just truncate the logs.

for cont in $(docker container ps | cut -f1 -d\ | grep -v CONTAINER); do 
  sudo truncate -s0 $(docker container inspect  --format='{{.LogPath}}' $cont); 
done

Is there a more correct way to one-time clear the log files without touching the files directly?

How/where do I run this on Docker Desktop for Windows? There is no /var/lib/docker in WSL2.

Edit: Sorry, just realized I am in the for Linux only repo, but this is the only thread I found on this issue that matches my problem with a specific mysql container.

Like someone previously said, on windows I found my containers through this path \\wsl.localhost\docker-desktop-data\data\docker\containers

I also did it manually using notepad++, first replaced the nulls then had to also remove the residue, because there was an unclosed left curly brackets of the shape: {"log": <broken_string>NULLx20 {"log": normal string}
So be careful when replacing the nulls, because they might your only indicators to where the problematic line is.

After removing that broken in half log message, the logging resumed normally.

[vladttt1123]

what helped me is removing the volume, docker volume ls Identify from which volume the issues may be coming from and run docker volume rm {{volume_name}}

Ensure you don't have any needed data in that volume. If you get an error that the volume is used by other container, feel free to stop and remove container too

hope this helps

[sirno-baka]

This command helped me delete \x00 in files while creating backup copies

find /var/lib/docker/containers/ -type f -name "*.log*" -exec cp {} {}.bak \; -exec perl -pi -e 's/\x00//g' {} \; But it may be that it will miss some files, I found them using grep -r -n -a -P '\x00' /var/lib/docker/containers/

and then manually delete \x00 perl -pi -e 's/\x00//g' <filename>

via ChatGPT

[aprilmintacpineda]

For me, when I do docker inspect container-name --format='{{.LogPath}}', it will output something like /var/lib/docker/containers/f1806a7873b733af99115a242050dc95ae78b7facc0b79cbf7c2834d0c69915b/f1806a7873b733af99115a242050dc95ae78b7facc0b79cbf7c2834d0c69915b-json.log but when I try to find it in the container or the host, I can't even find the file.

[danwdart]

If you're not using Linux as a host, the file will be in a Linux VM of some kind - accessible through the desktop app.

[Marv963]

This command helped me delete \x00 in files while creating backup copies

find /var/lib/docker/containers/ -type f -name "*.log*" -exec cp {} {}.bak \; -exec perl -pi -e 's/\x00//g' {} \; But it may be that it will miss some files, I found them using grep -r -n -a -P '\x00' /var/lib/docker/containers/

and then manually delete \x00 perl -pi -e 's/\x00//g' <filename>

via ChatGPT

I've adjusted the command a bit to make it a single line operation:

grep -r -l -a -P '\x00' /var/lib/docker/containers/ | xargs -I {} perl -pi -e 's/\x00//g' {}

[defconxt]

This command helped me delete \x00 in files while creating backup copies find /var/lib/docker/containers/ -type f -name "*.log*" -exec cp {} {}.bak \; -exec perl -pi -e 's/\x00//g' {} \; But it may be that it will miss some files, I found them using grep -r -n -a -P '\x00' /var/lib/docker/containers/ and then manually delete \x00 perl -pi -e 's/\x00//g' <filename> via ChatGPT

I've adjusted the command a bit to make it a single line operation:

grep -r -l -a -P '\x00' /var/lib/docker/containers/ | xargs -I {} perl -pi -e 's/\x00//g' {}

thank you! I'm using dozzle to monitor docker logs and saw this being spammed...seemed to have solved the issue. Although I'm getting "Error grabbing logs: invalid character 'l' after object key:value pair"

This happened after I stupidly seized up my server by maxing out the hard drive space, had to run a fstrim -a, and learned about that fun task that needs to be regularly ran.

[HugoP27]

Any progress on fixing this issue, getting the same thing:

[XaratosS]

Hello guys,

this is affecting also following version of Docker:

Client: Docker Engine - Community
 Version:           25.0.3
 API version:       1.44
 Go version:        go1.21.6
 Git commit:        4debf41
 Built:             Tue Feb  6 21:14:25 2024
 OS/Arch:           linux/amd64
 Context:           default

Server: Docker Engine - Community
 Engine:
  Version:          25.0.3
  API version:      1.44 (minimum version 1.24)
  Go version:       go1.21.6
  Git commit:       f417435
  Built:            Tue Feb  6 21:14:25 2024
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.6.28
  GitCommit:        ae07eda36dd25f8a1b98dfbf587313b99c0190bb
 runc:
  Version:          1.1.12
  GitCommit:        v1.1.12-0-g51d5e94
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

Is there already a fix or did you guys find the culrprit already?

[hohwille]

FYI: I am using Docker on Windows but also get endless output like this:

grafana-promtail  | level=warn ts=2024-03-11T08:56:35.516533218Z caller=target.go:130 target=docker/490f87197ccb8dc354191f5303082226b06fd1a4d1af209bb95d8815f9efb71b msg="could not transfer logs" written=38414 container=490f87197ccb8dc354191f5303082226b06fd1a4d1af209bb95d8815f9efb71b err="error from daemon in stream: Error grabbing logs: invalid character '\\x00' looking for beginning of value\n"

Also I was seeing this with other docker containers. IMHO this problem is not OS specific and somewhere deep in the internals of docker ecosystem on log processing. As logs are written as JSON I assume that if something crashes or hangs (what I also often experience and what forces me to shutdown and restart my entire PC) some logs may get corrupted as the JSON is not properly terminated. If someone thinks that JSON is a smart format for log-entries then he should implement a very robust parser for reading the logs and should avoid infinity loops processing faulty log entries - but these are just my 5 cents from an outside in perspective.

[GiulioWecove]

I've solved it using docker compose down docker compose up -d