Serve a cache hit with no database read or write (closes #309)

A hit opens the variant file and nothing else: its content type comes
from the file's first bytes, and a file in no output format is a miss.
Its access time and hit count, and the access time of a cached source a
miss uses, go without waiting to the goroutine that wrote late counts,
which now writes them all once a second; each kind of access time waits
in a channel of 10,000 that drops the rest. checkNegativeCache leaves
expired rows to CleanExpired. The .meta files, metaCache, Lookup and
golang-lru go, with their tests. Dropping the .meta skip made the
variant and source reconciliation walks identical, so they share one.
make bench runs a parallel cache hit benchmark on the host, outside
make check.

Model: opus-5-5

internal/handlers/cache_hit_internal_test.go

@@ -0,0 +1,265 @@
+package handlers
+
+import (
+	"bytes"
+	"context"
+	"database/sql"
+	"database/sql/driver"
+	"image"
+	"image/jpeg"
+	"log/slog"
+	"net/http"
+	"net/http/httptest"
+	"path/filepath"
+	"sync/atomic"
+	"testing"
+	"testing/fstest"
+	"time"
+
+	"github.com/go-chi/chi/v5"
+
+	"sneak.berlin/go/pixa/internal/database"
+	"sneak.berlin/go/pixa/internal/encurl"
+	"sneak.berlin/go/pixa/internal/imagerequest"
+	"sneak.berlin/go/pixa/internal/imgcache"
+)
+
+// countingHost is the allowlisted host whose photoPath the server of
+// newCountingDatabaseServer serves.
+const countingHost = "counting.example.com"
+
+// countingConnector opens connections to the SQLite database file name with
+// sqliteDriver, each one counting in statements the statements run on it.
+type countingConnector struct {
+	sqliteDriver driver.Driver
+	name         string
+	statements   *atomic.Int64
+}
+
+func (c countingConnector) Connect(context.Context) (driver.Conn, error) {
+	conn, err := c.sqliteDriver.Open(c.name)
+	if err != nil {
+		return nil, err
+	}
+
+	return countingConn{Conn: conn, statements: c.statements}, nil
+}
+
+func (c countingConnector) Driver() driver.Driver {
+	return c.sqliteDriver
+}
+
+// countingConn counts the statements run on its connection. It has only the
+// methods of driver.Conn, so database/sql prepares every query and every
+// other statement with Prepare, which counts it.
+type countingConn struct {
+	driver.Conn
+
+	statements *atomic.Int64
+}
+
+func (c countingConn) Prepare(query string) (driver.Stmt, error) {
+	c.statements.Add(1)
+
+	return c.Conn.Prepare(query)
+}
+
+// newCountingDatabase returns a database with pixa's schema, in a file of
+// its own and with one connection, and the count of the statements run on
+// it once the schema is in place.
+func newCountingDatabase(tb testing.TB) (*sql.DB, *atomic.Int64) {
+	tb.Helper()
+
+	path := filepath.Join(tb.TempDir(), "state.sqlite3")
+
+	schemaDB, err := sql.Open("sqlite", path)
+	if err != nil {
+		tb.Fatalf("opening the database: %v", err)
+	}
+
+	defer func() { _ = schemaDB.Close() }()
+
+	err = database.ApplyMigrations(tb.Context(), schemaDB, nil)
+	if err != nil {
+		tb.Fatalf("applying the migrations: %v", err)
+	}
+
+	statements := new(atomic.Int64)
+
+	db := sql.OpenDB(countingConnector{
+		sqliteDriver: schemaDB.Driver(),
+		name:         path,
+		statements:   statements,
+	})
+	db.SetMaxOpenConns(1)
+
+	tb.Cleanup(func() { _ = db.Close() })
+
+	return db, statements
+}
+
+// newCountingDatabaseServer returns a router for both image routes whose
+// image cache uses newCountingDatabase, the count of the statements run on
+// that database, and a URL on each route for a different image of
+// photoPath on countingHost. Nothing writes the cache's pending counts and
+// access times in the background, so every statement counted comes from a
+// request.
+func newCountingDatabaseServer(
+	tb testing.TB,
+) (http.Handler, *atomic.Int64, []string) {
+	tb.Helper()
+
+	db, statements := newCountingDatabase(tb)
+
+	var photo bytes.Buffer
+
+	err := jpeg.Encode(&photo, image.NewRGBA(image.Rect(0, 0, 100, 100)), nil)
+	if err != nil {
+		tb.Fatalf("encoding the photo: %v", err)
+	}
+
+	cache, err := imgcache.NewCache(db, imgcache.CacheConfig{
+		StateDir:    tb.TempDir(),
+		NegativeTTL: 5 * time.Minute,
+	})
+	if err != nil {
+		tb.Fatalf("imgcache.NewCache() error = %v", err)
+	}
+
+	svc, err := imgcache.NewService(&imgcache.ServiceConfig{
+		Cache: cache,
+		Fetcher: newMockFetcher(fstest.MapFS{
+			countingHost + photoPath: &fstest.MapFile{Data: photo.Bytes()},
+		}),
+		SigningKey: testSigningKey,
+		Allowlist:  []string{countingHost},
+		Logger:     slog.New(slog.DiscardHandler),
+	})
+	if err != nil {
+		tb.Fatalf("imgcache.NewService() error = %v", err)
+	}
+
+	encGen, err := encurl.NewGenerator(testSigningKey)
+	if err != nil {
+		tb.Fatalf("encurl.NewGenerator() error = %v", err)
+	}
+
+	token, err := encGen.Generate(&imagerequest.Request{
+		Source: imagerequest.Source{Host: countingHost, Path: photoPath},
+		Transform: imagerequest.Transform{
+			Size:    imagerequest.Size{Width: 40, Height: 40},
+			Format:  imagerequest.FormatJPEG,
+			Quality: 85,
+			FitMode: imagerequest.FitCover,
+		},
+	})
+	if err != nil {
+		tb.Fatalf("encGen.Generate() error = %v", err)
+	}
+
+	h := &Handlers{
+		log:    slog.New(slog.DiscardHandler),
+		imgSvc: svc,
+		encGen: encGen,
+	}
+
+	r := chi.NewRouter()
+	r.Get("/v1/image/*", h.HandleImage())
+	r.Get("/v1/e/{token}/*", h.HandleImageEnc())
+
+	return r, statements, []string{
+		"/v1/image/" + countingHost + photoPath + "/50x50.jpeg",
+		"/v1/e/" + token + "/img.jpg",
+	}
+}
+
+// serveImage sends srv a GET for target and returns the response, failing
+// the test unless it is a 200 with an image.
+func serveImage(
+	tb testing.TB, srv http.Handler, target string,
+) *httptest.ResponseRecorder {
+	tb.Helper()
+
+	rec := httptest.NewRecorder()
+	srv.ServeHTTP(rec,
+		httptest.NewRequestWithContext(tb.Context(), http.MethodGet, target, nil))
+
+	if rec.Code != http.StatusOK || rec.Body.Len() == 0 {
+		tb.Errorf("GET %s: %d with %d bytes, want 200 with an image",
+			target, rec.Code, rec.Body.Len())
+	}
+
+	return rec
+}
+
+// TestImageRoutes_CacheHitsMakeNoDatabaseCall serves an image on each image
+// route once, which makes and caches it, then serves it again from the cache.
+// Serving those cache hits must run no statement on the database.
+func TestImageRoutes_CacheHitsMakeNoDatabaseCall(t *testing.T) {
+	t.Parallel()
+
+	srv, statements, targets := newCountingDatabaseServer(t)
+
+	for _, target := range targets {
+		before := statements.Load()
+
+		serveImage(t, srv, target)
+
+		afterMiss := statements.Load()
+		t.Logf("GET %s, a miss: %d statements", target, afterMiss-before)
+
+		if afterMiss == before {
+			t.Fatalf("GET %s, a miss: no statement counted, want some", target)
+		}
+
+		for range 3 {
+			rec := serveImage(t, srv, target)
+
+			cacheStatus := rec.Header().Get("X-Pixa-Cache")
+			if cacheStatus != string(imgcache.CacheHit) {
+				t.Errorf("GET %s: X-Pixa-Cache = %q, want %s",
+					target, cacheStatus, imgcache.CacheHit)
+			}
+		}
+
+		if hitStatements := statements.Load() - afterMiss; hitStatements != 0 {
+			t.Errorf("GET %s: 3 cache hits ran %d statements, want 0",
+				target, hitStatements)
+		}
+	}
+}
+
+// BenchmarkHandleImage_CacheHits serves one cached image through the
+// /v1/image/ route from b.RunParallel's goroutines, and reports the cache
+// hits served per second. It fails if serving them ran any statement on the
+// database. script/bench runs it.
+func BenchmarkHandleImage_CacheHits(b *testing.B) {
+	srv, statements, targets := newCountingDatabaseServer(b)
+	target := targets[0]
+
+	serveImage(b, srv, target)
+
+	before := statements.Load()
+
+	b.ResetTimer()
+
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			rec := serveImage(b, srv, target)
+
+			cacheStatus := rec.Header().Get("X-Pixa-Cache")
+			if cacheStatus != string(imgcache.CacheHit) {
+				b.Errorf("GET %s: X-Pixa-Cache = %q, want %s",
+					target, cacheStatus, imgcache.CacheHit)
+
+				return
+			}
+		}
+	})
+
+	b.ReportMetric(float64(b.N)/b.Elapsed().Seconds(), "hits/s")
+
+	if hitStatements := statements.Load() - before; hitStatements != 0 {
+		b.Fatalf("%d cache hits ran %d statements, want 0", b.N, hitStatements)
+	}
+}

internal/handlers/handlers.go

@@ -76,8 +76,8 @@ func New(lc fx.Lifecycle, params Params) (*Handlers, error) {
 		OnStart: func(_ context.Context) error {
 			return s.initImageService()
 		},
-		// The pending counts are written here, before the database's stop
-		// hook closes it.
+		// The pending counts and access times are written here, before the
+		// database's stop hook closes it.
 		OnStop: func(ctx context.Context) error {
 			if s.imgCache == nil {
 				return nil
@@ -128,7 +128,8 @@ func (s *Handlers) initImageService() error {
 	// rows, which is all it does when the disk cache is disabled.
 	cache.StartEviction(imgcache.DefaultEvictionInterval)
 
-	// Writes the counts requests could not write by their deadline
+	// Writes the counts and the access times of cache hits that requests
+	// hand over, so that no request waits for the database to record them
 	cache.StartPendingCountWrites()
 
 	// Create the fetcher config