Ensure HC events fire after logs are written

HC events were firing as part of the `exec` call, before it had
even been decided whether the HC succeeded or failed. As such,
the status was not going to be correct any time there was a
change (e.g. the first event after a container went healthy to
unhealthy would still read healthy). Move the event into the
actual Healthcheck function and throw it in a defer to make sure
it happens at the very end, after logs are written.

Ignores several conditions that did not log previously (container
in question does not have a healthcheck, or an internal failure
that should not really happen).

Still not a perfect solution. This relies on the HC log being
written, when instead we could just get the status straight from
the function writing the event - so if we fail to write the log,
we can still report a bad status. But if the log wasn't written,
we're in bad shape regardless - `podman ps` would disagree with
the event written, for example.

Fixes containers#19237

Signed-off-by: Matt Heon <[email protected]>

libpod/container_exec.go

@@ -321,9 +321,7 @@ func (c *Container) execStartAndAttach(sessionID string, streams *define.AttachS
 		return err
 	}
 
-	if isHealthcheck {
-		c.newContainerEvent(events.HealthStatus)
-	} else {
+	if !isHealthcheck {
 		c.newContainerEvent(events.Exec)
 	}
 

libpod/healthcheck.go

@@ -11,6 +11,7 @@ import (
 	"time"
 
 	"github.com/containers/podman/v4/libpod/define"
+	"github.com/containers/podman/v4/libpod/events"
 	"github.com/sirupsen/logrus"
 	"golang.org/x/sys/unix"
 )
@@ -60,6 +61,7 @@ func (c *Container) runHealthCheck(ctx context.Context, isStartup bool) (define.
 		returnCode    int
 		inStartPeriod bool
 	)
+
 	hcCommand := c.HealthCheckConfig().Test
 	if isStartup {
 		logrus.Debugf("Running startup healthcheck for container %s", c.ID())
@@ -167,6 +169,13 @@ func (c *Container) runHealthCheck(ctx context.Context, isStartup bool) (define.
 		return hcResult, "", fmt.Errorf("unable to update health check log %s for %s: %w", c.healthCheckLogPath(), c.ID(), err)
 	}
 
+	// Write HC event with appropriate status as the last thing before we
+	// return.
+	if hcResult == define.HealthCheckNotDefined || hcResult == define.HealthCheckInternalError {
+		return hcResult, logStatus, hcErr
+	}
+	c.newContainerEvent(events.HealthStatus)
+
 	return hcResult, logStatus, hcErr
 }
 

test/e2e/healthcheck_run_test.go

@@ -245,6 +245,16 @@ var _ = Describe("Podman healthcheck run", func() {
 		inspect = podmanTest.InspectContainer("hc")
 		Expect(inspect[0].State.Health).To(HaveField("Status", define.HealthCheckHealthy))
 
+		// Test that events generated have correct status (#19237)
+		events := podmanTest.Podman([]string{"events", "--stream=false", "--filter", "event=health_status", "--since", "1m"})
+		events.WaitWithDefaultTimeout()
+		Expect(events).Should(Exit(0))
+		eventsOut := events.OutputToStringArray()
+		Expect(eventsOut).To(HaveLen(3))
+		Expect(eventsOut[0]).To(ContainSubstring("health_status=starting"))
+		Expect(eventsOut[1]).To(ContainSubstring("health_status=unhealthy"))
+		Expect(eventsOut[2]).To(ContainSubstring("health_status=healthy"))
+
 		// Test podman ps --filter health is working (#11687)
 		ps := podmanTest.Podman([]string{"ps", "--filter", "health=healthy"})
 		ps.WaitWithDefaultTimeout()