This should test that
- all the messages produced are delivered (i.e. not lost)
- followLogs() exits
Loosely based on the test having the same name by Brian Goff, see
https://gist.github.com/cpuguy83/e538793de18c762608358ee0eaddc197
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit f845d76d047760c91dc0c7076aea840291fbdbc5)
Upstream-commit: 2a82480df9ad91593d59be4b5283917dbea2da39
Component: engine
When daemon.ContainerLogs() is called with options.follow=true
(as in "docker logs --follow"), the "loggerutils.followLogs()"
function never returns (even then the logs consumer is gone).
As a result, all the resources associated with it (including
an opened file descriptor for the log file being read, two FDs
for a pipe, and two FDs for inotify watch) are never released.
If this is repeated (such as by running "docker logs --follow"
and pressing Ctrl-C a few times), this results in DoS caused by
either hitting the limit of inotify watches, or the limit of
opened files. The only cure is daemon restart.
Apparently, what happens is:
1. logs producer (a container) is gone, calling (*LogWatcher).Close()
for all its readers (daemon/logger/jsonfilelog/jsonfilelog.go:175).
2. WatchClose() is properly handled by a dedicated goroutine in
followLogs(), cancelling the context.
3. Upon receiving the ctx.Done(), the code in followLogs()
(daemon/logger/loggerutils/logfile.go#L626-L638) keeps to
send messages _synchronously_ (which is OK for now).
4. Logs consumer is gone (Ctrl-C is pressed on a terminal running
"docker logs --follow"). Method (*LogWatcher).Close() is properly
called (see daemon/logs.go:114). Since it was called before and
due to to once.Do(), nothing happens (which is kinda good, as
otherwise it will panic on closing a closed channel).
5. A goroutine (see item 3 above) keeps sending log messages
synchronously to the logWatcher.Msg channel. Since the
channel reader is gone, the channel send operation blocks forever,
and resource cleanup set up in defer statements at the beginning
of followLogs() never happens.
Alas, the fix is somewhat complicated:
1. Distinguish between close from logs producer and logs consumer.
To that effect,
- yet another channel is added to LogWatcher();
- {Watch,}Close() are renamed to {Watch,}ProducerGone();
- {Watch,}ConsumerGone() are added;
*NOTE* that ProducerGone()/WatchProducerGone() pair is ONLY needed
in order to stop ConsumerLogs(follow=true) when a container is stopped;
otherwise we're not interested in it. In other words, we're only
using it in followLogs().
2. Code that was doing (logWatcher*).Close() is modified to either call
ProducerGone() or ConsumerGone(), depending on the context.
3. Code that was waiting for WatchClose() is modified to wait for
either ConsumerGone() or ProducerGone(), or both, depending on the
context.
4. followLogs() are modified accordingly:
- context cancellation is happening on WatchProducerGone(),
and once it's received the FileWatcher is closed and waitRead()
returns errDone on EOF (i.e. log rotation handling logic is disabled);
- due to this, code that was writing synchronously to logWatcher.Msg
can be and is removed as the code above it handles this case;
- function returns once ConsumerGone is received, freeing all the
resources -- this is the bugfix itself.
While at it,
1. Let's also remove the ctx usage to simplify the code a bit.
It was introduced by commit a69a59ffc7e3d ("Decouple removing the
fileWatcher from reading") in order to fix a bug. The bug was actually
a deadlock in fsnotify, and the fix was just a workaround. Since then
the fsnofify bug has been fixed, and a new fsnotify was vendored in.
For more details, please see
https://github.com/moby/moby/pull/27782#issuecomment-416794490
2. Since `(*filePoller).Close()` is fixed to remove all the files
being watched, there is no need to explicitly call
fileWatcher.Remove(name) anymore, so get rid of the extra code.
Should fix https://github.com/moby/moby/issues/37391
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit 916eabd459fe707b5c4a86377d12e2ad1871b353)
Upstream-commit: 84a5b528aede5579861201e869870d10fc98c07c
Component: engine
This test case checks that followLogs() exits once the reader is gone.
Currently it does not (i.e. this test is supposed to fail) due to #37391.
[kolyshkin@: test case Brian Goff, changelog and all bugs are by me]
Source: https://gist.github.com/cpuguy83/e538793de18c762608358ee0eaddc197
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit d37a11bfbab83ab42b1160f116e863daac046192)
Upstream-commit: 511741735e0aa2fe68a66d99384c00d187d1a157
Component: engine
This makes it so consumers of `LogFile` should pass in how to get an
io.Reader to the requested number of lines to tail.
This is also much more efficient when tailing a large number of lines.
Signed-off-by: Brian Goff <cpuguy83@gmail.com>
Upstream-commit: 94a10150f64a24793216f5324a34e62be3f31a2d
Component: engine
There are two build errors when using go-1.11beta1:
> daemon/logger/loggerutils/logfile.go:367: Warningf format %q arg f.Name is a func value, not called
> daemon/logger/loggerutils/logfile.go:564: Debug call has possible formatting directive %v
In the first place, the file name is actually not required as error
message already includes it.
While at it, fix a couple of other places for more correct messages, and
make sure to not add a file name if an error already has it.
Fixes: f69f09f44c
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
Upstream-commit: 09ad434f10cff48741322854a3003686b28295b5
Component: engine
remove unnescessary import aliases, brackets, and so on.
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
Upstream-commit: f23c00d8701e4bd0f2372a586dacbf66a26f9a51
Component: engine
- Check errors.Cause(err) when comparing errors
- Fix bug where oldest log file is not actually removed. This in
particular causes issues when compression is enabled. On rotate it just
overwrites the data in the log file corrupting it.
- Use O_TRUNC to open new gzip files to ensure we don't corrupt log
files as happens without the above fix.
Signed-off-by: Brian Goff <cpuguy83@gmail.com>
Upstream-commit: e87e9e6ad6ba501cc42a2ef47ac18c88a68f258f
Component: engine
This PR adds support for compressibility of log file.
I added a new option conpression for the jsonfile log driver,
this option allows the user to specify compression algorithm to
compress the log files. By default, the log files will be
not compressed. At present, only support 'gzip'.
Signed-off-by: Yanqiang Miao <miao.yanqiang@zte.com.cn>
'docker logs' can read from compressed files
Signed-off-by: Yanqiang Miao <miao.yanqiang@zte.com.cn>
Add Metadata to the gzip header, optmize 'readlog'
Signed-off-by: Yanqiang Miao <miao.yanqiang@zte.com.cn>
Upstream-commit: f69f09f44ce9fedbc9d70f11980c1fc8d7f77cec
Component: engine
This fixes an issue where the container LogPath was empty when the
non-blocking logging mode was enabled. This change sets the LogPath on
the container as soon as the path is generated, instead of setting the
LogPath on a logger struct and then attempting to pull it off that
logger at a later point. That attempt to pull the LogPath off the logger
was error prone since it assumed that the logger would only ever be a
single type.
Prior to this change docker inspect returned an empty string for
LogPath. This caused issues with tools that rely on docker inspect
output to discover container logs, e.g. Kubernetes.
This commit also removes some LogPath methods that are now unnecessary
and are never invoked.
Signed-off-by: junzhe and mnussbaum <code@getbraintree.com>
Upstream-commit: 20ca612a59c45c0bd58c71c199a7ebd2a6bf1a9e
Component: engine
When tailing a container log, if the log file is empty it will cause the
log stream to abort with an unexpected `EOF`.
Note that this only applies to the "current" log file as rotated files
cannot be empty.
This fix just skips adding the "current" file the log tail if it is
empty.
Signed-off-by: Brian Goff <cpuguy83@gmail.com>
Upstream-commit: f40860c5f3d3575629d4a932207e866c1fea625d
Component: engine
This allows much of the read logic to be shared for other things,
especially for the new log driver proposed in
https://github.com/moby/moby/issues/33475
The only logic for reads in the json logger is around decoding log
messages, which gets passed into the log file object.
This also helps with implementing compression as it allows us to
simplify locking strategies.
Signed-off-by: Brian Goff <cpuguy83@gmail.com>
Upstream-commit: 16f7cd674902b69b97692de2a83915a1a6be2cdb
Component: engine
Make the `*RotateFileWriter` specifically about writing
`logger.Message`'s, which is what it's used for.
This allows for future changes where the log writer can cache details
about log entries such as (e.g.) the timestamps included in a particular
log file, which can be used to optimize reads.
Signed-off-by: Brian Goff <cpuguy83@gmail.com>
Upstream-commit: 52d82b4fbc9f0fe00f63e2df9a3d2a49d4095bda
Component: engine
- Remove unused function and variables from the package
- Remove usage of it from `profiles/apparmor` where it wasn't required
- Move the package to `daemon/logger/templates` where it's only used
Signed-off-by: Vincent Demeester <vincent@sbr.pm>
Upstream-commit: 9ef3b535974612b137abae062b7a8a0f7e969871
Component: engine
the filemode should be 0640 but not 06400
Signed-off-by: Lei Jitang <leijitang@huawei.com>
Upstream-commit: 96ea8eaa1592856e0829c3465e64f93911d3e389
Component: engine
When closing the log-file, and the file is already
closed, there's no need to log an error.
This patch adds a `closed` boolean to check if the
file was closed, and if so, skip closing the file.
This prevents errors like this being logged:
level=error msg="Error closing logger: invalid argument"
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
Upstream-commit: 07b51ed300429e88871e40b4d67dc031e2e8901c
Component: engine
Use the same default tag value for all loggers that support tags.
Signed-off-by: Vincent Demeester <vincent@sbr.pm>
Upstream-commit: f900e1cf47f6a18eaa4ce438cc8fc0623f2eaec0
Component: engine
This fix tries to address the issue raised in #22358 where syslog's
message tag always starts with `docker/` and can not be removed
by changing the log tag templates.
The issue is that syslog driver hardcodes `path.Base(os.Args[0])`
as the prefix, which is the binary file name of the daemon (`dockerd`).
This could be an issue for certain situations (e.g., #22358) where
user may prefer not to have a dedicated prefix in syslog messages.
There is no way to override this behavior in the current verison of
the docker.
This fix tries to address this issue without making changes in the
default behavior of the syslog driver. An additional
`{{.DaemonName}}` has been introduced in the syslog tag. This is
assigned as the `docker` when daemon starts. The default log tag
template has also been changed from
`path.Base(os.Args[0]) + "/{{.ID}}"` to `{{.DaemonName}}/{{.ID}}`.
Therefore, there is no behavior changes when log-tag is not provided.
In order to be consistent, the default log tag for fluentd has been
changed from `docker.{{.ID}}` to `{{DaemonName}}.{{.ID}}` as well.
The documentation for log-tag has been updated to reflect this change.
Additional test cases have been added to cover changes in this fix.
This fix fixes#22358.
Signed-off-by: Yong Tang <yong.tang.github@outlook.com>
Upstream-commit: 38c49d99870c762a0ea23dadda414f9cc59071b6
Component: engine
Since 1.9, driver specific log tag options
`syslog-tag`
`gelf-tag`
`fluentd-tag`
have been deprecated in favor of the generic tag
option which is standard across different logging
drivers.
This fix removed the deprecated driver specific
log tag options of `syslog-tag`, `gelf-tag`,
`fluentd-tag` for 1.12 and updated the docs.
Signed-off-by: Yong Tang <yong.tang.github@outlook.com>
Upstream-commit: a20b02b9158c283402d174926c84e657e53b17a1
Component: engine
This cleans up some of the use of the filepoller which makes reading
significantly more robust and gives fewer changes to fallback to the
polling based watcher.
In a lot of cases, if the file was being rotated while we were adding it
to the watcher, it would return an error that the file doesn't exist and
would fallback.
In some cases this fallback could be triggered multiple times even if we
were already on the fallback/poll-based watcher.
It also fixes an open file leak caused by not closing files properly on
rotate, as well as not closing files that were read via the `tail`
function until after the log reader is completed.
Prior to the above changes, it was relatively simple to cause the log
reader to error out by having quick rotations, for example:
```
$ docker run --name test --log-opt max-size=10b --log-opt max-files=10
-d busybox sh -c 'while true; do usleep 500000; echo hello; done'
$ docker logs -f test
```
After these changes I can run this forever without error.
Another fix removes 2 `os.Stat` calls when rotating files. The stat
calls are not needed since we are just calling `os.Rename` anyway, which
will in turn also just produce the same error that `Stat` would.
These `Stat` calls were also quite expensive.
Removing these stat calls also seemed to resolve an issue causing slow
memory growth on the daemon.
Signed-off-by: Brian Goff <cpuguy83@gmail.com>
Upstream-commit: 1ae9dcf97dc6ccaf7a7977fe8ae1812b691ccba2
Component: engine
This change centralizes the template manipulation in a single package
and adds basic string functions to their execution.
Signed-off-by: David Calavera <david.calavera@gmail.com>
Upstream-commit: 8514880997bd1bc944769dcc41e52307bb01f7ff
Component: engine
Signed-off-by: Jussi Nummelin <jussi.nummelin@gmail.com>
Changed buffer size to 1M and removed unnecessary fmt call
Signed-off-by: Jussi Nummelin <jussi.nummelin@gmail.com>
Updated docs for the new fluentd opts
Signed-off-by: Jussi Nummelin <jussi.nummelin@gmail.com>
Upstream-commit: 3cf82ff1ab14e1ddd2b629524e894ac359168388
Component: engine
