From cbd54470ba1992079e50f5450672ea356b73795b Mon Sep 17 00:00:00 2001 From: Marco Jantke Date: Wed, 3 Jan 2018 12:32:03 +0100 Subject: [PATCH] Improve logging output for failing healthchecks --- healthcheck/healthcheck.go | 62 +++++++++++++++++++-------------- healthcheck/healthcheck_test.go | 6 ++-- server/server.go | 4 +-- 3 files changed, 40 insertions(+), 32 deletions(-) diff --git a/healthcheck/healthcheck.go b/healthcheck/healthcheck.go index b3c6ace09..c77ee86c4 100644 --- a/healthcheck/healthcheck.go +++ b/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 { - currentBackendID := backendID + for _, backend := range hc.Backends { 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) { - log.Debugf("Initial healthcheck for currentBackend %s ", backendID) - checkBackend(backend) +func (hc *HealthCheck) execute(ctx context.Context, backend *BackendHealthCheck) { + log.Debugf("Initial health check for backend: %q", backend.name) + 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) - checkBackend(backend) + log.Debugf("Refreshing health check for backend: %s", backend.name) + hc.checkBackend(backend) } } } -func checkBackend(currentBackend *BackendHealthCheck) { - enabledURLs := currentBackend.LB.Servers() +func (hc *HealthCheck) checkBackend(backend *BackendHealthCheck) { + enabledURLs := backend.LB.Servers() var newDisabledURLs []*url.URL - for _, url := range currentBackend.disabledURLs { - if checkHealth(url, currentBackend) { - log.Debugf("HealthCheck is up [%s]: Upsert in server list", url.String()) - currentBackend.LB.UpsertServer(url, roundrobin.Weight(1)) + for _, url := range backend.disabledURLs { + if err := checkHealth(url, backend); err == nil { + log.Warnf("Health check up: Returning to server list. Backend: %q URL: %q", backend.name, url.String()) + 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) { - log.Warnf("HealthCheck has failed [%s]: Remove from server list", url.String()) - currentBackend.LB.RemoveServer(url) - currentBackend.disabledURLs = append(currentBackend.disabledURLs, url) + if err := checkHealth(url, backend); err != nil { + log.Warnf("Health check failed: Remove from server list. Backend: %q URL: %q Reason: %s", backend.name, url.String(), err) + backend.LB.RemoveServer(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 false + return fmt.Errorf("failed to create HTTP request: %s", err) } 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 } diff --git a/healthcheck/healthcheck_test.go b/healthcheck/healthcheck_test.go index fa969379a..81089bb13 100644 --- a/healthcheck/healthcheck_test.go +++ b/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", diff --git a/server/server.go b/server/server.go index cf45781d1..f5d5200aa 100644 --- a/server/server.go +++ b/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) }