libpod: correctly capture healthcheck output

Using the scanner is just unnecessary complicated an buggy as it will
not read the final line with a newline. There is also the problem that
it happens in a separate goroutine so it could loose output if we read
the array before the scanner was done.

The API accepts a Writer so we can just directly use a bytes.Buffer
which captures all output in memory without the need of another
goroutine.

This also means that now we always include the final newline in the
output. I checked with docker and they do the same so this is good.

Fixes #23332

Signed-off-by: Paul Holzinger <[email protected]>

Author: Luap99

libpod/healthcheck.go

@@ -4,6 +4,7 @@ package libpod
 
 import (
 	"bufio"
+	"bytes"
 	"context"
 	"errors"
 	"fmt"
@@ -87,30 +88,17 @@ func (c *Container) runHealthCheck(ctx context.Context, isStartup bool) (define.
 	if len(newCommand) < 1 || newCommand[0] == "" {
 		return define.HealthCheckNotDefined, "", fmt.Errorf("container %s has no defined healthcheck", c.ID())
 	}
-	rPipe, wPipe, err := os.Pipe()
-	if err != nil {
-		return define.HealthCheckInternalError, "", fmt.Errorf("unable to create pipe for healthcheck session: %w", err)
-	}
-	defer wPipe.Close()
-	defer rPipe.Close()
 
 	streams := new(define.AttachStreams)
+	output := &bytes.Buffer{}
 
 	streams.InputStream = bufio.NewReader(os.Stdin)
-	streams.OutputStream = wPipe
-	streams.ErrorStream = wPipe
+	streams.OutputStream = output
+	streams.ErrorStream = output
 	streams.AttachOutput = true
 	streams.AttachError = true
 	streams.AttachInput = true
 
-	stdout := []string{}
-	go func() {
-		scanner := bufio.NewScanner(rPipe)
-		for scanner.Scan() {
-			stdout = append(stdout, scanner.Text())
-		}
-	}()
-
 	logrus.Debugf("executing health check command %s for %s", strings.Join(newCommand, " "), c.ID())
 	timeStart := time.Now()
 	hcResult := define.HealthCheckSuccess
@@ -154,7 +142,7 @@ func (c *Container) runHealthCheck(ctx context.Context, isStartup bool) (define.
 		}
 	}
 
-	eventLog := strings.Join(stdout, "\n")
+	eventLog := output.String()
 	if len(eventLog) > MaxHealthCheckLogLength {
 		eventLog = eventLog[:MaxHealthCheckLogLength]
 	}

test/e2e/healthcheck_run_test.go

@@ -41,25 +41,22 @@ var _ = Describe("Podman healthcheck run", func() {
 	})
 
 	It("podman run healthcheck and logs should contain healthcheck output", func() {
-		session := podmanTest.Podman([]string{"run", "--name", "test-logs", "-dt", "--health-interval", "1s", "--health-cmd", "echo working", "busybox", "sleep", "3600"})
+		session := podmanTest.Podman([]string{"run", "--name", "test-logs", "-dt", "--health-interval", "1s",
+			// echo -n is important for https://github.com/containers/podman/issues/23332
+			"--health-cmd", "echo -n working", ALPINE, "sleep", "3600"})
 		session.WaitWithDefaultTimeout()
 		Expect(session).Should(ExitCleanly())
 
-		// Buy a little time to get container running
-		for i := 0; i < 5; i++ {
-			hc := podmanTest.Podman([]string{"healthcheck", "run", "test-logs"})
-			hc.WaitWithDefaultTimeout()
-			exitCode := hc.ExitCode()
-			if exitCode == 0 || i == 4 {
-				break
-			}
-			time.Sleep(1 * time.Second)
-		}
+		hc := podmanTest.Podman([]string{"healthcheck", "run", "test-logs"})
+		hc.WaitWithDefaultTimeout()
+		Expect(hc).Should(ExitCleanly())
 
-		hc := podmanTest.Podman([]string{"container", "inspect", "--format", "{{.State.Healthcheck.Log}}", "test-logs"})
+		// using json formatter here to make sure the newline is not part of the output string an just added by podman inspect
+		hc = podmanTest.Podman([]string{"container", "inspect", "--format", "{{json (index .State.Healthcheck.Log 0).Output}}", "test-logs"})
 		hc.WaitWithDefaultTimeout()
 		Expect(hc).Should(ExitCleanly())
-		Expect(hc.OutputToString()).To(ContainSubstring("working"))
+		// exact output match for https://github.com/containers/podman/issues/23332
+		Expect(string(hc.Out.Contents())).To(Equal("\"working\"\n"))
 	})
 
 	It("podman healthcheck from image's config (not container config)", func() {

test/system/220-healthcheck.bats

@@ -59,7 +59,7 @@ function _check_health {
 Status           | \"healthy\"
 FailingStreak    | 0
 Log[-1].ExitCode | 0
-Log[-1].Output   | \"Life is Good on stdout\\\nLife is Good on stderr\"
+Log[-1].Output   | \"Life is Good on stdout\\\nLife is Good on stderr\\\n\"
 " "$current_time" "healthy"
 
     current_time=$(date --iso-8601=seconds)
@@ -71,7 +71,7 @@ Log[-1].Output   | \"Life is Good on stdout\\\nLife is Good on stderr\"
 Status           | \"healthy\"
 FailingStreak    | [123]
 Log[-1].ExitCode | 1
-Log[-1].Output   | \"Uh-oh on stdout!\\\nUh-oh on stderr!\"
+Log[-1].Output   | \"Uh-oh on stdout!\\\nUh-oh on stderr!\\\n\"
 " "$current_time" "healthy"
 
     # Check that we now we do have valid podman units with this
@@ -85,7 +85,7 @@ Log[-1].Output   | \"Uh-oh on stdout!\\\nUh-oh on stderr!\"
 Status           | \"unhealthy\"
 FailingStreak    | [3456]
 Log[-1].ExitCode | 1
-Log[-1].Output   | \"Uh-oh on stdout!\\\nUh-oh on stderr!\"
+Log[-1].Output   | \"Uh-oh on stdout!\\\nUh-oh on stderr!\\\n\"
 " "$current_time" "unhealthy"
 
     # now the on-failure should kick in and kill the container