Repository: caddyserver/caddy (language: go)

Issue:
Active health check logs on every check instead of state change
Hello, first of all thanks for caddy, I enjoy using it!

I recently updated from 2.7.6 to 2.8.4, because I required the behavior of not following HTTP redirects on active health checks and noticed that, as opposed to 2.7.6, the newer version logs the host status on every active check when the host is up instead of only when the state changes from down to up.

I investigated the source and found that the logic was changed between the versions. In 2.7.6 the log was written when the event was emitted (https://github.com/caddyserver/caddy/blob/v2.7.6/modules/caddyhttp/reverseproxy/healthchecks.go#L443) while in 2.8.4 the emitting of the event was refactored into `markHealthy()` with the logging being moved to a higher level (https://github.com/caddyserver/caddy/blob/v2.8.4/modules/caddyhttp/reverseproxy/healthchecks.go#L495)

I am not sure this is the intended behavior as it fills the log quickly with identical messages (except for the timestamp of course).

I think the simplest solution would be to move the logging of "host is up" (L495) into `markHealthy()` (after L428) because it checks for the previous state before emitting the event.

Thank you and best regards!
Active health check logs on every check instead of state change
Hello, first of all thanks for caddy, I enjoy using it!

I recently updated from 2.7.6 to 2.8.4, because I required the behavior of not following HTTP redirects on active health checks and noticed that, as opposed to 2.7.6, the newer version logs the host status on every active check when the host is up instead of only when the state changes from down to up.

I investigated the source and found that the logic was changed between the versions. In 2.7.6 the log was written when the event was emitted (https://github.com/caddyserver/caddy/blob/v2.7.6/modules/caddyhttp/reverseproxy/healthchecks.go#L443) while in 2.8.4 the emitting of the event was refactored into `markHealthy()` with the logging being moved to a higher level (https://github.com/caddyserver/caddy/blob/v2.8.4/modules/caddyhttp/reverseproxy/healthchecks.go#L495)

I am not sure this is the intended behavior as it fills the log quickly with identical messages (except for the timestamp of course).

I think the simplest solution would be to move the logging of "host is up" (L495) into `markHealthy()` (after L428) because it checks for the previous state before emitting the event.

Thank you and best regards!


Discussion / hints:

Fix patch:
diff --git a/modules/caddyhttp/reverseproxy/healthchecks.go b/modules/caddyhttp/reverseproxy/healthchecks.go
index 90db9b3402a..888dadb794a 100644
--- a/modules/caddyhttp/reverseproxy/healthchecks.go
+++ b/modules/caddyhttp/reverseproxy/healthchecks.go
@@ -426,6 +426,7 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, upstre
 		}
 		if upstream.Host.activeHealthPasses() >= h.HealthChecks.Active.Passes {
 			if upstream.setHealthy(true) {
+				h.HealthChecks.Active.logger.Info("host is up", zap.String("host", hostAddr))
 				h.events.Emit(h.ctx, "healthy", map[string]any{"host": hostAddr})
 				upstream.Host.resetHealth()
 			}
@@ -492,7 +493,6 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, upstre
 	}
 
 	// passed health check parameters, so mark as healthy
-	h.HealthChecks.Active.logger.Info("host is up", zap.String("host", hostAddr))
 	markHealthy()
 
 	return nil


Test patch: