Answer 499 to a client that goes away while waiting for an image (closes #339)

When a request waits for an image another request is making and its
client goes away, the image proxy returns context.Canceled. serveImage
now answers it 499, the status nginx calls "client closed request". It
logs it once at info level with the request_id, host and path. It was
answered 500 and logged at error level, as pixa's own failure. A
cancellation while the request's context is live is still answered 500.
The request making the image is still answered as before. README.md
lists the 499 on both image routes.

Model: opus-5-5

TODO.md

@@ -30,28 +30,10 @@ P2: security: per-origin rate limiting
 
 # Completed Steps
 
-- 2026-10-27 the reconciliation pass skips a directory it cannot list and a file
-  whose info it cannot read, and goes on (closes #343). It stopped before its
-  later checks at a directory it could not list, or at a source or variant file
-  whose info it could not read.
-    - It logs the warning "skipped unreadable entry in cache directory", with
-      the path and the error.
-    - A file renamed or removed after its directory was listed gets no warning.
-    - `reconcileFiles` reads each file's info once, before the temp-file check,
-      and hands it to `sweepStaleTempFile`, `reconcileVariantFile` or
-      `reconcileSourceFile`.
-    - A cancelled context still stops the walk with its error.
-- 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
+  level when its client goes away while waiting for an image another request is
-  request making the image (closes #339). It was answered 500 and logged at
+  making (closes #339). It was answered 500 and logged at error level, as pixa's
-  error level, as pixa's own failure.
+  own failure.
     - The line is "client went away before the image was ready". It carries the
       `request_id`, the host and the path.
     - The 499 has no body, since nobody reads it.

internal/handlers/client_gone_internal_test.go

@@ -58,14 +58,13 @@ func readLogLines(t *testing.T, logs *bytes.Buffer) []map[string]any {
 	return lines
 }
 
-// TestImageRoutes_ClientGoneWhileWaitingAnswers499 checks that both image
+// TestImageRoutes_ClientGoneAnswers499 checks that both image routes answer
-// routes answer 499 to a request whose client goes away while it waits for an
+// 499 to a request whose client goes away while its image is being made. A
-// image another request is making. A first request's fetch is held, so the
+// first request's fetch is held, so the image is being made, and a second
-// image is being made, and a second request for the same image waits for it
+// request for the same image waits for it until its client goes away. The
-// until its client goes away. The second request must be logged once at info
+// second request must be logged once at info level with its request ID and
-// level with its request ID and the source host and path. Nothing may be
+// the source host and path. Nothing may be logged at error level.
-// logged at error level.
+func TestImageRoutes_ClientGoneAnswers499(t *testing.T) {
-func TestImageRoutes_ClientGoneWhileWaitingAnswers499(t *testing.T) {
 	t.Parallel()
 
 	const requestID = "test-request-id"

internal/handlers/image.go

@@ -21,9 +21,9 @@ import (
 )
 
 // statusClientClosedRequest is the status nginx calls "client closed
-// request". The image routes answer it when the client goes away before its
+// request". The image routes answer it when the client goes away while
-// image is ready, unless its request is the one making the image. Nobody reads
+// waiting for an image another request is making. Nobody reads it; it is for
-// it; it is for logs and metrics.
+// logs and metrics.
 const statusClientClosedRequest = 499
 
 // HandleImage handles the main image proxy route:
@@ -353,8 +353,8 @@ func notModified(w http.ResponseWriter, r *http.Request, etag string) bool {
 // once they have the request and its URL's expiry, which ends the
 // Cache-Control max-age. It chooses the format for the format auto, answers
 // If-None-Match with 304 and HEAD with the headers only. It answers 499 when
-// the image service stopped because the client went away, and any other error
+// the client goes away while waiting for an image another request is making.
-// of the image service with respondImageError.
+// It answers any other error of the image service with respondImageError.
 func (s *Handlers) serveImage(
 	w http.ResponseWriter, r *http.Request,
 	req *imagerequest.Request, expires time.Time,

internal/imgcache/eviction.go

@@ -515,15 +515,12 @@ func (c *Cache) reconcileAccounting(ctx context.Context) error {
 }
 
 // reconcileFiles walks baseDir, one of the cache's storage directories,
-// sweeping stale temp files and passing each other file, with its info and
+// sweeping stale temp files and passing each other file, with its name, to
-// name, to reconcileFile. It skips a directory it cannot list and a file
+// reconcileFile. Once ctx is cancelled it stops at the next file and
-// whose info it cannot read, so one such entry does not stop the pass. It
+// returns ctx's error.
-// logs a warning naming the path and the error. A file renamed or removed
-// after its directory was listed is skipped with no warning. Once ctx is
-// cancelled it stops at the next file and returns ctx's error.
 func (c *Cache) reconcileFiles(
 	ctx context.Context, baseDir string,
-	reconcileFile func(path string, info fs.FileInfo, name string) error,
+	reconcileFile func(path string, entry fs.DirEntry, name string) error,
 ) error {
 	return filepath.WalkDir(
 		baseDir,
@@ -532,38 +529,19 @@ func (c *Cache) reconcileFiles(
 				return ctx.Err()
 			}
 
-			if err != nil {
+			if err != nil || entry.IsDir() {
-				c.log.Warn("skipped unreadable entry in cache directory",
+				return err
-					"path", path, "error", err)
-
-				return nil
-			}
-
-			if entry.IsDir() {
-				return nil
-			}
-
-			info, err := entry.Info()
-			if errors.Is(err, fs.ErrNotExist) {
-				return nil
-			}
-
-			if err != nil {
-				c.log.Warn("skipped unreadable entry in cache directory",
-					"path", path, "error", err)
-
-				return nil
 			}
 
 			name := entry.Name()
 
 			if strings.HasPrefix(name, tempFilePrefix) {
-				c.sweepStaleTempFile(path, info)
+				c.sweepStaleTempFile(path, entry)
 
 				return nil
 			}
 
-			return reconcileFile(path, info, name)
+			return reconcileFile(path, entry, name)
 		},
 	)
 }
@@ -573,8 +551,8 @@ func (c *Cache) reconcileFiles(
 // and sweeping stale temp files.
 func (c *Cache) reconcileVariantFiles(ctx context.Context) error {
 	return c.reconcileFiles(ctx, c.variants.baseDir,
-		func(path string, info fs.FileInfo, name string) error {
+		func(path string, entry fs.DirEntry, name string) error {
-			return c.reconcileVariantFile(ctx, path, info, imagerequest.VariantKey(name))
+			return c.reconcileVariantFile(ctx, path, entry, imagerequest.VariantKey(name))
 		})
 }
 
@@ -584,11 +562,16 @@ func (c *Cache) reconcileVariantFiles(ctx context.Context) error {
 // crash or a restored snapshot can leave it, is removed with its row and
 // a warning naming it, so the variant is converted again.
 func (c *Cache) reconcileVariantFile(
-	ctx context.Context, path string, info fs.FileInfo, cacheKey imagerequest.VariantKey,
+	ctx context.Context, path string, entry fs.DirEntry, cacheKey imagerequest.VariantKey,
 ) error {
+	info, err := entry.Info()
+	if err != nil {
+		return fmt.Errorf("failed to stat variant file: %w", err)
+	}
+
 	var recordedSize int64
 
-	err := c.db.QueryRowContext(ctx,
+	err = c.db.QueryRowContext(ctx,
 		`SELECT size_bytes FROM variant_content WHERE cache_key = ?`, string(cacheKey),
 	).Scan(&recordedSize)
 
@@ -630,9 +613,7 @@ func (c *Cache) adoptVariantFile(
 }
 
 // reconcileVariantRows drops accounting rows whose variant files are
-// missing, so the database never references deleted content. A file whose
+// missing, so the database never references deleted content.
-// 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
 
@@ -660,13 +641,6 @@ 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 {
@@ -731,8 +705,8 @@ func queryStringColumn[T ~string](
 // and sweeping stale temp files.
 func (c *Cache) reconcileSourceFiles(ctx context.Context) error {
 	return c.reconcileFiles(ctx, c.srcContent.baseDir,
-		func(path string, info fs.FileInfo, name string) error {
+		func(path string, entry fs.DirEntry, name string) error {
-			return c.reconcileSourceFile(ctx, path, info, imagerequest.SourceKey(name))
+			return c.reconcileSourceFile(ctx, path, entry, imagerequest.SourceKey(name))
 		})
 }
 
@@ -743,11 +717,16 @@ func (c *Cache) reconcileSourceFiles(ctx context.Context) error {
 // is removed with its row and a warning naming it, so the source is
 // fetched again.
 func (c *Cache) reconcileSourceFile(
-	ctx context.Context, path string, info fs.FileInfo, key imagerequest.SourceKey,
+	ctx context.Context, path string, entry fs.DirEntry, key imagerequest.SourceKey,
 ) error {
+	info, err := entry.Info()
+	if err != nil {
+		return fmt.Errorf("failed to stat source content file: %w", err)
+	}
+
 	var recordedSize int64
 
-	err := c.db.QueryRowContext(ctx,
+	err = c.db.QueryRowContext(ctx,
 		`SELECT size_bytes FROM source_content WHERE source_key = ?`,
 		string(key),
 	).Scan(&recordedSize)
@@ -912,12 +891,17 @@ func (c *Cache) correctUsageTotal(
 
 // sweepStaleTempFile removes a temp file left behind by a crashed
 // write once it is old enough that no in-flight store can own it.
-func (c *Cache) sweepStaleTempFile(path string, info fs.FileInfo) {
+func (c *Cache) sweepStaleTempFile(path string, entry fs.DirEntry) {
+	info, err := entry.Info()
+	if err != nil {
+		return
+	}
+
 	if time.Since(info.ModTime()) < staleTempFileAge {
 		return
 	}
 
-	err := os.Remove(path)
+	err = os.Remove(path)
 	if err != nil && !os.IsNotExist(err) {
 		c.log.Warn("failed to remove stale temp file", "path", path, "error", err)
 

internal/imgcache/eviction_internal_test.go

@@ -9,10 +9,8 @@ import (
 	"log/slog"
 	"os"
 	"path/filepath"
-	"slices"
 	"strings"
 	"sync"
-	"syscall"
 	"testing"
 	"time"
 
@@ -701,291 +699,6 @@ 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)
-	}
-}
-
-// openDirectoryNearPathLimit makes a chain of directories inside dir, each
-// named with 255 zeros, the longest name Linux allows. Linux refuses a path
-// of 4096 bytes or more, and the chain goes as deep as it can below that.
-// It returns the chain's deepest directory as an os.Root, closed when the
-// test ends. An entry made through it with a 255-byte name has a path even
-// the root user cannot read. The os.Root can make that entry because it
-// names the entry only by its name, not by the whole path.
-func openDirectoryNearPathLimit(t *testing.T, dir string) *os.Root {
-	t.Helper()
-
-	name := strings.Repeat("0", 255)
-	deepest := dir
-
-	for len(filepath.Join(deepest, name)) < 4096 {
-		deepest = filepath.Join(deepest, name)
-	}
-
-	err := os.MkdirAll(deepest, StorageDirPerm)
-	if err != nil {
-		t.Fatalf("failed to make a chain of directories: %v", err)
-	}
-
-	root, err := os.OpenRoot(deepest)
-	if err != nil {
-		t.Fatalf("os.OpenRoot(%s) error = %v", deepest, err)
-	}
-
-	t.Cleanup(func() { _ = root.Close() })
-
-	return root
-}
-
-// makeEntriesTooLongToRead makes a new directory and a new file in the
-// deepest directory of the chain that openDirectoryNearPathLimit makes
-// inside dir. Even the root user can then neither list the new directory
-// nor read the new file's info. It returns the paths of the new directory
-// and the new file.
-func makeEntriesTooLongToRead(t *testing.T, dir string) []string {
-	t.Helper()
-
-	deepest := openDirectoryNearPathLimit(t, dir)
-	dirName := strings.Repeat("0", 255)
-
-	err := deepest.Mkdir(dirName, StorageDirPerm)
-	if err != nil {
-		t.Fatalf("failed to make a directory too deep to list: %v", err)
-	}
-
-	fileName := strings.Repeat("1", 255)
-
-	err = deepest.WriteFile(fileName, []byte("unreadable"), StorageFilePerm)
-	if err != nil {
-		t.Fatalf("failed to make a file too deep to read: %v", err)
-	}
-
-	return []string{
-		filepath.Join(deepest.Name(), dirName),
-		filepath.Join(deepest.Name(), fileName),
-	}
-}
-
-// makeTempFileTooLongToRead makes a temp file in the deepest directory of
-// the chain that openDirectoryNearPathLimit makes inside dir. Even the
-// root user then cannot read the temp file's info. It returns the temp
-// file's path.
-func makeTempFileTooLongToRead(t *testing.T, dir string) string {
-	t.Helper()
-
-	deepest := openDirectoryNearPathLimit(t, dir)
-	name := tempFilePrefix + strings.Repeat("1", 255-len(tempFilePrefix))
-
-	err := deepest.WriteFile(name, []byte("partial"), StorageFilePerm)
-	if err != nil {
-		t.Fatalf("failed to make a temp file too deep to read: %v", err)
-	}
-
-	return filepath.Join(deepest.Name(), name)
-}
-
-// assertSkippedEntryWarning checks that logs hold the warning "skipped
-// unreadable entry in cache directory" naming path, with the error
-// ENAMETOOLONG for that path.
-func assertSkippedEntryWarning(t *testing.T, logs, path string) {
-	t.Helper()
-
-	for line := range strings.Lines(logs) {
-		if strings.Contains(line, `"level":"WARN"`) &&
-			strings.Contains(line, `"msg":"skipped unreadable entry in cache directory"`) &&
-			strings.Contains(line, `"path":"`+path+`"`) &&
-			strings.Contains(line, path+": "+syscall.ENAMETOOLONG.Error()) {
-			return
-		}
-	}
-
-	t.Errorf("no warning %q names %s with the error %q",
-		"skipped unreadable entry in cache directory", path, syscall.ENAMETOOLONG)
-}
-
-// TestReconciliationGoesOnPastEntriesItCannotRead puts, in each storage
-// directory, a directory the pass cannot list and a file whose info it
-// cannot read. The pass walks each directory in name order, so it reaches
-// them before the cache's files, whose keys start with a letter. It must
-// log a warning naming each one's path and the error, and still do the
-// rest of its work:
-//   - adopt a variant file that has no row
-//   - drop the row of a variant whose file is missing
-//   - remove a source file that has no row
-//   - correct a wrong total cache usage
-func TestReconciliationGoesOnPastEntriesItCannotRead(t *testing.T) {
-	t.Parallel()
-
-	cache, _ := newEvictionTestCache(t, 1<<30)
-	ctx := t.Context()
-
-	untrackedVariant := []byte("variant with no row")
-
-	err := cache.variants.Write(string(testVariantKeyOne), untrackedVariant)
-	if err != nil {
-		t.Fatalf("failed to write a variant file with no row: %v", err)
-	}
-
-	storeEvictionTestVariant(t, cache, testVariantKeyTwo, []byte("variant two"))
-
-	err = os.Remove(cache.variants.keyToPath(string(testVariantKeyTwo)))
-	if err != nil {
-		t.Fatalf("failed to remove the second variant's file: %v", err)
-	}
-
-	untrackedSourceKey := "ffeeddcc0001"
-
-	err = cache.srcContent.Write(untrackedSourceKey, []byte("source with no row"))
-	if err != nil {
-		t.Fatalf("failed to write a source file with no row: %v", err)
-	}
-
-	_, err = cache.db.ExecContext(ctx,
-		`UPDATE cache_usage SET total_size_bytes = 1 WHERE id = 1`)
-	if err != nil {
-		t.Fatalf("failed to set a wrong total: %v", err)
-	}
-
-	unreadable := slices.Concat(
-		makeEntriesTooLongToRead(t, cache.variants.baseDir),
-		makeEntriesTooLongToRead(t, cache.srcContent.baseDir),
-	)
-
-	logs := reconcileAsAtStartup(t, cache)
-
-	for _, path := range unreadable {
-		assertSkippedEntryWarning(t, logs, path)
-	}
-
-	rowQuery := `SELECT COUNT(*) FROM variant_content WHERE cache_key = ?`
-
-	if n := countRows(t, cache, rowQuery, string(testVariantKeyOne)); n != 1 {
-		t.Errorf("the variant file with no row got %d rows, want 1", n)
-	}
-
-	if n := countRows(t, cache, rowQuery, string(testVariantKeyTwo)); n != 0 {
-		t.Errorf("the variant with no file kept %d rows, want 0", n)
-	}
-
-	_, err = os.Stat(cache.srcContent.keyToPath(untrackedSourceKey))
-	if err == nil {
-		t.Error("the source file with no row is still on disk")
-	}
-
-	usage, err := cache.UsageBytes(ctx)
-	if err != nil {
-		t.Fatalf("UsageBytes() error = %v", err)
-	}
-
-	if usage != int64(len(untrackedVariant)) {
-		t.Errorf("UsageBytes() = %d, want %d, the size of the adopted variant",
-			usage, len(untrackedVariant))
-	}
-}
-
-// TestReconciliationWarnsOfTempFilesWhoseInfoItCannotRead puts, in each
-// storage directory, a temp file whose info the pass cannot read. The
-// pass must log a warning naming each one's path and the error, as it
-// does for any other file whose info it cannot read.
-func TestReconciliationWarnsOfTempFilesWhoseInfoItCannotRead(t *testing.T) {
-	t.Parallel()
-
-	cache, _ := newEvictionTestCache(t, 1<<30)
-
-	unreadable := []string{
-		makeTempFileTooLongToRead(t, cache.variants.baseDir),
-		makeTempFileTooLongToRead(t, cache.srcContent.baseDir),
-	}
-
-	logs := reconcileAsAtStartup(t, cache)
-
-	for _, path := range unreadable {
-		assertSkippedEntryWarning(t, logs, path)
-	}
-}
-
 // 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