Improve logging output for failing healthchecks

healthcheck/healthcheck.go

@@ -42,6 +42,7 @@ func (opt Options) String() string {
 // BackendHealthCheck HealthCheck configuration for a backend
 type BackendHealthCheck struct {
 	Options
+	name           string
 	disabledURLs   []*url.URL
 	requestTimeout time.Duration
 }
@@ -66,9 +67,10 @@ func newHealthCheck() *HealthCheck {
 }
 
 // NewBackendHealthCheck Instantiate a new BackendHealthCheck
-func NewBackendHealthCheck(options Options) *BackendHealthCheck {
+func NewBackendHealthCheck(options Options, backendName string) *BackendHealthCheck {
 	return &BackendHealthCheck{
 		Options:        options,
+		name:           backendName,
 		requestTimeout: 5 * time.Second,
 	}
 }
@@ -82,51 +84,50 @@ func (hc *HealthCheck) SetBackendsConfiguration(parentCtx context.Context, backe
 	ctx, cancel := context.WithCancel(parentCtx)
 	hc.cancel = cancel
 
-	for backendID, backend := range hc.Backends {
+	for _, backend := range hc.Backends {
-		currentBackendID := backendID
 		currentBackend := backend
 		safe.Go(func() {
-			hc.execute(ctx, currentBackendID, currentBackend)
+			hc.execute(ctx, currentBackend)
 		})
 	}
 }
 
-func (hc *HealthCheck) execute(ctx context.Context, backendID string, backend *BackendHealthCheck) {
+func (hc *HealthCheck) execute(ctx context.Context, backend *BackendHealthCheck) {
-	log.Debugf("Initial healthcheck for currentBackend %s ", backendID)
+	log.Debugf("Initial health check for backend: %q", backend.name)
-	checkBackend(backend)
+	hc.checkBackend(backend)
 	ticker := time.NewTicker(backend.Interval)
 	defer ticker.Stop()
 	for {
 		select {
 		case <-ctx.Done():
-			log.Debug("Stopping all current Healthcheck goroutines")
+			log.Debug("Stopping current health check goroutines of backend: %s", backend.name)
 			return
 		case <-ticker.C:
-			log.Debugf("Refreshing healthcheck for currentBackend %s ", backendID)
+			log.Debugf("Refreshing health check for backend: %s", backend.name)
-			checkBackend(backend)
+			hc.checkBackend(backend)
 		}
 	}
 }
 
-func checkBackend(currentBackend *BackendHealthCheck) {
+func (hc *HealthCheck) checkBackend(backend *BackendHealthCheck) {
-	enabledURLs := currentBackend.LB.Servers()
+	enabledURLs := backend.LB.Servers()
 	var newDisabledURLs []*url.URL
-	for _, url := range currentBackend.disabledURLs {
+	for _, url := range backend.disabledURLs {
-		if checkHealth(url, currentBackend) {
+		if err := checkHealth(url, backend); err == nil {
-			log.Debugf("HealthCheck is up [%s]: Upsert in server list", url.String())
+			log.Warnf("Health check up: Returning to server list. Backend: %q URL: %q", backend.name, url.String())
-			currentBackend.LB.UpsertServer(url, roundrobin.Weight(1))
+			backend.LB.UpsertServer(url, roundrobin.Weight(1))
 		} else {
-			log.Warnf("HealthCheck is still failing [%s]", url.String())
+			log.Warnf("Health check still failing. Backend: %q URL: %q Reason: %s", backend.name, url.String(), err)
 			newDisabledURLs = append(newDisabledURLs, url)
 		}
 	}
-	currentBackend.disabledURLs = newDisabledURLs
+	backend.disabledURLs = newDisabledURLs
 
 	for _, url := range enabledURLs {
-		if !checkHealth(url, currentBackend) {
+		if err := checkHealth(url, backend); err != nil {
-			log.Warnf("HealthCheck has failed [%s]: Remove from server list", url.String())
+			log.Warnf("Health check failed: Remove from server list. Backend: %q URL: %q Reason: %s", backend.name, url.String(), err)
-			currentBackend.LB.RemoveServer(url)
+			backend.LB.RemoveServer(url)
-			currentBackend.disabledURLs = append(currentBackend.disabledURLs, url)
+			backend.disabledURLs = append(backend.disabledURLs, url)
 		}
 	}
 }
@@ -145,21 +146,28 @@ func (backend *BackendHealthCheck) newRequest(serverURL *url.URL) (*http.Request
 	return http.NewRequest(http.MethodGet, u.String(), nil)
 }
 
-func checkHealth(serverURL *url.URL, backend *BackendHealthCheck) bool {
+// checkHealth returns a nil error in case it was successful and otherwise
+// a non-nil error with a meaningful description why the health check failed.
+func checkHealth(serverURL *url.URL, backend *BackendHealthCheck) error {
 	client := http.Client{
 		Timeout:   backend.requestTimeout,
 		Transport: backend.Options.Transport,
 	}
 	req, err := backend.newRequest(serverURL)
 	if err != nil {
-		log.Errorf("Failed to create HTTP request [%s] for healthcheck: %s", serverURL, err)
+		return fmt.Errorf("failed to create HTTP request: %s", err)
-		return false
 	}
 
 	resp, err := client.Do(req)
-
 	if err == nil {
 		defer resp.Body.Close()
 	}
-	return err == nil && resp.StatusCode == http.StatusOK
+
+	switch {
+	case err != nil:
+		return fmt.Errorf("HTTP request failed: %s", err)
+	case resp.StatusCode != http.StatusOK:
+		return fmt.Errorf("received non-200 status code: %v", resp.StatusCode)
+	}
+	return nil
 }

healthcheck/healthcheck_test.go

@@ -81,7 +81,7 @@ func TestSetBackendsConfiguration(t *testing.T) {
 				Path:     "/path",
 				Interval: healthCheckInterval,
 				LB:       lb,
-			})
+			}, "backendName")
 			serverURL := testhelpers.MustParseURL(ts.URL)
 			if test.startHealthy {
 				lb.servers = append(lb.servers, serverURL)
@@ -95,7 +95,7 @@ func TestSetBackendsConfiguration(t *testing.T) {
 			wg := sync.WaitGroup{}
 			wg.Add(1)
 			go func() {
-				check.execute(ctx, "id", backend)
+				check.execute(ctx, backend)
 				wg.Done()
 			}()
 
@@ -168,7 +168,7 @@ func TestNewRequest(t *testing.T) {
 				Options{
 					Path: test.path,
 					Port: test.port,
-				})
+				}, "backendName")
 
 			u := &url.URL{
 				Scheme: "http",

server/server.go

@@ -1049,7 +1049,7 @@ func (s *Server) loadConfig(configurations types.Configurations, globalConfigura
 						if hcOpts != nil {
 							log.Debugf("Setting up backend health check %s", *hcOpts)
 							hcOpts.Transport = s.defaultForwardingRoundTripper
-							backendsHealthCheck[entryPointName+frontend.Backend] = healthcheck.NewBackendHealthCheck(*hcOpts)
+							backendsHealthCheck[entryPointName+frontend.Backend] = healthcheck.NewBackendHealthCheck(*hcOpts, frontend.Backend)
 						}
 						lb = middlewares.NewEmptyBackendHandler(rebalancer, lb)
 					case types.Wrr:
@@ -1071,7 +1071,7 @@ func (s *Server) loadConfig(configurations types.Configurations, globalConfigura
 						if hcOpts != nil {
 							log.Debugf("Setting up backend health check %s", *hcOpts)
 							hcOpts.Transport = s.defaultForwardingRoundTripper
-							backendsHealthCheck[entryPointName+frontend.Backend] = healthcheck.NewBackendHealthCheck(*hcOpts)
+							backendsHealthCheck[entryPointName+frontend.Backend] = healthcheck.NewBackendHealthCheck(*hcOpts, frontend.Backend)
 						}
 						lb = middlewares.NewEmptyBackendHandler(rr, lb)
 					}