when using journald log-driver, follow logs hangs after container is exited #575
Closed
2 of 3 tasks
Assignees
Comments
frnckdlprt
changed the title
|
Updated the title as apparently this may be related to journald log driver that we use. So on linux the following line should reproduce: |
|
I wonder if this is related to moby/moby#27343 ? |
|
Might be a regression since it works on 18.06.1, even while using the
|
|
Just found the same issue while working on fixing journald log driver, and currently have no idea of how to fix it... |
|
Proposed fix: moby/moby#38859 |
Vanient
added a commit
to Vanient/moby
that referenced
this issue
Jun 3, 2019
Fix when using journald as log-driver, docker logs -f <containerID> hangs after the container is exited. LogWatcher.WatchProducerGone() returns a channel receiver to receive notification once container is gone. fixes docker/for-linux#575 Signed-off-by: Danni Xia <xiadanni1@huawei.com>
|
fix : moby/moby#39305 |
kolyshkin
added a commit
to kolyshkin/moby
that referenced
this issue
Aug 2, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
docker-jenkins
pushed a commit
to docker/docker-ce
that referenced
this issue
Aug 9, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Upstream-commit: f091febc942859ffbc881f3a3aa327366603ae65
Component: engine
kolyshkin
added a commit
to kolyshkin/moby
that referenced
this issue
Aug 9, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit f091feb)
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
kolyshkin
added a commit
to kolyshkin/moby
that referenced
this issue
Aug 9, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit f091feb)
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
robertgzr
pushed a commit
to balena-os/balena-engine
that referenced
this issue
Aug 13, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit f091feb)
robertgzr
pushed a commit
to balena-os/balena-engine
that referenced
this issue
Aug 13, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit f091feb)
Signed-off-by: Robert Günzler <robertg@balena.io>
docker-jenkins
pushed a commit
to docker/docker-ce
that referenced
this issue
Aug 13, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit f091febc942859ffbc881f3a3aa327366603ae65)
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Upstream-commit: be568f93432ed1399a0aacca5fbd2c1046ccbc85
Component: engine
docker-jenkins
pushed a commit
to docker/docker-ce
that referenced
this issue
Aug 13, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
(cherry picked from commit f091febc942859ffbc881f3a3aa327366603ae65)
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Upstream-commit: 1cc7b3881d62eeeee3a60d97402559236cec9159
Component: engine
robertgzr
pushed a commit
to balena-os/balena-engine
that referenced
this issue
Aug 22, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
(cherry picked from commit f091feb)
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Signed-off-by: Robert Günzler <robertg@balena.io>
burnMyDread
pushed a commit
to burnMyDread/moby
that referenced
this issue
Oct 21, 2019
TL;DR: simplify the code, fix --follow hanging indefinitely
Do the following to simplify the followJournal() code:
1. Use Go-native select instead of C-native polling.
2. Use Watch{Producer,Consumer}Gone(), eliminating the need
to have journald.closed variable, and an extra goroutine.
3. Use sd_journal_wait(). In the words of its own man page:
> A synchronous alternative for using sd_journal_get_fd(),
> sd_journal_get_events(), sd_journal_get_timeout() and
> sd_journal_process() is sd_journal_wait().
Unfortunately, the logic is still not as simple as it
could be; the reason being, once the container has exited,
journald might still be writing some logs from its internal
buffers onto journal file(s), and there is no way to
figure out whether it's done so we are guaranteed to
read all of it back. This bug can be reproduced with
something like
> $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
> ...
> 128123
> $
(The last expected output line should be `150000`).
To avoid exiting from followJournal() early, add the
following logic: once the container is gone, keep trying
to drain the journal until there's no new data for at
least `waitTimeout` time period.
Should fix docker/for-linux#575
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Signed-off-by: zach <Zachary.Joyner@linux.com>
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Expected behavior
docker logs -f <container-id>should stop when the container exitsActual behavior
docker logs -f <container-id>hangs after the container has exited.Steps to reproduce the behavior
Running this command prints out 10 log lines then hangs:
docker logs -f $(docker run -d --rm busybox sh -c "for i in \$(seq 1 10); do echo logline \$i; sleep 1; done")EDIT: this may be related to journald log driver we use, so reproduction might work better with
docker logs -f $(docker run -d --rm --log-driver journald busybox sh -c "for i in \$(seq 1 10); do echo logline \$i; sleep 1; done")Output of
docker version:Output of
docker info:Additional environment details (AWS, VirtualBox, physical, etc.)
I only tested this on VMWare ESXi 6.5
The text was updated successfully, but these errors were encountered: