Keep counts not written by the request's deadline in memory (closes #224)

TestService_Get_ReturnsByItsDeadline failed on a busy host because its
request, past its deadline, still waited to write its miss count, a write
with no deadline; in pixad that write waits for the one database
connection every request shares. Each count write now keeps the request's
deadline but not its cancellation. A count not written by then is kept in
memory, where Stats includes it, and one goroutine of the cache writes
those counts one UPDATE at a time, and once more at shutdown before the
database closes. The test phase also runs go test with -parallel 4: on a
busy host, as many tests at once as there are CPUs wait so long to be
scheduled that a timed request can fail.

Model: opus-5-5

internal/imgcache/pendingcounts_internal_test.go

@@ -0,0 +1,316 @@
+package imgcache
+
+import (
+	"context"
+	"database/sql"
+	"errors"
+	"testing"
+	"time"
+)
+
+// pendingCountsWait is how long a test waits for the database's connection,
+// for a count to reach the database, for a write to start waiting for the
+// connection, or for StopPendingCountWrites to return.
+const pendingCountsWait = 5 * time.Second
+
+// holdDatabase takes the one connection of cache's database, so that every
+// other query waits for it, and returns the func that frees it.
+func holdDatabase(t *testing.T, cache *Cache) func() {
+	t.Helper()
+
+	ctx, cancel := context.WithTimeout(t.Context(), pendingCountsWait)
+	defer cancel()
+
+	conn, err := cache.db.Conn(ctx)
+	if err != nil {
+		t.Fatalf("failed to take the database connection: %v", err)
+	}
+
+	return func() { _ = conn.Close() }
+}
+
+// waitForConnectionWaits waits until db.Stats().WaitCount, the number of
+// times a caller has waited for a connection, reaches waits.
+func waitForConnectionWaits(t *testing.T, db *sql.DB, waits int64) {
+	t.Helper()
+
+	deadline := time.Now().Add(pendingCountsWait)
+
+	for db.Stats().WaitCount < waits {
+		if time.Now().After(deadline) {
+			t.Fatalf("callers waited for the database connection %d times, want %d",
+				db.Stats().WaitCount, waits)
+		}
+
+		time.Sleep(10 * time.Millisecond)
+	}
+}
+
+// waitForCounters waits until the cache_stats row holds want.
+func waitForCounters(t *testing.T, cache *Cache, want cacheStatsCounters) {
+	t.Helper()
+
+	deadline := time.Now().Add(pendingCountsWait)
+
+	for {
+		got := readCacheStatsCounters(t, cache)
+		if got == want {
+			return
+		}
+
+		if time.Now().After(deadline) {
+			t.Fatalf("counters = %+v, want %+v", got, want)
+		}
+
+		time.Sleep(10 * time.Millisecond)
+	}
+}
+
+// TestService_Get_ReturnsByItsDeadlineWhileTheDatabaseIsBusy holds the
+// database's one connection while a request whose fetch is held reaches its
+// deadline. The request must still return by its deadline with the
+// deadline's error, and its miss must reach the database once the
+// connection is free.
+func TestService_Get_ReturnsByItsDeadlineWhileTheDatabaseIsBusy(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures, fetcher := setupHeldFetchService(t)
+
+	svc.cache.StartPendingCountWrites()
+	defer func() { _ = svc.cache.StopPendingCountWrites(t.Context()) }()
+
+	// Room for the request to reach its fetch on a busy host
+	const timeout = 2 * time.Second
+
+	ctx, cancel := context.WithTimeout(t.Context(), timeout)
+	defer cancel()
+
+	deadline, _ := ctx.Deadline()
+
+	results := startGet(ctx, svc, photoVariant(fixtures, 85, FitCover))
+
+	// The request has made its database reads by the time it fetches.
+	select {
+	case <-fetcher.started:
+	case <-time.After(timeout):
+		t.Fatal("request did not reach its fetch by its deadline")
+	}
+
+	releaseDatabase := holdDatabase(t, svc.cache)
+	defer releaseDatabase()
+
+	select {
+	case got := <-results:
+		t.Logf("Get() returned %v after its deadline, error = %v",
+			time.Since(deadline), got.err)
+
+		if !errors.Is(got.err, context.DeadlineExceeded) {
+			t.Errorf("Get() error = %v, want %v", got.err, context.DeadlineExceeded)
+		}
+	case <-time.After(time.Until(deadline) + time.Second):
+		t.Fatal("request did not return by its deadline while the database was busy")
+	}
+
+	releaseDatabase()
+
+	waitForCounters(t, svc.cache, cacheStatsCounters{missCount: 1})
+}
+
+// TestIncrementStats_ManyCountsPastTheirDeadlineLeaveOneWriteWaiting holds the
+// database's one connection while many misses are counted past their
+// deadline. At most one write may then wait for the connection, and every
+// miss must reach the database once it is free.
+func TestIncrementStats_ManyCountsPastTheirDeadlineLeaveOneWriteWaiting(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	cache.StartPendingCountWrites()
+	defer func() { _ = cache.StopPendingCountWrites(t.Context()) }()
+
+	releaseDatabase := holdDatabase(t, cache)
+	defer releaseDatabase()
+
+	waitsBefore := cache.db.Stats().WaitCount
+
+	// Writes given a context past its deadline fail at once.
+	ended, cancel := context.WithDeadline(t.Context(), time.Now())
+	defer cancel()
+
+	const misses = 20
+
+	for range misses {
+		cache.IncrementStats(ended, false, 0)
+	}
+
+	// Once one write waits for the connection, any others start waiting too.
+	waitForConnectionWaits(t, cache.db, waitsBefore+1)
+	time.Sleep(arrivalWait)
+
+	waits := cache.db.Stats().WaitCount - waitsBefore
+	t.Logf("%d writes waited for the database", waits)
+
+	if waits > 1 {
+		t.Errorf("%d writes waited for the database, want at most 1", waits)
+	}
+
+	releaseDatabase()
+
+	waitForCounters(t, cache, cacheStatsCounters{missCount: misses})
+}
+
+// TestStats_IncludesPendingCounts counts hits and misses whose writes miss
+// their deadline, and checks that Stats adds them to the database's counts
+// before they are written.
+func TestStats_IncludesPendingCounts(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	_, err := cache.db.ExecContext(t.Context(),
+		`UPDATE cache_stats SET hit_count = 75, miss_count = 25 WHERE id = 1`)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	// Writes given a context past its deadline fail at once.
+	ended, cancel := context.WithDeadline(t.Context(), time.Now())
+	defer cancel()
+
+	cache.IncrementStats(ended, true, 0)
+	cache.IncrementStats(ended, true, 0)
+	cache.IncrementStats(ended, false, 0)
+
+	stats, err := cache.Stats(t.Context())
+	if err != nil {
+		t.Fatalf("Stats() error = %v", err)
+	}
+
+	if stats.HitCount != 77 || stats.MissCount != 26 {
+		t.Errorf("HitCount = %d, MissCount = %d, want 77 and 26",
+			stats.HitCount, stats.MissCount)
+	}
+
+	want := cacheStatsCounters{hitCount: 75, missCount: 25}
+	if got := readCacheStatsCounters(t, cache); got != want {
+		t.Errorf("counters in the database = %+v, want %+v", got, want)
+	}
+}
+
+// TestStopPendingCountWrites_WritesPendingCounts holds the database's one
+// connection while the goroutine that writes the pending counts waits for it,
+// counts more, then stops that goroutine. The stop must leave the write under
+// way to finish rather than cut it off, and every count must reach the
+// database once the connection is free.
+func TestStopPendingCountWrites_WritesPendingCounts(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	cache.StartPendingCountWrites()
+	defer func() { _ = cache.StopPendingCountWrites(t.Context()) }()
+
+	releaseDatabase := holdDatabase(t, cache)
+	defer releaseDatabase()
+
+	waitsBefore := cache.db.Stats().WaitCount
+
+	// Writes given a context past its deadline fail at once.
+	ended, cancel := context.WithDeadline(t.Context(), time.Now())
+	defer cancel()
+
+	cache.IncrementStats(ended, true, 0)
+
+	// The goroutine's write waits for the connection.
+	waitForConnectionWaits(t, cache.db, waitsBefore+1)
+
+	// Counted after that write read the pending counts
+	cache.IncrementStats(ended, false, 0)
+	cache.IncrementUpstreamFetch(ended, 1024)
+	cache.IncrementTransformCount(ended)
+
+	stopped := make(chan error, 1)
+
+	go func() {
+		stopped <- cache.StopPendingCountWrites(t.Context())
+	}()
+
+	// Had the stop cut off the write under way, its own write would wait for
+	// the connection too.
+	time.Sleep(arrivalWait)
+
+	waits := cache.db.Stats().WaitCount - waitsBefore
+	t.Logf("%d writes waited for the database", waits)
+
+	if waits > 1 {
+		t.Errorf("%d writes waited for the database, want 1: "+
+			"the stop cut off the write under way", waits)
+	}
+
+	releaseDatabase()
+
+	select {
+	case err := <-stopped:
+		if err != nil {
+			t.Fatalf("StopPendingCountWrites() error = %v", err)
+		}
+	case <-time.After(pendingCountsWait):
+		t.Fatal("StopPendingCountWrites() did not return once the database was free")
+	}
+
+	want := cacheStatsCounters{1, 1, 1, 1024, 1}
+	if got := readCacheStatsCounters(t, cache); got != want {
+		t.Errorf("counters = %+v, want %+v", got, want)
+	}
+}
+
+// TestStopPendingCountWrites_ReturnsWhenItsContextEnds holds the database's
+// one connection while the goroutine that writes the pending counts waits for
+// it, then stops that goroutine with a context that ends first. The stop must
+// return the context's error, and the write under way must still reach the
+// database once the connection is free.
+func TestStopPendingCountWrites_ReturnsWhenItsContextEnds(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	cache.StartPendingCountWrites()
+	defer func() { _ = cache.StopPendingCountWrites(t.Context()) }()
+
+	releaseDatabase := holdDatabase(t, cache)
+	defer releaseDatabase()
+
+	waitsBefore := cache.db.Stats().WaitCount
+
+	// Writes given a context past its deadline fail at once.
+	ended, cancel := context.WithDeadline(t.Context(), time.Now())
+	defer cancel()
+
+	cache.IncrementStats(ended, true, 0)
+
+	// The goroutine's write waits for the connection.
+	waitForConnectionWaits(t, cache.db, waitsBefore+1)
+
+	stopCtx, cancelStop := context.WithCancel(t.Context())
+	cancelStop()
+
+	stopped := make(chan error, 1)
+
+	go func() {
+		stopped <- cache.StopPendingCountWrites(stopCtx)
+	}()
+
+	select {
+	case err := <-stopped:
+		if !errors.Is(err, context.Canceled) {
+			t.Errorf("StopPendingCountWrites() error = %v, want %v",
+				err, context.Canceled)
+		}
+	case <-time.After(pendingCountsWait):
+		t.Fatal("StopPendingCountWrites() did not return once its context ended")
+	}
+
+	releaseDatabase()
+
+	waitForCounters(t, cache, cacheStatsCounters{hitCount: 1})
+}