Serve both image routes with one function and one error mapping (closes #316)

HandleImage parses the path and verifies the signature, and HandleImageEnc
decrypts the token. Each then calls serveImage, which chooses the format for
auto, gets the image and serves it: the headers, ETag and 304, HEAD, the copy
and the log line. respondImageError answers the image service's errors on both
routes, and handleImageError is gone. /v1/image/ now answers 504 when the
upstream sends no response headers within upstream_fetch_timeout, as README.md
documented for /v1/e/. /v1/e/ now logs these errors at error level, as
/v1/image/ does. README.md's route tables list 504 for /v1/image/. A new test
sends the same upstream fetch errors through both routes.

Model: opus-5-5

README.md

@@ -265,15 +265,15 @@ path under `/v1/` answers 200, in maintenance mode too.
   a body whose first bytes are not those of its `Content-Type`, for an image of
   the same source URL that pixa can neither serve from its cache nor make from
   the source image still in its cache; 503 when pixa is busy or in maintenance
-  mode; 500 for any other failure.
+  mode; 504 when the upstream has not sent its response headers within
+  `upstream_fetch_timeout`, but 500 when that time runs out while the image
+  itself is still arriving; 500 for any other failure.
 - `GET` or `HEAD` `/v1/e/<token>/<name>` — an image through an encrypted URL
   (see Encrypted URLs). Needs: nothing but the URL. Answers: 200; 304 when
   `If-None-Match` matches the image's `ETag`; 400 for a token that does not
   decrypt, or that asks for a size or fit that is not valid; 410 once it has
-  expired; 504 when the upstream has not sent its response headers within
-  `upstream_fetch_timeout`, but 500 when that time runs out while the image
-  itself is still arriving; 400 for an `Accept` header that is not valid, and
-  406, 403, 415, 429, 502, 503 and 500, as for `/v1/image/`.
+  expired; 400 for an `Accept` header that is not valid, and 406, 403, 415, 429,
+  502, 503, 504 and 500, as for `/v1/image/`.
 - `GET /robots.txt` — asks every crawler to stay away (`Disallow: /`). Needs:
   nothing. Answers: 200.
 - `GET /.well-known/healthcheck.json` — JSON with `status` (`ok`), `now`,

TODO.md

@@ -30,6 +30,18 @@ P2: security: per-origin rate limiting
 
 # Completed Steps
 
+- 2026-10-26 both image routes serve an image with one function, `serveImage`,
+  and answer its errors with one, `respondImageError` (closes #316).
+  `HandleImage` parses the path and verifies the signature, and `HandleImageEnc`
+  decrypts the token. Each then calls `serveImage`.
+    - `handleImageError`, the encrypted route's own mapping, is gone.
+    - `/v1/image/` answers 504 when the upstream has not sent its response
+      headers within `upstream_fetch_timeout`, as `/v1/e/` did. It answered 500.
+    - `/v1/e/` logs the image service's errors at error level, as `/v1/image/`
+      does. It logged only those it answered 500.
+    - The "image served" line carries the host, the path and `fetched_bytes` on
+      both routes, also after a failed write. The debug line "encrypted image
+      request" is gone.
 - 2026-10-26 every key derived from the signing key is derived in one place
   (closes #315): `seal.DeriveKeys` returns them as one `seal.Keys`, with their
   salts declared beside it. `internal/providers` calls it once at startup. Each

internal/handlers/avif_too_large_internal_test.go

@@ -12,11 +12,11 @@ import (
 	"sneak.berlin/go/pixa/internal/imagerequest"
 )
 
-// TestAVIFOutputTooLargeAnswers400 checks that respondImageError and
-// handleImageError, which answer the errors of the two image routes, answer
-// 400 naming the AVIF pixel limit when the image processor refuses an AVIF
-// output above it, wrapped as the service wraps it. The request's source only
-// goes into a log line, so it is left empty.
+// TestAVIFOutputTooLargeAnswers400 checks that respondImageError, which
+// answers the errors of both image routes, answers 400 naming the AVIF pixel
+// limit when the image processor refuses an AVIF output above it, wrapped as
+// the service wraps it. The request's source only goes into a log line, so it
+// is left empty.
 func TestAVIFOutputTooLargeAnswers400(t *testing.T) {
 	t.Parallel()
 
@@ -25,25 +25,15 @@ func TestAVIFOutputTooLargeAnswers400(t *testing.T) {
 		imageprocessor.ErrAVIFOutputTooLarge)
 	wantBody := fmt.Sprintf("above %d pixels", imageprocessor.MaxAVIFOutputPixels)
 
-	plain := httptest.NewRecorder()
-	h.respondImageError(plain, &imagerequest.Request{}, err)
+	rec := httptest.NewRecorder()
+	h.respondImageError(rec, &imagerequest.Request{}, err)
+	t.Logf("status = %d, body = %q", rec.Code, rec.Body.String())
 
-	encrypted := httptest.NewRecorder()
-	h.handleImageError(encrypted, err)
+	if rec.Code != http.StatusBadRequest {
+		t.Errorf("status = %d, want %d", rec.Code, http.StatusBadRequest)
+	}
 
-	for name, rec := range map[string]*httptest.ResponseRecorder{
-		"respondImageError": plain, "handleImageError": encrypted,
-	} {
-		t.Logf("%s: status = %d, body = %q", name, rec.Code, rec.Body.String())
-
-		if rec.Code != http.StatusBadRequest {
-			t.Errorf("%s: status = %d, want %d",
-				name, rec.Code, http.StatusBadRequest)
-		}
-
-		if !strings.Contains(rec.Body.String(), wantBody) {
-			t.Errorf("%s: body = %q, want it to say %q",
-				name, rec.Body.String(), wantBody)
-		}
+	if !strings.Contains(rec.Body.String(), wantBody) {
+		t.Errorf("body = %q, want it to say %q", rec.Body.String(), wantBody)
 	}
 }

internal/handlers/image.go

@@ -46,30 +46,7 @@ func (s *Handlers) HandleImage() http.HandlerFunc {
 			return
 		}
 
-		// The signature covers the format auto, not the format chosen
-		format, ok := s.chooseAutoFormat(w, r, req.Transform.Format)
-		if !ok {
-			return
-		}
-
-		req.Transform.Format = format
-
-		// Get cache key for logging
-		cacheKey := imagerequest.CacheKey(req)
-
-		// Get the image (from cache or fetch/process)
-		startTime := time.Now()
-
-		resp, err := s.imgSvc.Get(r.Context(), req)
-		if err != nil {
-			s.respondImageError(w, req, err)
-
-			return
-		}
-
-		defer func() { _ = resp.Content.Close() }()
-
-		s.writeImageResponse(w, r, req, expires, resp, cacheKey, startTime)
+		s.serveImage(w, r, req, expires)
 	}
 }
 
@@ -242,7 +219,8 @@ func (s *Handlers) HandleTooManyRequests() http.HandlerFunc {
 	}
 }
 
-// respondImageError maps image retrieval errors to HTTP responses.
+// respondImageError answers err, the image service's error for req, on both
+// image routes.
 func (s *Handlers) respondImageError(
 	w http.ResponseWriter, req *imagerequest.Request, err error,
 ) {
@@ -277,6 +255,12 @@ func (s *Handlers) respondImageError(
 		return
 	}
 
+	if errors.Is(err, httpfetcher.ErrUpstreamTimeout) {
+		s.respondError(w, "upstream timeout", http.StatusGatewayTimeout)
+
+		return
+	}
+
 	if errors.Is(err, httpfetcher.ErrTooManyConnections) ||
 		errors.Is(err, imageprocessor.ErrTooManyImages) ||
 		errors.Is(err, imgcache.ErrProcessingTimedOut) {
@@ -367,14 +351,34 @@ func notModified(w http.ResponseWriter, r *http.Request, etag string) bool {
 	return true
 }
 
-// writeImageResponse writes headers and streams the image content,
-// handling conditional and HEAD requests. expires is the URL's expiry, which
-// ends the Cache-Control max-age.
-func (s *Handlers) writeImageResponse(
+// serveImage serves the image that req asks for. Both image routes call it
+// 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, and answers an error
+// of the image service with respondImageError.
+func (s *Handlers) serveImage(
 	w http.ResponseWriter, r *http.Request,
-	req *imagerequest.Request, expires time.Time, resp *imgcache.ImageResponse,
-	cacheKey imagerequest.VariantKey, startTime time.Time,
+	req *imagerequest.Request, expires time.Time,
 ) {
+	// The signature or the token covers the format auto, not the format chosen
+	format, ok := s.chooseAutoFormat(w, r, req.Transform.Format)
+	if !ok {
+		return
+	}
+
+	req.Transform.Format = format
+
+	startTime := time.Now()
+
+	resp, err := s.imgSvc.Get(r.Context(), req)
+	if err != nil {
+		s.respondImageError(w, req, err)
+
+		return
+	}
+
+	defer func() { _ = resp.Content.Close() }()
+
 	// Set response headers
 	w.Header().Set("Content-Type", resp.ContentType)
 
@@ -411,7 +415,9 @@ func (s *Handlers) writeImageResponse(
 	duration := time.Since(startTime)
 	s.log.Info("image served",
 		"request_id", middleware.GetReqID(r.Context()),
-		"cache_key", cacheKey,
+		"cache_key", imagerequest.CacheKey(req),
+		"host", req.Source.Host,
+		"path", req.Source.Path,
 		"cache_status", resp.CacheStatus,
 		"duration_ms", duration.Milliseconds(),
 		"format", req.Transform.Format,

internal/handlers/image_errors_internal_test.go

@@ -1,9 +1,11 @@
 package handlers
 
 import (
+	"context"
 	"encoding/json"
 	"fmt"
 	"image/color"
+	"io"
 	"log/slog"
 	"net/http"
 	"net/http/httptest"
@@ -414,3 +416,66 @@ func TestHandleImage_HashInSourcePathOrQuery_Returns400(t *testing.T) {
 		})
 	}
 }
+
+// failingFetcher answers every fetch with its error.
+type failingFetcher struct {
+	err error
+}
+
+// Fetch returns f's error.
+func (f failingFetcher) Fetch(
+	context.Context, imagerequest.Source,
+) (*httpfetcher.FetchResult, error) {
+	return nil, f.err
+}
+
+// TestImageRoutes_SameErrorAnswers checks that both image routes answer each
+// upstream fetch error below with the same status. Each request gets routes of
+// its own, so no request finds another's failed fetch in the negative cache.
+func TestImageRoutes_SameErrorAnswers(t *testing.T) {
+	t.Parallel()
+
+	tests := []struct {
+		name       string
+		err        error
+		wantStatus int
+	}{
+		{"blocked upstream address", httpfetcher.ErrSSRFBlocked,
+			http.StatusForbidden},
+		{"upstream error status",
+			fmt.Errorf("%w: status 404", httpfetcher.ErrUpstreamError),
+			http.StatusBadGateway},
+		{"no response headers within the fetch timeout",
+			httpfetcher.ErrUpstreamTimeout, http.StatusGatewayTimeout},
+		{"no free upstream connection", httpfetcher.ErrTooManyConnections,
+			http.StatusServiceUnavailable},
+		{"Content-Type not a source format",
+			fmt.Errorf("%w: image/svg+xml", httpfetcher.ErrInvalidContentType),
+			http.StatusUnsupportedMediaType},
+		{"any other failure", io.ErrUnexpectedEOF,
+			http.StatusInternalServerError},
+	}
+
+	// The URL of the JPEG at photoPath on signedHost on each image route.
+	imageURLs := map[string]func(*testing.T, *Handlers) string{
+		"/v1/image/": signedPhotoURL,
+		"/v1/e/":     encPhotoURL,
+	}
+
+	for _, tt := range tests {
+		for route, imageURL := range imageURLs {
+			t.Run(route+" "+tt.name, func(t *testing.T) {
+				t.Parallel()
+
+				h, routes := newRoutesFetchingThrough(t,
+					failingFetcher{err: tt.err}, slog.New(slog.DiscardHandler))
+
+				rec := sendGet(t, routes, imageURL(t, h))
+				if rec.Code != tt.wantStatus {
+					t.Errorf("status = %d, want %d: %s",
+						rec.Code, tt.wantStatus, rec.Body)
+				}
+			})
+		}
+	}
+}

internal/handlers/imageenc.go

@@ -2,21 +2,13 @@ package handlers
 
 import (
 	"errors"
-	"fmt"
-	"io"
 	"net/http"
-	"strconv"
 	"time"
 
 	"github.com/go-chi/chi/v5"
-	"github.com/go-chi/chi/v5/middleware"
 
 	"sneak.berlin/go/pixa/internal/encurl"
-	"sneak.berlin/go/pixa/internal/httpfetcher"
-	"sneak.berlin/go/pixa/internal/imageprocessor"
 	"sneak.berlin/go/pixa/internal/imagerequest"
-	"sneak.berlin/go/pixa/internal/imgcache"
-	"sneak.berlin/go/pixa/internal/magic"
 )
 
 // HandleImageEnc handles requests to /v1/e/{token}/* for encrypted
@@ -28,83 +20,12 @@ func (s *Handlers) HandleImageEnc() http.HandlerFunc {
 			return
 		}
 
-		ctx := r.Context()
-		start := time.Now()
-
 		req, expires, ok := s.parseImageEncRequest(w, r)
 		if !ok {
 			return
 		}
 
-		format, ok := s.chooseAutoFormat(w, r, req.Transform.Format)
-		if !ok {
-			return
-		}
-
-		req.Transform.Format = format
-
-		// Log the request
-		s.log.Debug("encrypted image request",
-			"host", req.Source.Host,
-			"path", req.Source.Path,
-			"dimensions", fmt.Sprintf("%dx%d",
-				req.Transform.Size.Width, req.Transform.Size.Height),
-			"format", req.Transform.Format,
-		)
-
-		// Fetch and process the image (no signature validation
-		// needed - encrypted URL is trusted)
-		resp, err := s.imgSvc.Get(ctx, req)
-		if err != nil {
-			s.handleImageError(w, err)
-
-			return
-		}
-
-		defer func() { _ = resp.Content.Close() }()
-
-		// Set response headers
-		w.Header().Set("Content-Type", resp.ContentType)
-
-		if resp.ContentLength > 0 {
-			w.Header().Set("Content-Length", strconv.FormatInt(resp.ContentLength, 10))
-		}
-
-		// Cache headers: max-age ends at the URL's expiry
-		w.Header().Set("Cache-Control", cacheControl(expires))
-		w.Header().Set("X-Pixa-Cache", string(resp.CacheStatus))
-
-		if notModified(w, r, resp.ETag) {
-			return
-		}
-
-		// A HEAD request gets the headers only
-		if r.Method == http.MethodHead {
-			w.WriteHeader(http.StatusOK)
-
-			return
-		}
-
-		// Stream the response
-		written, err := io.Copy(w, resp.Content)
-		if err != nil {
-			s.log.Error("failed to write response", "error", err)
-
-			return
-		}
-
-		// Log completion
-		duration := time.Since(start)
-		s.log.Info("image served",
-			"request_id", middleware.GetReqID(ctx),
-			"cache_key", imagerequest.CacheKey(req),
-			"host", req.Source.Host,
-			"path", req.Source.Path,
-			"format", req.Transform.Format,
-			"cache_status", resp.CacheStatus,
-			"served_bytes", written,
-			"duration_ms", duration.Milliseconds(),
-		)
+		s.serveImage(w, r, req, expires)
 	}
 }
 
@@ -154,38 +75,3 @@ func (s *Handlers) parseImageEncRequest(
 
 	return req, expires, true
 }
-
-// handleImageError converts image service errors to HTTP responses.
-func (s *Handlers) handleImageError(w http.ResponseWriter, err error) {
-	switch {
-	case errors.Is(err, httpfetcher.ErrSSRFBlocked):
-		s.respondError(w, "forbidden", http.StatusForbidden)
-	case errors.Is(err, httpfetcher.ErrUpstreamError):
-		s.respondError(w, "upstream error", http.StatusBadGateway)
-	case errors.Is(err, httpfetcher.ErrUpstreamTimeout):
-		s.respondError(w, "upstream timeout", http.StatusGatewayTimeout)
-	case errors.Is(err, httpfetcher.ErrTooManyConnections),
-		errors.Is(err, imageprocessor.ErrTooManyImages),
-		errors.Is(err, imgcache.ErrProcessingTimedOut):
-		s.respondError(w, "server busy, try again later",
-			http.StatusServiceUnavailable)
-	case errors.Is(err, httpfetcher.ErrInvalidContentType),
-		errors.Is(err, imageprocessor.ErrUnsupportedInputFormat),
-		errors.Is(err, magic.ErrMagicByteMismatch),
-		errors.Is(err, magic.ErrUnknownFormat),
-		errors.Is(err, magic.ErrNotEnoughData):
-		s.respondError(w, "unsupported source format",
-			http.StatusUnsupportedMediaType)
-	case errors.Is(err, imageprocessor.ErrOutputTooLarge):
-		s.respondError(w, fmt.Sprintf("size too large for the source: the side "+
-			"computed from its proportions is above %d",
-			imageprocessor.MaxOutputDimension), http.StatusBadRequest)
-	case errors.Is(err, imageprocessor.ErrAVIFOutputTooLarge):
-		s.respondError(w, fmt.Sprintf("size too large for AVIF: the output "+
-			"would be above %d pixels", imageprocessor.MaxAVIFOutputPixels),
-			http.StatusBadRequest)
-	default:
-		s.log.Error("image request failed", "error", err)
-		s.respondError(w, "internal error", http.StatusInternalServerError)
-	}
-}

internal/handlers/server_busy_internal_test.go

@@ -15,9 +15,10 @@ import (
 	"sneak.berlin/go/pixa/internal/imgcache"
 )
 
-// TestServerBusyAnswers503 checks that both image routes answer 503 with
-// a clear error when the image service gives up waiting for a free upstream
-// connection or processing slot, wrapped as the service wraps them.
+// TestServerBusyAnswers503 checks that respondImageError, which answers the
+// errors of both image routes, answers 503 with a clear error when the image
+// service gives up waiting for a free upstream connection or processing slot,
+// wrapped as the service wraps them.
 func TestServerBusyAnswers503(t *testing.T) {
 	t.Parallel()
 
@@ -30,35 +31,28 @@ func TestServerBusyAnswers503(t *testing.T) {
 		fmt.Errorf("upstream fetch failed: %w", httpfetcher.ErrTooManyConnections),
 		fmt.Errorf("image processing failed: %w", imageprocessor.ErrTooManyImages),
 	} {
-		plain := httptest.NewRecorder()
-		h.respondImageError(plain, req, err)
+		rec := httptest.NewRecorder()
+		h.respondImageError(rec, req, err)
 
-		encrypted := httptest.NewRecorder()
-		h.handleImageError(encrypted, err)
+		if rec.Code != http.StatusServiceUnavailable {
+			t.Errorf("for %v: status = %d, want %d",
+				err, rec.Code, http.StatusServiceUnavailable)
+		}
 
-		for route, rec := range map[string]*httptest.ResponseRecorder{
-			"/v1/image/": plain, "/v1/e/": encrypted,
-		} {
-			if rec.Code != http.StatusServiceUnavailable {
-				t.Errorf("%s for %v: status = %d, want %d",
-					route, err, rec.Code, http.StatusServiceUnavailable)
-			}
-
-			if !strings.Contains(rec.Body.String(), "server busy, try again later") {
-				t.Errorf("%s for %v: body = %q, want the server busy error",
-					route, err, rec.Body.String())
-			}
+		if !strings.Contains(rec.Body.String(), "server busy, try again later") {
+			t.Errorf("for %v: body = %q, want the server busy error",
+				err, rec.Body.String())
 		}
 	}
 }
 
-// TestProcessingTimedOutAnswers503 checks that respondImageError and
-// handleImageError, which answer the errors of the two image routes, answer
-// 503 with the server busy error when the image service reports that
-// processing stopped at the deadline of the request doing it, wrapped as the
-// service wraps it. A request that waited for that processing gets this error
-// while its own deadline may have time left. The request's source only goes
-// into a log line, so it is left empty.
+// TestProcessingTimedOutAnswers503 checks that respondImageError, which
+// answers the errors of both image routes, answers 503 with the server busy
+// error when the image service reports that processing stopped at the
+// deadline of the request doing it, wrapped as the service wraps it. A request
+// that waited for that processing gets this error while its own deadline may
+// have time left. The request's source only goes into a log line, so it is
+// left empty.
 func TestProcessingTimedOutAnswers503(t *testing.T) {
 	t.Parallel()
 
@@ -66,25 +60,15 @@ func TestProcessingTimedOutAnswers503(t *testing.T) {
 	err := fmt.Errorf("%w: failed to encode: %w",
 		imgcache.ErrProcessingTimedOut, context.DeadlineExceeded)
 
-	plain := httptest.NewRecorder()
-	h.respondImageError(plain, &imagerequest.Request{}, err)
+	rec := httptest.NewRecorder()
+	h.respondImageError(rec, &imagerequest.Request{}, err)
+	t.Logf("status = %d, body = %q", rec.Code, rec.Body.String())
 
-	encrypted := httptest.NewRecorder()
-	h.handleImageError(encrypted, err)
+	if rec.Code != http.StatusServiceUnavailable {
+		t.Errorf("status = %d, want %d", rec.Code, http.StatusServiceUnavailable)
+	}
 
-	for name, rec := range map[string]*httptest.ResponseRecorder{
-		"respondImageError": plain, "handleImageError": encrypted,
-	} {
-		t.Logf("%s: status = %d, body = %q", name, rec.Code, rec.Body.String())
-
-		if rec.Code != http.StatusServiceUnavailable {
-			t.Errorf("%s: status = %d, want %d",
-				name, rec.Code, http.StatusServiceUnavailable)
-		}
-
-		if !strings.Contains(rec.Body.String(), "server busy, try again later") {
-			t.Errorf("%s: body = %q, want the server busy error",
-				name, rec.Body.String())
-		}
+	if !strings.Contains(rec.Body.String(), "server busy, try again later") {
+		t.Errorf("body = %q, want the server busy error", rec.Body.String())
 	}
 }

internal/handlers/unsupported_source_internal_test.go

@@ -13,10 +13,11 @@ import (
 	"sneak.berlin/go/pixa/internal/imagerequest"
 )
 
-// TestUnsupportedSourceFormatAnswers415 checks that both image routes answer
-// 415 with a clear error when the upstream answers with a content type pixa
-// does not accept, such as SVG, and when orig is asked of a source in a
-// format the processor cannot name, wrapped as the service wraps them.
+// TestUnsupportedSourceFormatAnswers415 checks that respondImageError, which
+// answers the errors of both image routes, answers 415 with a clear error when
+// the upstream answers with a content type pixa does not accept, such as SVG,
+// and when orig is asked of a source in a format the processor cannot name,
+// wrapped as the service wraps them.
 func TestUnsupportedSourceFormatAnswers415(t *testing.T) {
 	t.Parallel()
 
@@ -31,26 +32,18 @@ func TestUnsupportedSourceFormatAnswers415(t *testing.T) {
 		fmt.Errorf("image processing failed: %w: unknown",
 			imageprocessor.ErrUnsupportedInputFormat),
 	} {
-		plain := httptest.NewRecorder()
-		h.respondImageError(plain, req, err)
+		rec := httptest.NewRecorder()
+		h.respondImageError(rec, req, err)
+		t.Logf("for %v: %d %s", err, rec.Code, rec.Body.String())
 
-		encrypted := httptest.NewRecorder()
-		h.handleImageError(encrypted, err)
+		if rec.Code != http.StatusUnsupportedMediaType {
+			t.Errorf("for %v: status = %d, want %d",
+				err, rec.Code, http.StatusUnsupportedMediaType)
+		}
 
-		for route, rec := range map[string]*httptest.ResponseRecorder{
-			"HandleImage": plain, "HandleImageEnc": encrypted,
-		} {
-			t.Logf("%s for %v: %d %s", route, err, rec.Code, rec.Body.String())
-
-			if rec.Code != http.StatusUnsupportedMediaType {
-				t.Errorf("%s for %v: status = %d, want %d",
-					route, err, rec.Code, http.StatusUnsupportedMediaType)
-			}
-
-			if !strings.Contains(rec.Body.String(), "unsupported source format") {
-				t.Errorf("%s for %v: body = %q, want the unsupported source format error",
-					route, err, rec.Body.String())
-			}
+		if !strings.Contains(rec.Body.String(), "unsupported source format") {
+			t.Errorf("for %v: body = %q, want the unsupported source format error",
+				err, rec.Body.String())
 		}
 	}
 }