Files
pixa/internal/imgcache/stats_internal_test.go
T
clawbot 3daa416f4b 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
2026-09-29 02:46:31 +00:00

500 lines
12 KiB
Go

package imgcache
import (
"bytes"
"context"
"database/sql"
"image/color"
"io"
"io/fs"
"log/slog"
"math"
"strings"
"testing"
"time"
"sneak.berlin/go/pixa/internal/database"
"sneak.berlin/go/pixa/internal/httpfetcher"
)
func setupStatsTestDB(t *testing.T) *sql.DB {
t.Helper()
db, err := sql.Open("sqlite", ":memory:")
if err != nil {
t.Fatal(err)
}
err = database.ApplyMigrations(context.Background(), db, nil)
if err != nil {
t.Fatal(err)
}
t.Cleanup(func() { _ = db.Close() })
return db
}
func TestStats_HitRateIsRatio(t *testing.T) {
t.Parallel()
db := setupStatsTestDB(t)
dir := t.TempDir()
cache, err := NewCache(db, CacheConfig{
StateDir: dir,
CacheTTL: time.Hour,
NegativeTTL: 5 * time.Minute,
})
if err != nil {
t.Fatal(err)
}
ctx := context.Background()
// Set some hit/miss counts and a transform_count
_, err = db.ExecContext(ctx, `
UPDATE cache_stats
SET hit_count = 75, miss_count = 25, transform_count = 9999
WHERE id = 1
`)
if err != nil {
t.Fatal(err)
}
stats, err := cache.Stats(ctx)
if err != nil {
t.Fatal(err)
}
if stats.HitCount != 75 {
t.Errorf("HitCount = %d, want 75", stats.HitCount)
}
if stats.MissCount != 25 {
t.Errorf("MissCount = %d, want 25", stats.MissCount)
}
// HitRate should be 0.75, NOT 9999 (transform_count)
expectedRate := 0.75
if math.Abs(stats.HitRate-expectedRate) > 0.001 {
t.Errorf("HitRate = %f, want %f (was it scanning transform_count?)",
stats.HitRate, expectedRate)
}
}
func TestStats_ZeroCounts(t *testing.T) {
t.Parallel()
db := setupStatsTestDB(t)
dir := t.TempDir()
cache, err := NewCache(db, CacheConfig{
StateDir: dir,
CacheTTL: time.Hour,
NegativeTTL: 5 * time.Minute,
})
if err != nil {
t.Fatal(err)
}
stats, err := cache.Stats(context.Background())
if err != nil {
t.Fatal(err)
}
// With zero hits and misses, HitRate should be 0, not some garbage value
if stats.HitRate != 0.0 {
t.Errorf("HitRate = %f, want 0.0 for zero counts", stats.HitRate)
}
}
// TestStats_LogsFailedCountQueries verifies that a failed item count query
// and a failed size query are each logged at warn and Stats still succeeds.
func TestStats_LogsFailedCountQueries(t *testing.T) {
t.Parallel()
db := setupStatsTestDB(t)
var logBuf bytes.Buffer
cache, err := NewCache(db, CacheConfig{
StateDir: t.TempDir(),
CacheTTL: time.Hour,
NegativeTTL: 5 * time.Minute,
Logger: slog.New(slog.NewJSONHandler(&logBuf, nil)),
})
if err != nil {
t.Fatal(err)
}
_, err = db.ExecContext(t.Context(),
`DROP TABLE source_content; DROP TABLE variant_content`)
if err != nil {
t.Fatal(err)
}
_, err = cache.Stats(t.Context())
if err != nil {
t.Fatalf("Stats() error = %v, want nil", err)
}
for _, msg := range []string{
"failed to count cache items for stats",
"failed to sum cache size for stats",
} {
want := `"level":"WARN","msg":"` + msg + `"`
if !strings.Contains(logBuf.String(), want) {
t.Errorf("log missing %s; got %q", want, logBuf.String())
}
}
}
// TestIncrementStats_LogsFailedUpdates verifies that a failed hit or miss
// count update and a failed upstream fetch count update are each logged at
// warn.
func TestIncrementStats_LogsFailedUpdates(t *testing.T) {
t.Parallel()
db := setupStatsTestDB(t)
var logBuf bytes.Buffer
cache, err := NewCache(db, CacheConfig{
StateDir: t.TempDir(),
CacheTTL: time.Hour,
NegativeTTL: 5 * time.Minute,
Logger: slog.New(slog.NewJSONHandler(&logBuf, nil)),
})
if err != nil {
t.Fatal(err)
}
_, err = db.ExecContext(t.Context(), `DROP TABLE cache_stats`)
if err != nil {
t.Fatal(err)
}
cache.IncrementStats(t.Context(), false, 1024)
for _, msg := range []string{
"failed to count cache hit or miss",
"failed to count upstream fetch",
} {
want := `"level":"WARN","msg":"` + msg + `"`
if !strings.Contains(logBuf.String(), want) {
t.Errorf("log missing %s; got %q", want, logBuf.String())
}
}
}
// 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)
}
}