Space reconciliation passes by ten times the last pass's time (closes #250)

The reconciliation pass reads a row and stats a file for every cached
file, and it ran on every eviction tick, so on a large cache a pass
longer than the tick was followed by the next one at once. It still runs
at startup and is considered on each tick, but it now starts no sooner
than ten times as long after the last pass ended as that pass took, so
it takes at most about a tenth of the time however large the cache.
Eviction and the removal of expired negative cache rows still run on
every tick. The comments that bound the drift, and README.md, give the
new bound. No existing test changed.

Model: opus-5-5

internal/imgcache/eviction_internal_test.go

@@ -918,6 +918,89 @@ func TestPeriodicReconciliationAdoptsFileThatAppearsAfterStartup(t *testing.T) {
 	}
 }
 
+// TestReconciliationPassesAreSpacedByTenTimesTheirTime makes the hook
+// called after every read of the reconciliation pass sleep 10 ms, runs
+// the eviction loop on a 10 ms interval, and records when each of those
+// calls starts and ends. A pass starts before its first call and ends
+// after its last, so the time from the first call's start to the last
+// call's end is at most the pass's time. The next pass's first call must
+// start at least ten times that long after the last call ended.
+func TestReconciliationPassesAreSpacedByTenTimesTheirTime(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+
+	// A pass made here, before the loop starts, counts the reads one
+	// pass makes on this empty cache, so the reads recorded below can be
+	// split into passes.
+	readsPerPass := 0
+	cache.reconciliationReadTestHook = func(int) { readsPerPass++ }
+
+	err := cache.reconcileAccounting(t.Context())
+	if err != nil {
+		t.Fatalf("reconcileAccounting failed: %v", err)
+	}
+
+	t.Logf("one reconciliation pass makes %d reads", readsPerPass)
+
+	if readsPerPass == 0 {
+		t.Fatal("a reconciliation pass made no read")
+	}
+
+	// The pass at startup and two after it.
+	const passes = 3
+
+	type read struct{ start, end time.Time }
+
+	// The channel holds every read the test looks at, so none of those
+	// is dropped; reads after them are, and never block the loop.
+	reads := make(chan read, passes*readsPerPass)
+
+	cache.reconciliationReadTestHook = func(int) {
+		start := time.Now()
+
+		time.Sleep(10 * time.Millisecond)
+
+		select {
+		case reads <- read{start: start, end: time.Now()}:
+		default:
+		}
+	}
+
+	cache.StartEviction(10 * time.Millisecond)
+	defer func() { _ = cache.StopEviction(t.Context()) }()
+
+	recorded := make([]read, 0, passes*readsPerPass)
+	timeout := time.After(15 * time.Second)
+
+	for len(recorded) < passes*readsPerPass {
+		select {
+		case r := <-reads:
+			recorded = append(recorded, r)
+		case <-timeout:
+			t.Fatalf("saw %d reconciliation reads in 15 s, want %d (%d passes)",
+				len(recorded), passes*readsPerPass, passes)
+		}
+	}
+
+	for pass := range passes - 1 {
+		first := recorded[pass*readsPerPass]
+		last := recorded[(pass+1)*readsPerPass-1]
+		next := recorded[(pass+1)*readsPerPass]
+
+		passTime := last.end.Sub(first.start)
+		wait := next.start.Sub(last.end)
+
+		t.Logf("pass %d took at least %v, and the next pass started %v after it",
+			pass+1, passTime, wait)
+
+		if wait < 10*passTime {
+			t.Errorf("pass %d took at least %v, and the next pass started %v "+
+				"after it, want at least %v", pass+1, passTime, wait, 10*passTime)
+		}
+	}
+}
+
 // 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