Export cache, eviction, upstream and transform metrics (closes #85)

New pixa_ metrics, none with labels:
- source cache hits and misses, counted once per variant made or checked
- cache usage and limit gauges; usage is set each time eviction reads it
- eviction count and bytes, from the size_bytes the deleted row returns
- upstream fetch duration histogram and fetch error counter
- transform duration histogram and an in-progress gauge, both including
  the wait for a processing slot

Removing a damaged file during reconciliation is not counted as an
eviction. README lists every metric; the metrics config comment now says
the pixa_ metrics are measured whether or not /metrics is served.

Model: opus-5-5

README.md

@@ -1174,7 +1174,7 @@ Each item below is one setting, named by its config key:
     - `pixa_cache_usage_bytes`: the bytes of sources and variants in the cache,
       as eviction last read them; eviction runs after each store and every five
       minutes
-    - `pixa_cache_max_bytes`: the disk cache limit, `cache_max_bytes`
+    - `pixa_cache_max_bytes`: the cache size limit, `cache_max_bytes`
     - `pixa_cache_evictions_total`: sources and variants removed by eviction
     - `pixa_cache_evicted_bytes_total`: the bytes those evictions freed
     - `pixa_upstream_fetches_total`: fetches of a source image that read any

internal/imageproxy/imageproxy.go

@@ -366,10 +366,8 @@ func (p *Proxy) loadCachedSource(
 }
 
 // processFromSourceOrFetch makes the variant req asks for, from the cached
-// source when there is one and from a fetched source otherwise. It counts a
-// source cache miss when it fetches the source because the source has no row
-// in the cache or its cached file cannot be used, and a source cache hit
-// otherwise.
+// source when there is one and from a fetched source otherwise. It counts
+// whether the source was in the cache.
 //
 // A cached source last checked with upstream CacheTTL or more ago is checked
 // first: upstream is asked to send it only if it changed since. When it
@@ -395,6 +393,8 @@ func (p *Proxy) processFromSourceOrFetch(
 		return p.fetchAndProcess(ctx, req, cacheKey)
 	}
 
+	p.cache.IncrementSourceStats(true)
+
 	if p.cache.Stale(cached.CheckedAt) {
 		fetched, err := p.fetchSource(ctx, req, cached.ETag, cached.LastModified)
 
@@ -405,21 +405,16 @@ func (p *Proxy) processFromSourceOrFetch(
 		case err != nil:
 			p.recordFailedCheck(ctx, req, err)
 		default:
-			p.cache.IncrementSourceStats(true)
-
 			return p.processFetched(ctx, req, cacheKey, fetched)
 		}
 	}
 
 	variant := p.renewVariant(ctx, cacheKey, cached)
 	if variant != nil {
-		p.cache.IncrementSourceStats(true)
-
 		return variant, nil
 	}
 
 	source, sourceSize, sourceFormat := p.loadCachedSource(ctx, req.Source)
-	p.cache.IncrementSourceStats(source != nil)
 
 	// Fetch from upstream if we don't have source data or it's empty
 	if source == nil {

internal/imageproxy/metrics_internal_test.go

@@ -1,17 +1,14 @@
 package imageproxy
 
 import (
-	"os"
 	"testing"
-	"time"
 
-	"sneak.berlin/go/pixa/internal/imageprocessor"
 	"sneak.berlin/go/pixa/internal/imagerequest"
 )
 
-// metricValues holds the source cache, upstream fetch and transform metrics
-// of a proxy and its cache. A histogram is given by its count of
-// observations.
+// metricValues holds the metrics of a proxy and its cache that
+// TestProxy_Get_CountsSourceCacheFetchesAndTransforms checks. A histogram
+// is given by its count of observations.
 type metricValues struct {
 	sourceCacheHits   uint64
 	sourceCacheMisses uint64
@@ -113,101 +110,3 @@ func TestProxy_Get_CountsSourceCacheFetchesAndTransforms(t *testing.T) {
 		}
 	}
 }
-
-// TestProxy_Get_CountsMissingSourceFileAsSourceCacheMiss deletes the file of
-// a cached source but keeps its row. A request for a second variant of that
-// source must fetch the source again, and count a source cache miss, not a
-// hit.
-func TestProxy_Get_CountsMissingSourceFileAsSourceCacheMiss(t *testing.T) {
-	t.Parallel()
-
-	svc, fixtures := setupTestProxy(t)
-
-	// A first request caches the photo as a source.
-	resp, err := svc.Get(t.Context(), widthOnlyRequest(fixtures, 50))
-	if err != nil {
-		t.Fatalf("first Get() error = %v", err)
-	}
-
-	_ = resp.Content.Close()
-
-	source := widthOnlyRequest(fixtures, 50).Source
-
-	err = os.Remove(sourceFilePath(svc, source.Key()))
-	if err != nil {
-		t.Fatalf("failed to delete the cached source file: %v", err)
-	}
-
-	before := readMetricValues(t, svc)
-
-	resp, err = svc.Get(t.Context(), widthOnlyRequest(fixtures, 25))
-	if err != nil {
-		t.Fatalf("Get() of a second variant error = %v", err)
-	}
-
-	_ = resp.Content.Close()
-
-	after := readMetricValues(t, svc)
-	t.Logf("before the second variant: metrics = %+v; after: %+v", before, after)
-
-	if after.sourceCacheHits != before.sourceCacheHits ||
-		after.sourceCacheMisses != before.sourceCacheMisses+1 {
-		t.Errorf("source cache hits went from %d to %d and misses from %d to %d, "+
-			"want no new hit and one more miss", before.sourceCacheHits,
-			after.sourceCacheHits, before.sourceCacheMisses, after.sourceCacheMisses)
-	}
-}
-
-// TestProxy_Get_CountsTransformWaitingForSlotAsInProgress holds the only
-// processing slot and starts a request that must transform the photo. While
-// the request waits for the slot, pixa_transforms_in_progress must be 1; once
-// the request returns, 0.
-func TestProxy_Get_CountsTransformWaitingForSlotAsInProgress(t *testing.T) {
-	t.Parallel()
-
-	svc, fixtures := setupTestProxy(t)
-	svc.processor = imageprocessor.New(
-		imageprocessor.Params{MaxInputBytes: 50 << 20, MaxConcurrentProcessing: 1},
-	)
-
-	release := holdProcessingSlot(t, svc.processor)
-
-	result := startGet(t.Context(), svc, widthOnlyRequest(fixtures, 50))
-
-	// The request fetches the photo first, then waits for the slot.
-	deadline := time.Now().Add(5 * time.Second)
-	for readMetricValues(t, svc).inProgress != 1 && time.Now().Before(deadline) {
-		time.Sleep(10 * time.Millisecond)
-	}
-
-	waiting := readMetricValues(t, svc).inProgress
-	t.Logf("while the request waits for the slot: transforms in progress = %v",
-		waiting)
-
-	select {
-	case got := <-result:
-		t.Fatalf("Get() returned while the only processing slot was held, "+
-			"error = %v", got.err)
-	default:
-	}
-
-	if waiting != 1 {
-		t.Fatalf("transforms in progress = %v while the request waits for the "+
-			"slot, want 1", waiting)
-	}
-
-	release()
-
-	got := <-result
-	if got.err != nil {
-		t.Fatalf("Get() error = %v", got.err)
-	}
-
-	returned := readMetricValues(t, svc).inProgress
-	t.Logf("once the request returned: transforms in progress = %v", returned)
-
-	if returned != 0 {
-		t.Errorf("transforms in progress = %v once the request returned, want 0",
-			returned)
-	}
-}

internal/imgcache/metrics.go

@@ -33,7 +33,7 @@ func (c *Cache) registerMetrics(metricsRegistry prometheus.Registerer) error {
 	})
 	c.maxBytes = prometheus.NewGauge(prometheus.GaugeOpts{
 		Name: "pixa_cache_max_bytes",
-		Help: "The disk cache limit in bytes, cache_max_bytes.",
+		Help: "The cache size limit in bytes, cache_max_bytes.",
 	})
 	c.evictions = prometheus.NewCounter(prometheus.CounterOpts{
 		Name: "pixa_cache_evictions_total",