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

README.md

@@ -310,6 +310,8 @@ path under `/v1/` answers 200, in maintenance mode too.
     - 403 when the upstream host, or a host it redirects to, has an address in a
       blocked network (see `blocked_networks`).
     - 429 over `image_requests_per_minute` (below).
+    - 499 when the client goes away while waiting for an image another request
+      is making (below).
     - 415 when the upstream answers with a `Content-Type` that is not one of the
       source formats (below).
     - 415 when the upstream sends a body whose first bytes are not those of the
@@ -341,6 +343,7 @@ path under `/v1/` answers 200, in maintenance mode too.
         - 403
         - 415
         - 429
+        - 499
         - 502
         - 503
         - 504

TODO.md

@@ -30,6 +30,17 @@ P2: security: per-origin rate limiting
 
 # Completed Steps
 
+- 2026-10-26 on both image routes, a request is answered 499 and logged at info
+  level when its client goes away while waiting for an image another request is
+  making (closes #339). It was answered 500 and logged at error level, as pixa's
+  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.
+    - `serveImage` answers it before calling `respondImageError`, which cannot
+      see the request's context.
+    - An error wrapping `context.Canceled` while the request's context is live
+      is still answered 500 and logged at error level.
 - 2026-10-26 `README.md`'s Design section starts with a Concepts list (closes
   #321). Each concept gets one sentence, under the name the code gives it.
     - Storage calls the transformed images variants, in shorter sentences.

internal/handlers/client_gone_internal_test.go

@@ -0,0 +1,177 @@
+package handlers
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"log/slog"
+	"net/http"
+	"net/http/httptest"
+	"slices"
+	"testing"
+	"time"
+
+	"github.com/go-chi/chi/v5/middleware"
+	"sneak.berlin/go/pixa/internal/httpfetcher"
+	"sneak.berlin/go/pixa/internal/imagerequest"
+)
+
+// heldFetcher sends on started when a fetch begins, and holds the fetch until
+// release is closed. It then fails the fetch as an upstream error.
+type heldFetcher struct {
+	started chan struct{}
+	release chan struct{}
+}
+
+// Fetch sends on f.started, waits for f.release to be closed, and returns
+// httpfetcher.ErrUpstreamError.
+func (f heldFetcher) Fetch(
+	context.Context, imagerequest.Source,
+) (*httpfetcher.FetchResult, error) {
+	f.started <- struct{}{}
+
+	<-f.release
+
+	return nil, httpfetcher.ErrUpstreamError
+}
+
+// readLogLines decodes the JSON log lines in logs.
+func readLogLines(t *testing.T, logs *bytes.Buffer) []map[string]any {
+	t.Helper()
+
+	t.Logf("logged:\n%s", logs.String())
+
+	var lines []map[string]any
+
+	dec := json.NewDecoder(logs)
+	for dec.More() {
+		var line map[string]any
+
+		err := dec.Decode(&line)
+		if err != nil {
+			t.Fatalf("decoding log line: %v", err)
+		}
+
+		lines = append(lines, line)
+	}
+
+	return lines
+}
+
+// TestImageRoutes_ClientGoneWhileWaitingAnswers499 checks that both image
+// routes answer 499 to a request whose client goes away while it waits for an
+// image another request is making. A first request's fetch is held, so the
+// image is being made, and a second request for the same image waits for it
+// until its client goes away. The second request must be logged once at info
+// level with its request ID and the source host and path. Nothing may be
+// logged at error level.
+func TestImageRoutes_ClientGoneWhileWaitingAnswers499(t *testing.T) {
+	t.Parallel()
+
+	const requestID = "test-request-id"
+
+	for route, imageURL := range photoURLsByRoute() {
+		t.Run(route, func(t *testing.T) {
+			t.Parallel()
+
+			var logs bytes.Buffer
+
+			fetcher := heldFetcher{started: make(chan struct{}), release: make(chan struct{})}
+			h, routes := newRoutesFetchingThrough(t, fetcher,
+				slog.New(slog.NewJSONHandler(&logs, nil)))
+			target := imageURL(t, h)
+
+			firstDone := make(chan struct{})
+
+			go func() {
+				defer close(firstDone)
+
+				sendGet(t, routes, target)
+			}()
+
+			<-fetcher.started
+
+			ctx, cancel := context.WithCancel(context.WithValue(t.Context(),
+				middleware.RequestIDKey, requestID))
+			rec := httptest.NewRecorder()
+			secondDone := make(chan struct{})
+
+			go func() {
+				defer close(secondDone)
+
+				routes.ServeHTTP(rec, httptest.NewRequestWithContext(
+					ctx, http.MethodGet, target, nil))
+			}()
+
+			// Give the second request time to start waiting for the first
+			// request's image. The fetch is still held, so the second request
+			// can end only because its client went away
+			time.Sleep(100 * time.Millisecond)
+			cancel()
+			<-secondDone
+
+			close(fetcher.release)
+			<-firstDone
+
+			if rec.Code != 499 {
+				t.Errorf("status = %d, want 499", rec.Code)
+			}
+
+			var clientGoneLines int
+
+			for _, line := range readLogLines(t, &logs) {
+				if line["level"] == slog.LevelError.String() {
+					t.Errorf("logged at error level: %v", line["msg"])
+				}
+
+				if line["level"] == slog.LevelInfo.String() &&
+					line["msg"] == "client went away before the image was ready" &&
+					line["request_id"] == requestID &&
+					line["host"] == signedHost &&
+					line["path"] == photoPath {
+					clientGoneLines++
+				}
+			}
+
+			if clientGoneLines != 1 {
+				t.Errorf("info line naming the request logged %d times, want 1",
+					clientGoneLines)
+			}
+		})
+	}
+}
+
+// TestImageRoutes_CanceledWithLiveRequestAnswers500 checks that both image
+// routes answer 500, logged as "failed to get image" at error level, for an
+// image service error that wraps context.Canceled while the request's own
+// context is live. Its client has not gone away, so the cancellation is
+// pixa's own failure.
+func TestImageRoutes_CanceledWithLiveRequestAnswers500(t *testing.T) {
+	t.Parallel()
+
+	for route, imageURL := range photoURLsByRoute() {
+		t.Run(route, func(t *testing.T) {
+			t.Parallel()
+
+			var logs bytes.Buffer
+
+			h, routes := newRoutesFetchingThrough(t,
+				failingFetcher{err: context.Canceled},
+				slog.New(slog.NewJSONHandler(&logs, nil)))
+
+			rec := sendGet(t, routes, imageURL(t, h))
+			if rec.Code != http.StatusInternalServerError {
+				t.Errorf("status = %d, want %d",
+					rec.Code, http.StatusInternalServerError)
+			}
+
+			if !slices.ContainsFunc(readLogLines(t, &logs),
+				func(line map[string]any) bool {
+					return line["level"] == slog.LevelError.String() &&
+						line["msg"] == "failed to get image"
+				}) {
+				t.Error(`no "failed to get image" line logged at error level`)
+			}
+		})
+	}
+}

