Stop cache eviction in progress at shutdown (closes #102)

StartEviction runs the eviction goroutine with its own context, which
StopEviction cancels in place of the old stop channel, so a pass in
progress stops at its next database call, file, row or eviction
candidate instead of running to completion, and no new pass starts.
StopEviction takes a context: when it ends before the goroutine exits,
StopEviction stops waiting and returns an error wrapping it. The
handlers' stop hook passes fx's stop context, so an eviction still
running at fx's stop deadline fails the stop and the exit code is 1.
A stop logs at most one warning.

Model: opus-5-5

internal/imgcache/eviction_internal_test.go

@@ -4,9 +4,12 @@ import (
 	"bytes"
 	"context"
 	"database/sql"
+	"errors"
 	"io/fs"
+	"log/slog"
 	"os"
 	"path/filepath"
+	"strings"
 	"testing"
 	"time"
 
@@ -657,7 +660,7 @@ func TestEvictionRunsUnderWritePressure(t *testing.T) {
 	// An interval far longer than the test ensures only write
 	// pressure can trigger eviction here.
 	cache.StartEviction(time.Hour)
-	defer cache.StopEviction()
+	defer func() { _ = cache.StopEviction(t.Context()) }()
 
 	keys := []VariantKey{
 		testVariantKeyOne, testVariantKeyTwo, testVariantKeyThree,
@@ -690,7 +693,7 @@ func TestEvictionRunsOnPeriodicSchedule(t *testing.T) {
 	// write-pressure notification fires and only the periodic ticker
 	// can trigger eviction.
 	cache.StartEviction(100 * time.Millisecond)
-	defer cache.StopEviction()
+	defer func() { _ = cache.StopEviction(t.Context()) }()
 
 	keys := []VariantKey{
 		testVariantKeyOne, testVariantKeyTwo, testVariantKeyThree,
@@ -751,7 +754,7 @@ func TestStartEvictionReconcilesAccountingWithDisk(t *testing.T) {
 	}
 
 	cache.StartEviction(time.Hour)
-	defer cache.StopEviction()
+	defer func() { _ = cache.StopEviction(t.Context()) }()
 
 	deadline := time.Now().Add(5 * time.Second)
 
@@ -808,7 +811,7 @@ func TestPeriodicReconciliationAdoptsFileThatAppearsAfterStartup(t *testing.T) {
 	const interval = 100 * time.Millisecond
 
 	cache.StartEviction(interval)
-	defer cache.StopEviction()
+	defer func() { _ = cache.StopEviction(t.Context()) }()
 
 	// Let startup reconciliation run and settle on an empty cache
 	// before introducing the untracked file, so the adoption we assert
@@ -862,6 +865,242 @@ func TestPeriodicReconciliationAdoptsFileThatAppearsAfterStartup(t *testing.T) {
 	}
 }
 
+// TestStopEvictionInterruptsPassInProgress holds the test database's
+// only connection, so the startup reconciliation pass waits for it, and
+// checks that StopEviction stops that pass instead of waiting for the
+// connection to come free, and that the stop logs one warning: the
+// interrupted reconciliation's, with no eviction pass started after it.
+func TestStopEvictionInterruptsPassInProgress(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	var logBuf bytes.Buffer
+
+	cache.log = slog.New(slog.NewJSONHandler(&logBuf, nil))
+
+	conn, err := cache.db.Conn(t.Context())
+	if err != nil {
+		t.Fatalf("failed to take the database connection: %v", err)
+	}
+
+	defer func() { _ = conn.Close() }()
+
+	cache.StartEviction(time.Hour)
+
+	// The pass is in progress once it waits for the connection.
+	deadline := time.Now().Add(5 * time.Second)
+
+	for cache.db.Stats().WaitCount == 0 {
+		if time.Now().After(deadline) {
+			t.Fatal("the reconciliation pass never waited for the database")
+		}
+
+		time.Sleep(10 * time.Millisecond)
+	}
+
+	ctx, cancel := context.WithTimeout(t.Context(), 5*time.Second)
+	defer cancel()
+
+	err = cache.StopEviction(ctx)
+	t.Logf("StopEviction() error = %v", err)
+
+	if err != nil {
+		t.Fatalf("StopEviction() error = %v, want nil: the pass waiting for "+
+			"the database did not stop", err)
+	}
+
+	t.Logf("log output: %s", logBuf.String())
+
+	warnings := strings.Count(logBuf.String(), `"level":"WARN"`)
+	if warnings != 1 {
+		t.Errorf("the stop logged %d warnings, want 1", warnings)
+	}
+}
+
+// TestEvictToLimitStopsAtNextCandidateOnceCancelled cancels the context
+// while the oldest of three source blobs is being evicted, and checks that
+// EvictToLimit then returns context.Canceled without evicting the other
+// two or logging a warning for either of them.
+func TestEvictToLimitStopsAtNextCandidateOnceCancelled(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1)
+
+	var logBuf bytes.Buffer
+
+	cache.log = slog.New(slog.NewJSONHandler(&logBuf, nil))
+
+	hashes := []ContentHash{
+		storeEvictionTestSource(t, cache, "cancel.example.com", "/a.jpg",
+			bytes.Repeat([]byte{0x61}, 1000)),
+		storeEvictionTestSource(t, cache, "cancel.example.com", "/b.jpg",
+			bytes.Repeat([]byte{0x62}, 1000)),
+		storeEvictionTestSource(t, cache, "cancel.example.com", "/c.jpg",
+			bytes.Repeat([]byte{0x63}, 1000)),
+	}
+
+	base := time.Now().Add(-time.Hour)
+
+	for i, hash := range hashes {
+		setSourceLastAccessed(t, cache, hash, base.Add(time.Duration(i)*time.Minute))
+	}
+
+	ctx, cancel := context.WithCancel(t.Context())
+	defer cancel()
+
+	cache.evictSourceBlobTestHook = func(ContentHash) { cancel() }
+
+	err := cache.EvictToLimit(ctx)
+	t.Logf("EvictToLimit() error = %v", err)
+	t.Logf("log output: %s", logBuf.String())
+
+	if !errors.Is(err, context.Canceled) {
+		t.Errorf("EvictToLimit() error = %v, want context.Canceled", err)
+	}
+
+	if cache.srcContent.Exists(hashes[0]) {
+		t.Errorf("source blob %s, evicted when the context was cancelled, "+
+			"is still on disk", hashes[0])
+	}
+
+	for _, hash := range hashes[1:] {
+		if !cache.srcContent.Exists(hash) {
+			t.Errorf("source blob %s was evicted after the context was cancelled", hash)
+		}
+	}
+
+	if strings.Contains(logBuf.String(), `"level":"WARN"`) {
+		t.Errorf("EvictToLimit logged a warning after the context was cancelled")
+	}
+
+	assertNoDanglingReferences(t, cache)
+}
+
+// TestStopEvictionReturnsWhenItsContextEnds pauses an eviction pass where
+// cancellation cannot reach it, after a source blob's rows are deleted and
+// before its file is removed, and checks that StopEviction returns its
+// context's error when that context ends instead of waiting for the pass.
+// Once the pass goes on, the goroutine exits and no row points at a
+// missing file.
+func TestStopEvictionReturnsWhenItsContextEnds(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1)
+
+	paused := make(chan struct{})
+	resume := make(chan struct{})
+
+	cache.evictSourceBlobTestHook = func(ContentHash) {
+		close(paused)
+		<-resume
+	}
+
+	hash := storeEvictionTestSource(t, cache, "stop.example.com", "/a.jpg",
+		bytes.Repeat([]byte{0x61}, 1000))
+
+	cache.StartEviction(time.Hour)
+
+	select {
+	case <-paused:
+	case <-time.After(5 * time.Second):
+		t.Fatal("the eviction pass never reached the source blob")
+	}
+
+	ctx, cancel := context.WithTimeout(t.Context(), 50*time.Millisecond)
+	defer cancel()
+
+	err := cache.StopEviction(ctx)
+	t.Logf("StopEviction() error = %v", err)
+
+	if !errors.Is(err, context.DeadlineExceeded) {
+		t.Errorf("StopEviction() error = %v, want context.DeadlineExceeded", err)
+	}
+
+	close(resume)
+
+	err = cache.StopEviction(t.Context())
+	if err != nil {
+		t.Fatalf("second StopEviction() error = %v, want nil", err)
+	}
+
+	assertNoDanglingReferences(t, cache)
+
+	if cache.srcContent.Exists(hash) {
+		t.Errorf("source blob %s is still on disk after its rows were deleted", hash)
+	}
+}
+
+// TestReconciliationWalksStopOnceCancelled checks that both directory
+// walks of a reconciliation pass return the context's error once it is
+// cancelled, leaving in place a stale temp file they would otherwise
+// remove.
+func TestReconciliationWalksStopOnceCancelled(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	ctx, cancel := context.WithCancel(t.Context())
+	cancel()
+
+	staleTime := time.Now().Add(-2 * staleTempFileAge)
+
+	walks := map[string]func(context.Context) error{
+		cache.variants.baseDir:   cache.reconcileVariantFiles,
+		cache.srcContent.baseDir: cache.reconcileSourceFiles,
+	}
+
+	for dir, walk := range walks {
+		tempFile := filepath.Join(dir, tempFilePrefix+"stale")
+
+		err := os.WriteFile(tempFile, []byte("partial"), 0o600)
+		if err != nil {
+			t.Fatalf("failed to write temp file: %v", err)
+		}
+
+		err = os.Chtimes(tempFile, staleTime, staleTime)
+		if err != nil {
+			t.Fatalf("failed to backdate temp file: %v", err)
+		}
+
+		err = walk(ctx)
+		t.Logf("walk of %s: error = %v", dir, err)
+
+		if !errors.Is(err, context.Canceled) {
+			t.Errorf("walk of %s: error = %v, want context.Canceled", dir, err)
+		}
+
+		_, err = os.Stat(tempFile)
+		if err != nil {
+			t.Errorf("walk of %s went on after cancellation: %v", dir, err)
+		}
+	}
+}
+
+// TestReconciliationPassLogsNoWarningOnceCancelled checks that a
+// reconciliation pass run with an already cancelled context logs no
+// warning, so a periodic tick the loop takes after a stop adds no
+// warning to the one from the pass the stop interrupted.
+func TestReconciliationPassLogsNoWarningOnceCancelled(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	var logBuf bytes.Buffer
+
+	cache.log = slog.New(slog.NewJSONHandler(&logBuf, nil))
+
+	ctx, cancel := context.WithCancel(t.Context())
+	cancel()
+
+	cache.runReconciliationPass(ctx)
+	t.Logf("log output: %s", logBuf.String())
+
+	if strings.Contains(logBuf.String(), `"level":"WARN"`) {
+		t.Errorf("runReconciliationPass logged a warning with a cancelled context")
+	}
+}
+
 // TestEvictSourceBlobExcludesConcurrentStoreOfIdenticalContent exercises
 // the exact TOCTOU window between evictSourceBlob's row-deletion
 // transaction commit and its content file unlink: a concurrent