Test that a late hit and a disabled cache are counted right (closes #56)

A hit served after the request context has ended must still move the hit
count, and a disabled disk cache must report no items and no size even
when its database holds rows from an earlier run.

Model: opus-5-5

TODO.md

@@ -37,6 +37,16 @@ exhaustion
   that is sooner, never negative; an allowlisted host's URL that has an `exp`
   follows it too; `immutable` stays, as freshness now ends at the expiry;
   documented in `README.md`.
+- 2026-09-28 cache stats report real numbers (closes #56): `Cache.Stats`
+  counts the cached source images and processed variants (`source_content`
+  plus `variant_content`) and takes their size from `Cache.UsageBytes`,
+  instead of reading `request_cache` and `output_content`, which nothing
+  writes; those two tables are left in the schema. A miss is counted after
+  it is served or fails, even when the request context has ended by then,
+  with the bytes it read from upstream, so `upstream_fetch_count` and
+  `upstream_fetch_bytes` move, including for an upstream body that fails
+  partway or a fetched source that then fails the magic byte check;
+  `transform_count` counts each image the image processor transcodes.
 - 2026-09-28 strip metadata from processed images (closes #82): every output is
   exported with govips' `StripMetadata`, so it carries no EXIF, XMP, IPTC or ICC
   profile; the image is first turned upright with `AutoRotate` (before sizes are

internal/imgcache/cache.go

@@ -419,17 +419,16 @@ func (c *Cache) Stats(ctx context.Context) (*CacheStats, error) {
 		return nil, fmt.Errorf("failed to get cache stats: %w", err)
 	}
 
-	// Get actual item count and total size from content tables
+	// Count and size the cached source images and processed variants
-	err = c.db.QueryRowContext(ctx,
+	err = c.db.QueryRowContext(ctx, `
-		`SELECT COUNT(*) FROM request_cache`,
+		SELECT (SELECT COUNT(*) FROM source_content)
-	).Scan(&stats.TotalItems)
+		     + (SELECT COUNT(*) FROM variant_content)
+	`).Scan(&stats.TotalItems)
 	if err != nil {
 		c.log.Warn("failed to count cache items for stats", "error", err)
 	}
 
-	err = c.db.QueryRowContext(ctx,
+	stats.TotalSizeBytes, err = c.UsageBytes(ctx)
-		`SELECT COALESCE(SUM(size_bytes), 0) FROM output_content`,
-	).Scan(&stats.TotalSizeBytes)
 	if err != nil {
 		c.log.Warn("failed to sum cache size for stats", "error", err)
 	}
@@ -481,6 +480,19 @@ func (c *Cache) IncrementStats(ctx context.Context, hit bool, fetchBytes int64)
 	}
 }
 
+// IncrementTransformCount counts one image transcoded by the image processor.
+func (c *Cache) IncrementTransformCount(ctx context.Context) {
+	_, err := c.db.ExecContext(ctx, `
+		UPDATE cache_stats
+		SET transform_count = transform_count + 1,
+		    last_updated_at = CURRENT_TIMESTAMP
+		WHERE id = 1
+	`)
+	if err != nil {
+		c.log.Warn("failed to count transform", "error", err)
+	}
+}
+
 // writeMetadataSidecar writes the JSON metadata sidecar of a stored source.
 // A failure is logged and is otherwise non-fatal; the metadata is in the
 // database.

internal/imgcache/imgcache.go

@@ -163,9 +163,11 @@ type ImageCache interface {
 
 // CacheStats contains cache statistics
 type CacheStats struct {
-	// TotalItems is the number of cached items
+	// TotalItems is the number of cached source images plus processed
+	// variants
 	TotalItems int64
-	// TotalSizeBytes is the total size of cached content
+	// TotalSizeBytes is the total size of cached source images and
+	// processed variants
 	TotalSizeBytes int64
 	// HitCount is the number of cache hits
 	HitCount int64

internal/imgcache/service.go

@@ -155,12 +155,15 @@ func (s *Service) Get(ctx context.Context, req *ImageRequest) (*ImageResponse, e
 		}
 	}
 
-	// Cache miss - check if we have source content cached
+	// Cache miss - process the cached source or fetch it, then count the
+	// miss with the bytes it fetched from upstream, also when it failed or
+	// the request context has ended meanwhile
 	cacheKey := CacheKey(req)
 
-	s.cache.IncrementStats(ctx, false, 0)
+	response, fetchedBytes, err := s.processFromSourceOrFetch(ctx, req, cacheKey)
+
+	s.cache.IncrementStats(context.WithoutCancel(ctx), false, fetchedBytes)
 
-	response, err := s.processFromSourceOrFetch(ctx, req, cacheKey)
 	if err != nil {
 		return nil, err
 	}
@@ -268,22 +271,20 @@ func (s *Service) loadCachedSource(contentHash ContentHash) []byte {
 }
 
 // processFromSourceOrFetch processes an image, using cached source content
-// if available.
+// if available. It also returns the number of bytes fetched from upstream,
+// as fetchAndProcess does, or 0 when the cached source was used.
 func (s *Service) processFromSourceOrFetch(
 	ctx context.Context,
 	req *ImageRequest,
 	cacheKey VariantKey,
-) (*ImageResponse, error) {
+) (*ImageResponse, int64, error) {
 	// Check if we have cached source content
 	contentHash, _, err := s.cache.LookupSource(ctx, req)
 	if err != nil {
 		s.log.Warn("source lookup failed", "error", err)
 	}
 
-	var (
+	var sourceData []byte
-		sourceData []byte
-		fetchBytes int64
-	)
 
 	if contentHash != "" {
 		s.log.Debug("using cached source", "hash", contentHash)
@@ -292,26 +293,25 @@ func (s *Service) processFromSourceOrFetch(
 
 	// Fetch from upstream if we don't have source data or it's empty
 	if len(sourceData) == 0 {
-		resp, err := s.fetchAndProcess(ctx, req, cacheKey)
+		return s.fetchAndProcess(ctx, req, cacheKey)
-		if err != nil {
-			return nil, err
-		}
-
-		return resp, nil
 	}
 
-	// Process using cached source
+	// Process using cached source; nothing was fetched from upstream
-	fetchBytes = int64(len(sourceData))
+	resp, err := s.processAndStore(
+		ctx, req, cacheKey, sourceData, int64(len(sourceData)),
+	)
 
-	return s.processAndStore(ctx, req, cacheKey, sourceData, fetchBytes)
+	return resp, 0, err
 }
 
 // fetchAndProcess fetches from upstream, processes, and caches the result.
+// It also returns the number of bytes read from upstream, including when
+// reading the response or a later step fails.
 func (s *Service) fetchAndProcess(
 	ctx context.Context,
 	req *ImageRequest,
 	cacheKey VariantKey,
-) (*ImageResponse, error) {
+) (*ImageResponse, int64, error) {
 	// Fetch from upstream
 	sourceURL := req.SourceURL()
 
@@ -330,20 +330,20 @@ func (s *Service) fetchAndProcess(
 			}
 		}
 
-		return nil, fmt.Errorf("upstream fetch failed: %w", err)
+		return nil, 0, fmt.Errorf("upstream fetch failed: %w", err)
 	}
 
 	defer func() { _ = fetchResult.Content.Close() }()
 
 	// Read and validate the source content
 	sourceData, err := io.ReadAll(fetchResult.Content)
+	fetchBytes := int64(len(sourceData))
+
 	if err != nil {
-		return nil, fmt.Errorf("failed to read upstream response: %w", err)
+		return nil, fetchBytes, fmt.Errorf("failed to read upstream response: %w", err)
 	}
 
 	// Calculate download bitrate
-	fetchBytes := int64(len(sourceData))
-
 	var downloadRate string
 
 	if fetchResult.FetchDurationMs > 0 {
@@ -368,7 +368,7 @@ func (s *Service) fetchAndProcess(
 	// Validate magic bytes match content type
 	err = magic.ValidateMagicBytes(sourceData, fetchResult.ContentType)
 	if err != nil {
-		return nil, fmt.Errorf("content validation failed: %w", err)
+		return nil, fetchBytes, fmt.Errorf("content validation failed: %w", err)
 	}
 
 	// Store source content
@@ -378,7 +378,9 @@ func (s *Service) fetchAndProcess(
 		// Continue even if caching fails
 	}
 
-	return s.processAndStore(ctx, req, cacheKey, sourceData, fetchBytes)
+	resp, err := s.processAndStore(ctx, req, cacheKey, sourceData, fetchBytes)
+
+	return resp, fetchBytes, err
 }
 
 // processAndStore processes an image and stores the result.
@@ -406,6 +408,9 @@ func (s *Service) processAndStore(
 
 	processDuration := time.Since(processStart)
 
+	// Counted also when the request context has ended meanwhile
+	s.cache.IncrementTransformCount(context.WithoutCancel(ctx))
+
 	// Read processed content
 	processedData, err := io.ReadAll(processResult.Content)
 	_ = processResult.Content.Close()

internal/imgcache/stats_internal_test.go

@@ -4,6 +4,9 @@ import (
 	"bytes"
 	"context"
 	"database/sql"
+	"image/color"
+	"io"
+	"io/fs"
 	"log/slog"
 	"math"
 	"strings"
@@ -11,6 +14,7 @@ import (
 	"time"
 
 	"sneak.berlin/go/pixa/internal/database"
+	"sneak.berlin/go/pixa/internal/httpfetcher"
 )
 
 func setupStatsTestDB(t *testing.T) *sql.DB {
@@ -125,7 +129,7 @@ func TestStats_LogsFailedCountQueries(t *testing.T) {
 	}
 
 	_, err = db.ExecContext(t.Context(),
-		`DROP TABLE request_cache; DROP TABLE output_content`)
+		`DROP TABLE source_content; DROP TABLE variant_content`)
 	if err != nil {
 		t.Fatal(err)
 	}
@@ -183,3 +187,313 @@ func TestIncrementStats_LogsFailedUpdates(t *testing.T) {
 		}
 	}
 }
+
+// TestStats_TotalsCountSourcesAndVariants verifies that TotalItems and
+// TotalSizeBytes cover the stored source images and processed variants.
+func TestStats_TotalsCountSourcesAndVariants(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	storeEvictionTestSource(t, cache, testHostCDN, testPathCat,
+		bytes.Repeat([]byte{0xAA}, 1000))
+	storeEvictionTestVariant(t, cache, testVariantKeyOne,
+		bytes.Repeat([]byte{0xAB}, 500))
+	storeEvictionTestVariant(t, cache, testVariantKeyTwo,
+		bytes.Repeat([]byte{0xAC}, 250))
+
+	stats, err := cache.Stats(t.Context())
+	if err != nil {
+		t.Fatalf("Stats() error = %v", err)
+	}
+
+	if stats.TotalItems != 3 {
+		t.Errorf("TotalItems = %d, want 3 (1 source, 2 variants)", stats.TotalItems)
+	}
+
+	if stats.TotalSizeBytes != 1750 {
+		t.Errorf("TotalSizeBytes = %d, want 1750 (1000+500+250)",
+			stats.TotalSizeBytes)
+	}
+}
+
+// TestStats_DisabledCacheReportsNoItems verifies that a disabled disk cache
+// reports no items and no size, even when its database still holds the
+// rows of an earlier run with the disk cache enabled.
+func TestStats_DisabledCacheReportsNoItems(t *testing.T) {
+	t.Parallel()
+
+	enabled, _ := newEvictionTestCache(t, 1<<30)
+
+	storeEvictionTestSource(t, enabled, testHostCDN, testPathCat,
+		bytes.Repeat([]byte{0xAA}, 1000))
+	storeEvictionTestVariant(t, enabled, testVariantKeyOne,
+		bytes.Repeat([]byte{0xAB}, 500))
+
+	disabled, err := NewCache(enabled.db, CacheConfig{
+		StateDir:         t.TempDir(),
+		CacheTTL:         time.Hour,
+		NegativeTTL:      5 * time.Minute,
+		DisableDiskCache: true,
+	})
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	stats, err := disabled.Stats(t.Context())
+	if err != nil {
+		t.Fatalf("Stats() error = %v", err)
+	}
+
+	if stats.TotalItems != 0 || stats.TotalSizeBytes != 0 {
+		t.Errorf("TotalItems = %d, TotalSizeBytes = %d, want 0 and 0",
+			stats.TotalItems, stats.TotalSizeBytes)
+	}
+}
+
+// cacheStatsCounters holds the counters of the cache_stats row, in column
+// order.
+type cacheStatsCounters struct {
+	hitCount           int64
+	missCount          int64
+	upstreamFetchCount int64
+	upstreamFetchBytes int64
+	transformCount     int64
+}
+
+// readCacheStatsCounters reads the counters of the cache_stats row.
+func readCacheStatsCounters(t *testing.T, cache *Cache) cacheStatsCounters {
+	t.Helper()
+
+	var got cacheStatsCounters
+
+	err := cache.db.QueryRowContext(t.Context(), `
+		SELECT hit_count, miss_count, upstream_fetch_count,
+		       upstream_fetch_bytes, transform_count
+		FROM cache_stats WHERE id = 1
+	`).Scan(&got.hitCount, &got.missCount, &got.upstreamFetchCount,
+		&got.upstreamFetchBytes, &got.transformCount)
+	if err != nil {
+		t.Fatalf("failed to read cache_stats: %v", err)
+	}
+
+	return got
+}
+
+// TestService_Get_CountsStats walks Get through a miss that fetches the
+// source, a hit, a miss that reuses the cached source, and two misses whose
+// source cannot be used, checking every cache_stats counter after each.
+func TestService_Get_CountsStats(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures := SetupTestService(t)
+
+	// NewTestFS builds the same files the test service's fetcher serves.
+	testFS, _ := NewTestFS(t)
+
+	photo, err := fs.ReadFile(testFS, fixtures.GoodHostJPEG)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	fake, err := fs.ReadFile(testFS, fixtures.InvalidFile)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	photoBytes, fakeBytes := int64(len(photo)), int64(len(fake))
+
+	// want is hits, misses, upstream fetches, upstream bytes, transforms.
+	steps := []struct {
+		name    string
+		path    string
+		size    int
+		wantErr bool
+		want    cacheStatsCounters
+	}{
+		{"miss that fetches the source", testPathPhoto, 50, false,
+			cacheStatsCounters{0, 1, 1, photoBytes, 1}},
+		{"hit", testPathPhoto, 50, false,
+			cacheStatsCounters{1, 1, 1, photoBytes, 1}},
+		{"miss that reuses the cached source", testPathPhoto, 25, false,
+			cacheStatsCounters{1, 2, 1, photoBytes, 2}},
+		{"miss whose source fails the magic byte check", "/images/fake.jpg", 50, true,
+			cacheStatsCounters{1, 3, 2, photoBytes + fakeBytes, 2}},
+		{"miss whose source is not found", "/images/nonexistent.jpg", 50, true,
+			cacheStatsCounters{1, 4, 2, photoBytes + fakeBytes, 2}},
+	}
+
+	for _, step := range steps {
+		resp, err := svc.Get(t.Context(), &ImageRequest{
+			SourceHost: fixtures.GoodHost,
+			SourcePath: step.path,
+			Size:       Size{Width: step.size, Height: step.size},
+			Format:     FormatJPEG,
+			Quality:    85,
+			FitMode:    FitCover,
+		})
+		if (err != nil) != step.wantErr {
+			t.Fatalf("%s: Get() error = %v, want error %t", step.name, err, step.wantErr)
+		}
+
+		if err == nil {
+			_ = resp.Content.Close()
+		}
+
+		got := readCacheStatsCounters(t, svc.cache)
+		if got != step.want {
+			t.Fatalf("after the %s: counters = %+v, want %+v", step.name, got, step.want)
+		}
+	}
+}
+
+// fakeUpstream answers every fetch with itself as a JPEG body. The body
+// serves data, then calls cancel, when set, and returns err; io.EOF ends
+// the body normally.
+type fakeUpstream struct {
+	data   *bytes.Reader
+	cancel context.CancelFunc
+	err    error
+}
+
+func (u *fakeUpstream) Fetch(
+	context.Context, string,
+) (*httpfetcher.FetchResult, error) {
+	return &httpfetcher.FetchResult{
+		Content:       io.NopCloser(u),
+		ContentLength: -1,
+		ContentType:   testContentTypeJPEG,
+	}, nil
+}
+
+func (u *fakeUpstream) Read(p []byte) (int, error) {
+	if u.data.Len() > 0 {
+		return u.data.Read(p)
+	}
+
+	if u.cancel != nil {
+		u.cancel()
+	}
+
+	return 0, u.err
+}
+
+// TestService_Get_CountsInterruptedMisses checks every cache_stats counter
+// after a miss whose request context ends during or after the upstream
+// fetch, and after a miss whose upstream body is over the size limit.
+func TestService_Get_CountsInterruptedMisses(t *testing.T) {
+	t.Parallel()
+
+	photo := generateTestJPEG(t, 100, 100, color.RGBA{255, 0, 0, 255})
+	half := len(photo) / 2
+
+	// want is hits, misses, upstream fetches, upstream bytes, transforms.
+	tests := []struct {
+		name    string
+		served  int   // bytes of the photo the upstream body serves
+		cancel  bool  // whether the body then ends the request context
+		readErr error // what the body then returns
+		wantErr bool
+		want    cacheStatsCounters
+	}{
+		{"request context ends during the fetch", half, true, context.Canceled, true,
+			cacheStatsCounters{0, 1, 1, int64(half), 0}},
+		{"request context ends after the fetch", len(photo), true, io.EOF, false,
+			cacheStatsCounters{0, 1, 1, int64(len(photo)), 1}},
+		{"upstream body over the size limit", half, false,
+			httpfetcher.ErrResponseTooLarge, true,
+			cacheStatsCounters{0, 1, 1, int64(half), 0}},
+	}
+
+	for _, tc := range tests {
+		t.Run(tc.name, func(t *testing.T) {
+			t.Parallel()
+
+			svc, fixtures := SetupTestService(t)
+
+			ctx, cancel := context.WithCancel(t.Context())
+			defer cancel()
+
+			upstream := &fakeUpstream{
+				data: bytes.NewReader(photo[:tc.served]),
+				err:  tc.readErr,
+			}
+			if tc.cancel {
+				upstream.cancel = cancel
+			}
+
+			svc.fetcher = upstream
+
+			resp, err := svc.Get(ctx, &ImageRequest{
+				SourceHost: fixtures.GoodHost,
+				SourcePath: testPathPhoto,
+				Size:       Size{Width: 50, Height: 50},
+				Format:     FormatJPEG,
+				Quality:    85,
+				FitMode:    FitCover,
+			})
+			t.Logf("Get() error = %v", err)
+
+			if (err != nil) != tc.wantErr {
+				t.Fatalf("Get() error = %v, want error %t", err, tc.wantErr)
+			}
+
+			if err == nil {
+				_ = resp.Content.Close()
+			}
+
+			got := readCacheStatsCounters(t, svc.cache)
+			if got != tc.want {
+				t.Errorf("counters = %+v, want %+v", got, tc.want)
+			}
+		})
+	}
+}
+
+// TestService_Get_CountsHitAfterRequestEnds checks every cache_stats counter
+// after a hit served with a request context that has already ended: only
+// the hit count moves.
+func TestService_Get_CountsHitAfterRequestEnds(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures := SetupTestService(t)
+
+	req := &ImageRequest{
+		SourceHost: fixtures.GoodHost,
+		SourcePath: testPathPhoto,
+		Size:       Size{Width: 50, Height: 50},
+		Format:     FormatJPEG,
+		Quality:    85,
+		FitMode:    FitCover,
+	}
+
+	// A first request caches the variant.
+	resp, err := svc.Get(t.Context(), req)
+	if err != nil {
+		t.Fatalf("first Get() error = %v", err)
+	}
+
+	_ = resp.Content.Close()
+
+	want := readCacheStatsCounters(t, svc.cache)
+	want.hitCount++
+
+	ctx, cancel := context.WithCancel(t.Context())
+	cancel()
+
+	resp, err = svc.Get(ctx, req)
+	if err != nil {
+		t.Fatalf("Get() with an ended request context: error = %v", err)
+	}
+
+	_ = resp.Content.Close()
+
+	if resp.CacheStatus != CacheHit {
+		t.Fatalf("CacheStatus = %v, want %v", resp.CacheStatus, CacheHit)
+	}
+
+	got := readCacheStatsCounters(t, svc.cache)
+	if got != want {
+		t.Errorf("counters = %+v, want %+v", got, want)
+	}
+}