moby: Following large files (docker logs -f) does not work as expected when combined with --tail or --since on the json-file logger
Steps to reproduce the issue:
If the -f
flag is present, seeking begins at the start of the file, even if --since
or --tail
are provided.
I have a log file that has grown quite large.
If I run docker logs --tail 100
, it returns right away with the expected lines, even if the log file is huge.
If I run docker logs --since 2m
, it returns right away with the expected lines, even if the log file is huge.
If I run docker logs -f
, I will never get to the end of the log file because it begins sending bits from the beginning of the file.
If I run docker logs --tail 100 -f
or docker logs --since 2m -f
, against a very large log file, the process hangs, cpu is maxed and eventually if it can get enough resources, it behaves as expected.
Unfortunately, the typical conditions where we need this feature to work (for our product at least), tends to be when we’re having resource contention on a given node and we want to understand it.
This problem makes it impossible for us to get recent context and continue watching logs as we interact with the application.
I suspect the problem is related to the order in which we work with inbound arguments in the jsonfilelog/read.go file.
Output of docker version
:
Client:
Version: 1.8.3
API version: 1.20
Go version: go1.4.2
Git commit: cedd534-dirty
Built: Thu Feb 18 16:25:16 UTC 2016
OS/Arch: linux/amd64
Server:
Version: 1.8.3
API version: 1.20
Go version: go1.4.2
Git commit: cedd534-dirty
Built: Thu Feb 18 16:25:16 UTC 2016
OS/Arch: linux/amd64
Output of docker info
:
Containers: 140
Images: 807
Storage Driver: overlay
Backing Filesystem: extfs
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 4.2.2-coreos-r2
Operating System: CoreOS 835.13.0
CPUs: 8
Total Memory: 31.43 GiB
Name: [redacted]
ID: [redacted]
Additional environment details (AWS, VirtualBox, physical, etc.):
AWS EC2 and Kubernetes
About this issue
- Original URL
- State: closed
- Created 8 years ago
- Reactions: 7
- Comments: 17 (9 by maintainers)
@cpuguy83 Large was ~5GB @AndrewGuenther Yep, we worked around the problem (for now) by rotating logs more frequently
@sravanikoilada, et al: The bug is that
-f
breaks the expected behavior that--tail
implies based on experiences with tools likegrep
.The expectation is that these flags begin scanning a file of any size from the end, going backward, but in this case, whenever the
-f
flag is present, these expectations are not met and instead, the file is scanned from the beginning.I believe this is a serious bug, because there are a number of problems that can cause a log file to grow relatively large that don’t necessarily implicate inappropriate configuration (though that was, admittedly the case here) and that these problems tend to coincide with environments that are resource constrained or otherwise under load.
I could be misunderstanding the root cause and jumping to incorrect conclusions, so please forgive me if that’s the case.
The observed facts with at least one large log file are:
--tail
works perfectly alone--since
works perfectly alone-f
(along side either--tail
or--since
) causes the process to lag and become unresponsive@lukebayes
-f
does not cause docker to scan from the beginning.-f
tells docker to follow the file, and you need to set--tail
if you don’t want to start from the beginning.Yep it seems that it is working, I don’t exactly know what I got 4 months ago but I can now follow with tail.
@Gui13 I’m using Docker version 18.09.0 on CentOS 7. As @cpuguy83 mentioned if you use
-f
with--tail
logs don’t start from beginning. For example below command works for me:It starts listing from last 10 line and follows log after 10 line.
It is not stale, there is still the issue as of today.
If your file is that large shouldn’t you be rotating it?