Send the request ID upstream and log it with each image

The fetcher sends the request ID chi's RequestID middleware put in the
context as X-Request-Id, next to User-Agent and Accept, and the
"upstream fetched", "image converted" and "image served" lines carry it
as request_id, as the request log line does. A fetch shared by several
requests runs with the first request's context values, so it carries
that request's ID; README says so where it describes the shared fetch.

Model: opus-5-5

README.md

@@ -141,7 +141,9 @@ Every response carries an `X-Request-ID` header holding the request's ID, which
 a client can quote when reporting a problem: the request's own `X-Request-ID`
 when it sent one, as a reverse proxy in front of pixa may, otherwise one pixa
 makes up from its host name, a random string chosen at startup and a counter.
-pixa's log line for the request carries the same ID as `request_id`.
+pixa's log line for the request carries the same ID as `request_id`, and so do
+the lines it logs when it fetches, converts and serves an image; the fetch sends
+it to the upstream host as `X-Request-ID`.
 
 Both `POST` routes accept only a form that pixa's own page served: the page puts
 a token in the form and sets a cookie to match, and a request without both is
@@ -192,7 +194,9 @@ source) and one transcode: the first request does the work, and the others wait
 for its image or its error, holding no upstream connection or processing slot
 of their own. A waiting request stops waiting when its own client goes away.
 The work goes on for the others even if the first request's client goes away,
-until that request's `downstream_timeout` ends.
+until that request's `downstream_timeout` ends. The shared fetch sends the first
+request's ID upstream, and the lines logged for the fetch and the transcode
+carry that ID.
 
 The login form (`POST /`) is limited to 5 attempts per minute per client
 address, counting an IPv6 client by its /64; an attempt over the limit is

internal/handlers/image.go

@@ -10,6 +10,7 @@ import (
 	"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"
@@ -298,6 +299,7 @@ func (s *Handlers) writeImageResponse(
 	// Log cache status and timing after serving
 	duration := time.Since(startTime)
 	s.log.Info("image served",
+		"request_id", middleware.GetReqID(r.Context()),
 		"cache_key", cacheKey,
 		"cache_status", resp.CacheStatus,
 		"duration_ms", duration.Milliseconds(),

internal/handlers/imageenc.go

@@ -9,6 +9,7 @@ import (
 	"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"
@@ -105,6 +106,7 @@ func (s *Handlers) HandleImageEnc() http.HandlerFunc {
 		// Log completion
 		duration := time.Since(start)
 		s.log.Info("image served",
+			"request_id", middleware.GetReqID(ctx),
 			"cache_key", imgcache.CacheKey(req),
 			"host", req.SourceHost,
 			"path", req.SourcePath,

internal/httpfetcher/httpfetcher.go

@@ -18,6 +18,8 @@ import (
 	"strings"
 	"sync"
 	"time"
+
+	"github.com/go-chi/chi/v5/middleware"
 )
 
 // Fetcher configuration constants.
@@ -267,6 +269,13 @@ func (f *HTTPFetcher) Fetch(ctx context.Context, url string) (*FetchResult, erro
 	req.Header.Set("User-Agent", f.config.UserAgent)
 	req.Header.Set("Accept", strings.Join(f.config.AllowedContentTypes, ", "))
 
+	// The ID of the request this fetch serves, so the fetch can be found in
+	// the upstream host's logs
+	requestID := middleware.GetReqID(ctx)
+	if requestID != "" {
+		req.Header.Set(middleware.RequestIDHeader, requestID)
+	}
+
 	// Use httptrace to capture connection details
 	var remoteAddr string
 

internal/imgcache/service.go

@@ -13,6 +13,7 @@ import (
 
 	"github.com/dustin/go-humanize"
 	"github.com/getsentry/sentry-go"
+	"github.com/go-chi/chi/v5/middleware"
 	"golang.org/x/sync/singleflight"
 	"sneak.berlin/go/pixa/internal/allowlist"
 	"sneak.berlin/go/pixa/internal/httpfetcher"
@@ -461,6 +462,7 @@ func (s *Service) fetchAndProcess(
 
 	// Log upstream fetch details
 	s.log.Info("upstream fetched",
+		"request_id", middleware.GetReqID(ctx),
 		"host", req.SourceHost,
 		"path", req.SourcePath,
 		"bytes", fetchBytes,
@@ -545,6 +547,7 @@ func (s *Service) processAndStore(
 	}
 
 	s.log.Info("image converted",
+		"request_id", middleware.GetReqID(ctx),
 		"host", req.SourceHost,
 		"path", req.SourcePath,
 		"src_format", processResult.InputFormat,