Merge branch '18659-cast-devnum'

[arvados.git] / services / keep-web / cache.go

diff --git a/services/keep-web/cache.go b/services/keep-web/cache.go
index 16fbd0788cb3840f299d649aa73378aae579fce1..d2c79326af1ec45a03cb852f3e69b96c61b590d3 100644 (file)
--- a/services/keep-web/cache.go
+++ b/services/keep-web/cache.go
@@ -14,6 +14,7 @@ import (
        "git.arvados.org/arvados.git/sdk/go/keepclient"
        lru "github.com/hashicorp/golang-lru"
        "github.com/prometheus/client_golang/prometheus"
+       "github.com/sirupsen/logrus"
 )
 
 const metricsUpdateInterval = time.Second / 10
@@ -21,6 +22,7 @@ const metricsUpdateInterval = time.Second / 10
 type cache struct {
        cluster     *arvados.Cluster
        config      *arvados.WebDAVCacheConfig // TODO: use cluster.Collections.WebDAV instead
+       logger      logrus.FieldLogger
        registry    *prometheus.Registry
        metrics     cacheMetrics
        pdhs        *lru.TwoQueueCache
@@ -332,12 +334,15 @@ func (c *cache) Get(arv *arvadosclient.ArvadosClient, targetID string, forceRelo
        if pdh == "" {
                // UUID->PDH mapping is not cached, might as well get
                // the whole collection record and be done (below).
+               c.logger.Debugf("cache(%s): have no pdh", targetID)
        } else if cached := c.lookupCollection(arv.ApiToken + "\000" + pdh); cached == nil {
                // PDH->manifest is not cached, might as well get the
                // whole collection record (below).
+               c.logger.Debugf("cache(%s): have pdh %s but manifest is not cached", targetID, pdh)
        } else if !pdhRefresh {
                // We looked up UUID->PDH very recently, and we still
                // have the manifest for that PDH.
+               c.logger.Debugf("cache(%s): have pdh %s and refresh not needed", targetID, pdh)
                return cached, nil
        } else {
                // Get current PDH for this UUID (and confirm we still
@@ -353,11 +358,13 @@ func (c *cache) Get(arv *arvadosclient.ArvadosClient, targetID string, forceRelo
                if current.PortableDataHash == pdh {
                        // PDH has not changed, cached manifest is
                        // correct.
-                       return cached, err
+                       c.logger.Debugf("cache(%s): verified cached pdh %s is still correct", targetID, pdh)
+                       return cached, nil
                }
                if cached := c.lookupCollection(arv.ApiToken + "\000" + current.PortableDataHash); cached != nil {
                        // PDH changed, and we already have the
                        // manifest for that new PDH.
+                       c.logger.Debugf("cache(%s): cached pdh %s was stale, new pdh is %s and manifest is already in cache", targetID, pdh, current.PortableDataHash)
                        return cached, nil
                }
        }
@@ -370,6 +377,7 @@ func (c *cache) Get(arv *arvadosclient.ArvadosClient, targetID string, forceRelo
        if err != nil {
                return nil, err
        }
+       c.logger.Debugf("cache(%s): retrieved manifest, caching with pdh %s", targetID, retrieved.PortableDataHash)
        exp := time.Now().Add(time.Duration(c.config.TTL))
        if targetID != retrieved.PortableDataHash {
                c.pdhs.Add(targetID, &cachedPDH{