internal/handlers/image.go

@@ -1,6 +1,7 @@
 package handlers
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"io"
@@ -19,6 +20,12 @@ import (
 	"sneak.berlin/go/pixa/internal/magic"
 )
 
+// statusClientClosedRequest is the status nginx calls "client closed
+// request". The image routes answer it when the client goes away while
+// waiting for an image another request is making. Nobody reads it; it is for
+// logs and metrics.
+const statusClientClosedRequest = 499
+
 // HandleImage handles the main image proxy route:
 // /v1/image/<host>/<path>/<width>x<height>.<format>, or with no format
 // /v1/image/<host>/<path>/<width>x<height>
@@ -345,8 +352,9 @@ func notModified(w http.ResponseWriter, r *http.Request, etag string) bool {
 // 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.
+// If-None-Match with 304 and HEAD with the headers only. It answers 499 when
+// the client goes away while waiting for an image another request is making.
+// 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,
@@ -362,6 +370,21 @@ func (s *Handlers) serveImage(
 	startTime := time.Now()
 
 	resp, err := s.imgSvc.Get(r.Context(), req)
+
+	// The client went away before its image was ready, which is not pixa's
+	// failure. A cancellation while the request's context is live is pixa's,
+	// and respondImageError answers it 500.
+	if errors.Is(err, context.Canceled) && r.Context().Err() != nil {
+		s.log.Info("client went away before the image was ready",
+			"request_id", middleware.GetReqID(r.Context()),
+			"host", req.Source.Host,
+			"path", req.Source.Path,
+		)
+		w.WriteHeader(statusClientClosedRequest)
+
+		return
+	}
+
 	if err != nil {
 		s.respondImageError(w, req, err)