Docker 1.6+ stops writing log lines to disk after one long line

[jgadling]

Description of problem:
If a container writes a log line > 65536 bytes long to stdout, docker will stop writing any further log lines to that container's log file at /var/lib/docker/[hash]/[hash]-json.log

docker version:
Client version: 1.6.2
Client API version: 1.18
Go version (client): go1.4.2
Git commit (client): 7c8fca2
OS/Arch (client): linux/amd64
Server version: 1.6.2
Server API version: 1.18
Go version (server): go1.4.2
Git commit (server): 7c8fca2
OS/Arch (server): linux/amd64

docker info:
Containers: 12
Images: 222
Storage Driver: aufs
Root Dir: /var/lib/docker/aufs
Backing Filesystem: extfs
Dirs: 246
Dirperm1 Supported: false
Execution Driver: native-0.2
Kernel Version: 3.13.0-45-generic
Operating System: Ubuntu 14.04.1 LTS
CPUs: 1
Total Memory: 1.955 GiB
Name: vagrant-ubuntu-trusty-64

uname -a:
Linux vagrant-ubuntu-trusty-64 3.13.0-45-generic #74-Ubuntu SMP Tue Jan 13 19:36:28 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

Environment details (AWS, VirtualBox, physical, etc.):
VirtualBox, AWS

How reproducible:
Always

Steps to Reproduce:

1. Run a container that produces a mix of log lines < and > 65k in length
2. Tail /var/lib/docker/[hash]/[hash]-json.log

Actual Results:
/var/lib/docker/[hash]/[hash]-json.log does not contain any log lines after the first line >65k in length

Expected Results:
All log lines are present in /var/lib/docker/[hash]/[hash]-json.log

Additional info:

A simple container that demonstrates the problem:
https://github.com/jgadling/docker-log-lines
or:
https://registry.hub.docker.com/u/jgadling/docker-log-lines/

This container outputs log lines of increasing size, until eventually lines stop being appended to the logfile in /var/lib/docker:

{"log":"done outputting 65520 bytes\n","stream":"stdout","time":"2015-05-19T19:31:09.768520457Z"}
{"log":"Asking for 66560 bytes\n","stream":"stdout","time":"2015-05-19T19:31:09.768525016Z"}
{"log":"Outputting 66560 bytes next\n","stream":"stdout","time":"2015-05-19T19:31:09.768527738Z"}
[EOF]

Even though the lines aren't being written to the log file, they are visible by running 'docker logs --tail=1 -f [container]' while the container is still running.

[GordonTheTurtle]

Hi!
If you are reporting a new issue, PLEASE make sure that does not have any duplicates already open.

We would like to take this time to remind you of the information we need to debug the problem you are seeing. This is an automated response so if this ticket is not about a bug, do not fret.

If you fail to provide this information within 7 days, we will close this because we cannot debug your issue. We can reopen whenever the information is provided.

Thank you.

Please see:
https://github.com/docker/docker/blob/master/CONTRIBUTING.md#reporting-other-issues

Description of problem:


`docker version`:


`docker info`:


`uname -a`:


Environment details (AWS, VirtualBox, physical, etc.):


How reproducible:


Steps to Reproduce:
1.
2.
3.


Actual Results:


Expected Results:


Additional info:

#ENEEDMOREINFO

[codeboten]

Running Docker in debug mode I'm seeing this error in the logs:

ERRO[1068] Error scanning log stream: bufio.Scanner: token too long

It looks like the logger is hitting this limit in bufio https://github.com/golang/go/blob/master/src/bufio/scan.go#L71

const (
    // MaxScanTokenSize is the maximum size used to buffer a token.
    // The actual maximum token size may be smaller as the buffer
    // may need to include, for instance, a newline.
    MaxScanTokenSize = 64 * 1024
)

[LK4D4]

Nice find, thank you.

[LK4D4]

We should change scanner for bufio.Reader and use ReadLine

[unclejack]

I'll take care of this one to make sure we don't regress on anything else when fixing this.

[thaJeztah]

This should be resolved by #13564, so closing.

ping @unclejack @LK4D4 please check if this is fully addressed by #13564