From 0ec806fb67687a307455a5e4b79c7d192536b4dd Mon Sep 17 00:00:00 2001 From: sneak Date: Mon, 28 Sep 2026 17:24:13 +0000 Subject: [PATCH] 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 | 4 +- TODO.md | 9 ++++ internal/handlers/image.go | 30 ++++++++++--- internal/imgcache/cache.go | 83 +++++++++++++++++++++++++----------- internal/imgcache/service.go | 7 ++- internal/imgcache/storage.go | 13 ++++-- 6 files changed, 112 insertions(+), 34 deletions(-) diff --git a/README.md b/README.md index 5a1785c..ce8883d 100644 --- a/README.md +++ b/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 diff --git a/TODO.md b/TODO.md index a327b56..672d6d1 100644 --- a/TODO.md +++ b/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 diff --git a/internal/handlers/image.go b/internal/handlers/image.go index 5139905..00b271e 100644 --- a/internal/handlers/image.go +++ b/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, diff --git a/internal/imgcache/cache.go b/internal/imgcache/cache.go index f31880b..172b40e 100644 --- a/internal/imgcache/cache.go +++ b/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 } diff --git a/internal/imgcache/service.go b/internal/imgcache/service.go index d6e07df..3b295c7 100644 --- a/internal/imgcache/service.go +++ b/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) diff --git a/internal/imgcache/storage.go b/internal/imgcache/storage.go index 893b176..b9487ce 100644 --- a/internal/imgcache/storage.go +++ b/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 }