Refuse an unparseable exp with 400; log swallowed cache errors (closes #72)

An exp that was not a whole number, or empty, was ignored, so a URL for
a host that needs a signature got 401 as if it had no exp. It is now a
400 naming exp and the value; only an exp missing from the URL is
unchanged.

A failed variant .meta write, source metadata JSON write, Stats count
query, stats counter update, negative cache write or expired negative
cache delete was discarded without a trace. Each is now logged at warn
with the path or key and the error, and stays non-fatal. VariantStorage
takes the cache's logger for this. The metadata JSON write moved out of
StoreSource into writeMetadataSidecar to keep StoreSource within the
function length limit.

Model: opus-5-5

README.md

@@ -127,7 +127,9 @@ Where:
 - `width` — requested width in pixels, `0` for original
 - `height` — requested height in pixels, `0` for original
 - `format` — output format (jpeg, png, webp, avif, gif, orig)
-- `expiration` — Unix timestamp when signature expires
+- `expiration` — the URL's `exp` query parameter, the Unix timestamp when
+  the signature expires; a request whose `exp` is not a whole number, an
+  empty `exp=` included, is refused with 400
 - `quality` — the URL's `q` query parameter, a whole number from 1 to 100,
   or `85` when the URL has no `q`; a request whose `q` is anything else is
   refused with 400

TODO.md

@@ -30,6 +30,15 @@ exhaustion
 
 # Completed Steps
 
+- 2026-09-28 refuse an unparseable `exp` on `/v1/image/` and log swallowed
+  cache errors (closes #72): an `exp` in the URL that is not a whole
+  number, an empty `exp=` included, is a 400 naming `exp` and the value,
+  instead of being ignored and answered with 401 as if the URL had no
+  `exp`; only an `exp` missing from the URL is unchanged; `README.md` says
+  so where it documents `exp`. A failed variant `.meta` write, source
+  metadata JSON write, `Stats` count query, stats counter update, negative
+  cache write or expired negative cache delete is now logged at `warn`
+  with the path or key and the error, and stays non-fatal.
 - 2026-09-28 refuse an empty `fit` on `/v1/image/` (closes #139): a
   `fit` in the URL with an empty value (`fit=`) is a 400 naming `fit`,
   instead of being served as `cover` and verified against a signature

internal/handlers/image.go

@@ -116,11 +116,11 @@ func (s *Handlers) parseImageRequest(
 
 	req.Signature = query.Get("sig")
 
-	if expStr := query.Get("exp"); expStr != "" {
-		exp, parseErr := strconv.ParseInt(expStr, 10, 64)
-		if parseErr == nil {
-			req.Expires = time.Unix(exp, 0)
-		}
+	req.Expires, err = parseExpires(query)
+	if err != nil {
+		s.respondError(w, err.Error(), http.StatusBadRequest)
+
+		return nil, false
 	}
 
 	// Parse optional quality and fit params. Only a q missing from the URL is
@@ -174,6 +174,26 @@ func (s *Handlers) parseImageRequest(
 	return req, true
 }
 
+// parseExpires reads the exp query parameter, a Unix time in seconds. An exp
+// missing from the URL gives the zero time, which the signature check takes
+// as no expiration. An exp in the URL that is not a whole number, an empty
+// one included, is an error naming exp and the value.
+func parseExpires(query url.Values) (time.Time, error) {
+	if !query.Has("exp") {
+		return time.Time{}, nil
+	}
+
+	expStr := query.Get("exp")
+
+	exp, err := strconv.ParseInt(expStr, 10, 64)
+	if err != nil {
+		return time.Time{}, fmt.Errorf("%w exp: not a number, got %q",
+			errInvalidFormField, expStr)
+	}
+
+	return time.Unix(exp, 0), nil
+}
+
 // respondImageError maps image retrieval errors to HTTP responses.
 func (s *Handlers) respondImageError(
 	w http.ResponseWriter, req *imgcache.ImageRequest, err error,

internal/imgcache/cache.go

@@ -125,7 +125,7 @@ func NewCache(db *sql.DB, config CacheConfig) (*Cache, error) {
 	}
 
 	variants, err := NewVariantStorage(
-		filepath.Join(config.StateDir, "cache", "variants"),
+		filepath.Join(config.StateDir, "cache", "variants"), log,
 	)
 	if err != nil {
 		return nil, fmt.Errorf("failed to create variant storage: %w", err)
@@ -263,23 +263,7 @@ func (c *Cache) StoreSource(
 		return "", fmt.Errorf("failed to insert source metadata: %w", err)
 	}
 
-	// Store metadata JSON file
-	meta := &SourceMetadata{
-		Host:            req.SourceHost,
-		Path:            req.SourcePath,
-		Query:           req.SourceQuery,
-		ContentHash:     string(contentHash),
-		StatusCode:      result.StatusCode,
-		ContentType:     result.ContentType,
-		ContentLength:   result.ContentLength,
-		ResponseHeaders: result.Headers,
-		FetchedAt:       time.Now().UTC().Unix(),
-		FetchDurationMs: result.FetchDurationMs,
-		RemoteAddr:      result.RemoteAddr,
-	}
-
-	// A failure here is non-fatal; the metadata is in the database.
-	_ = c.srcMetadata.Store(req.SourceHost, pathHash, meta)
+	c.writeMetadataSidecar(req, pathHash, contentHash, result)
 
 	c.notifyWritePressure()
 
@@ -436,12 +420,19 @@ func (c *Cache) Stats(ctx context.Context) (*CacheStats, error) {
 	}
 
 	// Get actual item count and total size from content tables
-	_ = c.db.QueryRowContext(ctx,
+	err = c.db.QueryRowContext(ctx,
 		`SELECT COUNT(*) FROM request_cache`,
 	).Scan(&stats.TotalItems)
-	_ = c.db.QueryRowContext(ctx,
+	if err != nil {
+		c.log.Warn("failed to count cache items for stats", "error", err)
+	}
+
+	err = c.db.QueryRowContext(ctx,
 		`SELECT COALESCE(SUM(size_bytes), 0) FROM output_content`,
 	).Scan(&stats.TotalSizeBytes)
+	if err != nil {
+		c.log.Warn("failed to sum cache size for stats", "error", err)
+	}
 
 	// Compute hit rate as a ratio
 	if stats.HitCount+stats.MissCount > 0 {
@@ -453,15 +444,17 @@ func (c *Cache) Stats(ctx context.Context) (*CacheStats, error) {
 
 // IncrementStats increments cache statistics.
 func (c *Cache) IncrementStats(ctx context.Context, hit bool, fetchBytes int64) {
+	var err error
+
 	if hit {
-		_, _ = c.db.ExecContext(ctx, `
+		_, err = c.db.ExecContext(ctx, `
 			UPDATE cache_stats
 			SET hit_count = hit_count + 1,
 			    last_updated_at = CURRENT_TIMESTAMP
 			WHERE id = 1
 		`)
 	} else {
-		_, _ = c.db.ExecContext(ctx, `
+		_, err = c.db.ExecContext(ctx, `
 			UPDATE cache_stats
 			SET miss_count = miss_count + 1,
 			    last_updated_at = CURRENT_TIMESTAMP
@@ -469,14 +462,52 @@ func (c *Cache) IncrementStats(ctx context.Context, hit bool, fetchBytes int64)
 		`)
 	}
 
+	if err != nil {
+		c.log.Warn("failed to count cache hit or miss", "hit", hit, "error", err)
+	}
+
 	if fetchBytes > 0 {
-		_, _ = c.db.ExecContext(ctx, `
+		_, err = c.db.ExecContext(ctx, `
 			UPDATE cache_stats
 			SET upstream_fetch_count = upstream_fetch_count + 1,
 			    upstream_fetch_bytes = upstream_fetch_bytes + ?,
 			    last_updated_at = CURRENT_TIMESTAMP
 			WHERE id = 1
 		`, fetchBytes)
+		if err != nil {
+			c.log.Warn("failed to count upstream fetch",
+				"fetch_bytes", fetchBytes, "error", err)
+		}
+	}
+}
+
+// writeMetadataSidecar writes the JSON metadata sidecar of a stored source.
+// A failure is logged and is otherwise non-fatal; the metadata is in the
+// database.
+func (c *Cache) writeMetadataSidecar(
+	req *ImageRequest,
+	pathHash PathHash,
+	contentHash ContentHash,
+	result *httpfetcher.FetchResult,
+) {
+	meta := &SourceMetadata{
+		Host:            req.SourceHost,
+		Path:            req.SourcePath,
+		Query:           req.SourceQuery,
+		ContentHash:     string(contentHash),
+		StatusCode:      result.StatusCode,
+		ContentType:     result.ContentType,
+		ContentLength:   result.ContentLength,
+		ResponseHeaders: result.Headers,
+		FetchedAt:       time.Now().UTC().Unix(),
+		FetchDurationMs: result.FetchDurationMs,
+		RemoteAddr:      result.RemoteAddr,
+	}
+
+	err := c.srcMetadata.Store(req.SourceHost, pathHash, meta)
+	if err != nil {
+		c.log.Warn("failed to write metadata sidecar",
+			"host", req.SourceHost, "path_hash", pathHash, "error", err)
 	}
 }
 
@@ -528,10 +559,14 @@ func (c *Cache) checkNegativeCache(
 	// Check if expired
 	if time.Now().After(expiresAt) {
 		// Clean up expired entry
-		_, _ = c.db.ExecContext(ctx, `
+		_, err = c.db.ExecContext(ctx, `
 			DELETE FROM negative_cache
 			WHERE source_host = ? AND source_path = ? AND source_query = ?
 		`, req.SourceHost, req.SourcePath, req.SourceQuery)
+		if err != nil {
+			c.log.Warn("failed to delete expired negative cache entry",
+				"host", req.SourceHost, "path", req.SourcePath, "error", err)
+		}
 
 		return false, nil
 	}

internal/imgcache/service.go

@@ -322,7 +322,12 @@ func (s *Service) fetchAndProcess(
 		// Store negative cache for certain errors
 		if isNegativeCacheable(err) {
 			statusCode := extractStatusCode(err)
-			_ = s.cache.StoreNegative(ctx, req, statusCode, err.Error())
+
+			storeErr := s.cache.StoreNegative(ctx, req, statusCode, err.Error())
+			if storeErr != nil {
+				s.log.Warn("failed to store negative cache entry",
+					"host", req.SourceHost, "path", req.SourcePath, "error", storeErr)
+			}
 		}
 
 		return nil, fmt.Errorf("upstream fetch failed: %w", err)

internal/imgcache/storage.go

@@ -7,6 +7,7 @@ import (
 	"errors"
 	"fmt"
 	"io"
+	"log/slog"
 	"os"
 	"path/filepath"
 	"time"
@@ -392,6 +393,7 @@ func CacheKey(req *ImageRequest) VariantKey {
 // Unlike ContentStorage, the key is provided by the caller (not computed from content).
 type VariantStorage struct {
 	baseDir string
+	log     *slog.Logger
 }
 
 // VariantMeta contains metadata about a cached variant.
@@ -404,13 +406,14 @@ type VariantMeta struct {
 }
 
 // NewVariantStorage creates a new variant storage at the given base directory.
-func NewVariantStorage(baseDir string) (*VariantStorage, error) {
+// A failed .meta write is logged to log.
+func NewVariantStorage(baseDir string, log *slog.Logger) (*VariantStorage, error) {
 	err := os.MkdirAll(baseDir, StorageDirPerm)
 	if err != nil {
 		return nil, fmt.Errorf("failed to create variant storage directory: %w", err)
 	}
 
-	return &VariantStorage{baseDir: baseDir}, nil
+	return &VariantStorage{baseDir: baseDir, log: log}, nil
 }
 
 // Store writes content and metadata to storage at the given key.
@@ -478,7 +481,11 @@ func (s *VariantStorage) Store(
 	}
 
 	// Metadata write failure is non-fatal; content is already stored.
-	_ = os.WriteFile(metaPath, metaData, StorageFilePerm)
+	err = os.WriteFile(metaPath, metaData, StorageFilePerm)
+	if err != nil {
+		s.log.Warn("failed to write variant metadata sidecar",
+			"path", metaPath, "error", err)
+	}
 
 	return size, nil
 }