From 5f032256db59144373cb714473b251de3d63b24f Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Wed, 4 Jan 2023 16:34:50 +0100 Subject: [PATCH] podman logs: journald fix --since and --follow The `containerCouldBeLogging` bool should not be false by default, when --since is used we seek in the journal and can miss the start event so that bool would stay false forever. This means that a running container is not followed even when it should. To fix this we can just set the `containerCouldBeLogging` bool based on the current contianer state. Fixes #16950 Signed-off-by: Paul Holzinger --- libpod/container_log_linux.go | 13 +++++++++- test/system/035-logs.bats | 46 +++++++++++++++++++++++++++++++++++ 2 files changed, 58 insertions(+), 1 deletion(-) diff --git a/libpod/container_log_linux.go b/libpod/container_log_linux.go index 7e95f2449f..e8f957322b 100644 --- a/libpod/container_log_linux.go +++ b/libpod/container_log_linux.go @@ -97,7 +97,18 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption // exponential backoff. var cursor string var cursorError error - var containerCouldBeLogging bool + + c.lock.Lock() + if err := c.syncContainer(); err != nil { + c.lock.Unlock() + return err + } + // The initial "containerCouldBeLogging" state must be correct, we cannot rely on the start event being still in the journal. + // This can happen if the journal was rotated after the container was started or when --since is used. + // https://github.com/containers/podman/issues/16950 + containerCouldBeLogging := c.ensureState(define.ContainerStateRunning, define.ContainerStateStopping) + c.lock.Unlock() + for i := 1; i <= 3; i++ { cursor, cursorError = journal.GetCursor() hundreds := 1 diff --git a/test/system/035-logs.bats b/test/system/035-logs.bats index f9ac33d2c7..7e0efc6e98 100644 --- a/test/system/035-logs.bats +++ b/test/system/035-logs.bats @@ -298,4 +298,50 @@ $contentC" "logs -f on exitted container works" _log_test_follow journald } + +function _log_test_follow_since() { + local driver=$1 + cname=$(random_string) + content=$(random_string) + local events_backend=$(_additional_events_backend $driver) + + if [[ -n "${events_backend}" ]]; then + skip_if_remote "remote does not support --events-backend" + fi + + run_podman ${events_backend} run --log-driver=$driver --name $cname $IMAGE echo "$content" + # Using --since 0s can flake because the log might written in the second as the logs call is made. + # The -1s makes sure we only read logs that would be created 1s in the future which cannot happen. + run_podman ${events_backend} logs --since -1s -f $cname + assert "$output" == "" "logs --since -f on exited container works" + + run_podman ${events_backend} rm -t 0 -f $cname + + # Now do the same with a running container to check #16950. + run_podman ${events_backend} run --log-driver=$driver --name $cname -d $IMAGE \ + sh -c "sleep 0.5; while :; do echo $content && sleep 3; done" + + # sleep is required to make sure the podman event backend no longer sees the start event in the log + # This value must be greater or equal than the the value given in --since below + sleep 0.2 + + # Make sure podman logs actually follows by giving a low timeout and check that the command times out + PODMAN_TIMEOUT=2 run_podman 124 ${events_backend} logs --since 0.1s -f $cname + assert "$output" =~ "^$content +timeout: sending signal TERM to command.*" "logs --since -f on running container works" + + run_podman ${events_backend} rm -t 0 -f $cname +} + +@test "podman logs - --since --follow k8s-file" { + _log_test_follow_since k8s-file +} + +@test "podman logs - --since --follow journald" { + # We can't use journald on RHEL as rootless: rhbz#1895105 + skip_if_journald_unavailable + + _log_test_follow_since journald +} + # vim: filetype=sh