Merge pull request #19503 from edsantiago/journalctl_unreliable

CI: e2e: add delay before podman logs or journalctl

test/e2e/containers_conf_test.go

@@ -6,6 +6,7 @@ import (
 	"os/exec"
 	"path/filepath"
 	"strings"
+	"time"
 
 	"github.com/containers/podman/v4/libpod/define"
 	. "github.com/containers/podman/v4/test/utils"
@@ -254,6 +255,8 @@ var _ = Describe("Verify podman containers.conf usage", func() {
 		wait.WaitWithDefaultTimeout()
 		Expect(wait).Should(Exit(0))
 
+		// Flake prevention: journalctl makes no timeliness guarantees.
+		time.Sleep(1 * time.Second)
 		cmd := exec.Command("journalctl", "--no-pager", "-o", "json", "--output-fields=CONTAINER_TAG", fmt.Sprintf("CONTAINER_ID_FULL=%s", cid))
 		out, err := cmd.CombinedOutput()
 		Expect(err).ToNot(HaveOccurred())

test/e2e/logs_test.go

@@ -36,6 +36,12 @@ var _ = Describe("Podman logs", func() {
 		// This is important to move the 'log' var to the correct scope under Ginkgo flow.
 		log := log
 
+		// Flake prevention: journalctl makes no timeliness guarantees
+		logTimeout := time.Millisecond
+		if log == "journald" {
+			logTimeout = time.Second
+		}
+
 		skipIfJournaldInContainer := func() {
 			if log == "journald" {
 				SkipIfJournaldUnavailable()
@@ -54,11 +60,13 @@ var _ = Describe("Podman logs", func() {
 			results.WaitWithDefaultTimeout()
 			Expect(results).To(Exit(0))
 
-			results = podmanTest.Podman([]string{"logs", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results = podmanTest.Podman([]string{"logs", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(3))
+				g.Expect(results).To(Exit(0))
-			Expect(results.OutputToString()).To(Equal("podman podman podman"))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(3))
+				g.Expect(results.OutputToString()).To(Equal("podman podman podman"))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("tail two lines: "+log, func() {
@@ -73,10 +81,13 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "--tail", "2", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--tail", "2", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(2))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(2))
+				g.Expect(results.OutputToString()).To(Equal("podman podman"))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("tail zero lines: "+log, func() {
@@ -91,6 +102,7 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
+			time.Sleep(logTimeout)
 			results := podmanTest.Podman([]string{"logs", "--tail", "0", cid})
 			results.WaitWithDefaultTimeout()
 			Expect(results).To(Exit(0))
@@ -109,10 +121,12 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "--tail", "99", name})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--tail", "99", name})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(3))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(3))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("tail 800 lines: "+log, func() {
@@ -139,10 +153,12 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "--tail", "800", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--tail", "800", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(800))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(800))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("tail 2 lines with timestamps: "+log, func() {
@@ -157,10 +173,12 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "--tail", "2", "-t", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--tail", "2", "-t", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(2))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(2))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("since time 2017-08-07: "+log, func() {
@@ -175,10 +193,12 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "--since", "2017-08-07T10:10:09.056611202-04:00", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--since", "2017-08-07T10:10:09.056611202-04:00", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(3))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(3))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("since duration 10m: "+log, func() {
@@ -193,10 +213,12 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "--since", "10m", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--since", "10m", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(3))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(3))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("until duration 10m: "+log, func() {
@@ -211,10 +233,12 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "--until", "10m", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--until", "10m", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(3))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(3))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("until time NOW: "+log, func() {
@@ -229,13 +253,15 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			now := time.Now()
+			Eventually(func(g Gomega) {
-			now = now.Add(time.Minute * 1)
+				now := time.Now()
-			nowS := now.Format(time.RFC3339)
+				now = now.Add(time.Minute * 1)
-			results := podmanTest.Podman([]string{"logs", "--until", nowS, cid})
+				nowS := now.Format(time.RFC3339)
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "--until", nowS, cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToStringArray()).To(HaveLen(3))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToStringArray()).To(HaveLen(3))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("latest and container name should fail: "+log, func() {
@@ -363,10 +389,12 @@ var _ = Describe("Podman logs", func() {
 			Expect(inspect).To(Exit(0))
 			Expect(inspect.OutputToString()).To(Equal("10kB"))
 
-			results := podmanTest.Podman([]string{"logs", cid})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", cid})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToString()).To(Equal("podman podman podman"))
+				g.Expect(results).To(Exit(0))
+				g.Expect(results.OutputToString()).To(Equal("podman podman podman"))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("Make sure logs match expected length: "+log, func() {
@@ -380,13 +408,15 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", "test"})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", "test"})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			outlines := results.OutputToStringArray()
+				g.Expect(results).To(Exit(0))
-			Expect(outlines).To(HaveLen(2))
+				outlines := results.OutputToStringArray()
-			Expect(outlines[0]).To(Equal("1"))
+				g.Expect(outlines).To(HaveLen(2))
-			Expect(outlines[1]).To(Equal("2"))
+				g.Expect(outlines[0]).To(Equal("1"))
+				g.Expect(outlines[1]).To(Equal("2"))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("podman logs test stdout and stderr: "+log, func() {
@@ -401,11 +431,13 @@ var _ = Describe("Podman logs", func() {
 			wait.WaitWithDefaultTimeout()
 			Expect(wait).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"logs", cname})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"logs", cname})
-			Expect(results).To(Exit(0))
+				results.WaitWithDefaultTimeout()
-			Expect(results.OutputToString()).To(Equal("stdout"))
+				g.Expect(results).To(Exit(0))
-			Expect(results.ErrorToString()).To(Equal("stderr"))
+				g.Expect(results.OutputToString()).To(Equal("stdout"))
+				g.Expect(results.ErrorToString()).To(Equal("stderr"))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("podman logs partial log lines: "+log, func() {
@@ -421,15 +453,18 @@ var _ = Describe("Podman logs", func() {
 			// However this test must make sure that there is no such extra newline.
 			Expect(string(logc.Out.Contents())).To(Equal(content))
 
-			logs := podmanTest.Podman([]string{"logs", cname})
+			Eventually(func(g Gomega) {
-			logs.WaitWithDefaultTimeout()
+				logs := podmanTest.Podman([]string{"logs", cname})
-			Expect(logs).To(Exit(0))
+				logs.WaitWithDefaultTimeout()
-			// see comment above
+				g.Expect(logs).To(Exit(0))
-			Expect(string(logs.Out.Contents())).To(Equal(content))
+				// see comment above
+				g.Expect(string(logs.Out.Contents())).To(Equal(content))
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("podman pod logs -l with newer container created: "+log, func() {
 			skipIfJournaldInContainer()
+			SkipIfRemote("no -l in remote")
 
 			podName := "testPod"
 			containerName1 := "container1"
@@ -452,25 +487,24 @@ var _ = Describe("Podman logs", func() {
 			ctr.WaitWithDefaultTimeout()
 			Expect(ctr).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"pod", "logs", "-l"})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"pod", "logs", "-l"})
-			if IsRemote() {
+				results.WaitWithDefaultTimeout()
-				Expect(results).To(Exit(125))
+				g.Expect(results).To(Exit(0))
-			} else {
-				Expect(results).To(Exit(0))
 				podOutput := results.OutputToString()
 
 				results = podmanTest.Podman([]string{"logs", "-l"})
 				results.WaitWithDefaultTimeout()
-				Expect(results).To(Exit(0))
+				g.Expect(results).To(Exit(0))
 				ctrOutput := results.OutputToString()
 
-				Expect(podOutput).ToNot(Equal(ctrOutput))
+				g.Expect(podOutput).ToNot(Equal(ctrOutput))
-			}
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 
 		It("podman pod logs -l: "+log, func() {
 			skipIfJournaldInContainer()
+			SkipIfRemote("no -l in remote")
 
 			podName := "testPod"
 			containerName1 := "container1"
@@ -488,16 +522,14 @@ var _ = Describe("Podman logs", func() {
 			log2.WaitWithDefaultTimeout()
 			Expect(log2).To(Exit(0))
 
-			results := podmanTest.Podman([]string{"pod", "logs", "-l"})
+			Eventually(func(g Gomega) {
-			results.WaitWithDefaultTimeout()
+				results := podmanTest.Podman([]string{"pod", "logs", "-l"})
-			if IsRemote() {
+				results.WaitWithDefaultTimeout()
-				Expect(results).To(Exit(125))
+				g.Expect(results).To(Exit(0))
-			} else {
-				Expect(results).To(Exit(0))
 				output := results.OutputToString()
-				Expect(output).To(ContainSubstring("log1"))
+				g.Expect(output).To(ContainSubstring("log1"))
-				Expect(output).To(ContainSubstring("log2"))
+				g.Expect(output).To(ContainSubstring("log2"))
-			}
+			}).WithTimeout(logTimeout).Should(Succeed())
 		})
 	}
 
@@ -512,10 +544,12 @@ var _ = Describe("Podman logs", func() {
 		wait.WaitWithDefaultTimeout()
 		Expect(wait).To(Exit(0))
 
-		cmd := exec.Command("journalctl", "--no-pager", "-o", "json", "--output-fields=CONTAINER_TAG", fmt.Sprintf("CONTAINER_ID_FULL=%s", cid))
+		Eventually(func(g Gomega) {
-		out, err := cmd.CombinedOutput()
+			cmd := exec.Command("journalctl", "--no-pager", "-o", "json", "--output-fields=CONTAINER_TAG", fmt.Sprintf("CONTAINER_ID_FULL=%s", cid))
-		Expect(err).ToNot(HaveOccurred())
+			out, err := cmd.CombinedOutput()
-		Expect(string(out)).To(ContainSubstring("alpine"))
+			g.Expect(err).ToNot(HaveOccurred())
+			g.Expect(string(out)).To(ContainSubstring("alpine"))
+		}).Should(Succeed())
 	})
 
 	It("using journald container name", func() {
@@ -530,10 +564,12 @@ var _ = Describe("Podman logs", func() {
 		wait.WaitWithDefaultTimeout()
 		Expect(wait).To(Exit(0))
 
-		cmd := exec.Command("journalctl", "--no-pager", "-o", "json", "--output-fields=CONTAINER_NAME", fmt.Sprintf("CONTAINER_ID_FULL=%s", cid))
+		Eventually(func(g Gomega) {
-		out, err := cmd.CombinedOutput()
+			cmd := exec.Command("journalctl", "--no-pager", "-o", "json", "--output-fields=CONTAINER_NAME", fmt.Sprintf("CONTAINER_ID_FULL=%s", cid))
-		Expect(err).ToNot(HaveOccurred())
+			out, err := cmd.CombinedOutput()
-		Expect(string(out)).To(ContainSubstring(containerName))
+			g.Expect(err).ToNot(HaveOccurred())
+			g.Expect(string(out)).To(ContainSubstring(containerName))
+		}).Should(Succeed())
 	})
 
 	It("podman logs with log-driver=none errors", func() {
@@ -566,14 +602,16 @@ var _ = Describe("Podman logs", func() {
 		log2.WaitWithDefaultTimeout()
 		Expect(log2).To(Exit(0))
 
-		results := podmanTest.Podman([]string{"pod", "logs", "--names", podName})
+		Eventually(func(g Gomega) {
-		results.WaitWithDefaultTimeout()
+			results := podmanTest.Podman([]string{"pod", "logs", "--names", podName})
-		Expect(results).To(Exit(0))
+			results.WaitWithDefaultTimeout()
+			g.Expect(results).To(Exit(0))
 
-		output := results.OutputToStringArray()
+			output := results.OutputToStringArray()
-		Expect(output).To(HaveLen(2))
+			g.Expect(output).To(HaveLen(2))
-		Expect(output).To(ContainElement(ContainSubstring(containerName1)))
+			g.Expect(output).To(ContainElement(ContainSubstring(containerName1)))
-		Expect(output).To(ContainElement(ContainSubstring(containerName2)))
+			g.Expect(output).To(ContainElement(ContainSubstring(containerName2)))
+		}).Should(Succeed())
 	})
 	It("podman pod logs with different colors", func() {
 		SkipIfRemote("Remote can only process one container at a time")
@@ -589,13 +627,16 @@ var _ = Describe("Podman logs", func() {
 		log2 := podmanTest.Podman([]string{"run", "--name", containerName2, "--pod", podName, BB, "echo", "log2"})
 		log2.WaitWithDefaultTimeout()
 		Expect(log2).To(Exit(0))
-		results := podmanTest.Podman([]string{"pod", "logs", "--color", podName})
+
-		results.WaitWithDefaultTimeout()
+		Eventually(func(g Gomega) {
-		Expect(results).To(Exit(0))
+			results := podmanTest.Podman([]string{"pod", "logs", "--color", podName})
-		output := results.OutputToStringArray()
+			results.WaitWithDefaultTimeout()
-		Expect(output).To(HaveLen(2))
+			g.Expect(results).To(Exit(0))
-		Expect(output[0]).To(MatchRegexp(`\x1b\[3[0-9a-z ]+\x1b\[0m`))
+			output := results.OutputToStringArray()
-		Expect(output[1]).To(MatchRegexp(`\x1b\[3[0-9a-z ]+\x1b\[0m`))
+			g.Expect(output).To(HaveLen(2))
+			g.Expect(output[0]).To(MatchRegexp(`\x1b\[3[0-9a-z ]+\x1b\[0m`))
+			g.Expect(output[1]).To(MatchRegexp(`\x1b\[3[0-9a-z ]+\x1b\[0m`))
+		}).Should(Succeed())
 	})
 
 })

test/e2e/play_kube_test.go

@@ -2499,6 +2499,8 @@ var _ = Describe("Podman play kube", func() {
 		wait.WaitWithDefaultTimeout()
 		Expect(wait).Should(Exit(0))
 
+		// Flake prevention: journalctl makes no timeliness guarantees.
+		time.Sleep(1 * time.Second)
 		logs := podmanTest.Podman([]string{"logs", getCtrNameInPod(p)})
 		logs.WaitWithDefaultTimeout()
 		Expect(logs).Should(Exit(0))