Keep a variant's accounting row when its file cannot be read (closes #340) #342
@@ -252,6 +252,10 @@ less than ten times as long after the last look ended as that look took. After a
|
||||
look that took one minute, the next one starts 10 to 15 minutes after that look
|
||||
ended.
|
||||
|
||||
Each look also drops the rows of variants whose files are missing. When pixa
|
||||
cannot read a variant file's size for another reason, it keeps the variant's
|
||||
row. It logs a warning naming the variant key and the error.
|
||||
|
||||
pixa's target is 1-5k r/s, which has not been measured at that rate (see Load
|
||||
Test). Toward it, a cache hit opens the variant's file and nothing else, and
|
||||
makes no database call. The content type comes from the file's first bytes,
|
||||
|
||||
@@ -30,6 +30,13 @@ P2: security: per-origin rate limiting
|
||||
|
||||
# Completed Steps
|
||||
|
||||
- 2026-10-26 the reconciliation pass drops a variant's accounting row only when
|
||||
its file is missing (closes #340). Any other error reading the file's size
|
||||
keeps the row. It dropped the row on any error and logged the file as missing.
|
||||
- The kept row gets the warning "kept accounting row for unreadable variant
|
||||
file", with the variant key and the error.
|
||||
- The pass checks for `ErrNotFound`, which `FileStore.Size` returns for a
|
||||
missing file.
|
||||
- 2026-10-26 on both image routes, a request is answered 499 and logged at info
|
||||
level when its client goes away before its image is ready, unless it is the
|
||||
request making the image (closes #339). It was answered 500 and logged at
|
||||
|
||||
@@ -613,7 +613,9 @@ func (c *Cache) adoptVariantFile(
|
||||
}
|
||||
|
||||
// reconcileVariantRows drops accounting rows whose variant files are
|
||||
// missing, so the database never references deleted content.
|
||||
// missing, so the database never references deleted content. A file whose
|
||||
// size cannot be read for another reason may still be on disk, so its row
|
||||
// stays, with a warning naming its key and the error.
|
||||
func (c *Cache) reconcileVariantRows(ctx context.Context) error {
|
||||
var after imagerequest.VariantKey
|
||||
|
||||
@@ -641,6 +643,13 @@ func (c *Cache) reconcileVariantRows(ctx context.Context) error {
|
||||
continue
|
||||
}
|
||||
|
||||
if !errors.Is(err, ErrNotFound) {
|
||||
c.log.Warn("kept accounting row for unreadable variant file",
|
||||
"cache_key", key, "error", err)
|
||||
|
||||
continue
|
||||
}
|
||||
|
||||
_, err = c.db.ExecContext(ctx,
|
||||
`DELETE FROM variant_content WHERE cache_key = ?`, string(key))
|
||||
if err != nil {
|
||||
|
||||
@@ -699,6 +699,92 @@ func TestStartEvictionReconcilesAccountingWithDisk(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
// logLineNaming returns the first line of logs, written by slog's JSON
|
||||
// handler, that is at level and names the variant key, or "" if none is.
|
||||
func logLineNaming(logs, level string, key imagerequest.VariantKey) string {
|
||||
for line := range strings.Lines(logs) {
|
||||
if strings.Contains(line, `"level":"`+level+`"`) &&
|
||||
strings.Contains(line, `"cache_key":"`+string(key)+`"`) {
|
||||
return line
|
||||
}
|
||||
}
|
||||
|
||||
return ""
|
||||
}
|
||||
|
||||
// TestReconcileVariantRowsDropsOnlyRowsOfMissingFiles gives
|
||||
// reconcileVariantRows two tracked variants. The first one's file is a
|
||||
// symbolic link to itself, so its size cannot be read. Its row must stay,
|
||||
// with a warning naming its key and the error. The second one has no file.
|
||||
// Its row must go, with the info line for a missing file.
|
||||
func TestReconcileVariantRowsDropsOnlyRowsOfMissingFiles(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
cache, _ := newEvictionTestCache(t, 1<<30)
|
||||
storeEvictionTestVariant(t, cache, testVariantKeyOne, []byte("variant one"))
|
||||
storeEvictionTestVariant(t, cache, testVariantKeyTwo, []byte("variant two"))
|
||||
|
||||
unreadablePath := cache.variants.keyToPath(string(testVariantKeyOne))
|
||||
|
||||
err := os.Remove(unreadablePath)
|
||||
if err != nil {
|
||||
t.Fatalf("failed to remove the first variant's file: %v", err)
|
||||
}
|
||||
|
||||
err = os.Symlink(unreadablePath, unreadablePath)
|
||||
if err != nil {
|
||||
t.Fatalf("failed to link the first variant's path to itself: %v", err)
|
||||
}
|
||||
|
||||
_, statErr := os.Stat(unreadablePath)
|
||||
if statErr == nil || errors.Is(statErr, fs.ErrNotExist) {
|
||||
t.Fatalf("os.Stat() of the first variant: error = %v, "+
|
||||
"want an error other than a missing file", statErr)
|
||||
}
|
||||
|
||||
err = os.Remove(cache.variants.keyToPath(string(testVariantKeyTwo)))
|
||||
if err != nil {
|
||||
t.Fatalf("failed to remove the second variant's file: %v", err)
|
||||
}
|
||||
|
||||
var logBuf bytes.Buffer
|
||||
|
||||
cache.log = slog.New(slog.NewJSONHandler(&logBuf, nil))
|
||||
|
||||
err = cache.reconcileVariantRows(t.Context())
|
||||
t.Logf("reconcileVariantRows() error = %v, log: %s", err, logBuf.String())
|
||||
|
||||
if err != nil {
|
||||
t.Fatalf("reconcileVariantRows() error = %v", err)
|
||||
}
|
||||
|
||||
rowQuery := `SELECT COUNT(*) FROM variant_content WHERE cache_key = ?`
|
||||
|
||||
if n := countRows(t, cache, rowQuery, string(testVariantKeyOne)); n != 1 {
|
||||
t.Errorf("the variant whose size cannot be read has %d rows, want 1", n)
|
||||
}
|
||||
|
||||
if n := countRows(t, cache, rowQuery, string(testVariantKeyTwo)); n != 0 {
|
||||
t.Errorf("the variant with no file has %d rows, want 0", n)
|
||||
}
|
||||
|
||||
logs := logBuf.String()
|
||||
|
||||
warning := logLineNaming(logs, "WARN", testVariantKeyOne)
|
||||
if !strings.Contains(warning, statErr.Error()) {
|
||||
t.Errorf("no warning names %s and the error %q", testVariantKeyOne, statErr)
|
||||
}
|
||||
|
||||
if line := logLineNaming(logs, "INFO", testVariantKeyOne); line != "" {
|
||||
t.Errorf("the variant whose size cannot be read was logged at info: %s", line)
|
||||
}
|
||||
|
||||
dropped := logLineNaming(logs, "INFO", testVariantKeyTwo)
|
||||
if !strings.Contains(dropped, "dropped accounting row for missing variant file") {
|
||||
t.Errorf("no info line says the file of %s is missing", testVariantKeyTwo)
|
||||
}
|
||||
}
|
||||
|
||||
// TestPeriodicReconciliationAdoptsFileThatAppearsAfterStartup proves
|
||||
// reconciliation is not a one-shot startup-only pass: it must also run
|
||||
// on the periodic ticker, so a variant file that lands on disk with no
|
||||
|
||||
Reference in New Issue
Block a user