fix redis caching issue

* fix redis caching issue

earlier redis cache was updated when there was any error including any
temporary connectivity issue. This would trigger set calls which would
further increase load and possibly connectivity errors from redis
leaving the system with continuous errors and high latency. Now the
cache is updated only when it is genuine cache miss. Other errors do not
trigger a cache update.

* add back tracker Hit() and Miss() calls

*squashed commits*
(cherry picked from commit 6f3e1c10260ef59ba4e9c42e939329fad9fdd8c3)
(cherry picked from commit 6738ff3320cf82cc2df919a95a1bde2f7789a501)

Signed-off-by: Derek McGowan <derek@mcgstyle.net>

registry/storage/cache/cachedblobdescriptorstore.go

@@ -4,6 +4,7 @@ import (
 	"context"
 
 	"github.com/docker/distribution"
+	dcontext "github.com/docker/distribution/context"
 	prometheus "github.com/docker/distribution/metrics"
 	"github.com/opencontainers/go-digest"
 )
@@ -65,35 +66,41 @@ func NewCachedBlobStatterWithMetrics(cache distribution.BlobDescriptorService, b
 
 func (cbds *cachedBlobStatter) Stat(ctx context.Context, dgst digest.Digest) (distribution.Descriptor, error) {
 	cacheCount.WithValues("Request").Inc(1)
-	desc, err := cbds.cache.Stat(ctx, dgst)
-	if err != nil {
-		if err != distribution.ErrBlobUnknown {
-			logErrorf(ctx, cbds.tracker, "error retrieving descriptor from cache: %v", err)
-		}
 
-		goto fallback
+	// try getting from cache
-	}
+	desc, cacheErr := cbds.cache.Stat(ctx, dgst)
+	if cacheErr == nil {
 		cacheCount.WithValues("Hit").Inc(1)
 		if cbds.tracker != nil {
 			cbds.tracker.Hit()
 		}
 		return desc, nil
-fallback:
-	cacheCount.WithValues("Miss").Inc(1)
-	if cbds.tracker != nil {
-		cbds.tracker.Miss()
 	}
-	desc, err = cbds.backend.Stat(ctx, dgst)
+
+	// couldn't get from cache; get from backend
+	desc, err := cbds.backend.Stat(ctx, dgst)
 	if err != nil {
 		return desc, err
 	}
 
+	if cacheErr == distribution.ErrBlobUnknown {
+		// cache doesn't have info. update it with info got from backend
+		cacheCount.WithValues("Miss").Inc(1)
+		if cbds.tracker != nil {
+			cbds.tracker.Miss()
+		}
 		if err := cbds.cache.SetDescriptor(ctx, dgst, desc); err != nil {
-		logErrorf(ctx, cbds.tracker, "error adding descriptor %v to cache: %v", desc.Digest, err)
+			dcontext.GetLoggerWithField(ctx, "blob", dgst).WithError(err).Error("error from cache setting desc")
+		}
+		// we don't need to return cache error upstream if any. continue returning value from backend
+		return desc, nil
 	}
 
-	return desc, err
+	// unknown error from cache. just log and error. do not store cache as it may be trigger many set calls
+	dcontext.GetLoggerWithField(ctx, "blob", dgst).WithError(cacheErr).Error("error from cache stat(ing) blob")
+	cacheCount.WithValues("Error").Inc(1)
 
+	return desc, nil
 }
 
 func (cbds *cachedBlobStatter) Clear(ctx context.Context, dgst digest.Digest) error {
@@ -111,7 +118,7 @@ func (cbds *cachedBlobStatter) Clear(ctx context.Context, dgst digest.Digest) er
 
 func (cbds *cachedBlobStatter) SetDescriptor(ctx context.Context, dgst digest.Digest, desc distribution.Descriptor) error {
 	if err := cbds.cache.SetDescriptor(ctx, dgst, desc); err != nil {
-		logErrorf(ctx, cbds.tracker, "error adding descriptor %v to cache: %v", desc.Digest, err)
+		dcontext.GetLoggerWithField(ctx, "blob", dgst).WithError(err).Error("error from cache setting desc")
 	}
 	return nil
 }