From d9b8d30cad62d2fd845fd21e45999ca6b0162d69 Mon Sep 17 00:00:00 2001
From: Daniel Nephin <dnephin@hashicorp.com>
Date: Fri, 12 Feb 2021 12:43:36 -0500
Subject: [PATCH] cache: log a warning when Cache.Notify handles an error

Without these warnings, errors are silently ignored, which can make
debugging problems more challenging.
---
 agent/cache/cache.go                                  |  6 ++++++
 agent/cache/watch.go                                  | 11 +++++++++++
 .../config/testdata/TestRuntimeConfig_Sanitize.golden |  3 ++-
 agent/setup.go                                        |  1 +
 4 files changed, 20 insertions(+), 1 deletion(-)

diff --git a/agent/cache/cache.go b/agent/cache/cache.go
index b5d4b3aafd..8c64b8ac8d 100644
--- a/agent/cache/cache.go
+++ b/agent/cache/cache.go
@@ -25,6 +25,7 @@ import (
 
 	"github.com/armon/go-metrics"
 	"github.com/armon/go-metrics/prometheus"
+	"github.com/hashicorp/go-hclog"
 	"golang.org/x/time/rate"
 
 	"github.com/hashicorp/consul/acl"
@@ -170,6 +171,8 @@ type ResultMeta struct {
 
 // Options are options for the Cache.
 type Options struct {
+	Logger hclog.Logger
+
 	// EntryFetchMaxBurst max burst size of RateLimit for a single cache entry
 	EntryFetchMaxBurst int
 	// EntryFetchRate represents the max calls/sec for a single cache entry
@@ -189,6 +192,9 @@ func applyDefaultValuesOnOptions(options Options) Options {
 	if options.EntryFetchMaxBurst == 0 {
 		options.EntryFetchMaxBurst = DefaultEntryFetchMaxBurst
 	}
+	if options.Logger == nil {
+		options.Logger = hclog.New(nil)
+	}
 	return options
 }
 
diff --git a/agent/cache/watch.go b/agent/cache/watch.go
index 1fa228e39a..f50e280783 100644
--- a/agent/cache/watch.go
+++ b/agent/cache/watch.go
@@ -121,6 +121,12 @@ func (c *Cache) notifyBlockingQuery(ctx context.Context, r getOptions, correlati
 		} else {
 			failures++
 			wait = backOffWait(failures)
+
+			c.options.Logger.
+				With("error", err).
+				With("cache-type", r.TypeEntry.Name).
+				With("index", index).
+				Warn("handling error in Cache.Notify")
 		}
 
 		if wait > 0 {
@@ -177,6 +183,11 @@ func (c *Cache) notifyPollingQuery(ctx context.Context, r getOptions, correlatio
 			failures = 0
 		} else {
 			failures++
+			c.options.Logger.
+				With("error", err).
+				With("cache-type", r.TypeEntry.Name).
+				With("index", index).
+				Warn("handling error in Cache.Notify")
 		}
 
 		var wait time.Duration
diff --git a/agent/config/testdata/TestRuntimeConfig_Sanitize.golden b/agent/config/testdata/TestRuntimeConfig_Sanitize.golden
index 26510be642..921d101d1c 100644
--- a/agent/config/testdata/TestRuntimeConfig_Sanitize.golden
+++ b/agent/config/testdata/TestRuntimeConfig_Sanitize.golden
@@ -74,7 +74,8 @@
     "CAPath": "",
     "Cache": {
         "EntryFetchMaxBurst": 42,
-        "EntryFetchRate": 0.334
+        "EntryFetchRate": 0.334,
+        "Logger": null
     },
     "CertFile": "",
     "CheckDeregisterIntervalMin": "0s",
diff --git a/agent/setup.go b/agent/setup.go
index 63bb300706..0d485f08a0 100644
--- a/agent/setup.go
+++ b/agent/setup.go
@@ -97,6 +97,7 @@ func NewBaseDeps(configLoader ConfigLoader, logOut io.Writer) (BaseDeps, error)
 	d.RuntimeConfig = cfg
 	d.Tokens = new(token.Store)
 
+	cfg.Cache.Logger = d.Logger.Named("cache")
 	// cache-types are not registered yet, but they won't be used until the components are started.
 	d.Cache = cache.New(cfg.Cache)
 	d.ConnPool = newConnPool(cfg, d.Logger, d.TLSConfigurator)