From c723e6b978090df43afb2462f647a4c2fde03c28 Mon Sep 17 00:00:00 2001 From: Hironori Shiina Date: Fri, 22 Oct 2021 21:04:48 -0400 Subject: Fix a few problems in 'podman logs --tail' with journald driver The following problems regarding `logs --tail` with the journald log driver are fixed: - One more line than a specified value is displayed. - '--tail 0' displays all lines while the other log drivers displays nothing. - Partial lines are not considered. - If the journald events backend is used and a container has exited, nothing is displayed. Integration tests that should have detected the bugs are also fixed. The tests are executed with json-file log driver three times without this fix. Signed-off-by: Hironori Shiina --- libpod/container_log_linux.go | 33 ++++++++++++++------- test/e2e/logs_test.go | 69 +++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 91 insertions(+), 11 deletions(-) diff --git a/libpod/container_log_linux.go b/libpod/container_log_linux.go index 562169ce2..4029d0af7 100644 --- a/libpod/container_log_linux.go +++ b/libpod/container_log_linux.go @@ -121,7 +121,24 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption }() tailQueue := []*logs.LogLine{} // needed for options.Tail - doTail := options.Tail > 0 + doTail := options.Tail >= 0 + doTailFunc := func() { + // Flush *once* we hit the end of the journal. + startIndex := int64(len(tailQueue)) + outputLines := int64(0) + for startIndex > 0 && outputLines < options.Tail { + startIndex-- + for startIndex > 0 && tailQueue[startIndex].Partial() { + startIndex-- + } + outputLines++ + } + for i := startIndex; i < int64(len(tailQueue)); i++ { + logChannel <- tailQueue[i] + } + tailQueue = nil + doTail = false + } lastReadCursor := "" for { select { @@ -152,16 +169,7 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption // Hit the end of the journal (so far?). if cursor == lastReadCursor { if doTail { - // Flush *once* we hit the end of the journal. - startIndex := int64(len(tailQueue)-1) - options.Tail - if startIndex < 0 { - startIndex = 0 - } - for i := startIndex; i < int64(len(tailQueue)); i++ { - logChannel <- tailQueue[i] - } - tailQueue = nil - doTail = false + doTailFunc() } // Unless we follow, quit. if !options.Follow { @@ -194,6 +202,9 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption return } if status == events.Exited { + if doTail { + doTailFunc() + } return } continue diff --git a/test/e2e/logs_test.go b/test/e2e/logs_test.go index 314e09b9a..3beabec4b 100644 --- a/test/e2e/logs_test.go +++ b/test/e2e/logs_test.go @@ -13,6 +13,19 @@ import ( . "github.com/onsi/gomega/gexec" ) +func isEventBackendJournald(podmanTest *PodmanTestIntegration) bool { + if !podmanTest.RemoteTest { + // If not remote test, '--events-backend' is set to 'file' or 'none' + return false + } + info := podmanTest.Podman([]string{"info", "--format", "{{.Host.EventLogger}}"}) + info.WaitWithDefaultTimeout() + if info.OutputToString() == "journald" { + return true + } + return false +} + var _ = Describe("Podman logs", func() { var ( tempdir string @@ -38,8 +51,18 @@ var _ = Describe("Podman logs", func() { }) for _, log := range []string{"k8s-file", "journald", "json-file"} { + // This is important to move the 'log' var to the correct scope under Ginkgo flow. + log := log + + skipIfJournaldInContainer := func() { + if log == "journald" { + SkipIfInContainer("journalctl inside a container doesn't work correctly") + } + } It("all lines: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -53,6 +76,8 @@ var _ = Describe("Podman logs", func() { }) It("tail two lines: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -65,6 +90,8 @@ var _ = Describe("Podman logs", func() { }) It("tail zero lines: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -77,6 +104,8 @@ var _ = Describe("Podman logs", func() { }) It("tail 99 lines: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -89,6 +118,8 @@ var _ = Describe("Podman logs", func() { }) It("tail 800 lines: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "i=1; while [ \"$i\" -ne 1000 ]; do echo \"line $i\"; i=$((i + 1)); done"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -101,6 +132,8 @@ var _ = Describe("Podman logs", func() { }) It("tail 2 lines with timestamps: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -113,6 +146,8 @@ var _ = Describe("Podman logs", func() { }) It("since time 2017-08-07: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -125,6 +160,8 @@ var _ = Describe("Podman logs", func() { }) It("since duration 10m: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -137,6 +174,8 @@ var _ = Describe("Podman logs", func() { }) It("until duration 10m: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -149,6 +188,7 @@ var _ = Describe("Podman logs", func() { }) It("until time NOW: "+log, func() { + skipIfJournaldInContainer() logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) logc.WaitWithDefaultTimeout() @@ -165,13 +205,17 @@ var _ = Describe("Podman logs", func() { }) It("latest and container name should fail: "+log, func() { + skipIfJournaldInContainer() + results := podmanTest.Podman([]string{"logs", "-l", "foobar"}) results.WaitWithDefaultTimeout() Expect(results).To(ExitWithError()) }) It("two containers showing short container IDs: "+log, func() { + skipIfJournaldInContainer() SkipIfRemote("FIXME: podman-remote logs does not support showing two containers at the same time") + log1 := podmanTest.Podman([]string{"run", "--log-driver", log, "-dt", ALPINE, "sh", "-c", "echo podman; echo podman; echo podman"}) log1.WaitWithDefaultTimeout() Expect(log1).Should(Exit(0)) @@ -192,6 +236,8 @@ var _ = Describe("Podman logs", func() { }) It("podman logs on a created container should result in 0 exit code: "+log, func() { + skipIfJournaldInContainer() + session := podmanTest.Podman([]string{"create", "--log-driver", log, "-t", "--name", "log", ALPINE}) session.WaitWithDefaultTimeout() Expect(session).To(Exit(0)) @@ -202,6 +248,8 @@ var _ = Describe("Podman logs", func() { }) It("streaming output: "+log, func() { + skipIfJournaldInContainer() + containerName := "logs-f" logc := podmanTest.Podman([]string{"run", "--log-driver", log, "--name", containerName, "-dt", ALPINE, "sh", "-c", "echo podman-1; sleep 1; echo podman-2"}) @@ -210,6 +258,14 @@ var _ = Describe("Podman logs", func() { results := podmanTest.Podman([]string{"logs", "-f", containerName}) results.WaitWithDefaultTimeout() + + if log == "journald" && !isEventBackendJournald(podmanTest) { + // --follow + journald log-driver is only supported with journald events-backend(PR #10431) + Expect(results).To(Exit(125)) + Expect(results.ErrorToString()).To(ContainSubstring("using --follow with the journald --log-driver but without the journald --events-backend")) + return + } + Expect(results).To(Exit(0)) Expect(results.OutputToString()).To(ContainSubstring("podman-1")) @@ -233,6 +289,8 @@ var _ = Describe("Podman logs", func() { }) It("follow output stopped container: "+log, func() { + skipIfJournaldInContainer() + containerName := "logs-f" logc := podmanTest.Podman([]string{"run", "--log-driver", log, "--name", containerName, "-d", ALPINE, "true"}) @@ -241,10 +299,17 @@ var _ = Describe("Podman logs", func() { results := podmanTest.Podman([]string{"logs", "-f", containerName}) results.WaitWithDefaultTimeout() + if log == "journald" && !isEventBackendJournald(podmanTest) { + // --follow + journald log-driver is only supported with journald events-backend(PR #10431) + Expect(results).To(Exit(125)) + return + } Expect(results).To(Exit(0)) }) It("using container with container log-size: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "--log-opt=max-size=10k", "-d", ALPINE, "sh", "-c", "echo podman podman podman"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -266,6 +331,8 @@ var _ = Describe("Podman logs", func() { }) It("Make sure logs match expected length: "+log, func() { + skipIfJournaldInContainer() + logc := podmanTest.Podman([]string{"run", "--log-driver", log, "-t", "--name", "test", ALPINE, "sh", "-c", "echo 1; echo 2"}) logc.WaitWithDefaultTimeout() Expect(logc).To(Exit(0)) @@ -284,6 +351,8 @@ var _ = Describe("Podman logs", func() { }) It("podman logs test stdout and stderr: "+log, func() { + skipIfJournaldInContainer() + cname := "log-test" logc := podmanTest.Podman([]string{"run", "--log-driver", log, "--name", cname, ALPINE, "sh", "-c", "echo stdout; echo stderr >&2"}) logc.WaitWithDefaultTimeout() -- cgit v1.2.3-54-g00ecf