Support SVG sources (closes #68)

The fetcher accepts image/svg+xml; internal/magic detects SVG. orig of
an SVG at the orig size is the SVG unchanged, cached, with a
Content-Security-Policy allowing only its styles and data: images; at
another size, ErrSVGNotOriginalSize (400). Any other format renders it
at the least size covering the output, at most 8192 on a side.
Rendering refuses an SVG with a side over 8192 times the other
(ErrSVGTooThin, 415), and the orig size of one above 8192 on a side
(ErrSVGTooLargeForOrigSize, 400). Child processes of pixad read an
SVG's size and render it, killed after 20 seconds and limited to 1 GiB;
any failure there is ErrSVGRenderFailed (415). Tests pinning the SVG
refusal now expect SVG.

Model: opus-5-5

.gitignore

@@ -70,4 +70,3 @@ vendor/
 # Local dev configs
 config.yml
 config.yaml
-config.dev.yml

Makefile

@@ -79,12 +79,15 @@ docker-versioned:
 docker-test:
 	@script/test
 
-# Run local dev server in Docker
+# Run local dev server in Docker, with debug on and a new random signing
+# key each run. Log in to the page with the key it prints.
 devserver: docker-versioned devserver-stop
+	@key="$$(head -c 32 /dev/urandom | base64)" && \
 	docker run -d --name pixad-dev -p 8080:8080 \
-		-v $(CURDIR)/config.dev.yml:/etc/pixa/config.yml:ro \
+		-e PIXA_SIGNING_KEY="$$key" -e PIXA_DEBUG=true \
-		pixa:latest
+		pixa:latest >/dev/null && \
-	@echo "pixad running at http://localhost:8080"
+	echo "pixad running at http://localhost:8080" && \
+	echo "signing key: $$key"
 
 # Stop dev server
 devserver-stop:

cmd/pixad/main.go

@@ -1,10 +1,21 @@
-// Package main is the entry point for the pixad image proxy server.
+// Package main is the entry point for the pixad image proxy server. pixad
+// also runs as a child process of itself, to read the size of an SVG source
+// or to render it (see imageprocessor.RunAsSVGChildProcess).
 package main
 
-import "sneak.berlin/go/pixa/internal/app"
+import (
+	"os"
+
+	"sneak.berlin/go/pixa/internal/app"
+	"sneak.berlin/go/pixa/internal/imageprocessor"
+)
 
 var Version string //nolint:gochecknoglobals // set by ldflags
 
 func main() {
+	if imageprocessor.IsSVGChildProcess(os.Args[1:]) {
+		os.Exit(imageprocessor.RunAsSVGChildProcess(os.Args[1:]))
+	}
+
 	app.Run(Version)
 }

configs/config.example.yml

@@ -158,8 +158,9 @@ access_control_allow_origin: "*"
 # Sentry DSN for error reporting (default: empty, which turns it off)
 sentry_dsn: ""
 
-# Username and password for /metrics, set together (default: unset). Metrics
+# Username and password for /metrics, set together (default: unset). pixa
-# are measured and /metrics is served only when both are set.
+# serves /metrics, and measures HTTP requests, only when both are set. It
+# measures the pixa_ metrics either way.
 # metrics:
 #   username: "admin"
 #   password: "secret"

go.mod

@@ -17,6 +17,7 @@ require (
 	github.com/prometheus/client_golang v1.23.2
 	github.com/slok/go-http-metrics v0.13.0
 	github.com/spf13/cobra v1.10.2
+	go.uber.org/dig v1.19.0
 	go.uber.org/fx v1.24.0
 	golang.org/x/crypto v0.41.0
 	golang.org/x/sync v0.19.0
@@ -126,7 +127,6 @@ require (
 	go.opentelemetry.io/otel v1.36.0 // indirect
 	go.opentelemetry.io/otel/metric v1.36.0 // indirect
 	go.opentelemetry.io/otel/trace v1.36.0 // indirect
-	go.uber.org/dig v1.19.0 // indirect
 	go.uber.org/multierr v1.11.0 // indirect
 	go.uber.org/zap v1.27.0 // indirect
 	go.yaml.in/yaml/v2 v2.4.2 // indirect

internal/app/app.go

@@ -2,13 +2,16 @@
 package app
 
 import (
+	"context"
 	"fmt"
+	"io"
 	"os"
 	"os/signal"
 	"syscall"
 
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/spf13/cobra"
+	"go.uber.org/dig"
 	"go.uber.org/fx"
 	"sneak.berlin/go/pixa/internal/config"
 	"sneak.berlin/go/pixa/internal/database"
@@ -53,7 +56,10 @@ func run(_ *cobra.Command, _ []string) {
 	// A write to a closed stdout or stderr must not end the process.
 	signal.Ignore(syscall.SIGPIPE)
 
-	fx.New(
+	app := fx.New(
+		// pixad logs with slog only; runApp prints a startup or shutdown
+		// error itself.
+		fx.NopLogger,
 		fx.Provide(
 			config.New,
 			database.New,
@@ -71,5 +77,40 @@ func run(_ *cobra.Command, _ []string) {
 			func(log *logger.Logger) { log.Identify() },
 			func(*server.Server) {},
 		),
-	).Run()
+	)
+
+	exitCode := runApp(app, os.Stderr)
+	if exitCode != 0 {
+		os.Exit(exitCode)
+	}
+}
+
+// runApp starts app, waits for a signal or a shutdown request, stops app,
+// and returns the status pixad exits with, as fx.App.Run does. It prints
+// a start or stop error to stderr, once, as the error that caused it:
+// dig.RootCause drops the frames fx and dig wrap around it.
+func runApp(app *fx.App, stderr io.Writer) int {
+	startCtx, cancelStart := context.WithTimeout(context.Background(), app.StartTimeout())
+	defer cancelStart()
+
+	err := app.Start(startCtx)
+	if err != nil {
+		_, _ = fmt.Fprintln(stderr, dig.RootCause(err))
+
+		return 1
+	}
+
+	shutdown := <-app.Wait()
+
+	stopCtx, cancelStop := context.WithTimeout(context.Background(), app.StopTimeout())
+	defer cancelStop()
+
+	err = app.Stop(stopCtx)
+	if err != nil {
+		_, _ = fmt.Fprintln(stderr, dig.RootCause(err))
+
+		return 1
+	}
+
+	return shutdown.ExitCode
 }

internal/app/app_internal_test.go

@@ -0,0 +1,65 @@
+package app
+
+import (
+	"bytes"
+	"context"
+	"errors"
+	"io"
+	"testing"
+
+	"go.uber.org/fx"
+)
+
+var errTestStopFailed = errors.New("test stop hook failed")
+
+// TestRunAppPrintsStopErrorOnce checks that when a stop hook fails, runApp
+// prints the hook's error once and returns exit status 1.
+func TestRunAppPrintsStopErrorOnce(t *testing.T) {
+	t.Parallel()
+
+	app := fx.New(
+		fx.NopLogger,
+		fx.Invoke(func(lifecycle fx.Lifecycle, shutdowner fx.Shutdowner) {
+			lifecycle.Append(fx.Hook{
+				// Ask to shut down as soon as the app has started, so
+				// that runApp goes on to stop it.
+				OnStart: func(context.Context) error { return shutdowner.Shutdown() },
+				OnStop:  func(context.Context) error { return errTestStopFailed },
+			})
+		}),
+	)
+
+	var stderr bytes.Buffer
+
+	exitCode := runApp(app, &stderr)
+	if exitCode != 1 {
+		t.Errorf("runApp() = %d, want 1", exitCode)
+	}
+
+	want := errTestStopFailed.Error() + "\n"
+	if stderr.String() != want {
+		t.Errorf("stderr = %q, want %q", stderr.String(), want)
+	}
+}
+
+// TestRunAppReturnsShutdownExitCode checks that runApp returns the exit
+// code a shutdown request names.
+func TestRunAppReturnsShutdownExitCode(t *testing.T) {
+	t.Parallel()
+
+	app := fx.New(
+		fx.NopLogger,
+		fx.Invoke(func(lifecycle fx.Lifecycle, shutdowner fx.Shutdowner) {
+			lifecycle.Append(fx.Hook{
+				OnStart: func(context.Context) error {
+					return shutdowner.Shutdown(fx.ExitCode(3))
+				},
+			})
+		}),
+	)
+
+	exitCode := runApp(app, io.Discard)
+	if exitCode != 3 {
+		t.Errorf("runApp() = %d, want 3", exitCode)
+	}
+}

internal/app/app_test.go

@@ -0,0 +1,177 @@
+package app_test
+
+import (
+	"bytes"
+	"errors"
+	"fmt"
+	"net"
+	"net/http"
+	"os"
+	"os/exec"
+	"strconv"
+	"syscall"
+	"testing"
+	"time"
+
+	"sneak.berlin/go/pixa/internal/app"
+)
+
+// These tests run pixad in a child process: the test binary itself,
+// started again with runPixadInChildEnvVar set, which makes TestMain run
+// pixad instead of the tests.
+const runPixadInChildEnvVar = "TEST_RUN_PIXAD_IN_CHILD"
+
+const validTestSigningKey = "test-signing-key-for-app-tests-0123456789"
+
+func TestMain(m *testing.M) {
+	if os.Getenv(runPixadInChildEnvVar) == "1" {
+		os.Args = []string{"pixad"}
+
+		app.Run("test")
+		os.Exit(0)
+	}
+
+	os.Exit(m.Run())
+}
+
+// pixadCommand returns a command that runs pixad with only the given
+// environment, in an empty directory with an empty HOME, so that no
+// config file is found.
+func pixadCommand(t *testing.T, env ...string) (*exec.Cmd, *bytes.Buffer) {
+	t.Helper()
+
+	testBinary := os.Args[0]
+	cmd := exec.CommandContext(t.Context(), testBinary) //nolint:gosec // not tainted
+	cmd.Dir = t.TempDir()
+	// A test binary built with -cover warns on stderr at exit when
+	// GOCOVERDIR is not set.
+	cmd.Env = append([]string{
+		runPixadInChildEnvVar + "=1",
+		"HOME=" + t.TempDir(),
+		"GOCOVERDIR=" + t.TempDir(),
+	}, env...)
+
+	var stderr bytes.Buffer
+
+	cmd.Stderr = &stderr
+
+	return cmd, &stderr
+}
+
+// TestRunPrintsStartupErrorOnce checks that an invalid setting is
+// printed once, as the line that names it, and nothing else goes to
+// stderr.
+func TestRunPrintsStartupErrorOnce(t *testing.T) {
+	t.Parallel()
+
+	cmd, stderr := pixadCommand(t, "PIXA_SIGNING_KEY=short")
+
+	err := cmd.Run()
+
+	var exitErr *exec.ExitError
+	if !errors.As(err, &exitErr) || exitErr.ExitCode() != 1 {
+		t.Fatalf("pixad: got %v, want exit status 1; stderr:\n%s", err, stderr)
+	}
+
+	want := `config key "signing_key" (environment variable PIXA_SIGNING_KEY): ` +
+		"value too short: must be at least 32 characters, got 5\n"
+	if stderr.String() != want {
+		t.Errorf("stderr:\n%s\nwant:\n%s", stderr, want)
+	}
+}
+
+// TestRunWritesNothingToStderrOnStartAndStop starts pixad, waits until
+// it answers its health check, stops it with SIGTERM, and checks that it
+// wrote nothing to stderr.
+func TestRunWritesNothingToStderrOnStartAndStop(t *testing.T) {
+	t.Parallel()
+
+	port := freePort(t)
+	cmd, stderr := pixadCommand(t,
+		"PORT="+strconv.Itoa(port),
+		"PIXA_STATE_DIR="+t.TempDir(),
+		"PIXA_SIGNING_KEY="+validTestSigningKey,
+	)
+
+	err := cmd.Start()
+	if err != nil {
+		t.Fatalf("starting pixad: %v", err)
+	}
+
+	waitForHealthCheck(t, cmd, port, stderr)
+
+	err = cmd.Process.Signal(syscall.SIGTERM)
+	if err != nil {
+		t.Fatalf("signalling pixad: %v", err)
+	}
+
+	err = cmd.Wait()
+	if err != nil {
+		t.Fatalf("pixad: got %v, want exit status 0; stderr:\n%s", err, stderr)
+	}
+
+	if stderr.Len() != 0 {
+		t.Errorf("stderr is not empty:\n%s", stderr)
+	}
+}
+
+// freePort returns a TCP port on the loopback address that nothing
+// listens on.
+func freePort(t *testing.T) int {
+	t.Helper()
+
+	var listenConfig net.ListenConfig
+
+	listener, err := listenConfig.Listen(t.Context(), "tcp", "127.0.0.1:0")
+	if err != nil {
+		t.Fatalf("finding a free port: %v", err)
+	}
+
+	addr, ok := listener.Addr().(*net.TCPAddr)
+	if !ok {
+		t.Fatalf("listener address %v is not a TCP address", listener.Addr())
+	}
+
+	err = listener.Close()
+	if err != nil {
+		t.Fatalf("closing listener: %v", err)
+	}
+
+	return addr.Port
+}
+
+// waitForHealthCheck waits up to 30 seconds for pixad, started as cmd, to
+// answer its health check on port. If it does not, it stops pixad and
+// fails the test with what pixad wrote to stderr.
+func waitForHealthCheck(t *testing.T, cmd *exec.Cmd, port int, stderr *bytes.Buffer) {
+	t.Helper()
+
+	url := fmt.Sprintf("http://127.0.0.1:%d/.well-known/healthcheck.json", port)
+	deadline := time.Now().Add(30 * time.Second)
+
+	for time.Now().Before(deadline) {
+		req, err := http.NewRequestWithContext(t.Context(), http.MethodGet, url, nil)
+		if err != nil {
+			t.Fatalf("health check request: %v", err)
+		}
+
+		resp, err := http.DefaultClient.Do(req)
+		if err == nil {
+			_ = resp.Body.Close()
+
+			if resp.StatusCode == http.StatusOK {
+				return
+			}
+		}
+
+		time.Sleep(100 * time.Millisecond)
+	}
+
+	// Stop pixad first: stderr is complete, and safe to read, only once
+	// cmd.Wait has returned.
+	_ = cmd.Process.Kill()
+	_ = cmd.Wait()
+
+	t.Fatalf("pixad did not answer its health check on port %d; stderr:\n%s",
+		port, stderr)
+}

internal/db/migrations/001_schema.sql

@@ -3,14 +3,24 @@
 
 -- Source images, one row per source URL
 -- Files stored at: cache/sources/<ab>/<cd>/<source_key>, where source_key
--- is the SHA-256 of the source's host, path and query
+-- is the SHA-256 of the source's host, path and query.
+-- fetched_at is when the cached bytes were fetched. checked_at is when
+-- upstream last sent them or answered that they had not changed.
+-- upstream_etag and upstream_last_modified are the ETag and Last-Modified
+-- headers upstream sent with the bytes, or '' when it sent none.
 CREATE TABLE IF NOT EXISTS source_content (
     source_key TEXT PRIMARY KEY,
     size_bytes INTEGER NOT NULL,
-    last_accessed_at DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP
+    last_accessed_at DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP,
+    fetched_at DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP,
+    checked_at DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP,
+    upstream_etag TEXT NOT NULL DEFAULT '',
+    upstream_last_modified TEXT NOT NULL DEFAULT ''
 );
 CREATE INDEX IF NOT EXISTS idx_source_content_last_accessed
     ON source_content(last_accessed_at);
+CREATE INDEX IF NOT EXISTS idx_source_content_checked
+    ON source_content(checked_at);
 
 -- Processed variant blobs
 -- Files stored at: cache/variants/<ab>/<cd>/<cache_key>. Tracked here
@@ -18,14 +28,24 @@ CREATE INDEX IF NOT EXISTS idx_source_content_last_accessed
 -- without a directory scan, and so LRU eviction has a timestamp to order
 -- on. A cache hit does not read this table: it takes the content type
 -- from the file's first bytes, and its last_accessed_at is written
--- later, in a batch.
+-- later, in a batch. checked_at is the checked_at of the source the
+-- variant was made from, when it was made or last renewed; the variant
+-- file's modification time holds the same time for cache hits.
+-- upstream_etag and upstream_last_modified are those of the source bytes
+-- the variant was made from, so the variant can still be checked with
+-- upstream after its source is evicted.
 CREATE TABLE IF NOT EXISTS variant_content (
     cache_key TEXT PRIMARY KEY,
     size_bytes INTEGER NOT NULL,
-    last_accessed_at DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP
+    last_accessed_at DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP,
+    checked_at DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP,
+    upstream_etag TEXT NOT NULL DEFAULT '',
+    upstream_last_modified TEXT NOT NULL DEFAULT ''
 );
 CREATE INDEX IF NOT EXISTS idx_variant_content_last_accessed
     ON variant_content(last_accessed_at);
+CREATE INDEX IF NOT EXISTS idx_variant_content_checked
+    ON variant_content(checked_at);
 
 -- Total cache usage: the sum of size_bytes over source_content and
 -- variant_content, kept by the triggers below in the same statement

internal/handlers/auth_csrf_internal_test.go

@@ -55,7 +55,7 @@ func newCSRFTestRouter(t *testing.T) (*Handlers, http.Handler) {
 		config:      cfg,
 		sessMgr:     session.NewManager(keys.SessionHashKey, keys.SessionBlockKey),
 		encGen:      encurl.NewGenerator(keys.EncryptedURLKey),
-		csrfProtect: newCSRFProtect(keys.CSRFKey, cfg.Debug),
+		csrfProtect: newCSRFProtect(keys.CSRFKey, cfg.Debug, slog.New(slog.DiscardHandler)),
 	}
 
 	r := chi.NewRouter()

internal/handlers/bodylimit_internal_test.go

@@ -43,7 +43,7 @@ func newBodyLimitTestRouter(
 		config:      cfg,
 		sessMgr:     session.NewManager(keys.SessionHashKey, keys.SessionBlockKey),
 		encGen:      encurl.NewGenerator(keys.EncryptedURLKey),
-		csrfProtect: newCSRFProtect(keys.CSRFKey, cfg.Debug),
+		csrfProtect: newCSRFProtect(keys.CSRFKey, cfg.Debug, slog.New(slog.DiscardHandler)),
 	}
 
 	r := chi.NewRouter()

internal/handlers/client_gone_internal_test.go

@@ -26,7 +26,7 @@ type heldFetcher 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,
+	context.Context, imagerequest.Source, string, string,
 ) (*httpfetcher.FetchResult, error) {
 	f.started <- struct{}{}
 

internal/handlers/csrf.go

@@ -1,18 +1,43 @@
 package handlers
 
 import (
+	"bytes"
+	"errors"
 	"html/template"
+	"log/slog"
 	"net/http"
+	"net/url"
 
+	"github.com/go-chi/chi/v5/middleware"
 	"github.com/gorilla/csrf"
 
 	"sneak.berlin/go/pixa/internal/seal"
+	"sneak.berlin/go/pixa/internal/templates"
+)
+
+// The causes the form-refused page names, each with what to do about it.
+const (
+	causePlainHTTP = "This page was opened over plain HTTP while debug is " +
+		"off. Open it over HTTPS, or turn debug on to use plain HTTP on " +
+		"your own machine."
+	causeHTTPSWithDebug = "This page was opened over HTTPS while debug is " +
+		"on. Turn debug off, or open the page over plain HTTP."
+	causeOtherHost = "The form was sent from another host than the one in " +
+		"the request's Host header. A reverse proxy in front of pixa must " +
+		"pass the Host header on unchanged."
+	causeNoReferer = "The browser sent neither an Origin nor a Referer " +
+		"header, and over HTTPS pixa needs one to check where the form " +
+		"came from. Let the browser send the Referer header to this site."
+	causeStaleToken = "The form token is missing or out of date. Reload " +
+		"the page and submit the form again."
 )
 
 // newCSRFProtect builds the CSRF-protection middleware for the
 // state-mutating HTML form routes. The token lives in its own cookie,
 // independent of the session cookie, so it also protects the login POST
-// where no session exists yet (login CSRF). key signs that cookie.
+// where no session exists yet (login CSRF). key signs that cookie. A
+// refused form is answered by the handler that handleFormRefused returns.
+// log gets a warning with the library's reason, such as "origin invalid".
 //
 // When plaintext is true (local HTTP development), requests are marked
 // plaintext so the library neither demands an https Referer nor sets a
@@ -20,13 +45,14 @@ import (
 // service runs behind a TLS-terminating proxy, so plaintext is false and
 // the library enforces its https Referer origin check.
 func newCSRFProtect(
-	key [seal.KeySize]byte, plaintext bool,
+	key [seal.KeySize]byte, plaintext bool, log *slog.Logger,
 ) func(http.Handler) http.Handler {
 	protect := csrf.Protect(
 		key[:],
 		csrf.Path("/"),
 		csrf.Secure(!plaintext),
 		csrf.SameSite(csrf.SameSiteStrictMode),
+		csrf.ErrorHandler(handleFormRefused(plaintext, log)),
 	)
 
 	if !plaintext {
@@ -42,6 +68,84 @@ func newCSRFProtect(
 	}
 }
 
+// handleFormRefused returns the handler the CSRF middleware calls when it
+// refuses a request. It logs the library's reason with the request ID and
+// answers 403 with a page naming the cause and what to do. A reason that is
+// not a refusal, such as a failure to make a token, answers 500.
+func handleFormRefused(plaintext bool, log *slog.Logger) http.Handler {
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		reason := csrf.FailureReason(r)
+		requestID := middleware.GetReqID(r.Context())
+
+		cause := formRefusedCause(r, reason, plaintext)
+		if cause == "" {
+			log.Error("CSRF middleware failed",
+				"request_id", requestID, "error", reason)
+			http.Error(w, "Internal server error",
+				http.StatusInternalServerError)
+
+			return
+		}
+
+		log.Warn("form refused", "request_id", requestID, "reason", reason)
+
+		var page bytes.Buffer
+
+		err := templates.Render(&page, "form_refused.html",
+			struct{ Cause string }{Cause: cause})
+		if err != nil {
+			log.Error("failed to render form refused template", "error", err)
+			http.Error(w, "Internal server error",
+				http.StatusInternalServerError)
+
+			return
+		}
+
+		w.Header().Set("Content-Type", "text/html; charset=utf-8")
+		w.WriteHeader(http.StatusForbidden)
+
+		_, err = page.WriteTo(w)
+		if err != nil {
+			log.Error("failed to write form refused page", "error", err)
+		}
+	})
+}
+
+// formRefusedCause returns the cause the form-refused page names for the
+// CSRF middleware's reason, or "" when the reason is not a refusal.
+func formRefusedCause(r *http.Request, reason error, plaintext bool) string {
+	switch {
+	case errors.Is(reason, csrf.ErrNoToken), errors.Is(reason, csrf.ErrBadToken):
+		return causeStaleToken
+	case errors.Is(reason, csrf.ErrNoReferer):
+		return causeNoReferer
+	case errors.Is(reason, csrf.ErrBadOrigin):
+		return pageAddressCause(r.Header.Get("Origin"), r.Host, plaintext)
+	case errors.Is(reason, csrf.ErrBadReferer):
+		return pageAddressCause(r.Referer(), r.Host, plaintext)
+	default:
+		return ""
+	}
+}
+
+// pageAddressCause returns the cause for a form whose page address, the
+// Origin or Referer header, the CSRF middleware refused. The middleware
+// expects the request's own host, with https when plaintext is false and
+// http when it is true. So on the request's own host, only the scheme was
+// wrong.
+func pageAddressCause(pageAddress, host string, plaintext bool) string {
+	page, err := url.Parse(pageAddress)
+	if err != nil || page.Host != host {
+		return causeOtherHost
+	}
+
+	if plaintext {
+		return causeHTTPSWithDebug
+	}
+
+	return causePlainHTTP
+}
+
 // CSRF returns the CSRF-protection middleware for the login and generator
 // form routes.
 func (s *Handlers) CSRF() func(http.Handler) http.Handler {

internal/handlers/csrf_refused_internal_test.go

@@ -0,0 +1,205 @@
+package handlers
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"html/template"
+	"log/slog"
+	"net/http"
+	"net/http/httptest"
+	"net/url"
+	"strings"
+	"testing"
+
+	"github.com/go-chi/chi/v5/middleware"
+	"github.com/gorilla/csrf"
+
+	"sneak.berlin/go/pixa/internal/seal"
+)
+
+// refusedFormRequestID is the request ID of the requests postRefusedForm
+// sends, which the warning for a refused form must carry.
+const refusedFormRequestID = "test-request-id"
+
+// TestFormRefusedNamesCause verifies that a form the CSRF middleware refuses
+// answers 403 with a page naming the cause, and logs a warning with the
+// request ID and the middleware's reason.
+func TestFormRefusedNamesCause(t *testing.T) {
+	t.Parallel()
+
+	tests := []struct {
+		name       string
+		debug      bool
+		origin     string
+		referer    string
+		wantCause  string
+		wantReason error
+	}{
+		{
+			name:       "plain HTTP origin with debug off",
+			origin:     "http://example.com",
+			wantCause:  causePlainHTTP,
+			wantReason: csrf.ErrBadOrigin,
+		},
+		{
+			name:       "plain HTTP referer with debug off",
+			referer:    "http://example.com/",
+			wantCause:  causePlainHTTP,
+			wantReason: csrf.ErrBadReferer,
+		},
+		{
+			name:       "origin on another host",
+			origin:     "https://proxy.example.net",
+			wantCause:  causeOtherHost,
+			wantReason: csrf.ErrBadOrigin,
+		},
+		{
+			name:       "referer on another host",
+			referer:    "https://proxy.example.net/",
+			wantCause:  causeOtherHost,
+			wantReason: csrf.ErrBadReferer,
+		},
+		{
+			name:       "HTTPS origin with debug on",
+			debug:      true,
+			origin:     "https://example.com",
+			wantCause:  causeHTTPSWithDebug,
+			wantReason: csrf.ErrBadOrigin,
+		},
+		{
+			name:       "no origin or referer with debug off",
+			wantCause:  causeNoReferer,
+			wantReason: csrf.ErrNoReferer,
+		},
+		{
+			name:       "missing token",
+			debug:      true,
+			origin:     "http://example.com",
+			wantCause:  causeStaleToken,
+			wantReason: csrf.ErrNoToken,
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			t.Parallel()
+
+			rec, logLine := postRefusedForm(t, tt.debug, tt.origin, tt.referer,
+				nil, "")
+			checkFormRefused(t, rec, logLine, tt.wantCause, tt.wantReason)
+		})
+	}
+}
+
+// TestFormRefusedNamesCauseForForeignToken verifies that a form whose token
+// does not match its CSRF cookie answers 403 with a page naming
+// causeStaleToken, and logs a warning with the request ID and the
+// middleware's reason.
+func TestFormRefusedNamesCauseForForeignToken(t *testing.T) {
+	t.Parallel()
+
+	// The router and postRefusedForm derive their CSRF key from
+	// testSigningKey, so cookiesA is valid there and only tokenB is wrong.
+	_, router := newCSRFTestRouter(t)
+	cookiesA, _ := csrfCredentials(t, router, nil)
+	_, tokenB := csrfCredentials(t, router, nil)
+
+	rec, logLine := postRefusedForm(t, true, "http://example.com", "",
+		cookiesA, tokenB)
+	checkFormRefused(t, rec, logLine, causeStaleToken, csrf.ErrBadToken)
+}
+
+// postRefusedForm sends a POST with the given cookies to the CSRF
+// middleware built for debug. It adds the form token and the Origin and
+// Referer headers when they are not empty. It returns the response and the
+// one JSON log line the middleware wrote.
+func postRefusedForm(
+	t *testing.T, debug bool, origin, referer string,
+	cookies []*http.Cookie, token string,
+) (*httptest.ResponseRecorder, map[string]any) {
+	t.Helper()
+
+	keys, err := seal.DeriveKeys(testSigningKey)
+	if err != nil {
+		t.Fatalf("seal.DeriveKeys() error = %v", err)
+	}
+
+	var logs bytes.Buffer
+
+	log := slog.New(slog.NewJSONHandler(&logs, nil))
+	reached := http.HandlerFunc(func(_ http.ResponseWriter, _ *http.Request) {
+		t.Error("the refused form reached the handler behind the middleware")
+	})
+	srv := newCSRFProtect(keys.CSRFKey, debug, log)(reached)
+
+	form := url.Values{loginKeyField: {"x"}}
+	if token != "" {
+		form.Set(csrfTokenField, token)
+	}
+
+	ctx := context.WithValue(context.Background(),
+		middleware.RequestIDKey, refusedFormRequestID)
+	req := httptest.NewRequestWithContext(ctx, http.MethodPost,
+		"http://example.com/", strings.NewReader(form.Encode()))
+	req.Header.Set("Content-Type", "application/x-www-form-urlencoded")
+
+	for _, c := range cookies {
+		req.AddCookie(c)
+	}
+
+	if origin != "" {
+		req.Header.Set("Origin", origin)
+	}
+
+	if referer != "" {
+		req.Header.Set("Referer", referer)
+	}
+
+	rec := httptest.NewRecorder()
+	srv.ServeHTTP(rec, req)
+
+	var logLine map[string]any
+
+	err = json.Unmarshal(logs.Bytes(), &logLine)
+	if err != nil {
+		t.Fatalf("decoding log line %q: %v", logs.String(), err)
+	}
+
+	return rec, logLine
+}
+
+// checkFormRefused checks that rec is a 403 page naming wantCause and that
+// logLine is a warning carrying the request ID and wantReason.
+func checkFormRefused(
+	t *testing.T, rec *httptest.ResponseRecorder, logLine map[string]any,
+	wantCause string, wantReason error,
+) {
+	t.Helper()
+
+	if rec.Code != http.StatusForbidden {
+		t.Errorf("status = %d, want %d", rec.Code, http.StatusForbidden)
+	}
+
+	body := rec.Body.String()
+	t.Logf("body: %s", body)
+
+	if !strings.Contains(body, template.HTMLEscapeString(wantCause)) {
+		t.Errorf("page does not name the cause %q", wantCause)
+	}
+
+	t.Logf("log line: %v", logLine)
+
+	if logLine["level"] != "WARN" || logLine["msg"] != "form refused" {
+		t.Errorf("log line = %v, want a WARN \"form refused\"", logLine)
+	}
+
+	if logLine["request_id"] != refusedFormRequestID {
+		t.Errorf("logged request_id = %v, want %q",
+			logLine["request_id"], refusedFormRequestID)
+	}
+
+	if logLine["reason"] != wantReason.Error() {
+		t.Errorf("logged reason = %v, want %q", logLine["reason"], wantReason)
+	}
+}

internal/handlers/handlers.go

@@ -56,14 +56,16 @@ type Handlers struct {
 
 // New creates a new Handlers instance.
 func New(_ fx.Lifecycle, params Params) *Handlers {
+	log := params.Logger.Get()
+
 	return &Handlers{
-		log:              params.Logger.Get(),
+		log:              log,
 		hc:               params.Healthcheck,
 		config:           params.Config,
 		imgSvc:           params.ImageService,
 		sessMgr:          params.SessionManager,
 		encGen:           params.EncryptedURLGenerator,
-		csrfProtect:      newCSRFProtect(params.Keys.CSRFKey, params.Config.Debug),
+		csrfProtect:      newCSRFProtect(params.Keys.CSRFKey, params.Config.Debug, log),
 		signer:           signature.New(params.Config.SigningKey),
 		allowlist:        allowlist.New(params.Config.AllowlistHosts),
 		refererBlocklist: allowlist.New(params.Config.RefererBlocklist),

internal/handlers/handlers_internal_test.go

@@ -131,7 +131,7 @@ func newMockFetcher(fs fs.FS) *mockFetcher {
 }
 
 func (f *mockFetcher) Fetch(
-	_ context.Context, source imagerequest.Source,
+	_ context.Context, source imagerequest.Source, _, _ string,
 ) (*httpfetcher.FetchResult, error) {
 	path := source.Host + source.Path
 
@@ -257,6 +257,90 @@ func TestHandleImage_ConditionalRequest_IfNoneMatch_DifferentETag(t *testing.T)
 	}
 }
 
+// TestHandleImage_ConditionalRequest_EarlierETagGetsChangedImage serves an
+// image, changes it upstream, and requests it again with the ETag first
+// served, once the cache TTL has passed. The changed image must be served,
+// not 304 Not Modified.
+func TestHandleImage_ConditionalRequest_EarlierETagGetsChangedImage(t *testing.T) {
+	t.Parallel()
+
+	const host = "goodhost.example.com"
+
+	upstream := fstest.MapFS{
+		host + photoPath: &fstest.MapFile{
+			Data: generateTestJPEG(t, 100, 100, color.RGBA{255, 0, 0, 255}),
+		},
+	}
+
+	// A cache TTL of one nanosecond has passed by the second request
+	cache, err := imgcache.NewCache(setupTestDB(t), imgcache.Config{
+		StateDir:    t.TempDir(),
+		NegativeTTL: 5 * time.Minute,
+		CacheTTL:    time.Nanosecond,
+		MaxBytes:    1 << 30,
+	}, prometheus.NewRegistry())
+	if err != nil {
+		t.Fatalf("imgcache.NewCache() error = %v", err)
+	}
+
+	svc, err := imageproxy.New(&imageproxy.Config{
+		Cache:   cache,
+		Fetcher: newMockFetcher(upstream),
+		Processor: imageprocessor.New(imageprocessor.Params{
+			MaxInputBytes:           50 << 20,
+			MaxConcurrentProcessing: 2,
+		}),
+		MaxResponseSize: 50 << 20,
+		Logger:          slog.New(slog.DiscardHandler),
+	}, prometheus.NewRegistry())
+	if err != nil {
+		t.Fatalf("imageproxy.New() error = %v", err)
+	}
+
+	h := &Handlers{
+		imgSvc:    svc,
+		log:       slog.New(slog.DiscardHandler),
+		signer:    signature.New(testSigningKey),
+		allowlist: allowlist.New([]string{host}),
+	}
+
+	r := chi.NewRouter()
+	r.Get("/v1/image/*", h.HandleImage())
+
+	target := "/v1/image/" + host + photoPath + "/50x50.jpeg"
+
+	first := httptest.NewRecorder()
+	r.ServeHTTP(first,
+		httptest.NewRequestWithContext(t.Context(), http.MethodGet, target, nil))
+
+	etag := first.Header().Get("ETag")
+	if first.Code != http.StatusOK || etag == "" {
+		t.Fatalf("first request: status = %d, ETag = %q, want %d and an ETag",
+			first.Code, etag, http.StatusOK)
+	}
+
+	upstream[host+photoPath] = &fstest.MapFile{
+		Data: generateTestJPEG(t, 100, 100, color.RGBA{0, 0, 255, 255}),
+	}
+
+	req := httptest.NewRequestWithContext(t.Context(), http.MethodGet, target, nil)
+	req.Header.Set("If-None-Match", etag)
+
+	second := httptest.NewRecorder()
+	r.ServeHTTP(second, req)
+	t.Logf("first ETag %s; with it after the change: status %d, ETag %s, %d bytes",
+		etag, second.Code, second.Header().Get("ETag"), second.Body.Len())
+
+	if second.Code != http.StatusOK {
+		t.Fatalf("status = %d, want %d with the changed image",
+			second.Code, http.StatusOK)
+	}
+
+	if bytes.Equal(second.Body.Bytes(), first.Body.Bytes()) {
+		t.Error("the image served is the one made before the change")
+	}
+}
+
 func TestHandleImage_ETagHeader(t *testing.T) {
 	t.Parallel()
 

internal/handlers/image.go

@@ -234,12 +234,8 @@ func (s *Handlers) HandleTooManyRequests() http.HandlerFunc {
 func (s *Handlers) respondImageError(
 	w http.ResponseWriter, req *imagerequest.Request, err error,
 ) {
-	// An upstream body whose first bytes are not those of the format its
+	// The image service has logged this as a refused source
-	// Content-Type names is the upstream's error, not pixa's: the image
+	if isFirstBytesMismatch(err) {
-	// service has logged it as a refused source.
-	if errors.Is(err, magic.ErrMagicByteMismatch) ||
-		errors.Is(err, magic.ErrUnknownFormat) ||
-		errors.Is(err, magic.ErrNotEnoughData) {
 		s.respondError(w, "unsupported source format",
 			http.StatusUnsupportedMediaType)
 
@@ -254,7 +250,9 @@ func (s *Handlers) respondImageError(
 	switch {
 	case errors.Is(err, httpfetcher.ErrSSRFBlocked):
 		status, message = http.StatusForbidden, "forbidden"
-	case errors.Is(err, httpfetcher.ErrUpstreamError):
+	case errors.Is(err, httpfetcher.ErrUpstreamError),
+		errors.Is(err, httpfetcher.ErrInvalidHost),
+		errors.Is(err, httpfetcher.ErrUpstreamRequestFailed):
 		status, message = http.StatusBadGateway, "upstream error"
 	case errors.Is(err, httpfetcher.ErrUpstreamTimeout):
 		status, message = http.StatusGatewayTimeout, "upstream timeout"
@@ -267,6 +265,16 @@ func (s *Handlers) respondImageError(
 		errors.Is(err, imageprocessor.ErrUnsupportedInputFormat):
 		status = http.StatusUnsupportedMediaType
 		message = "unsupported source format"
+	case errors.Is(err, imageprocessor.ErrSVGTooThin):
+		status = http.StatusUnsupportedMediaType
+		message = fmt.Sprintf("SVG source too thin to render: one side is "+
+			"more than %d times the other", imageprocessor.MaxInputDimension)
+	case errors.Is(err, imageprocessor.ErrSVGRenderFailed):
+		status = http.StatusUnsupportedMediaType
+		message = fmt.Sprintf("SVG source could not be rendered: it is not "+
+			"valid, or it takes more than %d seconds or %d GiB of memory to "+
+			"render", int(imageprocessor.SVGRenderTimeout.Seconds()),
+			imageprocessor.MaxSVGRenderMemory/bytesPerGiB)
 	case errors.Is(err, imageprocessor.ErrOutputTooLarge):
 		status = http.StatusBadRequest
 		message = fmt.Sprintf("size too large for the source: the side "+
@@ -276,6 +284,10 @@ func (s *Handlers) respondImageError(
 		status = http.StatusBadRequest
 		message = "an SVG source is returned as SVG only at the orig size; " +
 			"ask for another format to resize it"
+	case errors.Is(err, imageprocessor.ErrSVGTooLargeForOrigSize):
+		status = http.StatusBadRequest
+		message = fmt.Sprintf("SVG source above %d on a side: give a size "+
+			"to render it at", imageprocessor.MaxOutputDimension)
 	case errors.Is(err, imageprocessor.ErrAVIFOutputTooLarge):
 		status = http.StatusBadRequest
 		message = fmt.Sprintf("size too large for AVIF: the output "+
@@ -299,6 +311,18 @@ func (s *Handlers) respondImageError(
 	s.respondError(w, message, status)
 }
 
+// bytesPerGiB is the number of bytes in a GiB.
+const bytesPerGiB = 1 << 30
+
+// isFirstBytesMismatch reports whether err refuses an upstream body whose
+// first bytes are not those of the format its Content-Type names. That is the
+// upstream's error, not pixa's.
+func isFirstBytesMismatch(err error) bool {
+	return errors.Is(err, magic.ErrMagicByteMismatch) ||
+		errors.Is(err, magic.ErrUnknownFormat) ||
+		errors.Is(err, magic.ErrNotEnoughData)
+}
+
 // cacheControl returns the Cache-Control header for an image served through a
 // URL that expires at expires, or never when expires is the zero time. A cache
 // may keep the image for a year, but not past the URL's expiry, after which
@@ -317,6 +341,26 @@ func cacheControl(expires time.Time) string {
 	return fmt.Sprintf("public, max-age=%d, immutable", int64(maxAge/time.Second))
 }
 
+// svgContentSecurityPolicyValue is the Content-Security-Policy header value
+// of an SVG response, in place of the middleware's. A browser that opens the
+// SVG applies its styles and draws its embedded data: images, but runs none
+// of its scripts and loads nothing else. The styles need unsafe-inline, as an
+// SVG keeps them inline, in style elements and attributes.
+const svgContentSecurityPolicyValue = "default-src 'none'; " +
+	"style-src 'unsafe-inline'; " +
+	"img-src data:; " +
+	"frame-ancestors 'none'; " +
+	"sandbox"
+
+// setSVGContentSecurityPolicy sets the Content-Security-Policy in header to
+// svgContentSecurityPolicyValue when contentType is that of SVG. Any other
+// response keeps the middleware's policy.
+func setSVGContentSecurityPolicy(header http.Header, contentType string) {
+	if contentType == imagerequest.FormatSVG.MIMEType() {
+		header.Set("Content-Security-Policy", svgContentSecurityPolicyValue)
+	}
+}
+
 // refuseBlockedReferer answers 403 with a JSON error when the request's Referer
 // names a host on referer_blocklist, and reports whether it answered. A request
 // with no Referer, or one that does not parse as a URL with a host, is not
@@ -399,6 +443,7 @@ func (s *Handlers) serveImage(
 
 	// Set response headers
 	w.Header().Set("Content-Type", resp.ContentType)
+	setSVGContentSecurityPolicy(w.Header(), resp.ContentType)
 
 	if resp.ContentLength > 0 {
 		w.Header().Set("Content-Length", strconv.FormatInt(resp.ContentLength, 10))

internal/handlers/image_cache_control_internal_test.go

@@ -185,13 +185,13 @@ func TestHandleImageEnc_MaxAge(t *testing.T) {
 
 	tests := []struct {
 		name        string
-		expires     time.Time
+		ttl         time.Duration
 		wantAtLeast int
 		wantAtMost  int
 	}{
-		{"60 second TTL", time.Now().Add(time.Minute), 50, 60},
+		{"60 second TTL", time.Minute, 50, 60},
-		{"two-year TTL", time.Now().Add(2 * 365 * 24 * time.Hour), 31536000, 31536000},
+		{"two-year TTL", 2 * 365 * 24 * time.Hour, 31536000, 31536000},
-		{"no TTL", time.Time{}, 31536000, 31536000},
+		{"no TTL", 0, 31536000, 31536000},
 	}
 
 	for _, tt := range tests {
@@ -200,6 +200,14 @@ func TestHandleImageEnc_MaxAge(t *testing.T) {
 
 			h, srv := newSignedHostServer(t, slog.New(slog.DiscardHandler))
 
+			// The expiry is set here, not in the table: a parallel subtest
+			// can wait behind other tests for more than the 10 seconds the
+			// 60 second case allows.
+			var expires time.Time
+			if tt.ttl != 0 {
+				expires = time.Now().Add(tt.ttl)
+			}
+
 			token, err := h.encGen.Generate(&imagerequest.Request{
 				Source: imagerequest.Source{
 					Host: signedHost,
@@ -209,7 +217,7 @@ func TestHandleImageEnc_MaxAge(t *testing.T) {
 					Size:   imagerequest.Size{Width: 50, Height: 50},
 					Format: imagerequest.FormatJPEG,
 				},
-			}, tt.expires)
+			}, expires)
 			if err != nil {
 				t.Fatalf("Generate() error = %v", err)
 			}

internal/handlers/image_errors_internal_test.go

@@ -12,6 +12,7 @@ import (
 	"net/http/httptest"
 	"slices"
 	"strings"
+	"syscall"
 	"testing"
 	"testing/fstest"
 	"time"
@@ -428,7 +429,7 @@ type failingFetcher struct {
 
 // Fetch returns f's error.
 func (f failingFetcher) Fetch(
-	context.Context, imagerequest.Source,
+	context.Context, imagerequest.Source, string, string,
 ) (*httpfetcher.FetchResult, error) {
 	return nil, f.err
 }
@@ -461,6 +462,13 @@ func TestImageRoutes_SameErrorAnswers(t *testing.T) {
 		{"upstream error status",
 			fmt.Errorf("%w: status 404", httpfetcher.ErrUpstreamError),
 			http.StatusBadGateway, slog.LevelWarn},
+		{"upstream host with no address",
+			fmt.Errorf("%w: cdn.example.com", httpfetcher.ErrInvalidHost),
+			http.StatusBadGateway, slog.LevelWarn},
+		{"connection refused",
+			fmt.Errorf("%w: %w", httpfetcher.ErrUpstreamRequestFailed,
+				syscall.ECONNREFUSED),
+			http.StatusBadGateway, slog.LevelWarn},
 		{"no response headers within the fetch timeout",
 			httpfetcher.ErrUpstreamTimeout, http.StatusGatewayTimeout,
 			slog.LevelWarn},

internal/handlers/referer_blocklist_internal_test.go

@@ -36,10 +36,11 @@ type countingFetcher struct {
 // Fetch counts the fetch and passes it on.
 func (f *countingFetcher) Fetch(
 	ctx context.Context, source imagerequest.Source,
+	ifNoneMatch, ifModifiedSince string,
 ) (*httpfetcher.FetchResult, error) {
 	f.fetches.Add(1)
 
-	return f.Fetcher.Fetch(ctx, source)
+	return f.Fetcher.Fetch(ctx, source, ifNoneMatch, ifModifiedSince)
 }
 
 // newRefererRoutes returns both image routes of a Handlers whose

internal/handlers/unsupported_source_internal_test.go

@@ -47,3 +47,67 @@ func TestUnsupportedSourceFormatAnswers415(t *testing.T) {
 		}
 	}
 }
+
+// TestSVGTooThinAnswers415 checks that respondImageError answers 415 with a
+// clear error for an SVG source too thin to render, wrapped as the service
+// wraps it.
+func TestSVGTooThinAnswers415(t *testing.T) {
+	t.Parallel()
+
+	h := &Handlers{log: slog.New(slog.DiscardHandler)}
+	req := &imagerequest.Request{
+		Source: imagerequest.Source{Host: "svg.example.com", Path: "/a.svg"},
+	}
+	err := fmt.Errorf("image processing failed: %w: 81930x10",
+		imageprocessor.ErrSVGTooThin)
+
+	rec := httptest.NewRecorder()
+	h.respondImageError(rec, req, err)
+	t.Logf("for %v: %d %s", err, rec.Code, rec.Body.String())
+
+	if rec.Code != http.StatusUnsupportedMediaType {
+		t.Errorf("status = %d, want %d", rec.Code,
+			http.StatusUnsupportedMediaType)
+	}
+
+	if !strings.Contains(rec.Body.String(), "SVG source too thin to render") {
+		t.Errorf("body = %q, want the SVG too thin error", rec.Body.String())
+	}
+}
+
+// TestSVGRenderFailedAnswers415 checks that respondImageError answers 415,
+// naming the limits, for an SVG source that a child process could not read
+// or render, wrapped as the service wraps it.
+func TestSVGRenderFailedAnswers415(t *testing.T) {
+	t.Parallel()
+
+	h := &Handlers{log: slog.New(slog.DiscardHandler)}
+	err := fmt.Errorf("image processing failed: %w: it took more than 20s",
+		imageprocessor.ErrSVGRenderFailed)
+
+	rec := httptest.NewRecorder()
+	h.respondImageError(rec, &imagerequest.Request{}, err)
+	t.Logf("for %v: %d %s", err, rec.Code, rec.Body.String())
+
+	checkErrorBody(t, rec, http.StatusUnsupportedMediaType,
+		"SVG source could not be rendered: it is not valid, or it takes more "+
+			"than 20 seconds or 1 GiB of memory to render")
+}
+
+// TestSVGTooLargeForOrigSizeAnswers400 checks that respondImageError answers
+// 400, asking for a size, for an SVG source above 8192 on a side asked for at
+// the orig size in a raster format, wrapped as the service wraps it.
+func TestSVGTooLargeForOrigSizeAnswers400(t *testing.T) {
+	t.Parallel()
+
+	h := &Handlers{log: slog.New(slog.DiscardHandler)}
+	err := fmt.Errorf("image processing failed: %w: 10000x10 is above 8192",
+		imageprocessor.ErrSVGTooLargeForOrigSize)
+
+	rec := httptest.NewRecorder()
+	h.respondImageError(rec, &imagerequest.Request{}, err)
+	t.Logf("for %v: %d %s", err, rec.Code, rec.Body.String())
+
+	checkErrorBody(t, rec, http.StatusBadRequest,
+		"SVG source above 8192 on a side: give a size to render it at")
+}

internal/httpfetcher/conditional_internal_test.go

@@ -0,0 +1,76 @@
+package httpfetcher
+
+import (
+	"errors"
+	"io"
+	"net/http"
+	"net/http/httptest"
+	"sync"
+	"testing"
+)
+
+// TestFetch_SendsConditionalHeadersAndHandlesNotModified checks that Fetch
+// sends a non-empty ifNoneMatch and ifModifiedSince as request headers, that
+// upstream's 304 to such a request is a result with status 304 and no
+// content, and that a 304 to a request with neither is ErrUpstreamError.
+func TestFetch_SendsConditionalHeadersAndHandlesNotModified(t *testing.T) {
+	t.Parallel()
+
+	const (
+		etag         = `"abc"`
+		lastModified = "Mon, 02 Nov 2026 10:00:00 GMT"
+	)
+
+	var (
+		mu       sync.Mutex
+		received http.Header
+	)
+
+	srv := httptest.NewServer(http.HandlerFunc(
+		func(w http.ResponseWriter, r *http.Request) {
+			mu.Lock()
+			received = r.Header.Clone()
+			mu.Unlock()
+
+			w.WriteHeader(http.StatusNotModified)
+		}))
+	t.Cleanup(srv.Close)
+
+	f, _ := newServerFetcher(t, srv, nil)
+
+	res, err := f.Fetch(testContext(t), upstreamSource("/image"), etag, lastModified)
+	if err != nil {
+		t.Fatalf("conditional Fetch() error = %v", err)
+	}
+
+	body, err := io.ReadAll(res.Content)
+	_ = res.Content.Close()
+
+	mu.Lock()
+	t.Logf("status = %d, body = %q, request headers = %v", res.StatusCode, body, received)
+	gotIfNoneMatch := received.Get("If-None-Match")
+	gotIfModifiedSince := received.Get("If-Modified-Since")
+	mu.Unlock()
+
+	if err != nil || len(body) != 0 {
+		t.Errorf("304 content = %q, error = %v; want empty", body, err)
+	}
+
+	if res.StatusCode != http.StatusNotModified {
+		t.Errorf("StatusCode = %d, want 304", res.StatusCode)
+	}
+
+	if gotIfNoneMatch != etag || gotIfModifiedSince != lastModified {
+		t.Errorf("If-None-Match = %q, If-Modified-Since = %q; want %q and %q",
+			gotIfNoneMatch, gotIfModifiedSince, etag, lastModified)
+	}
+
+	if held := len(f.allHostsSemaphore); held != 0 {
+		t.Errorf("connection still held after the 304: %d held", held)
+	}
+
+	_, err = f.Fetch(testContext(t), upstreamSource("/image"), "", "")
+	if !errors.Is(err, ErrUpstreamError) {
+		t.Errorf("unconditional Fetch() answered 304: error = %v, want ErrUpstreamError", err)
+	}
+}

internal/httpfetcher/dial_context_internal_test.go

@@ -51,12 +51,12 @@ func TestDialContextReplacesOnlyTheDialer(t *testing.T) {
 		t.Errorf("body = %q, want %q", body, imagePayload)
 	}
 
-	_, err := f.Fetch(testContext(t), imageSourceOn("127.0.0.1"))
+	_, err := f.Fetch(testContext(t), imageSourceOn("127.0.0.1"), "", "")
 	if !errors.Is(err, ErrSSRFBlocked) {
 		t.Errorf("Fetch(loopback URL) error = %v, want ErrSSRFBlocked", err)
 	}
 
-	_, err = f.Fetch(testContext(t), upstreamSource("/redirect/private"))
+	_, err = f.Fetch(testContext(t), upstreamSource("/redirect/private"), "", "")
 	if !errors.Is(err, ErrSSRFBlocked) {
 		t.Errorf("Fetch(/redirect/private) error = %v, want ErrSSRFBlocked", err)
 	}

internal/httpfetcher/fetch_internal_test.go

@@ -160,7 +160,7 @@ func testContext(t *testing.T) context.Context {
 func fetchImage(t *testing.T, f *HTTPFetcher, path string) *FetchResult {
 	t.Helper()
 
-	res, err := f.Fetch(testContext(t), upstreamSource(path))
+	res, err := f.Fetch(testContext(t), upstreamSource(path), "", "")
 	if err != nil {
 		t.Fatalf("Fetch(%s) error = %v", path, err)
 	}
@@ -172,7 +172,7 @@ func fetchImage(t *testing.T, f *HTTPFetcher, path string) *FetchResult {
 func fetchExpectError(t *testing.T, f *HTTPFetcher, path string) error {
 	t.Helper()
 
-	res, err := f.Fetch(testContext(t), upstreamSource(path))
+	res, err := f.Fetch(testContext(t), upstreamSource(path), "", "")
 	if err == nil {
 		_ = res.Content.Close()
 
@@ -224,7 +224,7 @@ func TestFetchRedirectToPrivateIPBlocked(t *testing.T) {
 	srv := startUpstream(t)
 	f, dialer := newServerFetcher(t, srv, nil)
 
-	_, err := f.Fetch(testContext(t), upstreamSource("/redirect/private"))
+	_, err := f.Fetch(testContext(t), upstreamSource("/redirect/private"), "", "")
 	if !errors.Is(err, ErrSSRFBlocked) {
 		t.Fatalf("Fetch() error = %v, want ErrSSRFBlocked", err)
 	}
@@ -624,7 +624,7 @@ func TestFetchSchemeFollowsAllowHTTP(t *testing.T) {
 				DialContext:           dialer.dialContext,
 			})
 
-			res, err := f.Fetch(testContext(t), upstreamSource("/image"))
+			res, err := f.Fetch(testContext(t), upstreamSource("/image"), "", "")
 			if err == nil {
 				_ = res.Content.Close()
 			}

internal/httpfetcher/httpfetcher.go

@@ -69,6 +69,10 @@ var (
 	ErrInvalidContentType = errors.New("invalid or unsupported content type")
 	ErrUpstreamError      = errors.New("upstream server error")
 	ErrUpstreamTimeout    = errors.New("upstream request timeout")
+	// ErrUpstreamRequestFailed is a fetch that failed before the upstream
+	// answered, other than by timeout or cancellation: a failed connection
+	// or TLS handshake, or a redirect the fetcher refuses.
+	ErrUpstreamRequestFailed = errors.New("upstream request failed")
 	ErrTooManyConnections    = errors.New("too many concurrent upstream connections")
 )
 
@@ -80,8 +84,13 @@ var (
 
 // Fetcher retrieves content from upstream origins.
 type Fetcher interface {
-	// Fetch retrieves the content of the source image.
+	// Fetch retrieves the content of the source image. A non-empty
-	Fetch(ctx context.Context, source imagerequest.Source) (*FetchResult, error)
+	// ifNoneMatch or ifModifiedSince is sent as the request header of that
+	// name, and upstream may then answer 304 Not Modified with no content.
+	Fetch(
+		ctx context.Context, source imagerequest.Source,
+		ifNoneMatch, ifModifiedSince string,
+	) (*FetchResult, error)
 }
 
 // FetchResult contains the result of fetching from upstream.
@@ -224,9 +233,13 @@ func New(config *Config) *HTTPFetcher {
 // Fetch retrieves the source image with SSRF protection, over https, or over
 // http when AllowHTTP is set. When MaxConnections fetches are already in
 // progress, it waits up to ConnectionWaitTimeout for one to finish, then
-// fails with ErrTooManyConnections.
+// fails with ErrTooManyConnections. A non-empty ifNoneMatch or
+// ifModifiedSince is sent as the If-None-Match or If-Modified-Since header.
+// Upstream's 304 Not Modified to such a request is a result with StatusCode
+// 304 and empty Content; to any other request it is ErrUpstreamError.
 func (f *HTTPFetcher) Fetch(
 	ctx context.Context, source imagerequest.Source,
+	ifNoneMatch, ifModifiedSince string,
 ) (*FetchResult, error) {
 	sourceURL := source.URL(f.config.AllowHTTP)
 
@@ -253,17 +266,7 @@ func (f *HTTPFetcher) Fetch(
 	req := &http.Request{
 		Method: http.MethodGet,
 		URL:    sourceURL,
-		Header: make(http.Header),
+		Header: requestHeaders(ctx, ifNoneMatch, ifModifiedSince),
-	}
-
-	req.Header.Set("User-Agent", userAgent)
-	req.Header.Set("Accept", strings.Join(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
@@ -285,11 +288,21 @@ func (f *HTTPFetcher) Fetch(
 	fetchDuration := time.Since(startTime)
 
 	if err != nil {
-		if errors.Is(err, context.DeadlineExceeded) {
+		return nil, upstreamRequestError(err)
-			return nil, ErrUpstreamTimeout
 	}
 
-		return nil, fmt.Errorf("upstream request failed: %w", err)
+	// The deferred release gives the connection back, as no body follows
+	conditional := ifNoneMatch != "" || ifModifiedSince != ""
+	if conditional && resp.StatusCode == http.StatusNotModified {
+		_ = resp.Body.Close()
+
+		return &FetchResult{
+			Content:         http.NoBody,
+			Headers:         resp.Header,
+			StatusCode:      resp.StatusCode,
+			FetchDurationMs: fetchDuration.Milliseconds(),
+			RemoteAddr:      remoteAddr,
+		}, nil
 	}
 
 	result, err := f.buildResult(resp, remoteAddr, fetchDuration, release)
@@ -304,6 +317,60 @@ func (f *HTTPFetcher) Fetch(
 	return result, nil
 }
 
+// upstreamRequestError returns the error Fetch reports when its upstream
+// request fails with err:
+//   - err wrapped in ErrUpstreamTimeout for a timeout, so the log names what
+//     timed out.
+//   - err, still matching context.Canceled, when the caller cancelled the
+//     fetch.
+//   - err wrapped in ErrUpstreamRequestFailed otherwise.
+func upstreamRequestError(err error) error {
+	var netErr net.Error
+
+	switch {
+	case errors.Is(err, context.DeadlineExceeded),
+		errors.Is(err, ErrUpstreamTimeout),
+		errors.As(err, &netErr) && netErr.Timeout():
+		// A timeout other than the fetch timeout, such as the TLS
+		// handshake timeout, does not match context.DeadlineExceeded. An
+		// address lookup or a connection that timed out is
+		// ErrUpstreamTimeout already, so its log line names that error twice.
+		return fmt.Errorf("%w: %w", ErrUpstreamTimeout, err)
+	case errors.Is(err, context.Canceled):
+		// The caller cancelled the fetch; the upstream did not fail
+		return fmt.Errorf("upstream request cancelled: %w", err)
+	default:
+		return fmt.Errorf("%w: %w", ErrUpstreamRequestFailed, err)
+	}
+}
+
+// requestHeaders returns the headers of a fetch: User-Agent, Accept, the
+// ID of the request the fetch serves, so the fetch can be found in the
+// upstream host's logs, and a non-empty ifNoneMatch or ifModifiedSince.
+func requestHeaders(
+	ctx context.Context, ifNoneMatch, ifModifiedSince string,
+) http.Header {
+	header := make(http.Header)
+
+	header.Set("User-Agent", userAgent)
+	header.Set("Accept", strings.Join(allowedContentTypes(), ", "))
+
+	requestID := middleware.GetReqID(ctx)
+	if requestID != "" {
+		header.Set(middleware.RequestIDHeader, requestID)
+	}
+
+	if ifNoneMatch != "" {
+		header.Set("If-None-Match", ifNoneMatch)
+	}
+
+	if ifModifiedSince != "" {
+		header.Set("If-Modified-Since", ifModifiedSince)
+	}
+
+	return header
+}
+
 // acquireConnection takes a slot for host, then one of the slots shared by
 // all hosts, and returns the func that gives both back. The host's slot
 // comes first, so fetches queued for one busy host hold no shared slot.
@@ -466,7 +533,7 @@ func validateURL(ctx context.Context, fetchURL *neturl.URL, allowHTTP bool) erro
 	// Resolve the host to check IP addresses
 	addrs, err := net.DefaultResolver.LookupIPAddr(ctx, host)
 	if err != nil {
-		return fmt.Errorf("%w: %s", ErrInvalidHost, host)
+		return addressLookupError(host, err)
 	}
 
 	private := slices.ContainsFunc(addrs, func(addr net.IPAddr) bool {
@@ -479,6 +546,23 @@ func validateURL(ctx context.Context, fetchURL *neturl.URL, allowHTTP bool) erro
 	return nil
 }
 
+// addressLookupError returns the error for a failed address lookup of host:
+//   - ErrUpstreamTimeout when the lookup timed out.
+//   - err, still matching context.Canceled, when the lookup was cancelled.
+//   - ErrInvalidHost otherwise.
+func addressLookupError(host string, err error) error {
+	var netErr net.Error
+	if errors.As(err, &netErr) && netErr.Timeout() {
+		return fmt.Errorf("%w: address lookup of %s", ErrUpstreamTimeout, host)
+	}
+
+	if errors.Is(err, context.Canceled) {
+		return fmt.Errorf("address lookup cancelled: %w", err)
+	}
+
+	return fmt.Errorf("%w: %s", ErrInvalidHost, host)
+}
+
 // isLocalhost checks if the host is localhost.
 func isLocalhost(host string) bool {
 	host = strings.ToLower(host)
@@ -607,7 +691,7 @@ func dialSSRFSafe(
 	// Resolve the address
 	ips, err := net.DefaultResolver.LookupIP(ctx, "ip", host)
 	if err != nil {
-		return nil, fmt.Errorf("%w: %s", ErrInvalidHost, host)
+		return nil, addressLookupError(host, err)
 	}
 
 	// Check all resolved IPs
@@ -618,7 +702,10 @@ func dialSSRFSafe(
 	}
 
 	// Connect using the first valid IP
-	var dialer net.Dialer
+	var (
+		dialer      net.Dialer
+		lastDialErr error
+	)
 
 	for _, ip := range ips {
 		addr := net.JoinHostPort(ip.String(), port)
@@ -627,9 +714,18 @@ func dialSSRFSafe(
 		if err == nil {
 			return conn, nil
 		}
+
+		lastDialErr = err
 	}
 
-	return nil, fmt.Errorf("%w to %s", errConnectFailed, host)
+	// Only the last address tried decides whether the connection timed out
+	var netErr net.Error
+	if errors.As(lastDialErr, &netErr) && netErr.Timeout() {
+		return nil, fmt.Errorf("%w: connect to %s: %w",
+			ErrUpstreamTimeout, host, lastDialErr)
+	}
+
+	return nil, fmt.Errorf("%w to %s: %w", errConnectFailed, host, lastDialErr)
 }
 
 // limitedReader wraps a reader and refuses a body longer than remaining

internal/httpfetcher/httpfetcher_internal_test.go

@@ -210,7 +210,7 @@ func TestMockFetcher_FetchesFile(t *testing.T) {
 	m := NewMock(mockFS)
 
 	result, err := m.Fetch(context.Background(),
-		imagerequest.Source{Host: testHost, Path: "/images/photo.jpg"})
+		imagerequest.Source{Host: testHost, Path: "/images/photo.jpg"}, "", "")
 	if err != nil {
 		t.Fatalf("Fetch() error = %v", err)
 	}
@@ -242,7 +242,7 @@ func TestMockFetcher_MissingFileReturnsUpstreamError(t *testing.T) {
 	m := NewMock(mockFS)
 
 	_, err := m.Fetch(context.Background(),
-		imagerequest.Source{Host: testHost, Path: "/missing.jpg"})
+		imagerequest.Source{Host: testHost, Path: "/missing.jpg"}, "", "")
 	if !errors.Is(err, ErrUpstreamError) {
 		t.Errorf("Fetch() error = %v, want ErrUpstreamError", err)
 	}
@@ -259,7 +259,7 @@ func TestMockFetcher_RespectsContextCancellation(t *testing.T) {
 	ctx, cancel := context.WithCancel(context.Background())
 	cancel()
 
-	_, err := m.Fetch(ctx, imagerequest.Source{Host: testHost, Path: "/photo.jpg"})
+	_, err := m.Fetch(ctx, imagerequest.Source{Host: testHost, Path: "/photo.jpg"}, "", "")
 	if !errors.Is(err, context.Canceled) {
 		t.Errorf("Fetch() error = %v, want context.Canceled", err)
 	}

internal/httpfetcher/max_connections_internal_test.go

@@ -45,12 +45,12 @@ func TestFetchLimitsConnectionsToAllHostsTogether(t *testing.T) {
 	f, _ := newServerFetcher(t, srv, cfg)
 	f.connectionWaitTimeout = 100 * time.Millisecond
 
-	first, err := f.Fetch(testContext(t), imageSourceOnPort(81))
+	first, err := f.Fetch(testContext(t), imageSourceOnPort(81), "", "")
 	if err != nil {
 		t.Fatalf("first Fetch() error = %v", err)
 	}
 
-	second, err := f.Fetch(testContext(t), imageSourceOnPort(82))
+	second, err := f.Fetch(testContext(t), imageSourceOnPort(82), "", "")
 	if err != nil {
 		t.Fatalf("second Fetch() error = %v", err)
 	}
@@ -59,7 +59,7 @@ func TestFetchLimitsConnectionsToAllHostsTogether(t *testing.T) {
 
 	start := time.Now()
 
-	_, err = f.Fetch(testContext(t), imageSourceOnPort(83))
+	_, err = f.Fetch(testContext(t), imageSourceOnPort(83), "", "")
 	if !errors.Is(err, ErrTooManyConnections) {
 		t.Fatalf("third Fetch() error = %v, want ErrTooManyConnections", err)
 	}
@@ -78,7 +78,7 @@ func TestFetchLimitsConnectionsToAllHostsTogether(t *testing.T) {
 		t.Fatalf("close first body: %v", err)
 	}
 
-	third, err := f.Fetch(testContext(t), imageSourceOnPort(83))
+	third, err := f.Fetch(testContext(t), imageSourceOnPort(83), "", "")
 	if err != nil {
 		t.Fatalf("Fetch() after a response was closed: error = %v", err)
 	}
@@ -105,7 +105,7 @@ func TestFetchFreesHostSlotWhenContextEndsWaitingForConnection(t *testing.T) {
 
 	f, _ := newServerFetcher(t, srv, cfg)
 
-	first, err := f.Fetch(testContext(t), imageSourceOnPort(81))
+	first, err := f.Fetch(testContext(t), imageSourceOnPort(81), "", "")
 	if err != nil {
 		t.Fatalf("first Fetch() error = %v", err)
 	}
@@ -115,7 +115,7 @@ func TestFetchFreesHostSlotWhenContextEndsWaitingForConnection(t *testing.T) {
 	ctx, cancel := context.WithTimeout(t.Context(), 100*time.Millisecond)
 	defer cancel()
 
-	_, err = f.Fetch(ctx, imageSourceOnPort(82))
+	_, err = f.Fetch(ctx, imageSourceOnPort(82), "", "")
 	if !errors.Is(err, context.DeadlineExceeded) {
 		t.Fatalf("second Fetch() error = %v, want context.DeadlineExceeded", err)
 	}
@@ -140,7 +140,7 @@ func TestFetchRemovesIdleHostSemaphores(t *testing.T) {
 
 	for i := range 100 {
 		wg.Go(func() {
-			res, err := f.Fetch(ctx, imageSourceOnPort(1+i%50))
+			res, err := f.Fetch(ctx, imageSourceOnPort(1+i%50), "", "")
 			if err != nil {
 				t.Errorf("Fetch() error = %v", err)
 
@@ -179,12 +179,12 @@ func TestFetchRemovesHostSemaphoreWhenNoConnection(t *testing.T) {
 	f, _ := newServerFetcher(t, srv, cfg)
 	f.connectionWaitTimeout = 100 * time.Millisecond
 
-	open, err := f.Fetch(testContext(t), imageSourceOnPort(81))
+	open, err := f.Fetch(testContext(t), imageSourceOnPort(81), "", "")
 	if err != nil {
 		t.Fatalf("first Fetch() error = %v", err)
 	}
 
-	_, err = f.Fetch(testContext(t), imageSourceOnPort(82))
+	_, err = f.Fetch(testContext(t), imageSourceOnPort(82), "", "")
 	if !errors.Is(err, ErrTooManyConnections) {
 		t.Fatalf("Fetch() from another host: error = %v, "+
 			"want ErrTooManyConnections", err)
@@ -193,7 +193,7 @@ func TestFetchRemovesHostSemaphoreWhenNoConnection(t *testing.T) {
 	ctx, cancel := context.WithTimeout(t.Context(), 100*time.Millisecond)
 	defer cancel()
 
-	_, err = f.Fetch(ctx, imageSourceOnPort(81))
+	_, err = f.Fetch(ctx, imageSourceOnPort(81), "", "")
 	if !errors.Is(err, context.DeadlineExceeded) {
 		t.Fatalf("Fetch() from the busy host: error = %v, "+
 			"want context.DeadlineExceeded", err)
@@ -205,7 +205,7 @@ func TestFetchRemovesHostSemaphoreWhenNoConnection(t *testing.T) {
 	ctx, cancel = context.WithTimeout(t.Context(), 100*time.Millisecond)
 	defer cancel()
 
-	_, err = f.Fetch(ctx, imageSourceOnPort(83))
+	_, err = f.Fetch(ctx, imageSourceOnPort(83), "", "")
 	if !errors.Is(err, context.DeadlineExceeded) {
 		t.Fatalf("Fetch() from a host with nothing open: error = %v, "+
 			"want context.DeadlineExceeded", err)
@@ -255,7 +255,7 @@ func TestFetchReleasesConnectionOnError(t *testing.T) {
 			f, _ := newServerFetcher(t, srv, cfg)
 			f.connectionWaitTimeout = 100 * time.Millisecond
 
-			_, err := f.Fetch(testContext(t), tc.source)
+			_, err := f.Fetch(testContext(t), tc.source, "", "")
 			if !errors.Is(err, tc.want) {
 				t.Fatalf("Fetch() error = %v, want %v", err, tc.want)
 			}

internal/httpfetcher/mock.go

@@ -24,9 +24,10 @@ func NewMock(fsys fs.FS) *MockFetcher {
 	return &MockFetcher{fs: fsys}
 }
 
-// Fetch retrieves the source's content from the mock filesystem.
+// Fetch retrieves the source's content from the mock filesystem. It ignores
+// ifNoneMatch and ifModifiedSince, and always sends the content.
 func (m *MockFetcher) Fetch(
-	ctx context.Context, source imagerequest.Source,
+	ctx context.Context, source imagerequest.Source, _, _ string,
 ) (*FetchResult, error) {
 	// Check context cancellation
 	select {

internal/httpfetcher/request_failed_internal_test.go

@@ -0,0 +1,213 @@
+package httpfetcher
+
+import (
+	"context"
+	"errors"
+	"net"
+	"os"
+	"syscall"
+	"testing"
+	"time"
+)
+
+// TestFetchFailedBeforeAnswer checks the error of a fetch whose connection
+// fails:
+//   - refused: ErrUpstreamRequestFailed.
+//   - timed out: ErrUpstreamTimeout, still matching the dial's error, even for
+//     a timeout error that does not match context.DeadlineExceeded, such as
+//     the TLS handshake timeout.
+//   - cancelled by its caller: context.Canceled, not ErrUpstreamRequestFailed.
+func TestFetchFailedBeforeAnswer(t *testing.T) {
+	t.Parallel()
+
+	tests := []struct {
+		name       string
+		dial       func(cancel context.CancelFunc) error
+		wantErrs   []error
+		wantNotErr error
+	}{
+		{
+			name: "connection refused",
+			dial: func(context.CancelFunc) error {
+				return syscall.ECONNREFUSED
+			},
+			wantErrs:   []error{ErrUpstreamRequestFailed},
+			wantNotErr: context.Canceled,
+		},
+		{
+			name: "timed out while connecting",
+			dial: func(context.CancelFunc) error {
+				return os.ErrDeadlineExceeded
+			},
+			wantErrs:   []error{ErrUpstreamTimeout, os.ErrDeadlineExceeded},
+			wantNotErr: ErrUpstreamRequestFailed,
+		},
+		{
+			name: "cancelled while connecting",
+			dial: func(cancel context.CancelFunc) error {
+				cancel()
+
+				return context.Canceled
+			},
+			wantErrs:   []error{context.Canceled},
+			wantNotErr: ErrUpstreamRequestFailed,
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			t.Parallel()
+
+			ctx, cancel := context.WithCancel(testContext(t))
+			defer cancel()
+
+			f := New(&Config{
+				Timeout:               30 * time.Second,
+				MaxResponseSize:       50 << 20,
+				AllowHTTP:             true,
+				MaxConnectionsPerHost: 20,
+				MaxConnections:        64,
+				DialContext: func(context.Context, string, string) (net.Conn, error) {
+					return nil, tt.dial(cancel)
+				},
+			})
+
+			_, err := f.Fetch(ctx, upstreamSource("/image"), "", "")
+			t.Logf("Fetch() error: %v", err)
+
+			for _, wantErr := range tt.wantErrs {
+				if !errors.Is(err, wantErr) {
+					t.Errorf("Fetch() error = %v, want %v", err, wantErr)
+				}
+			}
+
+			if errors.Is(err, tt.wantNotErr) {
+				t.Errorf("Fetch() error = %v, must not be %v", err, tt.wantNotErr)
+			}
+		})
+	}
+}
+
+// TestFetchAddressLookupTimedOut checks that a fetch whose address lookup
+// times out fails with ErrUpstreamTimeout, both for the lookup of the source
+// host and for the lookup while connecting. The error must match neither
+// ErrInvalidHost nor ErrUpstreamRequestFailed, which the image routes answer
+// 502. A context whose deadline has passed makes the lookup time out.
+func TestFetchAddressLookupTimedOut(t *testing.T) {
+	t.Parallel()
+
+	checkTimedOut := func(t *testing.T, err error) {
+		t.Helper()
+		t.Logf("Fetch() error: %v", err)
+
+		if !errors.Is(err, ErrUpstreamTimeout) {
+			t.Errorf("Fetch() error = %v, want ErrUpstreamTimeout", err)
+		}
+
+		if errors.Is(err, ErrInvalidHost) || errors.Is(err, ErrUpstreamRequestFailed) {
+			t.Errorf("Fetch() error = %v, must match neither ErrInvalidHost "+
+				"nor ErrUpstreamRequestFailed", err)
+		}
+	}
+
+	t.Run("lookup of the source host", func(t *testing.T) {
+		t.Parallel()
+
+		ctx, cancel := context.WithTimeout(testContext(t), 0)
+		defer cancel()
+
+		f := New(&Config{
+			Timeout:               30 * time.Second,
+			MaxResponseSize:       50 << 20,
+			MaxConnectionsPerHost: 20,
+			MaxConnections:        64,
+		})
+
+		_, err := f.Fetch(ctx, imageSourceOn("cdn.example.com"), "", "")
+		checkTimedOut(t, err)
+	})
+
+	t.Run("lookup while connecting", func(t *testing.T) {
+		t.Parallel()
+
+		// The source host is an address, which validateURL does not look up;
+		// the dialer looks up a name
+		f := New(&Config{
+			Timeout:               30 * time.Second,
+			MaxResponseSize:       50 << 20,
+			MaxConnectionsPerHost: 20,
+			MaxConnections:        64,
+			DialContext: func(ctx context.Context, network, _ string) (net.Conn, error) {
+				ctx, cancel := context.WithTimeout(ctx, 0)
+				defer cancel()
+
+				return dialSSRFSafe(ctx, network, "img.example.com:443", nil)
+			},
+		})
+
+		_, err := f.Fetch(testContext(t), upstreamSource("/image"), "", "")
+		checkTimedOut(t, err)
+	})
+}
+
+// TestFetchConnectionTimedOut checks that a fetch whose connection in
+// dialSSRFSafe times out fails with ErrUpstreamTimeout, which the image
+// routes answer 504. The error must match neither ErrUpstreamRequestFailed
+// nor ErrInvalidHost, which they answer 502. A context whose deadline has
+// passed makes the connection time out without touching the network.
+func TestFetchConnectionTimedOut(t *testing.T) {
+	t.Parallel()
+
+	f := New(&Config{
+		Timeout:               30 * time.Second,
+		MaxResponseSize:       50 << 20,
+		MaxConnectionsPerHost: 20,
+		MaxConnections:        64,
+		DialContext: func(ctx context.Context, network, addr string) (net.Conn, error) {
+			ctx, cancel := context.WithTimeout(ctx, 0)
+			defer cancel()
+
+			return dialSSRFSafe(ctx, network, addr, nil)
+		},
+	})
+
+	_, err := f.Fetch(testContext(t), upstreamSource("/image"), "", "")
+	t.Logf("Fetch() error: %v", err)
+
+	if !errors.Is(err, ErrUpstreamTimeout) {
+		t.Errorf("Fetch() error = %v, want ErrUpstreamTimeout", err)
+	}
+
+	if errors.Is(err, ErrUpstreamRequestFailed) || errors.Is(err, ErrInvalidHost) {
+		t.Errorf("Fetch() error = %v, must match neither "+
+			"ErrUpstreamRequestFailed nor ErrInvalidHost", err)
+	}
+}
+
+// TestFetchAddressLookupCancelled checks that a fetch whose address lookup
+// its caller cancelled fails with an error matching context.Canceled, not
+// ErrInvalidHost, which the image routes answer 502.
+func TestFetchAddressLookupCancelled(t *testing.T) {
+	t.Parallel()
+
+	ctx, cancel := context.WithCancel(testContext(t))
+	cancel()
+
+	f := New(&Config{
+		Timeout:               30 * time.Second,
+		MaxResponseSize:       50 << 20,
+		MaxConnectionsPerHost: 20,
+		MaxConnections:        64,
+	})
+
+	_, err := f.Fetch(ctx, imageSourceOn("cdn.example.com"), "", "")
+	t.Logf("Fetch() error: %v", err)
+
+	if !errors.Is(err, context.Canceled) {
+		t.Errorf("Fetch() error = %v, want context.Canceled", err)
+	}
+
+	if errors.Is(err, ErrInvalidHost) {
+		t.Errorf("Fetch() error = %v, must not be ErrInvalidHost", err)
+	}
+}

internal/httpfetcher/request_id_internal_test.go

@@ -35,7 +35,7 @@ func TestFetchSendsRequestID(t *testing.T) {
 
 	ctx := context.WithValue(testContext(t), middleware.RequestIDKey, requestID)
 
-	res, err := f.Fetch(ctx, upstreamSource("/image"))
+	res, err := f.Fetch(ctx, upstreamSource("/image"), "", "")
 	if err != nil {
 		t.Fatalf("Fetch() error = %v", err)
 	}

internal/imageprocessor/imageprocessor.go

@@ -1,4 +1,7 @@
 // Package imageprocessor provides image format conversion and resizing using libvips.
+// It reads the size of an SVG source and renders it in child processes, each
+// the running program started again (see RunAsSVGChildProcess). pixa kills
+// them after SVGRenderTimeout, and each may use at most MaxSVGRenderMemory.
 package imageprocessor
 
 import (
@@ -8,6 +11,7 @@ import (
 	"fmt"
 	"io"
 	"math"
+	"strconv"
 	"sync"
 	"time"
 
@@ -124,6 +128,33 @@ var ErrUnsupportedInputFormat = errors.New("unsupported input format")
 var ErrSVGNotOriginalSize = errors.New(
 	"an SVG is returned as SVG only at the orig size")
 
+// ErrSVGTooThin is returned, before rendering, when an SVG source has one
+// side more than MaxInputDimension times the other. Rendered with its longer
+// side at most MaxInputDimension, its shorter side would be under 1 pixel.
+var ErrSVGTooThin = errors.New("SVG source too thin to render")
+
+// ErrSVGTooLargeForOrigSize is returned, before rendering, when a format other
+// than orig asks for an SVG source at the orig size and the SVG has a side
+// above MaxOutputDimension.
+var ErrSVGTooLargeForOrigSize = errors.New(
+	"SVG source too large to render at its own size")
+
+// SVGRenderTimeout is how long the child processes that read the size of one
+// SVG source and render it may run, counted from the start of the first,
+// before pixa kills them.
+const SVGRenderTimeout = 20 * time.Second
+
+// MaxSVGRenderMemory is the most memory, in bytes, that each child process
+// reading the size of an SVG source or rendering it may use. It is the
+// child's RLIMIT_DATA, which limits its heap and its other private writable
+// memory.
+const MaxSVGRenderMemory = 1 << 30 // 1 GiB
+
+// ErrSVGRenderFailed is returned when a child process fails to read the size
+// of an SVG source or to render it: librsvg cannot read the SVG, or the
+// child takes more than SVGRenderTimeout or MaxSVGRenderMemory.
+var ErrSVGRenderFailed = errors.New("SVG source could not be rendered")
+
 // ErrTooManyImages is returned when MaxConcurrentProcessing images are being
 // processed and none finishes within ProcessingWaitTimeout.
 var ErrTooManyImages = errors.New("too many images being processed at once")
@@ -141,6 +172,10 @@ type ImageProcessor struct {
 	processingSemaphore chan struct{}
 	// processingWaitTimeout is ProcessingWaitTimeout; tests shorten it.
 	processingWaitTimeout time.Duration
+	// svgRenderTimeout is SVGRenderTimeout; tests shorten it.
+	svgRenderTimeout time.Duration
+	// maxSVGRenderMemory is MaxSVGRenderMemory; tests lower it.
+	maxSVGRenderMemory int
 }
 
 // Params holds configuration for creating an ImageProcessor. Both fields
@@ -160,6 +195,8 @@ func New(params Params) *ImageProcessor {
 		maxInputBytes:         params.MaxInputBytes,
 		processingSemaphore:   make(chan struct{}, params.MaxConcurrentProcessing),
 		processingWaitTimeout: ProcessingWaitTimeout,
+		svgRenderTimeout:      SVGRenderTimeout,
+		maxSVGRenderMemory:    MaxSVGRenderMemory,
 	}
 }
 
@@ -173,7 +210,8 @@ func New(params Params) *ImageProcessor {
 // slot until it finishes. An AVIF output of more than MaxAVIFOutputPixels is
 // refused with ErrAVIFOutputTooLarge before anything is decoded. orig of an
 // SVG source is the SVG as it is, since libvips cannot save SVG; any other
-// format renders it at the output size.
+// format renders it at the output size. Child processes read an SVG's size
+// and render it, as processSVG describes.
 func (p *ImageProcessor) Process(
 	ctx context.Context,
 	input io.Reader,
@@ -192,14 +230,11 @@ func (p *ImageProcessor) Process(
 		return nil, err
 	}
 
-	// Input libvips would not load as sourceFormat is refused before it is
+	if sourceFormat == imagerequest.FormatSVG {
-	// decoded
+		return p.processSVG(ctx, data, transform)
-	err = checkInputFormat(data, sourceFormat)
-	if err != nil {
-		return nil, err
 	}
 
-	img, err := loadImage(data)
+	img, err := loadImage(data, sourceFormat)
 	if err != nil {
 		return nil, err
 	}
@@ -208,10 +243,6 @@ func (p *ImageProcessor) Process(
 	origWidth, origHeight := img.Width(), img.Height()
 	outputFormat := resolveOutputFormat(transform.Format, sourceFormat)
 
-	if outputFormat == imagerequest.FormatSVG && sourceFormat == imagerequest.FormatSVG {
-		return svgAsItIs(data, transform.Size, origWidth, origHeight)
-	}
-
 	// Determine target dimensions; too large ones are refused before resizing
 	targetWidth, targetHeight, err := targetDimensions(transform.Size,
 		origWidth, origHeight)
@@ -227,19 +258,6 @@ func (p *ImageProcessor) Process(
 		return nil, err
 	}
 
-	// An SVG is rendered again at about the output size, to stay sharp
-	if sourceFormat == imagerequest.FormatSVG {
-		rendered, err := renderSVG(data,
-			svgDensity(origWidth, origHeight, outputWidth, outputHeight))
-		if err != nil {
-			return nil, err
-		}
-
-		defer rendered.Close()
-
-		img = rendered
-	}
-
 	// Resize if needed
 	if targetWidth != origWidth || targetHeight != origHeight {
 		err := p.resize(img, outputWidth, outputHeight, transform.FitMode)
@@ -248,8 +266,104 @@ func (p *ImageProcessor) Process(
 		}
 	}
 
-	// Encode to target format
+	return p.encodeResult(ctx, img, outputFormat, transform.Quality,
-	output, err := p.encode(ctx, img, outputFormat, transform.Quality)
+		origWidth, origHeight)
+}
+
+// WaitForProcessing waits until no image is being processed, or until ctx
+// ends, and returns how many images were still being processed then. It
+// waits by taking each slot in processingSemaphore as it frees up until it
+// holds them all, or until ctx ends, then gives back the slots it took.
+func (p *ImageProcessor) WaitForProcessing(ctx context.Context) int {
+	taken := 0
+
+	defer func() {
+		for range taken {
+			<-p.processingSemaphore
+		}
+	}()
+
+	for taken < cap(p.processingSemaphore) {
+		select {
+		case p.processingSemaphore <- struct{}{}:
+			taken++
+		case <-ctx.Done():
+			return len(p.processingSemaphore) - taken
+		}
+	}
+
+	return 0
+}
+
+// processSVG is Process for an SVG source, data. Apart from the first-bytes
+// check, pixad hands the SVG to libvips only in child processes (see
+// runSVGChildProcess). One reads the SVG's size. For a raster format a second
+// renders it as PNG, which is then resized and encoded as any other image.
+// pixa kills them once svgRenderTimeout has passed since the first one
+// started.
+func (p *ImageProcessor) processSVG(
+	ctx context.Context, data []byte, transform *imagerequest.Transform,
+) (*Result, error) {
+	err := checkInputFormat(data, imagerequest.FormatSVG)
+	if err != nil {
+		return nil, err
+	}
+
+	deadline := time.Now().Add(p.svgRenderTimeout)
+
+	origWidth, origHeight, err := p.readSVGSize(ctx, deadline, data)
+	if err != nil {
+		return nil, err
+	}
+
+	outputFormat := resolveOutputFormat(transform.Format, imagerequest.FormatSVG)
+	if outputFormat == imagerequest.FormatSVG {
+		return svgAsItIs(data, transform.Size, origWidth, origHeight)
+	}
+
+	err = checkSVGOrigSize(transform.Size, origWidth, origHeight)
+	if err != nil {
+		return nil, err
+	}
+
+	targetWidth, targetHeight, err := targetDimensions(transform.Size,
+		origWidth, origHeight)
+	if err != nil {
+		return nil, err
+	}
+
+	outputWidth, outputHeight, err := outputDimensions(origWidth, origHeight,
+		targetWidth, targetHeight, transform.FitMode, outputFormat)
+	if err != nil {
+		return nil, err
+	}
+
+	// The SVG is rendered at about the output size, to stay sharp
+	img, err := p.renderSVG(ctx, deadline, data, origWidth, origHeight,
+		outputWidth, outputHeight)
+	if err != nil {
+		return nil, err
+	}
+	defer img.Close()
+
+	if targetWidth != origWidth || targetHeight != origHeight {
+		err := p.resize(img, outputWidth, outputHeight, transform.FitMode)
+		if err != nil {
+			return nil, fmt.Errorf("failed to resize: %w", err)
+		}
+	}
+
+	return p.encodeResult(ctx, img, outputFormat, transform.Quality,
+		origWidth, origHeight)
+}
+
+// encodeResult encodes img as format at quality and returns it as the result
+// for a source of origWidth x origHeight.
+func (p *ImageProcessor) encodeResult(
+	ctx context.Context, img *vips.ImageRef, format imagerequest.Format,
+	quality, origWidth, origHeight int,
+) (*Result, error) {
+	output, err := p.encode(ctx, img, format, quality)
 	if err != nil {
 		return nil, fmt.Errorf("failed to encode: %w", err)
 	}
@@ -257,7 +371,7 @@ func (p *ImageProcessor) Process(
 	return &Result{
 		Content:       io.NopCloser(bytes.NewReader(output)),
 		ContentLength: int64(len(output)),
-		ContentType:   outputFormat.MIMEType(),
+		ContentType:   format.MIMEType(),
 		Width:         img.Width(),
 		Height:        img.Height(),
 		InputWidth:    origWidth,
@@ -309,11 +423,19 @@ func resolveOutputFormat(
 	return format
 }
 
-// loadImage decodes data and turns the image upright: encode strips the EXIF
+// loadImage refuses data that libvips would not load as sourceFormat, then
-// orientation tag, and sizes must be worked out on the upright image. An
+// decodes it and turns the image upright: encode strips the EXIF orientation
-// image with a side above MaxInputDimension is ErrInputTooLarge, which guards
+// tag, and sizes must be worked out on the upright image. An image with a
-// against decompression bombs.
+// side above MaxInputDimension is ErrInputTooLarge, which guards against
-func loadImage(data []byte) (*vips.ImageRef, error) {
+// decompression bombs.
+func loadImage(
+	data []byte, sourceFormat imagerequest.Format,
+) (*vips.ImageRef, error) {
+	err := checkInputFormat(data, sourceFormat)
+	if err != nil {
+		return nil, err
+	}
+
 	img, err := vips.NewImageFromBuffer(data)
 	if err != nil {
 		return nil, fmt.Errorf("failed to decode image: %w", err)
@@ -357,62 +479,56 @@ func svgAsItIs(
 	}, nil
 }
 
-// svgDefaultDensity is the density, in dots per inch, at which libvips
+// checkSVGOrigSize returns ErrSVGTooLargeForOrigSize when size is the orig
-// renders an SVG unless told otherwise. At it, an SVG of width="64" is 64
+// size and the SVG source, of width x height, has a side above
-// pixels wide.
+// MaxOutputDimension. processSVG calls it after returning orig of the SVG, so
-const svgDefaultDensity = 72
+// the SVG would be rendered at its own size.
+func checkSVGOrigSize(size imagerequest.Size, width, height int) error {
+	if size.OriginalSize() && max(width, height) > MaxOutputDimension {
+		return fmt.Errorf("%w: %dx%d is above %d", ErrSVGTooLargeForOrigSize,
+			width, height, MaxOutputDimension)
+	}
 
-// svgDensity returns the least density at which an SVG of width x height,
+	return nil
-// its size at svgDefaultDensity, covers outputWidth x outputHeight, so that
-// resize hardly changes it. Neither side is rendered above
-// MaxInputDimension.
-func svgDensity(width, height, outputWidth, outputHeight int) int {
-	scale := max(float64(outputWidth)/float64(width),
-		float64(outputHeight)/float64(height))
-	maxScale := float64(MaxInputDimension) / float64(max(width, height))
-
-	return min(int(math.Ceil(svgDefaultDensity*scale)),
-		int(svgDefaultDensity*maxScale))
 }
 
-// renderSVG loads the SVG data rendered at density, in dots per inch.
+// svgRenderSize returns the least size in the proportions of width x height,
-// librsvg renders it and, given the SVG as bytes with no file name, loads
+// an SVG's own size, that covers outputWidth x outputHeight, so that resize
-// no file or URL the SVG refers to.
+// hardly changes it. Neither side is above MaxInputDimension.
-func renderSVG(data []byte, density int) (*vips.ImageRef, error) {
+func svgRenderSize(width, height, outputWidth, outputHeight int) (int, int) {
-	params := vips.NewImportParams()
+	scale := min(
-	params.Density.Set(density)
+		max(float64(outputWidth)/float64(width),
+			float64(outputHeight)/float64(height)),
+		float64(MaxInputDimension)/float64(max(width, height)))
 
-	img, err := vips.LoadImageFromBuffer(data, params)
+	return int(math.Round(float64(width) * scale)),
+		int(math.Round(float64(height) * scale))
+}
+
+// renderSVG renders the SVG data, whose own size is width x height, at
+// svgRenderSize for outputWidth x outputHeight, in a child process that pixa
+// kills at deadline (see runSVGChildProcess). It returns the rendered image,
+// read from the child's PNG. An SVG with one side more than
+// MaxInputDimension times the other is ErrSVGTooThin.
+func (p *ImageProcessor) renderSVG(
+	ctx context.Context, deadline time.Time, data []byte,
+	width, height, outputWidth, outputHeight int,
+) (*vips.ImageRef, error) {
+	if max(width, height) > MaxInputDimension*min(width, height) {
+		return nil, fmt.Errorf("%w: %dx%d", ErrSVGTooThin, width, height)
+	}
+
+	renderWidth, renderHeight := svgRenderSize(width, height,
+		outputWidth, outputHeight)
+
+	png, err := p.runSVGChildProcess(ctx, deadline, data,
+		renderSVGAsPNGArgument, strconv.Itoa(renderWidth),
+		strconv.Itoa(renderHeight))
 	if err != nil {
-		return nil, fmt.Errorf("failed to render SVG: %w", err)
+		return nil, err
 	}
 
-	return img, nil
+	return loadImage(png, imagerequest.FormatPNG)
-}
-
-// WaitForProcessing waits until no image is being processed, or until ctx
-// ends, and returns how many images were still being processed then. It
-// waits by taking each slot in processingSemaphore as it frees up until it
-// holds them all, or until ctx ends, then gives back the slots it took.
-func (p *ImageProcessor) WaitForProcessing(ctx context.Context) int {
-	taken := 0
-
-	defer func() {
-		for range taken {
-			<-p.processingSemaphore
-		}
-	}()
-
-	for taken < cap(p.processingSemaphore) {
-		select {
-		case p.processingSemaphore <- struct{}{}:
-			taken++
-		case <-ctx.Done():
-			return len(p.processingSemaphore) - taken
-		}
-	}
-
-	return 0
 }
 
 // acquireSlot takes a slot in processingSemaphore, waiting at most

internal/imageprocessor/imageprocessor_internal_test.go

@@ -19,6 +19,11 @@ import (
 )
 
 func TestMain(m *testing.M) {
+	// The SVG tests start this test binary again as SVG child processes
+	if IsSVGChildProcess(os.Args[1:]) {
+		os.Exit(RunAsSVGChildProcess(os.Args[1:]))
+	}
+
 	initVips()
 
 	code := m.Run()

internal/imageprocessor/svg_child_process.go

@@ -0,0 +1,255 @@
+package imageprocessor
+
+import (
+	"bytes"
+	"context"
+	"errors"
+	"fmt"
+	"io"
+	"os"
+	"os/exec"
+	"strconv"
+	"syscall"
+	"time"
+
+	"github.com/davidbyttow/govips/v2/vips"
+)
+
+// An SVG child process is the running program started again with one of
+// these arguments first, naming what it does. Its command line, after the
+// program's name, is one of:
+//
+//	read-svg-size MEMORY_LIMIT
+//	render-svg-as-png MEMORY_LIMIT WIDTH HEIGHT
+//
+// MEMORY_LIMIT is in bytes. The child reads the SVG on standard input. It
+// writes the SVG's size as WIDTH HEIGHT, or the SVG rendered at WIDTH x
+// HEIGHT as PNG, to standard output.
+const (
+	readSVGSizeArgument    = "read-svg-size"
+	renderSVGAsPNGArgument = "render-svg-as-png"
+)
+
+// errSVGChildProcessArguments is returned for a command line that is not
+// that of an SVG child process.
+var errSVGChildProcessArguments = errors.New(
+	"not the command line of an SVG child process")
+
+// IsSVGChildProcess reports whether args, a process's command line after the
+// program's name, are those of an SVG child process.
+func IsSVGChildProcess(args []string) bool {
+	return len(args) > 0 &&
+		(args[0] == readSVGSizeArgument || args[0] == renderSVGAsPNGArgument)
+}
+
+// RunAsSVGChildProcess runs this process as the SVG child process that args,
+// its command line after the program's name, ask for. It returns the status
+// to exit with: 0 once it has written its result, and 1 after writing an
+// error to standard error, which the parent discards.
+func RunAsSVGChildProcess(args []string) int {
+	err := runAsSVGChildProcess(args, os.Stdin, os.Stdout)
+	if err != nil {
+		_, _ = fmt.Fprintln(os.Stderr, err)
+
+		return 1
+	}
+
+	return 0
+}
+
+// runAsSVGChildProcess does the work of RunAsSVGChildProcess, reading the SVG
+// from stdin and writing the result to stdout. It sets the process's limits
+// before it reads the SVG.
+func runAsSVGChildProcess(
+	args []string, stdin io.Reader, stdout io.Writer,
+) error {
+	numbers, err := parseSVGChildProcessArguments(args)
+	if err != nil {
+		return err
+	}
+
+	err = setSVGChildProcessLimits(numbers[0])
+	if err != nil {
+		return err
+	}
+
+	initVips()
+
+	svg, err := io.ReadAll(stdin)
+	if err != nil {
+		return fmt.Errorf("failed to read the SVG: %w", err)
+	}
+
+	if args[0] == readSVGSizeArgument {
+		return writeSVGSize(svg, stdout)
+	}
+
+	return writeSVGAsPNG(svg, numbers[1], numbers[2], stdout)
+}
+
+// parseSVGChildProcessArguments returns the numbers on the command line of an
+// SVG child process, args: the memory limit, then the width and height for
+// render-svg-as-png.
+func parseSVGChildProcessArguments(args []string) ([]int, error) {
+	wantArgs := 2
+	if len(args) > 0 && args[0] == renderSVGAsPNGArgument {
+		wantArgs = 4
+	}
+
+	if !IsSVGChildProcess(args) || len(args) != wantArgs {
+		return nil, fmt.Errorf("%w: %q", errSVGChildProcessArguments, args)
+	}
+
+	numbers := make([]int, 0, len(args)-1)
+
+	for _, arg := range args[1:] {
+		number, err := strconv.Atoi(arg)
+		if err != nil {
+			return nil, fmt.Errorf("%w: %q: %w", errSVGChildProcessArguments,
+				args, err)
+		}
+
+		numbers = append(numbers, number)
+	}
+
+	return numbers, nil
+}
+
+// setSVGChildProcessLimits sets this process's RLIMIT_DATA to memoryLimit
+// bytes, so that allocating heap or other private writable memory past it
+// fails. RLIMIT_AS would also count the address space the Go runtime reserves
+// but does not use. It also sets RLIMIT_CORE to 0: librsvg crashes when an
+// allocation fails, and the crash would write a core file of up to
+// memoryLimit bytes into pixad's working directory.
+func setSVGChildProcessLimits(memoryLimit int) error {
+	if memoryLimit < 1 {
+		return fmt.Errorf("%w: memory limit %d", errSVGChildProcessArguments,
+			memoryLimit)
+	}
+
+	err := syscall.Setrlimit(syscall.RLIMIT_DATA, &syscall.Rlimit{
+		Cur: uint64(memoryLimit),
+		Max: uint64(memoryLimit),
+	})
+	if err != nil {
+		return fmt.Errorf("failed to limit memory to %d bytes: %w",
+			memoryLimit, err)
+	}
+
+	err = syscall.Setrlimit(syscall.RLIMIT_CORE, &syscall.Rlimit{})
+	if err != nil {
+		return fmt.Errorf("failed to turn off core files: %w", err)
+	}
+
+	return nil
+}
+
+// writeSVGSize writes the size of svg to stdout as WIDTH HEIGHT. librsvg
+// reads the whole SVG for it.
+func writeSVGSize(svg []byte, stdout io.Writer) error {
+	img, err := vips.NewImageFromBuffer(svg)
+	if err != nil {
+		return fmt.Errorf("failed to read the SVG: %w", err)
+	}
+
+	defer img.Close()
+
+	_, err = fmt.Fprintf(stdout, "%d %d\n", img.Width(), img.Height())
+
+	return err
+}
+
+// writeSVGAsPNG renders svg at width x height and writes it to stdout as PNG.
+// libvips' thumbnail has librsvg render the SVG at that size directly, at
+// any scale: govips takes a density only in whole dots per inch, which cannot
+// render an SVG below 1/72 of its own size. Given the SVG as bytes with no
+// file name, librsvg loads no file or URL the SVG refers to.
+func writeSVGAsPNG(svg []byte, width, height int, stdout io.Writer) error {
+	img, err := vips.NewThumbnailWithSizeFromBuffer(svg, width, height,
+		vips.InterestingNone, vips.SizeBoth)
+	if err != nil {
+		return fmt.Errorf("failed to render the SVG: %w", err)
+	}
+
+	defer img.Close()
+
+	png, err := exportPNG(img)
+	if err != nil {
+		return fmt.Errorf("failed to save the SVG as PNG: %w", err)
+	}
+
+	_, err = stdout.Write(png)
+
+	return err
+}
+
+// readSVGSize reads the size of the SVG data in a child process that pixa
+// kills at deadline (see runSVGChildProcess).
+func (p *ImageProcessor) readSVGSize(
+	ctx context.Context, deadline time.Time, data []byte,
+) (int, int, error) {
+	output, err := p.runSVGChildProcess(ctx, deadline, data,
+		readSVGSizeArgument)
+	if err != nil {
+		return 0, 0, err
+	}
+
+	var width, height int
+
+	_, err = fmt.Sscan(string(output), &width, &height)
+	if err != nil {
+		return 0, 0, fmt.Errorf("failed to read the size %q an SVG child "+
+			"process wrote: %w", output, err)
+	}
+
+	return width, height, nil
+}
+
+// runSVGChildProcess starts the running program again as an SVG child
+// process, with argument, p.maxSVGRenderMemory and extraArgs as its command
+// line, and waits for it. It gives the child data on standard input,
+// discards its standard error, and returns its standard output. pixa kills
+// the child at deadline. A child that fails or is killed is
+// ErrSVGRenderFailed, unless ctx has ended: runSVGChildProcess then returns
+// ctx's error. Failing to start the child is another error.
+func (p *ImageProcessor) runSVGChildProcess(
+	ctx context.Context, deadline time.Time, data []byte,
+	argument string, extraArgs ...string,
+) ([]byte, error) {
+	executable, err := os.Executable()
+	if err != nil {
+		return nil, fmt.Errorf("failed to find the running program: %w", err)
+	}
+
+	childCtx, cancel := context.WithDeadline(ctx, deadline)
+	defer cancel()
+
+	args := append([]string{argument, strconv.Itoa(p.maxSVGRenderMemory)},
+		extraArgs...)
+
+	//nolint:gosec // the running program, with arguments pixa makes
+	cmd := exec.CommandContext(childCtx, executable, args...)
+	cmd.Stdin = bytes.NewReader(data)
+
+	var stdout bytes.Buffer
+
+	cmd.Stdout = &stdout
+
+	err = cmd.Run()
+
+	var exitError *exec.ExitError
+
+	switch {
+	case err == nil:
+		return stdout.Bytes(), nil
+	case ctx.Err() != nil:
+		return nil, ctx.Err()
+	case childCtx.Err() != nil:
+		return nil, fmt.Errorf("%w: it took more than %v", ErrSVGRenderFailed,
+			p.svgRenderTimeout)
+	case errors.As(err, &exitError):
+		return nil, fmt.Errorf("%w: %w", ErrSVGRenderFailed, err)
+	default:
+		return nil, fmt.Errorf("failed to run an SVG child process: %w", err)
+	}
+}

internal/imageprocessor/svg_internal_test.go

@@ -3,11 +3,16 @@ package imageprocessor
 import (
 	"bytes"
 	"errors"
+	"fmt"
 	"io"
 	"net/http"
 	"net/http/httptest"
+	"os"
+	"path/filepath"
+	"strings"
 	"sync/atomic"
 	"testing"
+	"time"
 
 	"github.com/davidbyttow/govips/v2/vips"
 	"sneak.berlin/go/pixa/internal/imagerequest"
@@ -140,14 +145,17 @@ func TestImageProcessor_RendersSVGSharpWhenEnlarged(t *testing.T) {
 	}
 }
 
-// TestImageProcessor_SVGFetchesNothing checks that rendering an SVG that
+// TestImageProcessor_SVGFetchesNothing checks that rendering an SVG draws no
-// refers to an image and an external entity on a local server makes no
+// image it refers to: one at a URL on a local server, by href or xlink:href,
-// request to that server.
+// or a local file that exists. Each SVG renders without error, white where
+// the image would be. An SVG that uses an external entity at that server is
+// a separate case. No SVG makes a request to the server.
 func TestImageProcessor_SVGFetchesNothing(t *testing.T) {
 	t.Parallel()
 
 	var requests atomic.Int64
 
+	// Blue is 128 in every pixel of this PNG.
 	png := createTestPNG(t, 4, 4)
 
 	server := httptest.NewServer(http.HandlerFunc(
@@ -159,64 +167,337 @@ func TestImageProcessor_SVGFetchesNothing(t *testing.T) {
 		}))
 	t.Cleanup(server.Close)
 
-	svg := `<?xml version="1.0"?>` +
+	pngPath := filepath.Join(t.TempDir(), "image.png")
-		`<!DOCTYPE svg [<!ENTITY outside SYSTEM "` + server.URL + `/entity">]>` +
-		`<svg xmlns="http://www.w3.org/2000/svg" ` +
-		`xmlns:xlink="http://www.w3.org/1999/xlink" width="16" height="12">` +
-		`<image href="` + server.URL + `/image.png" width="16" height="12"/>` +
-		`<image xlink:href="` + server.URL + `/xlink.png" width="16" height="12"/>` +
-		`<text y="10">&outside;</text></svg>`
 
-	_, _, err := processSVG(t, svg, imagerequest.Transform{
+	err := os.WriteFile(pngPath, png, 0o600)
+	if err != nil {
+		t.Fatalf("writing the PNG file: %v", err)
+	}
+
+	for _, reference := range []string{
+		`href="` + server.URL + `/image.png"`,
+		`xlink:href="` + server.URL + `/xlink.png"`,
+		`href="file://` + pngPath + `"`,
+	} {
+		svg := `<svg xmlns="http://www.w3.org/2000/svg" ` +
+			`xmlns:xlink="http://www.w3.org/1999/xlink" width="16" height="12">` +
+			`<rect width="16" height="12" fill="white"/>` +
+			`<image ` + reference + ` width="16" height="12"/></svg>`
+
+		_, output, err := processSVG(t, svg, imagerequest.Transform{
 			Format: imagerequest.FormatPNG,
 		})
-	t.Logf("SVG as PNG: error = %v", err)
+		if err != nil {
+			t.Errorf("SVG with image %s as PNG: %v", reference, err)
+
+			continue
+		}
+
+		img, err := vips.NewImageFromBuffer(output)
+		if err != nil {
+			t.Fatalf("decoding the PNG: %v", err)
+		}
+
+		point, err := img.GetPoint(8, 6)
+		img.Close()
+
+		if err != nil {
+			t.Fatalf("GetPoint(8, 6): %v", err)
+		}
+
+		t.Logf("SVG with image %s: pixel at 8,6 = %v", reference, point)
+
+		if point[2] != 255 {
+			t.Errorf("SVG with image %s: blue at 8,6 = %v, want 255: the "+
+				"image is drawn", reference, point[2])
+		}
+	}
+
+	svg := `<?xml version="1.0"?>` +
+		`<!DOCTYPE svg [<!ENTITY outside SYSTEM "` + server.URL + `/entity">]>` +
+		`<svg xmlns="http://www.w3.org/2000/svg" width="16" height="12">` +
+		`<text y="10">&outside;</text></svg>`
+
+	// librsvg loads no external entity, so it refuses this SVG: outside is
+	// not defined.
+	_, _, err = processSVG(t, svg, imagerequest.Transform{
+		Format: imagerequest.FormatPNG,
+	})
+	t.Logf("SVG with an external entity as PNG: error = %v", err)
 
 	if requests.Load() != 0 {
-		t.Errorf("rendering the SVG made %d requests, want none", requests.Load())
+		t.Errorf("rendering the SVGs made %d requests, want none",
+			requests.Load())
 	}
 }
 
-// TestImageProcessor_RefusesSVGTooLarge checks that an SVG wider than
+// TestImageProcessor_RendersSVGLargerThanMaxInputDimension checks that an
-// MaxInputDimension is ErrInputTooLarge, as a raster source is.
+// SVG whose own size is above MaxInputDimension is limited only by the
-func TestImageProcessor_RefusesSVGTooLarge(t *testing.T) {
+// output checks: it is rendered at a raster size, orig of it is the SVG
+// itself, and a raster format at its own size is ErrSVGTooLargeForOrigSize.
+// The 1000000x1000000 one is rendered at a ten-thousandth of its own size.
+func TestImageProcessor_RendersSVGLargerThanMaxInputDimension(t *testing.T) {
 	t.Parallel()
 
-	_, _, err := processSVG(t,
+	for _, svg := range []string{
-		`<svg xmlns="http://www.w3.org/2000/svg" width="10000" height="10"/>`,
+		`<svg xmlns="http://www.w3.org/2000/svg" width="10000" height="10">` +
-		imagerequest.Transform{
+			`<rect width="10000" height="10"/></svg>`,
+		`<svg xmlns="http://www.w3.org/2000/svg" width="1000000" ` +
+			`height="1000000"><rect width="1000000" height="1000000"/></svg>`,
+	} {
+		result, _, err := processSVG(t, svg, imagerequest.Transform{
 			Size:   imagerequest.Size{Width: 100, Height: 100},
 			Format: imagerequest.FormatPNG,
 		})
-	if !errors.Is(err, ErrInputTooLarge) {
+		if err != nil {
-		t.Errorf("SVG of 10000x10: error = %v, want %v", err, ErrInputTooLarge)
+			t.Errorf("%s as PNG at 100x100: %v", svg, err)
+		} else {
+			t.Logf("%s as PNG at 100x100: %dx%d", svg, result.Width, result.Height)
+
+			if result.Width != 100 || result.Height != 100 {
+				t.Errorf("%s as PNG at 100x100 = %dx%d, want 100x100", svg,
+					result.Width, result.Height)
+			}
+		}
+
+		result, output, err := processSVG(t, svg,
+			imagerequest.Transform{Format: imagerequest.FormatOriginal})
+		if err != nil || result.ContentType != imagerequest.FormatSVG.MIMEType() ||
+			string(output) != svg {
+			t.Errorf("orig of %s: error = %v, want the SVG itself", svg, err)
+		}
+
+		_, _, err = processSVG(t, svg,
+			imagerequest.Transform{Format: imagerequest.FormatPNG})
+		if !errors.Is(err, ErrSVGTooLargeForOrigSize) {
+			t.Errorf("%s as PNG at its own size: error = %v, want %v", svg,
+				err, ErrSVGTooLargeForOrigSize)
+		}
 	}
 }
 
-// TestSVGDensity checks the density at which an SVG is rendered to cover
+// TestImageProcessor_RefusesSVGTooThin checks that an SVG with one side more
-// an output size, and that it is held to MaxInputDimension.
+// than MaxInputDimension times the other is ErrSVGTooThin at a raster size,
-func TestSVGDensity(t *testing.T) {
+// that one at exactly that proportion is rendered, and that orig of either
+// is the SVG itself.
+func TestImageProcessor_RefusesSVGTooThin(t *testing.T) {
+	t.Parallel()
+
+	tooThin := `<svg xmlns="http://www.w3.org/2000/svg" width="81930" ` +
+		`height="10"><rect width="81930" height="10"/></svg>`
+	atTheLimit := `<svg xmlns="http://www.w3.org/2000/svg" width="81920" ` +
+		`height="10"><rect width="81920" height="10"/></svg>`
+	size := imagerequest.Size{Width: 100, Height: 100}
+
+	_, _, err := processSVG(t, tooThin,
+		imagerequest.Transform{Size: size, Format: imagerequest.FormatPNG})
+	if !errors.Is(err, ErrSVGTooThin) {
+		t.Errorf("81930x10 SVG as PNG at 100x100: error = %v, want %v", err,
+			ErrSVGTooThin)
+	}
+
+	result, _, err := processSVG(t, atTheLimit,
+		imagerequest.Transform{Size: size, Format: imagerequest.FormatPNG})
+	if err != nil {
+		t.Errorf("81920x10 SVG as PNG at 100x100: %v", err)
+	} else if result.Width != 100 || result.Height != 100 {
+		t.Errorf("81920x10 SVG as PNG at 100x100 = %dx%d, want 100x100",
+			result.Width, result.Height)
+	}
+
+	for _, svg := range []string{tooThin, atTheLimit} {
+		result, output, err := processSVG(t, svg,
+			imagerequest.Transform{Format: imagerequest.FormatOriginal})
+		if err != nil || result.ContentType != imagerequest.FormatSVG.MIMEType() ||
+			string(output) != svg {
+			t.Errorf("orig of %s: error = %v, want the SVG itself", svg, err)
+		}
+	}
+}
+
+// testSVGRenderTimeout is the time limit of the SVG time limit tests, short
+// so that they finish in a few seconds. Under the race detector a child
+// process takes about a second to start and read an SVG's size.
+const testSVGRenderTimeout = 3 * time.Second
+
+// processSVGTimed has processor process svg, as an SVG source, with transform,
+// and returns the error and how long it took.
+func processSVGTimed(
+	t *testing.T, processor *ImageProcessor, svg string,
+	transform imagerequest.Transform,
+) (time.Duration, error) {
+	t.Helper()
+
+	start := time.Now()
+	_, err := processor.Process(t.Context(), strings.NewReader(svg),
+		imagerequest.FormatSVG, &transform)
+
+	return time.Since(start), err
+}
+
+// checkProcessesAnotherImage checks that processor, after refusing an SVG,
+// processes a PNG.
+func checkProcessesAnotherImage(t *testing.T, processor *ImageProcessor) {
+	t.Helper()
+
+	_, err := processor.Process(t.Context(),
+		bytes.NewReader(createTestPNG(t, 64, 48)), imagerequest.FormatPNG,
+		&imagerequest.Transform{
+			Size:   imagerequest.Size{Width: 32, Height: 24},
+			Format: imagerequest.FormatJPEG,
+		})
+	if err != nil {
+		t.Errorf("a PNG after the SVG: %v", err)
+	}
+}
+
+// TestImageProcessor_StopsSlowSVGRender checks that an SVG that takes about
+// 12 seconds to render, 600 shapes each drawn with an feTurbulence filter
+// effect, is ErrSVGRenderFailed soon after a time limit of
+// testSVGRenderTimeout, not when the render would end. The processor then
+// processes another image.
+func TestImageProcessor_StopsSlowSVGRender(t *testing.T) {
+	t.Parallel()
+
+	svg := `<svg xmlns="http://www.w3.org/2000/svg" width="256" height="256">` +
+		`<filter id="noise">` +
+		`<feTurbulence baseFrequency="0.05" numOctaves="4"/></filter>` +
+		strings.Repeat(`<rect width="256" height="256" filter="url(#noise)"/>`,
+			600) +
+		`</svg>`
+
+	processor := newSVGTestProcessor()
+	processor.svgRenderTimeout = testSVGRenderTimeout
+
+	elapsed, err := processSVGTimed(t, processor, svg, imagerequest.Transform{
+		Size:   imagerequest.Size{Width: 256, Height: 256},
+		Format: imagerequest.FormatPNG,
+	})
+	t.Logf("slow SVG as PNG: error %v after %v", err, elapsed)
+
+	if !errors.Is(err, ErrSVGRenderFailed) {
+		t.Errorf("slow SVG as PNG: error = %v, want %v", err,
+			ErrSVGRenderFailed)
+	}
+
+	if elapsed > testSVGRenderTimeout+2*time.Second {
+		t.Errorf("slow SVG as PNG: refused after %v, want soon after %v",
+			elapsed, testSVGRenderTimeout)
+	}
+
+	checkProcessesAnotherImage(t, processor)
+}
+
+// TestImageProcessor_StopsSlowSVGSizeRead checks that orig of an SVG whose
+// size takes about 10 seconds to read is ErrSVGRenderFailed soon after a time
+// limit of testSVGRenderTimeout. To read the size, librsvg matches each of the
+// SVG's 2500 CSS rules against each of its 2500 shapes, walking up the 75
+// groups around it. The processor then processes another image.
+func TestImageProcessor_StopsSlowSVGSizeRead(t *testing.T) {
+	t.Parallel()
+
+	var rules strings.Builder
+
+	for i := range 2500 {
+		fmt.Fprintf(&rules, ".group%d rect { fill: red }", i)
+	}
+
+	svg := `<svg xmlns="http://www.w3.org/2000/svg" width="16" height="12">` +
+		`<style>` + rules.String() + `</style>` + strings.Repeat(`<g>`, 75) +
+		strings.Repeat(`<rect width="1" height="1"/>`, 2500) +
+		strings.Repeat(`</g>`, 75) + `</svg>`
+
+	processor := newSVGTestProcessor()
+	processor.svgRenderTimeout = testSVGRenderTimeout
+
+	elapsed, err := processSVGTimed(t, processor, svg,
+		imagerequest.Transform{Format: imagerequest.FormatOriginal})
+	t.Logf("orig of the SVG: error %v after %v", err, elapsed)
+
+	if !errors.Is(err, ErrSVGRenderFailed) {
+		t.Errorf("orig of the SVG: error = %v, want %v", err,
+			ErrSVGRenderFailed)
+	}
+
+	if elapsed > testSVGRenderTimeout+2*time.Second {
+		t.Errorf("orig of the SVG: refused after %v, want soon after %v",
+			elapsed, testSVGRenderTimeout)
+	}
+
+	checkProcessesAnotherImage(t, processor)
+}
+
+// TestImageProcessor_StopsSVGRenderOverMemoryLimit checks that an SVG that
+// needs about 500 MiB more than a child process's own memory to render, a
+// chain of 2000 blurs that each keep their result, is ErrSVGRenderFailed with
+// a memory limit of 512 MiB, and that a plain SVG renders under the same
+// limit. A child process needs about 130 MiB of its own, and about 350 MiB
+// under the race detector, so the chain also renders under MaxSVGRenderMemory.
+func TestImageProcessor_StopsSVGRenderOverMemoryLimit(t *testing.T) {
+	t.Parallel()
+
+	var blurs strings.Builder
+
+	blurs.WriteString(`<feGaussianBlur stdDeviation="3" result="blur0"/>`)
+
+	for i := 1; i < 2000; i++ {
+		fmt.Fprintf(&blurs,
+			`<feGaussianBlur in="blur%d" stdDeviation="3" result="blur%d"/>`,
+			i-1, i)
+	}
+
+	svg := `<svg xmlns="http://www.w3.org/2000/svg" width="256" height="256">` +
+		`<filter id="blurs" color-interpolation-filters="sRGB">` +
+		blurs.String() + `</filter>` +
+		`<rect width="256" height="256" fill="red" filter="url(#blurs)"/></svg>`
+	size := imagerequest.Size{Width: 256, Height: 256}
+
+	processor := newSVGTestProcessor()
+	processor.maxSVGRenderMemory = 512 << 20
+
+	elapsed, err := processSVGTimed(t, processor, svg,
+		imagerequest.Transform{Size: size, Format: imagerequest.FormatPNG})
+	t.Logf("SVG of 2000 blurs as PNG: error %v after %v", err, elapsed)
+
+	if !errors.Is(err, ErrSVGRenderFailed) {
+		t.Errorf("SVG of 2000 blurs as PNG: error = %v, want %v", err,
+			ErrSVGRenderFailed)
+	}
+
+	_, err = processSVGTimed(t, processor, testSVG,
+		imagerequest.Transform{Size: size, Format: imagerequest.FormatPNG})
+	if err != nil {
+		t.Errorf("plain SVG as PNG after it: %v", err)
+	}
+}
+
+// TestSVGRenderSize checks the size at which an SVG is rendered to cover an
+// output size, and that it is held to MaxInputDimension.
+func TestSVGRenderSize(t *testing.T) {
 	t.Parallel()
 
 	tests := []struct {
 		name                      string
 		width, height             int
 		outputWidth, outputHeight int
-		want                      int
+		wantWidth, wantHeight     int
 	}{
-		{"own size", 16, 12, 16, 12, svgDefaultDensity},
+		{"own size", 16, 12, 16, 12, 16, 12},
-		{"100 times larger", 16, 12, 1600, 1200, 7200},
+		{"100 times larger", 16, 12, 1600, 1200, 1600, 1200},
-		{"wider than the SVG's proportions", 16, 12, 160, 12, 720},
+		{"wider than the SVG's proportions", 16, 12, 160, 12, 160, 120},
-		{"10 times smaller", 100, 100, 10, 10, 8},
+		{"10 times smaller", 100, 100, 10, 10, 10, 10},
-		{"held to MaxInputDimension", 8192, 1, 8192, 8192, svgDefaultDensity},
+		{"held to MaxInputDimension", 8192, 1, 8192, 8192, 8192, 1},
-		{"held to MaxInputDimension when enlarged", 1024, 1, 8192, 8192, 576},
+		{"held to MaxInputDimension when enlarged", 1024, 1, 8192, 8192, 8192, 8},
+		{"far above MaxInputDimension", 1000000, 1000000, 100, 100, 100, 100},
 	}
 
 	for _, tt := range tests {
-		got := svgDensity(tt.width, tt.height, tt.outputWidth, tt.outputHeight)
+		gotWidth, gotHeight := svgRenderSize(tt.width, tt.height,
-		if got != tt.want {
+			tt.outputWidth, tt.outputHeight)
-			t.Errorf("%s: svgDensity(%d, %d, %d, %d) = %d, want %d", tt.name,
+		if gotWidth != tt.wantWidth || gotHeight != tt.wantHeight {
-				tt.width, tt.height, tt.outputWidth, tt.outputHeight, got, tt.want)
+			t.Errorf("%s: svgRenderSize(%d, %d, %d, %d) = %dx%d, want %dx%d",
+				tt.name, tt.width, tt.height, tt.outputWidth, tt.outputHeight,
+				gotWidth, gotHeight, tt.wantWidth, tt.wantHeight)
 		}
 	}
 }

internal/imageproxy/cache_ttl_internal_test.go

@@ -0,0 +1,493 @@
+package imageproxy
+
+import (
+	"bytes"
+	"context"
+	"errors"
+	"fmt"
+	"image/color"
+	"io"
+	"net/http"
+	"os"
+	"sync"
+	"testing"
+	"time"
+
+	"sneak.berlin/go/pixa/internal/httpfetcher"
+	"sneak.berlin/go/pixa/internal/imagerequest"
+)
+
+// Validators the test upstream sends with its image.
+const (
+	testETag         = `"v1"`
+	testLastModified = "Mon, 02 Nov 2026 10:00:00 GMT"
+)
+
+// errConnectionRefused stands for an upstream that cannot be reached.
+var errConnectionRefused = errors.New("connection refused")
+
+// upstreamFailure is one way a fetch from upstream fails.
+type upstreamFailure struct {
+	name string
+	err  error
+}
+
+// upstreamFailures returns the ways a check of a cached image with upstream
+// can fail: an error status, a timeout and no connection.
+func upstreamFailures() []upstreamFailure {
+	return []upstreamFailure{
+		{"error status", fmt.Errorf("%w: status 503", httpfetcher.ErrUpstreamError)},
+		{"timeout", httpfetcher.ErrUpstreamTimeout},
+		{"no connection", errConnectionRefused},
+	}
+}
+
+// conditionalUpstream serves one JPEG image with an ETag or a Last-Modified
+// header, or both. It answers 304 Not Modified to a fetch whose If-None-Match
+// is its ETag, or, when it has no ETag, whose If-Modified-Since is its
+// Last-Modified. While err is set, every fetch fails with it. It records the
+// conditional headers of every fetch.
+type conditionalUpstream struct {
+	mu           sync.Mutex
+	image        []byte
+	etag         string
+	lastModified string
+	err          error
+
+	ifNoneMatch     []string
+	ifModifiedSince []string
+}
+
+func (u *conditionalUpstream) Fetch(
+	_ context.Context, _ imagerequest.Source,
+	ifNoneMatch, ifModifiedSince string,
+) (*httpfetcher.FetchResult, error) {
+	u.mu.Lock()
+	defer u.mu.Unlock()
+
+	u.ifNoneMatch = append(u.ifNoneMatch, ifNoneMatch)
+	u.ifModifiedSince = append(u.ifModifiedSince, ifModifiedSince)
+
+	if u.err != nil {
+		return nil, u.err
+	}
+
+	unchanged := ifNoneMatch == u.etag
+	if u.etag == "" {
+		unchanged = ifModifiedSince == u.lastModified
+	}
+
+	if unchanged {
+		return &httpfetcher.FetchResult{
+			Content:    http.NoBody,
+			StatusCode: http.StatusNotModified,
+		}, nil
+	}
+
+	headers := http.Header{}
+	if u.etag != "" {
+		headers.Set("ETag", u.etag)
+	}
+
+	if u.lastModified != "" {
+		headers.Set("Last-Modified", u.lastModified)
+	}
+
+	return &httpfetcher.FetchResult{
+		Content:       io.NopCloser(bytes.NewReader(u.image)),
+		ContentLength: int64(len(u.image)),
+		ContentType:   testContentTypeJPEG,
+		Headers:       headers,
+		StatusCode:    http.StatusOK,
+	}, nil
+}
+
+// change replaces the upstream image and its ETag.
+func (u *conditionalUpstream) change(image []byte, etag string) {
+	u.mu.Lock()
+	defer u.mu.Unlock()
+
+	u.image = image
+	u.etag = etag
+}
+
+// fail makes every later fetch fail with err.
+func (u *conditionalUpstream) fail(err error) {
+	u.mu.Lock()
+	defer u.mu.Unlock()
+
+	u.err = err
+}
+
+// fetches returns how many fetches upstream was asked for.
+func (u *conditionalUpstream) fetches() int {
+	u.mu.Lock()
+	defer u.mu.Unlock()
+
+	return len(u.ifNoneMatch)
+}
+
+// lastConditionalHeaders returns the If-None-Match and If-Modified-Since of
+// the last fetch.
+func (u *conditionalUpstream) lastConditionalHeaders() (string, string) {
+	u.mu.Lock()
+	defer u.mu.Unlock()
+
+	last := len(u.ifNoneMatch) - 1
+
+	return u.ifNoneMatch[last], u.ifModifiedSince[last]
+}
+
+// setupConditionalUpstreamProxy returns a proxy whose upstream is a
+// conditionalUpstream serving a red JPEG with an ETag.
+func setupConditionalUpstreamProxy(
+	t *testing.T,
+) (*testProxy, *TestFixtures, *conditionalUpstream) {
+	t.Helper()
+
+	svc, fixtures := setupTestProxy(t)
+	upstream := &conditionalUpstream{
+		image: generateTestJPEG(t, 100, 100, color.RGBA{255, 0, 0, 255}),
+		etag:  testETag,
+	}
+	svc.fetcher = upstream
+
+	return svc, fixtures, upstream
+}
+
+// TestProxy_Get_FreshVariantAsksUpstreamNothing checks that a variant whose
+// source was checked with upstream less than the cache TTL ago is served from
+// the cache without asking upstream.
+func TestProxy_Get_FreshVariantAsksUpstreamNothing(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures, upstream := setupConditionalUpstreamProxy(t)
+	variant := photoVariant(fixtures, 85, imagerequest.FitCover)
+
+	first, _ := getImage(t, svc, variant)
+	second, status := getImage(t, svc, variant)
+
+	t.Logf("cache status = %s, upstream fetches = %d", status, upstream.fetches())
+
+	if status != CacheHit {
+		t.Errorf("CacheStatus = %q, want %q", status, CacheHit)
+	}
+
+	if !bytes.Equal(first, second) {
+		t.Error("the cached variant differs from the one first served")
+	}
+
+	if n := upstream.fetches(); n != 1 {
+		t.Errorf("upstream fetches = %d, want 1", n)
+	}
+}
+
+// TestProxy_Get_UnchangedSourceAfterTTLIsNotDownloadedAgain caches a variant,
+// sets its source's check time and the variant's file time two days back,
+// and requests it again, with the source still cached and with the source's
+// row and file removed, as eviction does. Upstream must be asked with the
+// validator it sent, answer 304, and send no bytes; the variant must be served
+// again without being made again, and then be served from the cache until the
+// TTL passes.
+func TestProxy_Get_UnchangedSourceAfterTTLIsNotDownloadedAgain(t *testing.T) {
+	t.Parallel()
+
+	tests := []struct {
+		name                string
+		sourceEvicted       bool
+		etag                string
+		lastModified        string
+		wantIfNoneMatch     string
+		wantIfModifiedSince string
+	}{
+		{"ETag", false, testETag, "", testETag, ""},
+		{"Last-Modified only", false, "", testLastModified, "", testLastModified},
+		{"both", false, testETag, testLastModified, testETag, testLastModified},
+		{"ETag, source evicted", true, testETag, "", testETag, ""},
+		{"Last-Modified only, source evicted", true, "", testLastModified, "",
+			testLastModified},
+		{"both, source evicted", true, testETag, testLastModified, testETag,
+			testLastModified},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			t.Parallel()
+
+			svc, fixtures, upstream := setupConditionalUpstreamProxy(t)
+			upstream.etag = tt.etag
+			upstream.lastModified = tt.lastModified
+			variant := photoVariant(fixtures, 85, imagerequest.FitCover)
+
+			first, _ := getImage(t, svc, variant)
+			setBackSourceAndVariant(t, svc, variant, time.Now().AddDate(0, 0, -2))
+
+			if tt.sourceEvicted {
+				evictSource(t, svc, variant.Source)
+			}
+
+			second, status := getImage(t, svc, variant)
+
+			ifNoneMatch, ifModifiedSince := upstream.lastConditionalHeaders()
+			counters := readCounters(t, svc)
+			t.Logf("cache status = %s, If-None-Match = %q, If-Modified-Since = %q, "+
+				"counters = %+v", status, ifNoneMatch, ifModifiedSince, counters)
+
+			if ifNoneMatch != tt.wantIfNoneMatch {
+				t.Errorf("If-None-Match = %q, want %q", ifNoneMatch, tt.wantIfNoneMatch)
+			}
+
+			if ifModifiedSince != tt.wantIfModifiedSince {
+				t.Errorf("If-Modified-Since = %q, want %q",
+					ifModifiedSince, tt.wantIfModifiedSince)
+			}
+
+			if !bytes.Equal(first, second) {
+				t.Error("the variant served after the check differs from the cached one")
+			}
+
+			if counters.upstreamFetchCount != 1 || counters.transformCount != 1 {
+				t.Errorf("upstream downloads = %d, transforms = %d; want 1 and 1",
+					counters.upstreamFetchCount, counters.transformCount)
+			}
+
+			_, status = getImage(t, svc, variant)
+			if status != CacheHit {
+				t.Errorf("CacheStatus after the check = %q, want %q", status, CacheHit)
+			}
+
+			if n := upstream.fetches(); n != 2 {
+				t.Errorf("upstream fetches = %d, want 2", n)
+			}
+		})
+	}
+}
+
+// TestProxy_Get_ChangedSourceAfterTTLReplacesSourceAndVariants caches two
+// variants of one source, changes the image upstream, and sets the source's
+// check time and both variants' file times two days back. Each variant must
+// then be made again from the new image, which is downloaded once.
+func TestProxy_Get_ChangedSourceAfterTTLReplacesSourceAndVariants(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures, upstream := setupConditionalUpstreamProxy(t)
+	variants := []*imagerequest.Request{
+		photoVariant(fixtures, 85, imagerequest.FitCover),
+		photoVariant(fixtures, 40, imagerequest.FitCover),
+	}
+
+	oldImages := make([][]byte, len(variants))
+	for i, variant := range variants {
+		oldImages[i], _ = getImage(t, svc, variant)
+	}
+
+	newSource := generateTestJPEG(t, 120, 90, color.RGBA{0, 0, 255, 255})
+	upstream.change(newSource, `"v2"`)
+
+	twoDaysAgo := time.Now().AddDate(0, 0, -2)
+	for _, variant := range variants {
+		setBackSourceAndVariant(t, svc, variant, twoDaysAgo)
+	}
+
+	for i, variant := range variants {
+		image, _ := getImage(t, svc, variant)
+		if bytes.Equal(image, oldImages[i]) {
+			t.Errorf("variant %d is still made from the old image", i)
+		}
+	}
+
+	counters := readCounters(t, svc)
+	t.Logf("counters = %+v, upstream fetches = %d", counters, upstream.fetches())
+
+	if counters.upstreamFetchCount != 2 {
+		t.Errorf("upstream downloads = %d, want 2", counters.upstreamFetchCount)
+	}
+
+	cached, err := os.ReadFile(sourceFilePath(svc, variants[0].Source.Key()))
+	if err != nil {
+		t.Fatalf("reading the cached source: %v", err)
+	}
+
+	if !bytes.Equal(cached, newSource) {
+		t.Error("the cached source is not the new image")
+	}
+}
+
+// TestProxy_Get_UpstreamFailureAfterTTLServesCachedImage caches a variant,
+// sets its source's check time and the variant's file time two days back, and
+// makes upstream fail. The cached variant must still be served, and a variant
+// not yet cached must be made from the cached source.
+func TestProxy_Get_UpstreamFailureAfterTTLServesCachedImage(t *testing.T) {
+	t.Parallel()
+
+	for _, failure := range upstreamFailures() {
+		t.Run(failure.name, func(t *testing.T) {
+			t.Parallel()
+
+			svc, fixtures, upstream := setupConditionalUpstreamProxy(t)
+			variant := photoVariant(fixtures, 85, imagerequest.FitCover)
+
+			first, _ := getImage(t, svc, variant)
+			setBackSourceAndVariant(t, svc, variant, time.Now().AddDate(0, 0, -2))
+			upstream.fail(failure.err)
+
+			second, _ := getImage(t, svc, variant)
+			t.Logf("upstream fetches = %d", upstream.fetches())
+
+			if upstream.fetches() != 2 {
+				t.Errorf("upstream fetches = %d, want 2", upstream.fetches())
+			}
+
+			if !bytes.Equal(first, second) {
+				t.Error("the variant served while upstream fails differs from the cached one")
+			}
+
+			getImage(t, svc, photoVariant(fixtures, 40, imagerequest.FitCover))
+		})
+	}
+}
+
+// TestProxy_Get_FailingUpstreamIsAskedOnceWhileImageIsServedOften caches a
+// variant, sets its source's check time and the variant's file time two days
+// back, and makes every fetch time out. Serving the variant ten times, and a
+// variant not yet cached, must ask upstream once: the failed check puts the
+// source URL in the negative cache.
+func TestProxy_Get_FailingUpstreamIsAskedOnceWhileImageIsServedOften(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures, upstream := setupConditionalUpstreamProxy(t)
+	variant := photoVariant(fixtures, 85, imagerequest.FitCover)
+
+	getImage(t, svc, variant)
+	setBackSourceAndVariant(t, svc, variant, time.Now().AddDate(0, 0, -2))
+	upstream.fail(httpfetcher.ErrUpstreamTimeout)
+
+	for range 10 {
+		getImage(t, svc, variant)
+	}
+
+	getImage(t, svc, photoVariant(fixtures, 40, imagerequest.FitCover))
+
+	t.Logf("upstream fetches = %d", upstream.fetches())
+
+	if n := upstream.fetches(); n != 2 {
+		t.Errorf("upstream fetches = %d, want 2: the first fetch and one check", n)
+	}
+}
+
+// TestProxy_Get_UpstreamFailureAfterTTLServesVariantOfEvictedSource caches a
+// variant, sets its file time two days back, removes its source's row and
+// file, as eviction does, and makes upstream fail. The cached variant must
+// still be served.
+func TestProxy_Get_UpstreamFailureAfterTTLServesVariantOfEvictedSource(t *testing.T) {
+	t.Parallel()
+
+	for _, failure := range upstreamFailures() {
+		t.Run(failure.name, func(t *testing.T) {
+			t.Parallel()
+
+			svc, fixtures, upstream := setupConditionalUpstreamProxy(t)
+			variant := photoVariant(fixtures, 85, imagerequest.FitCover)
+
+			first, _ := getImage(t, svc, variant)
+			setBackSourceAndVariant(t, svc, variant, time.Now().AddDate(0, 0, -2))
+			evictSource(t, svc, variant.Source)
+			upstream.fail(failure.err)
+
+			second, _ := getImage(t, svc, variant)
+			t.Logf("upstream fetches = %d", upstream.fetches())
+
+			if !bytes.Equal(first, second) {
+				t.Error("the variant served while upstream fails differs from the cached one")
+			}
+
+			if n := upstream.fetches(); n != 2 {
+				t.Errorf("upstream fetches = %d, want 2", n)
+			}
+		})
+	}
+}
+
+// TestProxy_Get_FailingUpstreamIsAskedOnceForVariantOfEvictedSource caches a
+// variant, sets its file time two days back, removes its source's row and
+// file, as eviction does, and makes every fetch time out. Serving the variant
+// ten times must ask upstream once: the failed check puts the source URL in
+// the negative cache.
+func TestProxy_Get_FailingUpstreamIsAskedOnceForVariantOfEvictedSource(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures, upstream := setupConditionalUpstreamProxy(t)
+	variant := photoVariant(fixtures, 85, imagerequest.FitCover)
+
+	first, _ := getImage(t, svc, variant)
+	setBackSourceAndVariant(t, svc, variant, time.Now().AddDate(0, 0, -2))
+	evictSource(t, svc, variant.Source)
+	upstream.fail(httpfetcher.ErrUpstreamTimeout)
+
+	for range 10 {
+		image, _ := getImage(t, svc, variant)
+		if !bytes.Equal(image, first) {
+			t.Fatal("the variant served while upstream fails differs from the cached one")
+		}
+	}
+
+	t.Logf("upstream fetches = %d", upstream.fetches())
+
+	if n := upstream.fetches(); n != 2 {
+		t.Errorf("upstream fetches = %d, want 2: the first fetch and one check", n)
+	}
+}
+
+// evictSource removes the row and then the file of src's cached source, as
+// the cache's eviction does, and leaves its variants cached.
+func evictSource(t *testing.T, svc *testProxy, src imagerequest.Source) {
+	t.Helper()
+
+	_, err := svc.db.ExecContext(t.Context(),
+		`DELETE FROM source_content WHERE source_key = ?`, string(src.Key()))
+	if err != nil {
+		t.Fatalf("deleting the source's row: %v", err)
+	}
+
+	err = os.Remove(sourceFilePath(svc, src.Key()))
+	if err != nil {
+		t.Fatalf("removing the source's file: %v", err)
+	}
+}
+
+// setBackSourceAndVariant sets back to when the times the cache keeps for
+// req's source and for the variant req asks for: the source's fetch and check
+// times, both last access times, the variant's check time, and the variant
+// file's modification time.
+func setBackSourceAndVariant(
+	t *testing.T, svc *testProxy, req *imagerequest.Request, when time.Time,
+) {
+	t.Helper()
+
+	key := req.Source.Key()
+	setSourceLastAccessed(t, svc.db, key, when)
+
+	_, err := svc.db.ExecContext(t.Context(),
+		`UPDATE source_content SET fetched_at = ?, checked_at = ?
+		WHERE source_key = ?`, when.UTC(), when.UTC(), string(key))
+	if err != nil {
+		t.Fatalf("setting back the source's fetch and check times: %v", err)
+	}
+
+	variantKey := imagerequest.CacheKey(req)
+	setVariantLastAccessed(t, svc.db, variantKey, when)
+
+	_, err = svc.db.ExecContext(t.Context(),
+		`UPDATE variant_content SET checked_at = ? WHERE cache_key = ?`,
+		when.UTC(), string(variantKey))
+	if err != nil {
+		t.Fatalf("setting back the variant's check time: %v", err)
+	}
+
+	path := variantFilePath(svc, variantKey)
+
+	err = os.Chtimes(path, when, when)
+	if err != nil {
+		t.Fatalf("setting back the times of %s: %v", path, err)
+	}
+}

internal/imageproxy/concurrent_misses_internal_test.go

@@ -37,6 +37,7 @@ type heldFetcher struct {
 
 func (f *heldFetcher) Fetch(
 	ctx context.Context, source imagerequest.Source,
+	ifNoneMatch, ifModifiedSince string,
 ) (*httpfetcher.FetchResult, error) {
 	f.fetches.Add(1)
 
@@ -48,7 +49,7 @@ func (f *heldFetcher) Fetch(
 		return nil, ctx.Err()
 	}
 
-	return f.upstream.Fetch(ctx, source)
+	return f.upstream.Fetch(ctx, source, ifNoneMatch, ifModifiedSince)
 }
 
 // releaseFetches lets every held fetch, and every later one, go on.
@@ -489,7 +490,7 @@ func TestProxy_Get_WaiterGetsProcessingTimedOut(t *testing.T) {
 type panickingFetcher struct{}
 
 func (panickingFetcher) Fetch(
-	context.Context, imagerequest.Source,
+	context.Context, imagerequest.Source, string, string,
 ) (*httpfetcher.FetchResult, error) {
 	panic("upstream fetcher panicked")
 }

internal/imageproxy/imageproxy.go

@@ -10,6 +10,7 @@ import (
 	"fmt"
 	"io"
 	"log/slog"
+	"net/http"
 	"runtime/debug"
 	"time"
 
@@ -36,11 +37,15 @@ type Proxy struct {
 	// same time share one fetch and one transcode.
 	variantsInProgress singleflight.Group
 
-	// The counts of upstream fetches and transforms, made and registered by
+	// The metrics of upstream fetches and transforms, made and registered by
-	// New. They are kept in memory, so adding to one waits for nothing.
+	// New. They are kept in memory, so updating one waits for nothing.
 	upstreamFetches        prometheus.Counter
 	upstreamFetchBytes     prometheus.Counter
+	upstreamFetchDurations prometheus.Histogram
+	upstreamFetchErrors    prometheus.Counter
 	transforms             prometheus.Counter
+	transformDurations     prometheus.Histogram
+	transformsInProgress   prometheus.Gauge
 }
 
 // Config holds the proxy's configuration.
@@ -61,9 +66,9 @@ type Config struct {
 // errCacheRequired is returned when the proxy is built without a cache.
 var errCacheRequired = errors.New("cache is required")
 
-// New creates a new image proxy and registers its counters on
+// New creates a new image proxy and registers its metrics on
 // metricsRegistry. pixad passes Prometheus' default registry, the one
-// /metrics serves. It fails when metricsRegistry already holds counters of
+// /metrics serves. It fails when metricsRegistry already holds metrics of
 // the same names.
 func New(
 	cfg *Config, metricsRegistry prometheus.Registerer,
@@ -98,18 +103,39 @@ func New(
 			Name: "pixa_upstream_fetch_bytes_total",
 			Help: "Bytes read from upstream by fetches of source images.",
 		}),
+		upstreamFetchDurations: prometheus.NewHistogram(prometheus.HistogramOpts{
+			Name: "pixa_upstream_fetch_duration_seconds",
+			Help: "Duration of the fetches pixa_upstream_fetches_total counts, " +
+				"until the response's last byte.",
+		}),
+		upstreamFetchErrors: prometheus.NewCounter(prometheus.CounterOpts{
+			Name: "pixa_upstream_fetch_errors_total",
+			Help: "Fetches of a source image from upstream that failed, " +
+				"before or while reading the response.",
+		}),
 		transforms: prometheus.NewCounter(prometheus.CounterOpts{
 			Name: "pixa_transforms_total",
 			Help: "Images the image processor transformed.",
 		}),
+		transformDurations: prometheus.NewHistogram(prometheus.HistogramOpts{
+			Name: "pixa_transform_duration_seconds",
+			Help: "Duration of the transforms pixa_transforms_total counts, " +
+				"waiting for a processing slot included.",
+		}),
+		transformsInProgress: prometheus.NewGauge(prometheus.GaugeOpts{
+			Name: "pixa_transforms_in_progress",
+			Help: "Images being transformed or waiting for a processing slot.",
+		}),
 	}
 
-	for _, counter := range []prometheus.Counter{
+	for _, metric := range []prometheus.Collector{
-		p.upstreamFetches, p.upstreamFetchBytes, p.transforms,
+		p.upstreamFetches, p.upstreamFetchBytes, p.upstreamFetchDurations,
+		p.upstreamFetchErrors, p.transforms, p.transformDurations,
+		p.transformsInProgress,
 	} {
-		err = metricsRegistry.Register(counter)
+		err = metricsRegistry.Register(metric)
 		if err != nil {
-			return nil, fmt.Errorf("failed to register the proxy's counters: %w", err)
+			return nil, fmt.Errorf("failed to register the proxy's metrics: %w", err)
 		}
 	}
 
@@ -157,7 +183,9 @@ const (
 //
 // A cache hit opens the variant file and makes no database call: the cache
 // hands its access time to the goroutine that writes access times, without
-// waiting for it, and its hit is counted in memory. A variant file that
+// waiting for it, and its hit is counted in memory. A variant whose source
+// was last checked with upstream CacheTTL or more ago is a miss, which checks
+// the source first (see processFromSourceOrFetch). A variant file that
 // cannot be served, such as one whose first bytes are not those of an output
 // format, is a miss, and the variant is made again.
 func (p *Proxy) Get(
@@ -165,20 +193,20 @@ func (p *Proxy) Get(
 ) (*ImageResponse, error) {
 	cacheKey := imagerequest.CacheKey(req)
 
-	reader, size, contentType, err := p.cache.Variant(cacheKey)
+	cached, err := p.cache.Variant(cacheKey)
 	if err == nil {
 		p.cache.IncrementStats(true)
 
 		return &ImageResponse{
-			Content:       reader,
+			Content:       cached.Content,
-			ContentLength: size,
+			ContentLength: cached.Size,
-			ContentType:   contentType,
+			ContentType:   cached.ContentType,
 			CacheStatus:   CacheHit,
-			ETag:          formatETag(cacheKey),
+			ETag:          formatETag(cacheKey, cached.CheckedAt),
 		}, nil
 	}
 
-	if !errors.Is(err, imgcache.ErrNotFound) {
+	if !errors.Is(err, imgcache.ErrNotFound) && !errors.Is(err, imgcache.ErrStale) {
 		p.log.Warn("cached variant not served, making it again",
 			"cache_key", cacheKey, "error", err)
 	}
@@ -285,7 +313,7 @@ func (p *Proxy) processOrWait(
 		ContentLength: int64(len(variant.data)),
 		ContentType:   variant.contentType,
 		FetchedBytes:  variant.fetchedBytes,
-		ETag:          formatETag(cacheKey),
+		ETag:          formatETag(cacheKey, variant.checkedAt),
 	}, nil
 }
 
@@ -337,14 +365,61 @@ func (p *Proxy) loadCachedSource(
 	return reader, size, format
 }
 
-// processFromSourceOrFetch processes an image, using cached source content
+// processFromSourceOrFetch makes the variant req asks for, from the cached
-// if available.
+// source when there is one and from a fetched source otherwise. It counts a
+// source cache miss when it fetches the source because the source has no row
+// in the cache or its cached file cannot be used, and a source cache hit
+// otherwise.
+//
+// A cached source last checked with upstream CacheTTL or more ago is checked
+// first: upstream is asked to send it only if it changed since. When it
+// changed, the new bytes replace the cached source and the variant is made
+// from them. When it did not change, or the check fails, the cached source
+// is used: the variant's cached file is served again if it was made from the
+// cached source's bytes, and otherwise the variant is made from them. When
+// the source is not cached but the variant is, the variant is checked with
+// upstream the same way (see fetchAndProcess).
 func (p *Proxy) processFromSourceOrFetch(
 	ctx context.Context,
 	req *imagerequest.Request,
 	cacheKey imagerequest.VariantKey,
 ) (*processedVariant, error) {
+	cached, err := p.cache.LookupSource(ctx, req.Source)
+	if err != nil {
+		if !errors.Is(err, imgcache.ErrNotFound) {
+			p.log.Warn("failed to look up cached source, fetching", "error", err)
+		}
+
+		p.cache.IncrementSourceStats(false)
+
+		return p.fetchAndProcess(ctx, req, cacheKey)
+	}
+
+	if p.cache.Stale(cached.CheckedAt) {
+		fetched, err := p.fetchSource(ctx, req, cached.ETag, cached.LastModified)
+
+		switch {
+		case errors.Is(err, errSourceNotModified):
+			cached.CheckedAt = time.Now().UTC()
+			p.renewSource(ctx, req.Source, cached.CheckedAt)
+		case err != nil:
+			p.recordFailedCheck(ctx, req, err)
+		default:
+			p.cache.IncrementSourceStats(true)
+
+			return p.processFetched(ctx, req, cacheKey, fetched)
+		}
+	}
+
+	variant := p.renewVariant(ctx, cacheKey, cached)
+	if variant != nil {
+		p.cache.IncrementSourceStats(true)
+
+		return variant, nil
+	}
+
 	source, sourceSize, sourceFormat := p.loadCachedSource(ctx, req.Source)
+	p.cache.IncrementSourceStats(source != nil)
 
 	// Fetch from upstream if we don't have source data or it's empty
 	if source == nil {
@@ -356,39 +431,217 @@ func (p *Proxy) processFromSourceOrFetch(
 	// Process using cached source; nothing was fetched from upstream. The
 	// image processor reads the source only once it has a processing slot,
 	// so a request waiting for one holds none of it in memory.
-	return p.processAndStore(ctx, req, cacheKey, source, sourceFormat, sourceSize)
+	return p.processAndStore(ctx, req, cacheKey, cached, source, sourceFormat,
+		sourceSize)
 }
 
-// fetchAndProcess fetches from upstream, processes, and caches the result.
+// recordFailedCheck logs a failed check of req's source with upstream, after
-// It counts the fetch with the bytes read from upstream, including when
+// which the image is still served from the cache. It puts the source URL in
-// reading the response or a later step fails. It fetches nothing while the
+// the negative cache, whatever the failure, a timeout included, so upstream
-// source URL is in the negative cache.
+// is asked at most once per NegativeTTL while it fails, however often the
+// image is served. A failure that was a negative cache hit records nothing.
+func (p *Proxy) recordFailedCheck(
+	ctx context.Context, req *imagerequest.Request, err error,
+) {
+	if errors.Is(err, ErrNegativeCached) {
+		return
+	}
+
+	p.log.Warn("checking source with upstream failed, serving from the cache",
+		"request_id", middleware.GetReqID(ctx),
+		"host", req.Source.Host, "path", req.Source.Path, "error", err)
+	p.storeNegative(ctx, req)
+}
+
+// renewSource records that upstream answered at checkedAt that src's cached
+// source had not changed. A failure to record it is only logged: the source
+// is then checked again on its next use.
+func (p *Proxy) renewSource(
+	ctx context.Context, src imagerequest.Source, checkedAt time.Time,
+) {
+	err := p.cache.RenewSource(ctx, src, checkedAt)
+	if err != nil {
+		p.log.Warn("failed to renew cached source", "source_key", src.Key(),
+			"error", err)
+	}
+}
+
+// renewVariant returns the cached variant of cacheKey when it was made from
+// the bytes of the cached source that source describes, and renews it to
+// source.CheckedAt (see imgcache.Cache.RenewVariant). It returns nil when
+// there is no such variant or it cannot be read.
+func (p *Proxy) renewVariant(
+	ctx context.Context, cacheKey imagerequest.VariantKey,
+	source imgcache.SourceInfo,
+) *processedVariant {
+	cached, err := p.cache.RenewVariant(ctx, cacheKey, source)
+	if err != nil {
+		if !errors.Is(err, imgcache.ErrNotFound) {
+			p.log.Warn("cached variant not renewed, making it again",
+				"cache_key", cacheKey, "error", err)
+		}
+
+		return nil
+	}
+
+	return p.readCachedVariant(cacheKey, cached)
+}
+
+// cachedVariantIgnoringTTL returns the cached variant of cacheKey whatever
+// its age, with what its row keeps about the source bytes it was made from
+// (see imgcache.Cache.LookupVariant). It returns nil when the variant is not
+// cached or cannot be read. The SourceInfo is empty when the variant is not
+// returned, or its row is missing or cannot be read.
+func (p *Proxy) cachedVariantIgnoringTTL(
+	ctx context.Context, cacheKey imagerequest.VariantKey,
+) (*processedVariant, imgcache.SourceInfo) {
+	cached, err := p.cache.VariantIgnoringTTL(cacheKey)
+	if err != nil {
+		if !errors.Is(err, imgcache.ErrNotFound) {
+			p.log.Warn("cached variant not served", "cache_key", cacheKey,
+				"error", err)
+		}
+
+		return nil, imgcache.SourceInfo{}
+	}
+
+	variant := p.readCachedVariant(cacheKey, cached)
+	if variant == nil {
+		return nil, imgcache.SourceInfo{}
+	}
+
+	madeFrom, err := p.cache.LookupVariant(ctx, cacheKey)
+	if err != nil && !errors.Is(err, imgcache.ErrNotFound) {
+		p.log.Warn("failed to look up cached variant", "cache_key", cacheKey,
+			"error", err)
+	}
+
+	return variant, madeFrom
+}
+
+// readCachedVariant reads the cached variant of cacheKey from its opened file,
+// and closes the file. It returns nil when the variant cannot be read.
+func (p *Proxy) readCachedVariant(
+	cacheKey imagerequest.VariantKey, file imgcache.VariantFile,
+) *processedVariant {
+	defer func() { _ = file.Content.Close() }()
+
+	data, err := io.ReadAll(file.Content)
+	if err != nil {
+		p.log.Warn("failed to read cached variant", "cache_key", cacheKey,
+			"error", err)
+
+		return nil
+	}
+
+	return &processedVariant{
+		data:        data,
+		contentType: file.ContentType,
+		checkedAt:   file.CheckedAt,
+	}
+}
+
+// fetchAndProcess fetches the source from upstream, stores it, and makes
+// and stores the variant from it.
+//
+// The variant can still be cached after eviction removed its source. The
+// fetch then sends the ETag and Last-Modified of the source bytes the variant
+// was made from, so upstream sends the source only if it changed since. When
+// it did not change, the cached variant is renewed and served, with no
+// download and no conversion. When the fetch fails, the cached variant is
+// served whatever its age, and the failure is recorded as a failed check (see
+// recordFailedCheck).
 func (p *Proxy) fetchAndProcess(
 	ctx context.Context,
 	req *imagerequest.Request,
 	cacheKey imagerequest.VariantKey,
 ) (*processedVariant, error) {
-	// Check negative cache - skip fetching for recently-failed URLs
+	variant, madeFrom := p.cachedVariantIgnoringTTL(ctx, cacheKey)
-	negHit, err := p.cache.Failure(ctx, req.Source)
+
+	fetched, err := p.fetchSource(ctx, req, madeFrom.ETag, madeFrom.LastModified)
+
+	switch {
+	case err == nil:
+		return p.processFetched(ctx, req, cacheKey, fetched)
+	case variant == nil:
+		return nil, err
+	case errors.Is(err, errSourceNotModified):
+		variant.checkedAt = time.Now().UTC()
+
+		err = p.cache.SetVariantCheckedAt(ctx, cacheKey, variant.checkedAt)
 		if err != nil {
-		p.log.Warn("negative cache check failed", "error", err)
+			p.log.Warn("failed to renew cached variant", "cache_key", cacheKey,
+				"error", err)
+		}
+	default:
+		p.recordFailedCheck(ctx, req, err)
 	}
 
-	if negHit {
+	return variant, nil
-		p.log.Debug("negative cache hit",
+}
-			"host", req.Source.Host,
-			"path", req.Source.Path,
-		)
 
-		return nil, fmt.Errorf("%w: %w", httpfetcher.ErrUpstreamError, ErrNegativeCached)
+// processFetched makes and stores the variant from the source fetchSource
+// fetched, then closes the fetch's response.
+func (p *Proxy) processFetched(
+	ctx context.Context,
+	req *imagerequest.Request,
+	cacheKey imagerequest.VariantKey,
+	fetched *fetchedSource,
+) (*processedVariant, error) {
+	// Closing the response frees the upstream connection. It is closed only
+	// after processing, so the fetcher's connection limit also bounds the
+	// fetched sources held in memory while their requests wait for a
+	// processing slot.
+	defer func() { _ = fetched.response.Close() }()
+
+	return p.processAndStore(ctx, req, cacheKey, fetched.info,
+		bytes.NewReader(fetched.data), fetched.format, int64(len(fetched.data)))
+}
+
+// errSourceNotModified is returned by fetchSource when upstream answers 304
+// Not Modified: the cached source has not changed.
+var errSourceNotModified = errors.New("upstream source not modified")
+
+// fetchedSource is a source fetchSource fetched and stored in the cache.
+type fetchedSource struct {
+	data   []byte
+	format imagerequest.Format
+	// info is what the cache keeps about the source
+	info imgcache.SourceInfo
+	// response is the fetch's response, still open; closing it frees the
+	// upstream connection
+	response io.Closer
+}
+
+// fetchSource fetches req's source from upstream and stores it in the cache.
+// A non-empty ifNoneMatch or ifModifiedSince asks upstream to send the source
+// only if it changed since; errSourceNotModified says it did not. It counts
+// the fetch with the bytes read from upstream and its duration, including
+// when reading the response or a later step fails, and counts a fetch that
+// fails or whose response cannot be read as an upstream fetch error. It
+// fetches nothing while the source URL is in the negative cache. The caller
+// closes the returned response.
+func (p *Proxy) fetchSource(
+	ctx context.Context,
+	req *imagerequest.Request,
+	ifNoneMatch, ifModifiedSince string,
+) (*fetchedSource, error) {
+	err := p.refuseNegativeCached(ctx, req)
+	if err != nil {
+		return nil, err
 	}
 
 	// Fetch from upstream
 	p.log.Debug("fetching from upstream", "host", req.Source.Host,
 		"path", req.Source.Path, "query", req.Source.Query)
 
-	fetchResult, err := p.fetcher.Fetch(ctx, req.Source)
+	fetchStart := time.Now()
+
+	fetchResult, err := p.fetcher.Fetch(ctx, req.Source,
+		ifNoneMatch, ifModifiedSince)
 	if err != nil {
+		p.upstreamFetchErrors.Inc()
+
 		// Store negative cache for certain errors
 		if isNegativeCacheable(err) {
 			p.storeNegative(ctx, req)
@@ -397,45 +650,32 @@ func (p *Proxy) fetchAndProcess(
 		return nil, fmt.Errorf("upstream fetch failed: %w", err)
 	}
 
-	// Closing the body frees the upstream connection. It is closed only
+	if fetchResult.StatusCode == http.StatusNotModified {
-	// after processing, so the fetcher's connection limit also bounds the
+		_ = fetchResult.Content.Close()
-	// fetched sources held in memory while their requests wait for a
+
-	// processing slot.
+		p.log.Info("upstream source not modified",
-	defer func() { _ = fetchResult.Content.Close() }()
+			"request_id", middleware.GetReqID(ctx), "host", req.Source.Host,
+			"path", req.Source.Path, "fetch_ms", fetchResult.FetchDurationMs)
+
+		return nil, errSourceNotModified
+	}
 
 	// Read and validate the source content
 	sourceData, err := io.ReadAll(fetchResult.Content)
 	fetchBytes := int64(len(sourceData))
 
 	// Counted also when the request context has ended meanwhile
-	p.incrementUpstreamFetch(fetchBytes)
+	p.incrementUpstreamFetch(fetchBytes, time.Since(fetchStart))
 
 	if err != nil {
+		p.upstreamFetchErrors.Inc()
+
+		_ = fetchResult.Content.Close()
+
 		return nil, fmt.Errorf("failed to read upstream response: %w", err)
 	}
 
-	// Calculate download bitrate
+	p.logUpstreamFetch(ctx, req, fetchResult, fetchBytes)
-	var downloadRate string
-
-	if fetchResult.FetchDurationMs > 0 {
-		seconds := float64(fetchResult.FetchDurationMs) / 1000.0 //nolint:mnd // ms to seconds
-		bitsPerSecond := float64(fetchBytes*8) / seconds         //nolint:mnd // bytes to bits
-		downloadRate = humanize.SI(bitsPerSecond, "bps")
-	}
-
-	// Log upstream fetch details
-	p.log.Info("upstream fetched",
-		"request_id", middleware.GetReqID(ctx),
-		"host", req.Source.Host,
-		"path", req.Source.Path,
-		"bytes", fetchBytes,
-		"fetch_ms", fetchResult.FetchDurationMs,
-		"rate", downloadRate,
-		"remote_addr", fetchResult.RemoteAddr,
-		"http", fetchResult.HTTPVersion,
-		"tls", fetchResult.TLSVersion,
-		"cipher", fetchResult.TLSCipherSuite,
-	)
 
 	// The source's format, detected from its first bytes, which must match
 	// its content type. A body that does not is the upstream's error, so it
@@ -448,30 +688,106 @@ func (p *Proxy) fetchAndProcess(
 			"content_type", fetchResult.ContentType, "error", err)
 		p.storeNegative(ctx, req)
 
+		_ = fetchResult.Content.Close()
+
 		return nil, fmt.Errorf("content validation failed: %w", err)
 	}
 
+	info := fetchedSourceInfo(fetchResult)
+
 	// Store source content
-	_, err = p.cache.PutSource(ctx, req.Source, bytes.NewReader(sourceData))
+	_, err = p.cache.PutSource(ctx, req.Source, bytes.NewReader(sourceData), info)
 	if err != nil {
 		p.log.Warn("failed to store source content", "error", err)
 		// Continue even if caching fails
 	}
 
-	return p.processAndStore(
+	return &fetchedSource{
-		ctx, req, cacheKey, bytes.NewReader(sourceData), sourceFormat, fetchBytes,
+		data:     sourceData,
+		format:   sourceFormat,
+		info:     info,
+		response: fetchResult.Content,
+	}, nil
+}
+
+// refuseNegativeCached returns an error wrapping ErrNegativeCached while
+// req's source URL is in the negative cache, and nil otherwise. A failure to
+// read the negative cache is only logged, and returns nil.
+func (p *Proxy) refuseNegativeCached(
+	ctx context.Context, req *imagerequest.Request,
+) error {
+	negHit, err := p.cache.Failure(ctx, req.Source)
+	if err != nil {
+		p.log.Warn("negative cache check failed", "error", err)
+	}
+
+	if !negHit {
+		return nil
+	}
+
+	p.log.Debug("negative cache hit",
+		"host", req.Source.Host,
+		"path", req.Source.Path,
+	)
+
+	return fmt.Errorf("%w: %w", httpfetcher.ErrUpstreamError, ErrNegativeCached)
+}
+
+// fetchedSourceInfo returns what the cache keeps about a source upstream
+// just sent: fetched and checked now, with the ETag and Last-Modified
+// headers of fetchResult.
+func fetchedSourceInfo(fetchResult *httpfetcher.FetchResult) imgcache.SourceInfo {
+	now := time.Now().UTC()
+	upstreamHeaders := http.Header(fetchResult.Headers)
+
+	return imgcache.SourceInfo{
+		FetchedAt:    now,
+		CheckedAt:    now,
+		ETag:         upstreamHeaders.Get("ETag"),
+		LastModified: upstreamHeaders.Get("Last-Modified"),
+	}
+}
+
+// logUpstreamFetch logs a fetch of req's source that read fetchBytes bytes,
+// with its download rate and connection details.
+func (p *Proxy) logUpstreamFetch(
+	ctx context.Context,
+	req *imagerequest.Request,
+	fetchResult *httpfetcher.FetchResult,
+	fetchBytes int64,
+) {
+	var downloadRate string
+
+	if fetchResult.FetchDurationMs > 0 {
+		seconds := float64(fetchResult.FetchDurationMs) / 1000.0 //nolint:mnd // ms to seconds
+		bitsPerSecond := float64(fetchBytes*8) / seconds         //nolint:mnd // bytes to bits
+		downloadRate = humanize.SI(bitsPerSecond, "bps")
+	}
+
+	p.log.Info("upstream fetched",
+		"request_id", middleware.GetReqID(ctx),
+		"host", req.Source.Host,
+		"path", req.Source.Path,
+		"bytes", fetchBytes,
+		"fetch_ms", fetchResult.FetchDurationMs,
+		"rate", downloadRate,
+		"remote_addr", fetchResult.RemoteAddr,
+		"http", fetchResult.HTTPVersion,
+		"tls", fetchResult.TLSVersion,
+		"cipher", fetchResult.TLSCipherSuite,
 	)
 }
 
-// incrementUpstreamFetch counts one upstream fetch that read fetchBytes bytes.
+// incrementUpstreamFetch counts one upstream fetch that read fetchBytes bytes
-// A fetch that read no bytes is not counted.
+// and took duration. A fetch that read no bytes is not counted.
-func (p *Proxy) incrementUpstreamFetch(fetchBytes int64) {
+func (p *Proxy) incrementUpstreamFetch(fetchBytes int64, duration time.Duration) {
 	if fetchBytes <= 0 {
 		return
 	}
 
 	p.upstreamFetches.Inc()
 	p.upstreamFetchBytes.Add(float64(fetchBytes))
+	p.upstreamFetchDurations.Observe(duration.Seconds())
 }
 
 // storeNegative stores a negative cache entry for req's source, whose fetch
@@ -491,14 +807,19 @@ type processedVariant struct {
 	data         []byte
 	contentType  string
 	fetchedBytes int64
+	// checkedAt is its source's check time when the variant was made or last
+	// renewed, which its cached file has as its modification time
+	checkedAt time.Time
 }
 
 // processAndStore processes the image read from source, which is in
-// sourceFormat, and stores the result.
+// sourceFormat, and stores the result. sourceInfo describes the source's
+// bytes, and is stored with the variant (see imgcache.Cache.PutVariant).
 func (p *Proxy) processAndStore(
 	ctx context.Context,
 	req *imagerequest.Request,
 	cacheKey imagerequest.VariantKey,
+	sourceInfo imgcache.SourceInfo,
 	source io.Reader,
 	sourceFormat imagerequest.Format,
 	fetchBytes int64,
@@ -508,8 +829,7 @@ func (p *Proxy) processAndStore(
 
 	// ctx has the deadline of the request doing the processing, which can
 	// end while a request waiting for its image has time left
-	processResult, err := p.processor.Process(ctx, source, sourceFormat,
+	processResult, err := p.transform(ctx, source, sourceFormat, &req.Transform)
-		&req.Transform)
 	if errors.Is(err, context.DeadlineExceeded) {
 		return nil, fmt.Errorf("%w: %w", ErrProcessingTimedOut, err)
 	}
@@ -522,6 +842,7 @@ func (p *Proxy) processAndStore(
 
 	// Counted also when the request context has ended meanwhile
 	p.transforms.Inc()
+	p.transformDurations.Observe(processDuration.Seconds())
 
 	// Read processed content
 	processedData, err := io.ReadAll(processResult.Content)
@@ -559,7 +880,8 @@ func (p *Proxy) processAndStore(
 	)
 
 	// Store variant to cache
-	err = p.cache.PutVariant(ctx, cacheKey, bytes.NewReader(processedData))
+	err = p.cache.PutVariant(ctx, cacheKey, sourceInfo,
+		bytes.NewReader(processedData))
 	if err != nil {
 		p.log.Warn("failed to store variant", "error", err)
 		// Continue even if caching fails
@@ -569,9 +891,25 @@ func (p *Proxy) processAndStore(
 		data:         processedData,
 		contentType:  processResult.ContentType,
 		fetchedBytes: fetchBytes,
+		checkedAt:    sourceInfo.CheckedAt,
 	}, nil
 }
 
+// transform has the image processor transform the image read from source
+// as requested says, and counts it in pixa_transforms_in_progress until the
+// processor returns or panics.
+func (p *Proxy) transform(
+	ctx context.Context,
+	source io.Reader,
+	sourceFormat imagerequest.Format,
+	requested *imagerequest.Transform,
+) (*imageprocessor.Result, error) {
+	p.transformsInProgress.Inc()
+	defer p.transformsInProgress.Dec()
+
+	return p.processor.Process(ctx, source, sourceFormat, requested)
+}
+
 // isNegativeCacheable returns true if the error should be cached.
 func isNegativeCacheable(err error) bool {
 	return errors.Is(err, httpfetcher.ErrUpstreamError)
@@ -580,13 +918,16 @@ func isNegativeCacheable(err error) bool {
 // etagHashLength is the number of hash characters to use for ETags.
 const etagHashLength = 16
 
-// formatETag formats a VariantKey as a quoted ETag value.
+// formatETag returns the quoted ETag of the variant of key: the first
-func formatETag(key imagerequest.VariantKey) string {
+// etagHashLength characters of key, then checkedAt in Unix nanoseconds.
+// checkedAt is its source's check time when the variant was made or last
+// renewed, so a variant made again from new source bytes gets another ETag.
+func formatETag(key imagerequest.VariantKey, checkedAt time.Time) string {
 	hash := string(key)
 	// Use first 16 characters of hash for a shorter but still unique ETag
 	if len(hash) > etagHashLength {
 		hash = hash[:etagHashLength]
 	}
 
-	return `"` + hash + `"`
+	return fmt.Sprintf(`"%s-%d"`, hash, checkedAt.UnixNano())
 }

internal/imageproxy/imageproxy_internal_test.go

@@ -3,9 +3,7 @@ package imageproxy
 import (
 	"context"
 	"io"
-	"os"
 	"testing"
-	"time"
 
 	"sneak.berlin/go/pixa/internal/imagerequest"
 	"sneak.berlin/go/pixa/internal/magic"
@@ -263,97 +261,6 @@ func TestProxy_Get_Caching(t *testing.T) {
 	}
 }
 
-// TestProxy_Get_ServesSourceAndVariantCachedTwoDaysAgo caches a source and
-// a variant of it and sets back two days every time pixa stored for them.
-// For the source: last_accessed_at in source_content, and the access and
-// modification times of its file. For the variant: last_accessed_at in
-// variant_content, and the access and modification times of its file. It
-// then checks that the variant is still served from the cache and that a new
-// variant is made from the cached source without fetching it again.
-//
-// Left at the present: the files' status change and birth times, which a
-// program cannot set, and the times of the directories holding the files,
-// which other entries share.
-func TestProxy_Get_ServesSourceAndVariantCachedTwoDaysAgo(t *testing.T) {
-	t.Parallel()
-
-	svc, fixtures := setupTestProxy(t)
-	variant := photoVariant(fixtures, 85, imagerequest.FitCover)
-
-	resp, err := svc.Get(t.Context(), variant)
-	if err != nil {
-		t.Fatalf("Get() first request error = %v", err)
-	}
-
-	_ = resp.Content.Close()
-
-	twoDaysAgo := time.Now().AddDate(0, 0, -2)
-	backdateSource(t, svc, variant, twoDaysAgo)
-	backdateVariant(t, svc, variant, twoDaysAgo)
-
-	resp, err = svc.Get(t.Context(), variant)
-	if err != nil {
-		t.Fatalf("Get() of the cached variant error = %v", err)
-	}
-
-	_ = resp.Content.Close()
-
-	if resp.CacheStatus != CacheHit {
-		t.Errorf("cached variant CacheStatus = %q, want %q",
-			resp.CacheStatus, CacheHit)
-	}
-
-	// Another quality is a new variant, made from the cached source
-	resp, err = svc.Get(t.Context(), photoVariant(fixtures, 40, imagerequest.FitCover))
-	if err != nil {
-		t.Fatalf("Get() of a new variant error = %v", err)
-	}
-
-	_ = resp.Content.Close()
-
-	fetches := readCounters(t, svc).upstreamFetchCount
-	if fetches != 1 {
-		t.Errorf("upstream fetches = %d, want 1", fetches)
-	}
-}
-
-// backdateSource sets every time pixa stored for req's cached source to when,
-// as listed on TestProxy_Get_ServesSourceAndVariantCachedTwoDaysAgo.
-func backdateSource(
-	t *testing.T, svc *testProxy, req *imagerequest.Request, when time.Time,
-) {
-	t.Helper()
-
-	key := req.Source.Key()
-	setSourceLastAccessed(t, svc.db, key, when)
-
-	path := sourceFilePath(svc, key)
-
-	err := os.Chtimes(path, when, when)
-	if err != nil {
-		t.Fatalf("setting back the times of %s: %v", path, err)
-	}
-}
-
-// backdateVariant sets every time pixa stored for the cached variant req asks
-// for to when, as listed on
-// TestProxy_Get_ServesSourceAndVariantCachedTwoDaysAgo.
-func backdateVariant(
-	t *testing.T, svc *testProxy, req *imagerequest.Request, when time.Time,
-) {
-	t.Helper()
-
-	key := imagerequest.CacheKey(req)
-	path := variantFilePath(svc, key)
-
-	setVariantLastAccessed(t, svc.db, key, when)
-
-	err := os.Chtimes(path, when, when)
-	if err != nil {
-		t.Fatalf("setting back the times of %s: %v", path, err)
-	}
-}
-
 func TestProxy_Get_DifferentSizes(t *testing.T) {
 	t.Parallel()
 

internal/imageproxy/metrics_internal_test.go

@@ -0,0 +1,213 @@
+package imageproxy
+
+import (
+	"os"
+	"testing"
+	"time"
+
+	"sneak.berlin/go/pixa/internal/imageprocessor"
+	"sneak.berlin/go/pixa/internal/imagerequest"
+)
+
+// metricValues holds the source cache, upstream fetch and transform metrics
+// of a proxy and its cache. A histogram is given by its count of
+// observations.
+type metricValues struct {
+	sourceCacheHits   uint64
+	sourceCacheMisses uint64
+	fetchDurations    uint64
+	fetchErrors       uint64
+	transformDuration uint64
+	inProgress        float64
+}
+
+// readMetricValues reads the metrics of svc and its cache that
+// metricValues holds from their metrics registry.
+func readMetricValues(t *testing.T, svc *testProxy) metricValues {
+	t.Helper()
+
+	families, err := svc.registry.Gather()
+	if err != nil {
+		t.Fatalf("failed to gather the metrics: %v", err)
+	}
+
+	var values metricValues
+
+	for _, family := range families {
+		metric := family.GetMetric()[0]
+
+		switch family.GetName() {
+		case "pixa_source_cache_hits_total":
+			values.sourceCacheHits = uint64(metric.GetCounter().GetValue())
+		case "pixa_source_cache_misses_total":
+			values.sourceCacheMisses = uint64(metric.GetCounter().GetValue())
+		case "pixa_upstream_fetch_duration_seconds":
+			values.fetchDurations = metric.GetHistogram().GetSampleCount()
+		case "pixa_upstream_fetch_errors_total":
+			values.fetchErrors = uint64(metric.GetCounter().GetValue())
+		case "pixa_transform_duration_seconds":
+			values.transformDuration = metric.GetHistogram().GetSampleCount()
+		case "pixa_transforms_in_progress":
+			values.inProgress = metric.GetGauge().GetValue()
+		}
+	}
+
+	return values
+}
+
+// TestProxy_Get_CountsSourceCacheFetchesAndTransforms walks Get through a
+// miss that fetches the source, a hit, a miss that uses the cached source
+// and a miss whose source is not found upstream, checking the source cache,
+// upstream fetch and transform metrics after each.
+func TestProxy_Get_CountsSourceCacheFetchesAndTransforms(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures := setupTestProxy(t)
+
+	// want is source cache hits, source cache misses, fetch durations
+	// observed, fetch errors, transform durations observed, transforms in
+	// progress.
+	steps := []struct {
+		name    string
+		path    string
+		size    int
+		wantErr bool
+		want    metricValues
+	}{
+		{"miss that fetches the source", testPathPhoto, 50, false,
+			metricValues{0, 1, 1, 0, 1, 0}},
+		{"hit", testPathPhoto, 50, false,
+			metricValues{0, 1, 1, 0, 1, 0}},
+		{"miss that uses the cached source", testPathPhoto, 25, false,
+			metricValues{1, 1, 1, 0, 2, 0}},
+		{"miss whose source is not found", "/images/absent.jpg", 50, true,
+			metricValues{1, 2, 1, 1, 2, 0}},
+	}
+
+	for _, step := range steps {
+		resp, err := svc.Get(t.Context(), &imagerequest.Request{
+			Source: imagerequest.Source{
+				Host: fixtures.GoodHost,
+				Path: step.path,
+			},
+			Transform: imagerequest.Transform{
+				Size:    imagerequest.Size{Width: step.size, Height: step.size},
+				Format:  imagerequest.FormatJPEG,
+				Quality: 85,
+				FitMode: imagerequest.FitCover,
+			},
+		})
+		if (err != nil) != step.wantErr {
+			t.Fatalf("%s: Get() error = %v, want error %t", step.name, err, step.wantErr)
+		}
+
+		if err == nil {
+			_ = resp.Content.Close()
+		}
+
+		got := readMetricValues(t, svc)
+		t.Logf("after the %s: metrics = %+v", step.name, got)
+
+		if got != step.want {
+			t.Fatalf("after the %s: metrics = %+v, want %+v", step.name, got, step.want)
+		}
+	}
+}
+
+// TestProxy_Get_CountsMissingSourceFileAsSourceCacheMiss deletes the file of
+// a cached source but keeps its row. A request for a second variant of that
+// source must fetch the source again, and count a source cache miss, not a
+// hit.
+func TestProxy_Get_CountsMissingSourceFileAsSourceCacheMiss(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures := setupTestProxy(t)
+
+	// A first request caches the photo as a source.
+	resp, err := svc.Get(t.Context(), widthOnlyRequest(fixtures, 50))
+	if err != nil {
+		t.Fatalf("first Get() error = %v", err)
+	}
+
+	_ = resp.Content.Close()
+
+	source := widthOnlyRequest(fixtures, 50).Source
+
+	err = os.Remove(sourceFilePath(svc, source.Key()))
+	if err != nil {
+		t.Fatalf("failed to delete the cached source file: %v", err)
+	}
+
+	before := readMetricValues(t, svc)
+
+	resp, err = svc.Get(t.Context(), widthOnlyRequest(fixtures, 25))
+	if err != nil {
+		t.Fatalf("Get() of a second variant error = %v", err)
+	}
+
+	_ = resp.Content.Close()
+
+	after := readMetricValues(t, svc)
+	t.Logf("before the second variant: metrics = %+v; after: %+v", before, after)
+
+	if after.sourceCacheHits != before.sourceCacheHits ||
+		after.sourceCacheMisses != before.sourceCacheMisses+1 {
+		t.Errorf("source cache hits went from %d to %d and misses from %d to %d, "+
+			"want no new hit and one more miss", before.sourceCacheHits,
+			after.sourceCacheHits, before.sourceCacheMisses, after.sourceCacheMisses)
+	}
+}
+
+// TestProxy_Get_CountsTransformWaitingForSlotAsInProgress holds the only
+// processing slot and starts a request that must transform the photo. While
+// the request waits for the slot, pixa_transforms_in_progress must be 1; once
+// the request returns, 0.
+func TestProxy_Get_CountsTransformWaitingForSlotAsInProgress(t *testing.T) {
+	t.Parallel()
+
+	svc, fixtures := setupTestProxy(t)
+	svc.processor = imageprocessor.New(
+		imageprocessor.Params{MaxInputBytes: 50 << 20, MaxConcurrentProcessing: 1},
+	)
+
+	release := holdProcessingSlot(t, svc.processor)
+
+	result := startGet(t.Context(), svc, widthOnlyRequest(fixtures, 50))
+
+	// The request fetches the photo first, then waits for the slot.
+	deadline := time.Now().Add(5 * time.Second)
+	for readMetricValues(t, svc).inProgress != 1 && time.Now().Before(deadline) {
+		time.Sleep(10 * time.Millisecond)
+	}
+
+	waiting := readMetricValues(t, svc).inProgress
+	t.Logf("while the request waits for the slot: transforms in progress = %v",
+		waiting)
+
+	select {
+	case got := <-result:
+		t.Fatalf("Get() returned while the only processing slot was held, "+
+			"error = %v", got.err)
+	default:
+	}
+
+	if waiting != 1 {
+		t.Fatalf("transforms in progress = %v while the request waits for the "+
+			"slot, want 1", waiting)
+	}
+
+	release()
+
+	got := <-result
+	if got.err != nil {
+		t.Fatalf("Get() error = %v", got.err)
+	}
+
+	returned := readMetricValues(t, svc).inProgress
+	t.Logf("once the request returned: transforms in progress = %v", returned)
+
+	if returned != 0 {
+		t.Errorf("transforms in progress = %v once the request returned, want 0",
+			returned)
+	}
+}

internal/imageproxy/negative_cache_internal_test.go

@@ -82,15 +82,3 @@ func TestProxy_Get_ServesCachedVariantOfNegativeCachedURL(t *testing.T) {
 			err, ErrNegativeCached)
 	}
 }
-
-func TestProxy_Get_ReturnsErrorForNegativeCachedURL(t *testing.T) {
-	t.Parallel()
-
-	// This test verifies that Proxy.Get() checks the negative cache
-	// We can't easily test the full pipeline without vips, but we can
-	// verify the error type
-	err := ErrNegativeCached
-	if !errors.Is(err, ErrNegativeCached) {
-		t.Error("ErrNegativeCached should be identifiable with errors.Is")
-	}
-}

internal/imageproxy/stats_internal_test.go

@@ -94,7 +94,7 @@ type fakeUpstream struct {
 }
 
 func (u *fakeUpstream) Fetch(
-	context.Context, imagerequest.Source,
+	context.Context, imagerequest.Source, string, string,
 ) (*httpfetcher.FetchResult, error) {
 	return &httpfetcher.FetchResult{
 		Content:       io.NopCloser(u),

internal/imgcache/cache.go

@@ -3,8 +3,12 @@
 //   - the variants made from them
 //   - the negative cache: the source URLs whose fetch failed recently
 //
-// Each image is a file with a row in the database. Eviction removes the
+// Each image is a file with a row in the database. A source is used, and its
-// least recently used images to keep the cache under its size limit.
+// variants are served, until the cache TTL has passed since upstream last sent
+// the source or confirmed it unchanged. Then the source is due to be checked
+// with upstream again (see Stale). Eviction removes:
+//   - the least recently used images, to keep the cache under its size limit
+//   - the images not checked with upstream for EvictionAfterLastCheck
 package imgcache
 
 import (
@@ -13,7 +17,9 @@ import (
 	"errors"
 	"fmt"
 	"io"
+	"io/fs"
 	"log/slog"
+	"os"
 	"path/filepath"
 	"time"
 
@@ -38,11 +44,31 @@ const cleanExpiredBatchSize = 1000
 // cache.
 const DefaultNegativeTTL = 5 * time.Minute
 
+// DefaultCacheTTL is how long after upstream last sent a cached source, or
+// answered that it had not changed, pixad uses the source and serves its
+// variants without asking upstream again.
+const DefaultCacheTTL = 24 * time.Hour
+
+// EvictionAfterLastCheck is how long after upstream last sent a cached
+// source, or answered that it had not changed, the source and its variants
+// are evicted (see EvictNotCheckedRecently). Until then a source whose checks
+// fail is used.
+const EvictionAfterLastCheck = 30 * 24 * time.Hour
+
+// ErrStale is returned by Variant for a variant whose file's modification
+// time is CacheTTL or more ago (see Variant).
+var ErrStale = errors.New("cached variant is older than the cache TTL")
+
 // Config holds cache configuration.
 type Config struct {
 	StateDir    string
 	NegativeTTL time.Duration
 
+	// CacheTTL is how long a cached source is used, and its variants served,
+	// before upstream is asked again whether the source changed. Zero means
+	// DefaultCacheTTL.
+	CacheTTL time.Duration
+
 	// MaxBytes is the disk cache size limit in bytes that eviction
 	// enforces. Zero turns the disk cache off entirely: no cache
 	// directories are created, lookups always miss, stores are no-ops,
@@ -85,10 +111,16 @@ type Cache struct {
 	pendingAccessTimesDone    chan struct{}
 	pendingAccessTimesCancel  context.CancelFunc
 
-	// The counts of cache hits and misses, made and registered by
+	// The cache's metrics, made and registered by registerMetrics (see
-	// registerCounters (see counters.go)
+	// metrics.go)
 	cacheHits         prometheus.Counter
 	cacheMisses       prometheus.Counter
+	sourceCacheHits   prometheus.Counter
+	sourceCacheMisses prometheus.Counter
+	usageBytes        prometheus.Gauge
+	maxBytes          prometheus.Gauge
+	evictions         prometheus.Counter
+	evictedBytes      prometheus.Counter
 
 	// reconciliationPageSize is the most rows one read of a content table
 	// returns in the reconciliation pass. NewCache sets it to
@@ -102,7 +134,7 @@ type Cache struct {
 	reconciliationReadTestHook func(rows int)
 }
 
-// NewCache creates a new cache instance and registers its counters on
+// NewCache creates a new cache instance and registers its metrics on
 // metricsRegistry. pixad passes Prometheus' default registry, the one
 // /metrics serves. It makes no database call.
 func NewCache(
@@ -113,6 +145,10 @@ func NewCache(
 		log = slog.Default()
 	}
 
+	if config.CacheTTL == 0 {
+		config.CacheTTL = DefaultCacheTTL
+	}
+
 	c := &Cache{
 		db:               db,
 		config:           config,
@@ -127,7 +163,7 @@ func NewCache(
 		reconciliationPageSize: defaultReconciliationPageSize,
 	}
 
-	err := c.registerCounters(metricsRegistry)
+	err := c.registerMetrics(metricsRegistry)
 	if err != nil {
 		return nil, err
 	}
@@ -156,43 +192,167 @@ func NewCache(
 	return c, nil
 }
 
-// Variant opens a cached variant and returns a reader, its size and its
+// VariantFile is the open file of a cached variant, as Variant,
-// content type, read from the variant file's first bytes. It opens that one
+// VariantIgnoringTTL and RenewVariant return it.
-// file and makes no database call. A variant it opens has its access time
+type VariantFile struct {
-// handed to the background writer without waiting (see touchVariant). A
+	// Content reads the file. The caller closes it.
-// variant not in the cache, or any variant of a disabled cache, is
+	Content io.ReadCloser
-// ErrNotFound; a variant file whose first bytes are not those of an output
+	// Size is the file's size in bytes.
-// format is another error.
+	Size int64
-func (c *Cache) Variant(
+	// ContentType is the MIME type of the variant's format, read from the
-	cacheKey imagerequest.VariantKey,
+	// file's first bytes.
-) (io.ReadCloser, int64, string, error) {
+	ContentType string
+	// CheckedAt is the file's modification time: its source's check time
+	// when the variant was made or last renewed.
+	CheckedAt time.Time
+}
+
+// Variant opens a cached variant and returns its file (see VariantFile). It
+// opens that one file and makes no database call: the file's modification
+// time is its source's check time when the variant was made or last renewed
+// (see PutVariant), and a variant whose time is CacheTTL or more ago is
+// ErrStale. A variant it opens has its access time handed to the background
+// writer without waiting (see touchVariant). A variant not in the cache, or
+// any variant of a disabled cache, is ErrNotFound; a variant file whose first
+// bytes are not those of an output format is another error.
+func (c *Cache) Variant(cacheKey imagerequest.VariantKey) (VariantFile, error) {
 	if c.config.MaxBytes == 0 {
-		return nil, 0, "", ErrNotFound
+		return VariantFile{}, ErrNotFound
 	}
 
-	file, size, err := c.variants.Open(string(cacheKey))
+	file, info, err := c.variants.Open(string(cacheKey))
 	if err != nil {
-		return nil, 0, "", err
+		return VariantFile{}, err
+	}
+
+	if c.Stale(info.ModTime()) {
+		_ = file.Close()
+
+		return VariantFile{}, ErrStale
+	}
+
+	return c.finishOpeningVariant(cacheKey, file, info)
+}
+
+// VariantIgnoringTTL opens a cached variant whatever its age, and returns it
+// as Variant does. The image proxy reads it for a variant whose source is not
+// cached, before it checks the source with upstream (see LookupVariant).
+func (c *Cache) VariantIgnoringTTL(
+	cacheKey imagerequest.VariantKey,
+) (VariantFile, error) {
+	if c.config.MaxBytes == 0 {
+		return VariantFile{}, ErrNotFound
+	}
+
+	file, info, err := c.variants.Open(string(cacheKey))
+	if err != nil {
+		return VariantFile{}, err
+	}
+
+	return c.finishOpeningVariant(cacheKey, file, info)
+}
+
+// RenewVariant opens a cached variant made from the source bytes that source
+// describes, whatever its age, and returns it as Variant does. It moves the
+// variant's check time forward to source.CheckedAt (see SetVariantCheckedAt).
+// A variant made before source.FetchedAt was made from older bytes, and is
+// ErrNotFound, as is a variant not in the cache.
+func (c *Cache) RenewVariant(
+	ctx context.Context, cacheKey imagerequest.VariantKey, source SourceInfo,
+) (VariantFile, error) {
+	if c.config.MaxBytes == 0 {
+		return VariantFile{}, ErrNotFound
+	}
+
+	file, info, err := c.variants.Open(string(cacheKey))
+	if err != nil {
+		return VariantFile{}, err
+	}
+
+	if info.ModTime().Before(source.FetchedAt) {
+		_ = file.Close()
+
+		return VariantFile{}, ErrNotFound
 	}
 
 	format, err := readFormat(file)
 	if err != nil {
 		_ = file.Close()
 
-		return nil, 0, "", err
+		return VariantFile{}, err
+	}
+
+	checkedAt := info.ModTime()
+
+	if checkedAt.Before(source.CheckedAt) {
+		err = c.SetVariantCheckedAt(ctx, cacheKey, source.CheckedAt)
+		if err != nil {
+			_ = file.Close()
+
+			return VariantFile{}, err
+		}
+
+		checkedAt = source.CheckedAt
 	}
 
 	c.touchVariant(cacheKey)
 
-	return file, size, format.MIMEType(), nil
+	return VariantFile{
+		Content:     file,
+		Size:        info.Size(),
+		ContentType: format.MIMEType(),
+		CheckedAt:   checkedAt,
+	}, nil
 }
 
-// PutVariant stores a processed variant by its cache key and records
+// SetVariantCheckedAt records checkedAt as when upstream last sent the source
-// it in the size accounting. On a disabled cache it is a no-op. The
+// bytes the cached variant of cacheKey was made from, or answered that they
-// accounting insert is best-effort (the startup reconciliation pass
+// had not changed. It sets the variant file's modification time to checkedAt,
-// adopts any variant file that misses its accounting row).
+// so Variant serves the file until CacheTTL after it. It sets the checked_at
+// of the variant's row too, so eviction keeps the variant until
+// EvictionAfterLastCheck after it. A failure to write the row is only logged.
+// On a disabled cache it is a no-op.
+func (c *Cache) SetVariantCheckedAt(
+	ctx context.Context, cacheKey imagerequest.VariantKey, checkedAt time.Time,
+) error {
+	if c.config.MaxBytes == 0 {
+		return nil
+	}
+
+	err := c.variants.SetModTime(string(cacheKey), checkedAt)
+	if err != nil {
+		return err
+	}
+
+	_, err = c.db.ExecContext(ctx,
+		`UPDATE variant_content SET checked_at = ? WHERE cache_key = ?`,
+		checkedAt.UTC(), string(cacheKey))
+	if err != nil {
+		c.log.Warn("failed to renew variant's checked_at",
+			"cache_key", cacheKey, "error", err)
+	}
+
+	return nil
+}
+
+// Stale reports whether a source last checked with upstream at checkedAt,
+// and its variants, are due to be checked again.
+func (c *Cache) Stale(checkedAt time.Time) bool {
+	return time.Since(checkedAt) >= c.config.CacheTTL
+}
+
+// PutVariant stores a processed variant by its cache key and records it in
+// the size accounting. source describes the source bytes the variant was made
+// from. Its CheckedAt becomes the modification time of the variant's file,
+// which Variant and RenewVariant read. The variant's row keeps its CheckedAt,
+// ETag and LastModified (see LookupVariant). On a disabled cache it is a
+// no-op. The accounting insert is best-effort (the startup reconciliation
+// pass adopts any variant file that misses its accounting row).
 func (c *Cache) PutVariant(
-	ctx context.Context, cacheKey imagerequest.VariantKey, content io.Reader,
+	ctx context.Context,
+	cacheKey imagerequest.VariantKey,
+	source SourceInfo,
+	content io.Reader,
 ) error {
 	if c.config.MaxBytes == 0 {
 		return nil
@@ -208,15 +368,33 @@ func (c *Cache) PutVariant(
 		return err
 	}
 
+	// A file left with the time of its writing could be served as made from
+	// bytes fetched after the ones it was made from
+	err = c.variants.SetModTime(string(cacheKey), source.CheckedAt)
+	if err != nil {
+		deleteErr := c.variants.Delete(string(cacheKey))
+		if deleteErr != nil {
+			c.log.Warn("failed to remove variant file whose time was not set",
+				"cache_key", cacheKey, "error", deleteErr)
+		}
+
+		return err
+	}
+
 	size := int64(len(data))
 
 	_, err = c.db.ExecContext(ctx, `
-		INSERT INTO variant_content (cache_key, size_bytes)
+		INSERT INTO variant_content (cache_key, size_bytes, checked_at,
-		VALUES (?, ?)
+			upstream_etag, upstream_last_modified)
+		VALUES (?, ?, ?, ?, ?)
 		ON CONFLICT(cache_key) DO UPDATE SET
 			size_bytes = excluded.size_bytes,
-			last_accessed_at = CURRENT_TIMESTAMP
+			last_accessed_at = CURRENT_TIMESTAMP,
-	`, string(cacheKey), size)
+			checked_at = excluded.checked_at,
+			upstream_etag = excluded.upstream_etag,
+			upstream_last_modified = excluded.upstream_last_modified
+	`, string(cacheKey), size, source.CheckedAt.UTC(), source.ETag,
+		source.LastModified)
 	if err != nil {
 		c.log.Warn("failed to record variant in size accounting",
 			"cache_key", cacheKey, "error", err)
@@ -255,7 +433,7 @@ func (c *Cache) Source(
 		return nil, 0, "", ErrNotFound
 	}
 
-	file, size, err := c.srcContent.Open(string(key))
+	file, info, err := c.srcContent.Open(string(key))
 	if err != nil {
 		return nil, 0, "", err
 	}
@@ -269,19 +447,107 @@ func (c *Cache) Source(
 
 	c.touchSourceContent(key)
 
-	return file, size, format, nil
+	return file, info.Size(), format, nil
 }
 
-// PutSource stores fetched source content: it writes the file named by
+// SourceInfo is what the cache keeps in a cached source's row besides its
-// the source's key, then the source's row. When the row cannot be written
+// size and access time.
-// the file is removed and the store fails, as a file with no row is never
+type SourceInfo struct {
-// served or evicted; if that removal fails too, the next reconciliation
+	// FetchedAt is when the cached bytes were fetched.
-// pass removes the file. On a disabled cache it is a no-op returning an
+	FetchedAt time.Time
-// empty key.
+	// CheckedAt is when upstream last sent the bytes or answered that they
+	// had not changed.
+	CheckedAt time.Time
+	// ETag is the ETag header upstream sent with the bytes, or "".
+	ETag string
+	// LastModified is the Last-Modified header upstream sent with the
+	// bytes, or "".
+	LastModified string
+}
+
+// LookupSource returns what the cache keeps about the cached source of src.
+// A source with no row is ErrNotFound, as is any source of a disabled cache.
+func (c *Cache) LookupSource(
+	ctx context.Context, src imagerequest.Source,
+) (SourceInfo, error) {
+	if c.config.MaxBytes == 0 {
+		return SourceInfo{}, ErrNotFound
+	}
+
+	var info SourceInfo
+
+	err := c.db.QueryRowContext(ctx, `
+		SELECT fetched_at, checked_at, upstream_etag, upstream_last_modified
+		FROM source_content WHERE source_key = ?
+	`, string(src.Key())).Scan(
+		&info.FetchedAt, &info.CheckedAt, &info.ETag, &info.LastModified)
+	if errors.Is(err, sql.ErrNoRows) {
+		return SourceInfo{}, ErrNotFound
+	}
+
+	if err != nil {
+		return SourceInfo{}, fmt.Errorf("failed to look up source: %w", err)
+	}
+
+	return info, nil
+}
+
+// LookupVariant returns what the row of the cached variant of cacheKey keeps
+// about the source bytes the variant was made from: the CheckedAt, ETag and
+// LastModified they had when the variant was made or last renewed. The row
+// keeps no FetchedAt, so it is zero. With the ETag and LastModified the image
+// proxy checks the variant with upstream after its source is evicted. A
+// variant with no row is ErrNotFound, as is any variant of a disabled cache.
+func (c *Cache) LookupVariant(
+	ctx context.Context, cacheKey imagerequest.VariantKey,
+) (SourceInfo, error) {
+	if c.config.MaxBytes == 0 {
+		return SourceInfo{}, ErrNotFound
+	}
+
+	var info SourceInfo
+
+	err := c.db.QueryRowContext(ctx, `
+		SELECT checked_at, upstream_etag, upstream_last_modified
+		FROM variant_content WHERE cache_key = ?
+	`, string(cacheKey)).Scan(&info.CheckedAt, &info.ETag, &info.LastModified)
+	if errors.Is(err, sql.ErrNoRows) {
+		return SourceInfo{}, ErrNotFound
+	}
+
+	if err != nil {
+		return SourceInfo{}, fmt.Errorf("failed to look up variant: %w", err)
+	}
+
+	return info, nil
+}
+
+// RenewSource records that upstream answered at checkedAt that the cached
+// source of src had not changed.
+func (c *Cache) RenewSource(
+	ctx context.Context, src imagerequest.Source, checkedAt time.Time,
+) error {
+	_, err := c.db.ExecContext(ctx,
+		`UPDATE source_content SET checked_at = ? WHERE source_key = ?`,
+		checkedAt.UTC(), string(src.Key()))
+	if err != nil {
+		return fmt.Errorf("failed to renew source: %w", err)
+	}
+
+	return nil
+}
+
+// PutSource stores fetched source content with what info says about it: it
+// writes the file named by the source's key, then the source's row. When the
+// row cannot be written the file is removed and the store fails, as a file
+// with no row is never served or evicted; if that removal fails too, the
+// next reconciliation pass removes the file. On a disabled cache it is a
+// no-op returning an empty key.
 func (c *Cache) PutSource(
 	ctx context.Context,
 	src imagerequest.Source,
 	content io.Reader,
+	info SourceInfo,
 ) (imagerequest.SourceKey, error) {
 	if c.config.MaxBytes == 0 {
 		return "", nil
@@ -302,12 +568,18 @@ func (c *Cache) PutSource(
 	size := int64(len(data))
 
 	_, err = c.db.ExecContext(ctx, `
-		INSERT INTO source_content (source_key, size_bytes)
+		INSERT INTO source_content (source_key, size_bytes, fetched_at,
-		VALUES (?, ?)
+			checked_at, upstream_etag, upstream_last_modified)
+		VALUES (?, ?, ?, ?, ?, ?)
 		ON CONFLICT(source_key) DO UPDATE SET
 			size_bytes = excluded.size_bytes,
-			last_accessed_at = CURRENT_TIMESTAMP
+			last_accessed_at = CURRENT_TIMESTAMP,
-	`, string(key), size)
+			fetched_at = excluded.fetched_at,
+			checked_at = excluded.checked_at,
+			upstream_etag = excluded.upstream_etag,
+			upstream_last_modified = excluded.upstream_last_modified
+	`, string(key), size, info.FetchedAt.UTC(), info.CheckedAt.UTC(), info.ETag,
+		info.LastModified)
 	if err != nil {
 		deleteErr := c.srcContent.Delete(string(key))
 		if deleteErr != nil {
@@ -390,17 +662,6 @@ func (c *Cache) CleanExpired(ctx context.Context) error {
 	}
 }
 
-// IncrementStats counts a cache hit or miss. It only adds to the cache's
-// Prometheus counters in memory (see counters.go), so it never waits for the
-// database or fails.
-func (c *Cache) IncrementStats(hit bool) {
-	if hit {
-		c.cacheHits.Inc()
-	} else {
-		c.cacheMisses.Inc()
-	}
-}
-
 // touchVariant hands the access time of a variant served from the cache to
 // the goroutine StartPendingAccessTimeWrites starts, which writes it in its
 // next batch. It never waits: while maxPendingAccessTimes access times of
@@ -449,6 +710,31 @@ func (c *Cache) cleanExpiredBatch(ctx context.Context) (int64, error) {
 	return deleted, nil
 }
 
+// finishOpeningVariant returns a variant file that FileStore.Open opened, with
+// its information info, as Variant does. It reads the content type from the
+// file's first bytes and hands the variant's access time to the background
+// writer (see touchVariant). It closes the file when its first bytes are not
+// those of an output format.
+func (c *Cache) finishOpeningVariant(
+	cacheKey imagerequest.VariantKey, file *os.File, info fs.FileInfo,
+) (VariantFile, error) {
+	format, err := readFormat(file)
+	if err != nil {
+		_ = file.Close()
+
+		return VariantFile{}, err
+	}
+
+	c.touchVariant(cacheKey)
+
+	return VariantFile{
+		Content:     file,
+		Size:        info.Size(),
+		ContentType: format.MIMEType(),
+		CheckedAt:   info.ModTime(),
+	}, nil
+}
+
 // readFormat reads up to magic.MaxMagicBytes first bytes of a source or
 // variant file, without moving its offset, and returns the format they show.
 // Sources and variants are in the same seven formats; a variant is SVG only

internal/imgcache/cache_hit_internal_test.go

@@ -49,16 +49,19 @@ func TestVariant_ContentTypeFromFirstBytes(t *testing.T) {
 
 		key := imagerequest.VariantKey("aabbccdd10" + string(format))
 
-		err = cache.PutVariant(t.Context(), key, bytes.NewReader(image))
+		err = cache.PutVariant(t.Context(), key, SourceInfo{CheckedAt: time.Now()},
+			bytes.NewReader(image))
 		if err != nil {
 			t.Fatalf("PutVariant(%s) error = %v", format, err)
 		}
 
-		reader, size, contentType, err := cache.Variant(key)
+		variant, err := cache.Variant(key)
 		if err != nil {
 			t.Fatalf("Variant(%s) error = %v", format, err)
 		}
 
+		reader, size, contentType := variant.Content, variant.Size, variant.ContentType
+
 		served, err := io.ReadAll(reader)
 		_ = reader.Close()
 
@@ -107,16 +110,19 @@ func TestVariant_RefusesFileOfNoOutputFormat(t *testing.T) {
 			t.Fatalf("%s: storing the variant file: %v", tt.name, err)
 		}
 
-		reader, _, contentType, err := cache.Variant(key)
+		variant, err := cache.Variant(key)
 		t.Logf("%s: Variant() error = %v", tt.name, err)
 
+		reader, contentType := variant.Content, variant.ContentType
 		if reader != nil || contentType != "" || !errors.Is(err, tt.wantErr) {
 			t.Errorf("%s: Variant() = reader %v, content type %q, error %v; "+
 				"want no reader and %v", tt.name, reader, contentType, err, tt.wantErr)
 		}
 	}
 
-	reader, _, _, err := cache.Variant(testVariantKeyFour)
+	variant, err := cache.Variant(testVariantKeyFour)
+
+	reader := variant.Content
 	if reader != nil || !errors.Is(err, ErrNotFound) {
 		t.Errorf("Variant() of a variant with no file = reader %v, error %v; "+
 			"want no reader and %v", reader, err, ErrNotFound)
@@ -124,7 +130,9 @@ func TestVariant_RefusesFileOfNoOutputFormat(t *testing.T) {
 
 	disabled, _ := newEvictionTestCache(t, 0)
 
-	reader, _, _, err = disabled.Variant(testVariantKeyOne)
+	variant, err = disabled.Variant(testVariantKeyOne)
+
+	reader = variant.Content
 	if reader != nil || !errors.Is(err, ErrNotFound) {
 		t.Errorf("Variant() on a disabled cache = reader %v, error %v; "+
 			"want no reader and %v", reader, err, ErrNotFound)

internal/imgcache/counters.go

@@ -1,31 +0,0 @@
-package imgcache
-
-import (
-	"fmt"
-
-	"github.com/prometheus/client_golang/prometheus"
-)
-
-// registerCounters makes the cache's counters and registers them on
-// metricsRegistry. The counters are kept in memory, so adding to one waits
-// for nothing and makes no database call. It fails when metricsRegistry
-// already holds counters of the same names.
-func (c *Cache) registerCounters(metricsRegistry prometheus.Registerer) error {
-	c.cacheHits = prometheus.NewCounter(prometheus.CounterOpts{
-		Name: "pixa_cache_hits_total",
-		Help: "Image requests served from the cache.",
-	})
-	c.cacheMisses = prometheus.NewCounter(prometheus.CounterOpts{
-		Name: "pixa_cache_misses_total",
-		Help: "Image requests not served from the cache.",
-	})
-
-	for _, counter := range []prometheus.Counter{c.cacheHits, c.cacheMisses} {
-		err := metricsRegistry.Register(counter)
-		if err != nil {
-			return fmt.Errorf("failed to register the cache's counters: %w", err)
-		}
-	}
-
-	return nil
-}

internal/imgcache/evict_not_checked_recently_internal_test.go

@@ -0,0 +1,88 @@
+package imgcache
+
+import (
+	"bytes"
+	"os"
+	"slices"
+	"testing"
+	"time"
+
+	"sneak.berlin/go/pixa/internal/imagerequest"
+)
+
+// TestEvictNotCheckedRecently stores a source and a variant last checked with
+// upstream 31 days ago and a source and a variant checked 29 days ago.
+// EvictNotCheckedRecently must remove the rows and files of the first two and
+// keep the other two.
+func TestEvictNotCheckedRecently(t *testing.T) {
+	t.Parallel()
+
+	cache, _ := newEvictionTestCache(t, 1<<30)
+	old := time.Now().Add(-31 * 24 * time.Hour)
+	recent := time.Now().Add(-29 * 24 * time.Hour)
+
+	oldSource := imagerequest.Source{Host: testHostCDN, Path: "/old.jpg"}
+	recentSource := imagerequest.Source{Host: testHostCDN, Path: "/recent.jpg"}
+
+	for src, checkedAt := range map[imagerequest.Source]time.Time{
+		oldSource: old, recentSource: recent,
+	} {
+		_, err := cache.PutSource(t.Context(), src, bytes.NewReader([]byte("source")),
+			SourceInfo{FetchedAt: checkedAt, CheckedAt: checkedAt})
+		if err != nil {
+			t.Fatalf("PutSource(%s) error = %v", src.Path, err)
+		}
+	}
+
+	oldVariant := imagerequest.VariantKey("aabbccdd0001")
+	recentVariant := imagerequest.VariantKey("aabbccdd0002")
+
+	for key, checkedAt := range map[imagerequest.VariantKey]time.Time{
+		oldVariant: old, recentVariant: recent,
+	} {
+		err := cache.PutVariant(t.Context(), key, SourceInfo{CheckedAt: checkedAt},
+			bytes.NewReader([]byte("variant")))
+		if err != nil {
+			t.Fatalf("PutVariant(%s) error = %v", key, err)
+		}
+	}
+
+	err := cache.EvictNotCheckedRecently(t.Context())
+	if err != nil {
+		t.Fatalf("EvictNotCheckedRecently() error = %v", err)
+	}
+
+	sourceRows, err := queryStringColumn[imagerequest.SourceKey](t.Context(),
+		cache.db, `SELECT source_key FROM source_content`, "sources", "source")
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	variantRows, err := queryStringColumn[imagerequest.VariantKey](t.Context(),
+		cache.db, `SELECT cache_key FROM variant_content`, "variants", "variant")
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	t.Logf("source rows left = %v, variant rows left = %v", sourceRows, variantRows)
+
+	if !slices.Equal(sourceRows, []imagerequest.SourceKey{recentSource.Key()}) {
+		t.Errorf("source rows left = %v, want only %s", sourceRows, recentSource.Key())
+	}
+
+	if !slices.Equal(variantRows, []imagerequest.VariantKey{recentVariant}) {
+		t.Errorf("variant rows left = %v, want only %s", variantRows, recentVariant)
+	}
+
+	for path, wantKept := range map[string]bool{
+		cache.srcContent.keyToPath(string(oldSource.Key())):    false,
+		cache.srcContent.keyToPath(string(recentSource.Key())): true,
+		cache.variants.keyToPath(string(oldVariant)):           false,
+		cache.variants.keyToPath(string(recentVariant)):        true,
+	} {
+		_, statErr := os.Stat(path)
+		if kept := statErr == nil; kept != wantKept {
+			t.Errorf("file %s kept = %t, want %t (%v)", path, kept, wantKept, statErr)
+		}
+	}
+}

internal/imgcache/eviction.go

@@ -92,8 +92,9 @@ type evictionCandidate struct {
 }
 
 // EvictToLimit evicts least-recently-used cache entries until total
-// tracked usage is at or below the configured MaxBytes limit. It is a
+// tracked usage is at or below the configured MaxBytes limit. It sets the
-// no-op when the cache is disabled.
+// pixa_cache_usage_bytes gauge to each usage it reads. It is a no-op when
+// the cache is disabled.
 func (c *Cache) EvictToLimit(ctx context.Context) error {
 	if c.config.MaxBytes == 0 {
 		return nil
@@ -105,6 +106,8 @@ func (c *Cache) EvictToLimit(ctx context.Context) error {
 			return err
 		}
 
+		c.usageBytes.Set(float64(usage))
+
 		if usage <= c.config.MaxBytes {
 			return nil
 		}
@@ -131,6 +134,56 @@ func (c *Cache) EvictToLimit(ctx context.Context) error {
 	}
 }
 
+// EvictNotCheckedRecently evicts each source and variant whose checked_at is
+// EvictionAfterLastCheck or more ago, evictionBatchSize of each at a time,
+// until none is left. It is a no-op when the cache is disabled.
+func (c *Cache) EvictNotCheckedRecently(ctx context.Context) error {
+	if c.config.MaxBytes == 0 {
+		return nil
+	}
+
+	cutoff := time.Now().UTC().Add(-EvictionAfterLastCheck)
+
+	for {
+		sources, err := queryStringColumn[imagerequest.SourceKey](ctx, c.db, `
+			SELECT source_key FROM source_content WHERE checked_at < ? LIMIT ?
+		`, "sources not checked recently", "source key", cutoff, evictionBatchSize)
+		if err != nil {
+			return err
+		}
+
+		for _, key := range sources {
+			err = c.evictSourceBlob(ctx, key)
+			if err != nil {
+				return err
+			}
+		}
+
+		variants, err := queryStringColumn[imagerequest.VariantKey](ctx, c.db, `
+			SELECT cache_key FROM variant_content WHERE checked_at < ? LIMIT ?
+		`, "variants not checked recently", "variant key", cutoff, evictionBatchSize)
+		if err != nil {
+			return err
+		}
+
+		for _, key := range variants {
+			err = c.evictVariant(ctx, key)
+			if err != nil {
+				return err
+			}
+		}
+
+		if len(sources) > 0 || len(variants) > 0 {
+			c.log.Info("evicted cache content not checked with upstream recently",
+				"sources", len(sources), "variants", len(variants))
+		}
+
+		if len(sources) < evictionBatchSize && len(variants) < evictionBatchSize {
+			return nil
+		}
+	}
+}
+
 // evictBatch fetches one batch of LRU candidates across variants and
 // source blobs and evicts them oldest-first until excessBytes are
 // freed or the batch is exhausted. It returns the bytes freed. A
@@ -295,37 +348,95 @@ func (c *Cache) sourceCandidates(ctx context.Context) ([]evictionCandidate, erro
 	return candidates, nil
 }
 
-// evictVariant removes one variant: accounting row first, then the
+// evictVariant removes one variant (see removeVariant) and counts the
-// file, so the database never references a deleted file.
+// eviction with the size its row recorded.
 func (c *Cache) evictVariant(
 	ctx context.Context, cacheKey imagerequest.VariantKey,
 ) error {
-	_, err := c.db.ExecContext(ctx,
+	sizeBytes, err := c.removeVariant(ctx, cacheKey)
-		`DELETE FROM variant_content WHERE cache_key = ?`, string(cacheKey))
-	if err != nil {
-		return fmt.Errorf("failed to delete variant accounting row: %w", err)
-	}
-
-	err = c.variants.Delete(string(cacheKey))
 	if err != nil {
 		return err
 	}
 
+	c.countEviction(sizeBytes)
+
 	return nil
 }
 
-// evictSourceBlob removes one source: its row first, then its file, as
+// removeVariant removes one variant: accounting row first, then the
-// evictVariant does for a variant. It holds no lock: a store of the same
+// file, so the database never references a deleted file. It returns the
-// source in between can leave the source's row with no file, which
+// size the row recorded, or 0 when the variant had no row.
-// Source treats as a miss.
+func (c *Cache) removeVariant(
-func (c *Cache) evictSourceBlob(ctx context.Context, key imagerequest.SourceKey) error {
+	ctx context.Context, cacheKey imagerequest.VariantKey,
-	_, err := c.db.ExecContext(ctx,
+) (int64, error) {
-		`DELETE FROM source_content WHERE source_key = ?`, string(key))
+	sizeBytes, err := c.deleteRowReturningSize(ctx,
+		`DELETE FROM variant_content WHERE cache_key = ? RETURNING size_bytes`,
+		string(cacheKey))
 	if err != nil {
-		return fmt.Errorf("failed to delete source content row: %w", err)
+		return 0, fmt.Errorf("failed to delete variant accounting row: %w", err)
 	}
 
-	return c.srcContent.Delete(string(key))
+	err = c.variants.Delete(string(cacheKey))
+	if err != nil {
+		return 0, err
+	}
+
+	return sizeBytes, nil
+}
+
+// evictSourceBlob removes one source (see removeSourceBlob) and counts the
+// eviction with the size its row recorded.
+func (c *Cache) evictSourceBlob(ctx context.Context, key imagerequest.SourceKey) error {
+	sizeBytes, err := c.removeSourceBlob(ctx, key)
+	if err != nil {
+		return err
+	}
+
+	c.countEviction(sizeBytes)
+
+	return nil
+}
+
+// removeSourceBlob removes one source: its row first, then its file, as
+// removeVariant does for a variant, and returns the size the row recorded,
+// or 0 when the source had no row. It holds no lock: a store of the same
+// source in between can leave the source's row with no file, which Source
+// treats as a miss.
+func (c *Cache) removeSourceBlob(
+	ctx context.Context, key imagerequest.SourceKey,
+) (int64, error) {
+	sizeBytes, err := c.deleteRowReturningSize(ctx,
+		`DELETE FROM source_content WHERE source_key = ? RETURNING size_bytes`,
+		string(key))
+	if err != nil {
+		return 0, fmt.Errorf("failed to delete source content row: %w", err)
+	}
+
+	err = c.srcContent.Delete(string(key))
+	if err != nil {
+		return 0, err
+	}
+
+	return sizeBytes, nil
+}
+
+// deleteRowReturningSize runs deleteQuery, which deletes the row of key and
+// returns its size_bytes, and returns that size, or 0 when there was no row.
+func (c *Cache) deleteRowReturningSize(
+	ctx context.Context, deleteQuery string, key string,
+) (int64, error) {
+	var sizeBytes int64
+
+	err := c.db.QueryRowContext(ctx, deleteQuery, key).Scan(&sizeBytes)
+	if errors.Is(err, sql.ErrNoRows) {
+		return 0, nil
+	}
+
+	if err != nil {
+		return 0, err
+	}
+
+	return sizeBytes, nil
 }
 
 // notifyWritePressure wakes the background evictor after a store, so
@@ -344,8 +455,9 @@ func (c *Cache) notifyWritePressure() {
 }
 
 // StartEviction launches the background eviction goroutine, which
-// removes the expired negative cache rows at startup and again on every
+// removes the expired negative cache rows, and the sources and variants not
-// periodic tick thereafter, reconciles the database accounting with the
+// checked for EvictionAfterLastCheck, at startup and again on every periodic
+// tick thereafter, reconciles the database accounting with the
 // cache directories at startup and again on the first periodic tick
 // that comes at least ten times as long after a reconciliation pass
 // ended as that pass took, and evicts to the configured limit on the given
@@ -392,6 +504,7 @@ func (c *Cache) evictionLoop(ctx context.Context, interval time.Duration) {
 
 	nextReconciliation := c.runReconciliationPass(ctx)
 	c.runCleanExpired(ctx)
+	c.runEvictNotCheckedRecently(ctx)
 	c.runEvictionPass(ctx)
 
 	ticker := time.NewTicker(interval)
@@ -417,6 +530,7 @@ func (c *Cache) evictionLoop(ctx context.Context, interval time.Duration) {
 			}
 
 			c.runCleanExpired(ctx)
+			c.runEvictNotCheckedRecently(ctx)
 		case <-c.evictionPressure:
 		}
 
@@ -474,6 +588,21 @@ func (c *Cache) runCleanExpired(ctx context.Context) {
 	}
 }
 
+// runEvictNotCheckedRecently runs EvictNotCheckedRecently, logging a failure
+// instead of propagating it (the loop must keep running). It does nothing
+// once ctx is cancelled.
+func (c *Cache) runEvictNotCheckedRecently(ctx context.Context) {
+	if ctx.Err() != nil {
+		return
+	}
+
+	err := c.EvictNotCheckedRecently(ctx)
+	if err != nil {
+		c.log.Warn("evicting cache content not checked recently failed",
+			"error", err)
+	}
+}
+
 // reconcileAccounting synchronizes the database size accounting with
 // the actual contents of the cache directories. It runs at startup and
 // then on the first periodic eviction tick that comes at least ten times
@@ -605,20 +734,24 @@ func (c *Cache) reconcileVariantFile(
 	c.log.Warn("removing damaged cached variant file", "path", path,
 		"file_bytes", info.Size(), "recorded_bytes", recordedSize)
 
-	return c.evictVariant(ctx, cacheKey)
+	_, err = c.removeVariant(ctx, cacheKey)
+
+	return err
 }
 
 // adoptVariantFile inserts an accounting row for a variant file that
-// has none, using the file's size and modification time.
+// has none, using the file's size and modification time, which is also
+// the variant's checked_at.
 func (c *Cache) adoptVariantFile(
 	ctx context.Context, info fs.FileInfo, cacheKey imagerequest.VariantKey,
 ) error {
 	modTime := info.ModTime().UTC().Format(sqliteTimestampLayout)
 
 	_, err := c.db.ExecContext(ctx, `
-		INSERT INTO variant_content (cache_key, size_bytes, last_accessed_at)
+		INSERT INTO variant_content (cache_key, size_bytes, last_accessed_at,
-		VALUES (?, ?, ?)
+			checked_at)
-	`, string(cacheKey), info.Size(), modTime)
+		VALUES (?, ?, ?, ?)
+	`, string(cacheKey), info.Size(), modTime, info.ModTime().UTC())
 	if err != nil {
 		return fmt.Errorf("failed to adopt variant file into accounting: %w", err)
 	}
@@ -765,7 +898,9 @@ func (c *Cache) reconcileSourceFile(
 	c.log.Warn("removing damaged cached source file", "path", path,
 		"file_bytes", info.Size(), "recorded_bytes", recordedSize)
 
-	return c.evictSourceBlob(ctx, key)
+	_, err = c.removeSourceBlob(ctx, key)
+
+	return err
 }
 
 // removeUntrackedSourceFile deletes a source blob file that has no

internal/imgcache/eviction_internal_test.go

@@ -101,7 +101,7 @@ func storeEvictionTestSource(
 	}
 
 	key, err := cache.PutSource(
-		context.Background(), req.Source, bytes.NewReader(content),
+		context.Background(), req.Source, bytes.NewReader(content), SourceInfo{},
 	)
 	if err != nil {
 		t.Fatalf("PutSource(%s%s) failed: %v", host, path, err)
@@ -117,7 +117,8 @@ func storeEvictionTestVariant(
 ) {
 	t.Helper()
 
-	err := cache.PutVariant(t.Context(), key, bytes.NewReader(content))
+	err := cache.PutVariant(t.Context(), key, SourceInfo{CheckedAt: time.Now()},
+		bytes.NewReader(content))
 	if err != nil {
 		t.Fatalf("PutVariant(%s) failed: %v", key, err)
 	}
@@ -432,13 +433,14 @@ func assertDisabledCacheWritesAreNoOps(
 	ctx := t.Context()
 
 	err := cache.PutVariant(
-		ctx, imagerequest.CacheKey(req), bytes.NewReader([]byte("data")),
+		ctx, imagerequest.CacheKey(req), SourceInfo{}, bytes.NewReader([]byte("data")),
 	)
 	if err != nil {
 		t.Fatalf("PutVariant on disabled cache must be a no-op, got error: %v", err)
 	}
 
-	key, err := cache.PutSource(ctx, req.Source, bytes.NewReader([]byte("data")))
+	key, err := cache.PutSource(ctx, req.Source, bytes.NewReader([]byte("data")),
+		SourceInfo{})
 	if err != nil {
 		t.Fatalf("PutSource on disabled cache must be a no-op, got error: %v", err)
 	}

internal/imgcache/filestore.go

@@ -3,8 +3,10 @@ package imgcache
 import (
 	"errors"
 	"fmt"
+	"io/fs"
 	"os"
 	"path/filepath"
+	"time"
 )
 
 // Storage constants.
@@ -54,26 +56,26 @@ func (s *FileStore) Write(key string, data []byte) error {
 	return writeFileSynced(path, data)
 }
 
-// Open opens the file for key and returns it with its size in bytes. A
+// Open opens the file for key and returns it with its information, which
-// missing file is ErrNotFound.
+// gives its size and its modification time. A missing file is ErrNotFound.
-func (s *FileStore) Open(key string) (*os.File, int64, error) {
+func (s *FileStore) Open(key string) (*os.File, fs.FileInfo, error) {
 	f, err := os.Open(s.keyToPath(key))
 	if err != nil {
 		if os.IsNotExist(err) {
-			return nil, 0, ErrNotFound
+			return nil, nil, ErrNotFound
 		}
 
-		return nil, 0, fmt.Errorf("failed to open content: %w", err)
+		return nil, nil, fmt.Errorf("failed to open content: %w", err)
 	}
 
-	stat, err := f.Stat()
+	info, err := f.Stat()
 	if err != nil {
 		_ = f.Close()
 
-		return nil, 0, fmt.Errorf("failed to stat content: %w", err)
+		return nil, nil, fmt.Errorf("failed to stat content: %w", err)
 	}
 
-	return f, stat.Size(), nil
+	return f, info, nil
 }
 
 // Size returns the size in bytes of the file for key. A missing file is
@@ -91,6 +93,17 @@ func (s *FileStore) Size(key string) (int64, error) {
 	return stat.Size(), nil
 }
 
+// SetModTime sets the modification time of the file for key to modTime,
+// leaving its access time as it is.
+func (s *FileStore) SetModTime(key string, modTime time.Time) error {
+	err := os.Chtimes(s.keyToPath(key), time.Time{}, modTime)
+	if err != nil {
+		return fmt.Errorf("failed to set modification time: %w", err)
+	}
+
+	return nil
+}
+
 // Delete removes the file for key. A missing file is not an error.
 func (s *FileStore) Delete(key string) error {
 	err := os.Remove(s.keyToPath(key))

internal/imgcache/filestore_internal_test.go

@@ -38,15 +38,15 @@ func TestFileStore_WriteAndOpen(t *testing.T) {
 	}
 
 	// Open and verify size and content
-	r, size, err := storage.Open(key)
+	r, info, err := storage.Open(key)
 	if err != nil {
 		t.Fatalf("Open() error = %v", err)
 	}
 
 	defer func() { _ = r.Close() }()
 
-	if size != int64(len(content)) {
+	if info.Size() != int64(len(content)) {
-		t.Errorf("Open() size = %d, want %d", size, len(content))
+		t.Errorf("Open() size = %d, want %d", info.Size(), len(content))
 	}
 
 	loaded, err := io.ReadAll(r)

internal/imgcache/metrics.go

@@ -0,0 +1,88 @@
+package imgcache
+
+import (
+	"fmt"
+
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+// registerMetrics makes the cache's metrics and registers them on
+// metricsRegistry. The metrics are kept in memory, so updating one waits
+// for nothing and makes no database call. It fails when metricsRegistry
+// already holds metrics of the same names.
+func (c *Cache) registerMetrics(metricsRegistry prometheus.Registerer) error {
+	c.cacheHits = prometheus.NewCounter(prometheus.CounterOpts{
+		Name: "pixa_cache_hits_total",
+		Help: "Image requests served from the cache.",
+	})
+	c.cacheMisses = prometheus.NewCounter(prometheus.CounterOpts{
+		Name: "pixa_cache_misses_total",
+		Help: "Image requests not served from the cache.",
+	})
+	c.sourceCacheHits = prometheus.NewCounter(prometheus.CounterOpts{
+		Name: "pixa_source_cache_hits_total",
+		Help: "Variants made or checked whose source was in the cache.",
+	})
+	c.sourceCacheMisses = prometheus.NewCounter(prometheus.CounterOpts{
+		Name: "pixa_source_cache_misses_total",
+		Help: "Variants made or checked whose source was not in the cache.",
+	})
+	c.usageBytes = prometheus.NewGauge(prometheus.GaugeOpts{
+		Name: "pixa_cache_usage_bytes",
+		Help: "Bytes of sources and variants in the cache, as eviction last read them.",
+	})
+	c.maxBytes = prometheus.NewGauge(prometheus.GaugeOpts{
+		Name: "pixa_cache_max_bytes",
+		Help: "The disk cache limit in bytes, cache_max_bytes.",
+	})
+	c.evictions = prometheus.NewCounter(prometheus.CounterOpts{
+		Name: "pixa_cache_evictions_total",
+		Help: "Sources and variants removed by eviction.",
+	})
+	c.evictedBytes = prometheus.NewCounter(prometheus.CounterOpts{
+		Name: "pixa_cache_evicted_bytes_total",
+		Help: "Bytes of the sources and variants removed by eviction.",
+	})
+
+	c.maxBytes.Set(float64(c.config.MaxBytes))
+
+	for _, metric := range []prometheus.Collector{
+		c.cacheHits, c.cacheMisses, c.sourceCacheHits, c.sourceCacheMisses,
+		c.usageBytes, c.maxBytes, c.evictions, c.evictedBytes,
+	} {
+		err := metricsRegistry.Register(metric)
+		if err != nil {
+			return fmt.Errorf("failed to register the cache's metrics: %w", err)
+		}
+	}
+
+	return nil
+}
+
+// IncrementStats counts a cache hit or miss of an image request. It only
+// adds to the cache's counters in memory, so it never waits for the
+// database or fails.
+func (c *Cache) IncrementStats(hit bool) {
+	if hit {
+		c.cacheHits.Inc()
+	} else {
+		c.cacheMisses.Inc()
+	}
+}
+
+// IncrementSourceStats counts whether a variant being made or checked found
+// its source in the cache. Like IncrementStats, it never waits or fails.
+func (c *Cache) IncrementSourceStats(hit bool) {
+	if hit {
+		c.sourceCacheHits.Inc()
+	} else {
+		c.sourceCacheMisses.Inc()
+	}
+}
+
+// countEviction counts one source or variant of sizeBytes bytes removed by
+// eviction.
+func (c *Cache) countEviction(sizeBytes int64) {
+	c.evictions.Inc()
+	c.evictedBytes.Add(float64(sizeBytes))
+}

internal/imgcache/metrics_internal_test.go

@@ -0,0 +1,137 @@
+package imgcache
+
+import (
+	"bytes"
+	"testing"
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus"
+	"sneak.berlin/go/pixa/internal/imagerequest"
+)
+
+// gatheredValue returns the value of the metric name on registry: a
+// counter's or a gauge's value.
+func gatheredValue(t *testing.T, registry *prometheus.Registry, name string) float64 {
+	t.Helper()
+
+	families, err := registry.Gather()
+	if err != nil {
+		t.Fatalf("failed to gather the metrics: %v", err)
+	}
+
+	for _, family := range families {
+		if family.GetName() != name {
+			continue
+		}
+
+		metric := family.GetMetric()[0]
+		if metric.GetGauge() != nil {
+			return metric.GetGauge().GetValue()
+		}
+
+		return metric.GetCounter().GetValue()
+	}
+
+	t.Fatalf("the metric %s is not on the registry", name)
+
+	return 0
+}
+
+// TestEvictToLimit_CountsEvictionsAndUsage stores four variants of 1000
+// bytes in a cache limited to 3000 bytes. EvictToLimit must count the one
+// eviction and its bytes, and set the usage and limit gauges.
+func TestEvictToLimit_CountsEvictionsAndUsage(t *testing.T) {
+	t.Parallel()
+
+	const limit = 3000
+
+	registry := prometheus.NewRegistry()
+
+	cache, err := NewCache(evictionTestDB(t),
+		Config{StateDir: t.TempDir(), MaxBytes: limit}, registry)
+	if err != nil {
+		t.Fatalf("NewCache() error = %v", err)
+	}
+
+	keys := []imagerequest.VariantKey{
+		testVariantKeyOne, testVariantKeyTwo,
+		testVariantKeyThree, testVariantKeyFour,
+	}
+
+	for i, key := range keys {
+		storeEvictionTestVariant(t, cache, key, bytes.Repeat([]byte{0x01}, 1000))
+		setVariantLastAccessed(t, cache, key,
+			time.Now().Add(-time.Duration(len(keys)-i)*time.Hour))
+	}
+
+	err = cache.EvictToLimit(t.Context())
+	if err != nil {
+		t.Fatalf("EvictToLimit() error = %v", err)
+	}
+
+	want := map[string]float64{
+		"pixa_cache_evictions_total":     1,
+		"pixa_cache_evicted_bytes_total": 1000,
+		"pixa_cache_usage_bytes":         3000,
+		"pixa_cache_max_bytes":           limit,
+	}
+
+	for name, value := range want {
+		got := gatheredValue(t, registry, name)
+		t.Logf("%s = %v", name, got)
+
+		if got != value {
+			t.Errorf("%s = %v, want %v", name, got, value)
+		}
+	}
+}
+
+// TestEvictNotCheckedRecently_CountsEvictions stores a source of 6 bytes and
+// a variant of 7 bytes last checked with upstream 31 days ago.
+// EvictNotCheckedRecently must count both evictions and their 13 bytes.
+func TestEvictNotCheckedRecently_CountsEvictions(t *testing.T) {
+	t.Parallel()
+
+	registry := prometheus.NewRegistry()
+
+	cache, err := NewCache(evictionTestDB(t),
+		Config{StateDir: t.TempDir(), MaxBytes: 1 << 30}, registry)
+	if err != nil {
+		t.Fatalf("NewCache() error = %v", err)
+	}
+
+	old := time.Now().Add(-31 * 24 * time.Hour)
+
+	_, err = cache.PutSource(t.Context(),
+		imagerequest.Source{Host: testHostCDN, Path: "/old.jpg"},
+		bytes.NewReader([]byte("source")),
+		SourceInfo{FetchedAt: old, CheckedAt: old})
+	if err != nil {
+		t.Fatalf("PutSource() error = %v", err)
+	}
+
+	err = cache.PutVariant(t.Context(), testVariantKeyOne,
+		SourceInfo{CheckedAt: old}, bytes.NewReader([]byte("variant")))
+	if err != nil {
+		t.Fatalf("PutVariant() error = %v", err)
+	}
+
+	err = cache.EvictNotCheckedRecently(t.Context())
+	if err != nil {
+		t.Fatalf("EvictNotCheckedRecently() error = %v", err)
+	}
+
+	want := map[string]float64{
+		"pixa_cache_evictions_total":     2,
+		"pixa_cache_evicted_bytes_total": 13,
+	}
+
+	for name, value := range want {
+		got := gatheredValue(t, registry, name)
+		t.Logf("%s = %v", name, got)
+
+		if got != value {
+			t.Errorf("%s = %v, want %v", name, got, value)
+		}
+	}
+}

internal/imgcache/source_content_internal_test.go

@@ -128,7 +128,7 @@ func TestPutSource_FailedRowWriteLeavesNoFile(t *testing.T) {
 		Source: imagerequest.Source{Host: testHostCDN, Path: testPathCat},
 	}
 	key, err := cache.PutSource(t.Context(), req.Source,
-		bytes.NewReader([]byte("source bytes")))
+		bytes.NewReader([]byte("source bytes")), SourceInfo{})
 	t.Logf("PutSource() = %q, error = %v", key, err)
 
 	if err == nil {
@@ -170,7 +170,7 @@ func TestSource_FormatFromFirstBytes(t *testing.T) {
 			t.Fatalf("reading the %s image: %v", format, err)
 		}
 
-		_, err = cache.PutSource(t.Context(), src, bytes.NewReader(image))
+		_, err = cache.PutSource(t.Context(), src, bytes.NewReader(image), SourceInfo{})
 		if err != nil {
 			t.Fatalf("PutSource(%s) error = %v", format, err)
 		}

internal/imgcache/svg_internal_test.go

@@ -40,15 +40,15 @@ func TestSourceAndVariant_ReadSVG(t *testing.T) {
 		t.Fatalf("storing the variant file: %v", err)
 	}
 
-	reader, _, contentType, err := cache.Variant(key)
+	variant, err := cache.Variant(key)
-	t.Logf("Variant() content type = %q, error = %v", contentType, err)
+	t.Logf("Variant() content type = %q, error = %v", variant.ContentType, err)
 
-	if err != nil || contentType != "image/svg+xml" {
+	if err != nil || variant.ContentType != "image/svg+xml" {
 		t.Errorf("Variant() = content type %q, error %v; want image/svg+xml",
-			contentType, err)
+			variant.ContentType, err)
 	}
 
-	if reader != nil {
+	if variant.Content != nil {
-		_ = reader.Close()
+		_ = variant.Content.Close()
 	}
 }

internal/providers/providers.go

@@ -35,7 +35,7 @@ import (
 
 // Constructors returns the constructors of the parts this package builds,
 // for fx.Provide. The fx graph must also provide the prometheus.Registerer
-// the cache and the image service register their counters on.
+// the cache and the image service register their metrics on.
 func Constructors() []any {
 	return []any{
 		newKeys,
@@ -83,6 +83,7 @@ func newCache(lc fx.Lifecycle, params cacheParams) (*imgcache.Cache, error) {
 	cache, err := imgcache.NewCache(db, imgcache.Config{
 		StateDir:    cfg.StateDir,
 		NegativeTTL: imgcache.DefaultNegativeTTL,
+		CacheTTL:    imgcache.DefaultCacheTTL,
 		MaxBytes:    maxBytes,
 		Logger:      params.Logger.Get(),
 	}, params.MetricsRegistry)

internal/server/svg_internal_test.go

@@ -4,15 +4,27 @@ import (
 	"io"
 	"net/http"
 	"net/http/httptest"
-	"strings"
+	"os"
 	"sync/atomic"
 	"testing"
 
+	"sneak.berlin/go/pixa/internal/imageprocessor"
 	"sneak.berlin/go/pixa/internal/imageproxy"
 	"sneak.berlin/go/pixa/internal/imagerequest"
 	"sneak.berlin/go/pixa/internal/magic"
+	"sneak.berlin/go/pixa/internal/middleware"
 )
 
+// TestMain runs this test binary as an SVG child process when the image
+// processor starts it again as one, as the SVG tests below make it do.
+func TestMain(m *testing.M) {
+	if imageprocessor.IsSVGChildProcess(os.Args[1:]) {
+		os.Exit(imageprocessor.RunAsSVGChildProcess(os.Args[1:]))
+	}
+
+	os.Exit(m.Run())
+}
+
 // testSVG is the SVG the upstream serves in the SVG tests below.
 const testSVG = `<svg xmlns="http://www.w3.org/2000/svg" width="64" height="48">` +
 	`<rect width="64" height="48"/></svg>`
@@ -38,12 +50,15 @@ func startSVGUpstream(t *testing.T) (*httptest.Server, *atomic.Int64) {
 // TestImageProxyServesSVGAsItIs requests an SVG source in its own format
 // (orig) at the orig size through pixa's router, upstream fetcher, image
 // processor and cache, twice. Both answers are the SVG itself, never another
-// format, the second from the cache; the upstream is asked once. Scripts in
+// format, the second from the cache; the upstream is asked once. Both carry
-// the SVG cannot run, as the Content-Security-Policy allows no inline
+// the Content-Security-Policy of an SVG response in place of the
-// script. orig at another size is refused with 400.
+// middleware's. orig at another size is refused with 400.
 func TestImageProxyServesSVGAsItIs(t *testing.T) {
 	t.Parallel()
 
+	const wantPolicy = "default-src 'none'; style-src 'unsafe-inline'; " +
+		"img-src data:; frame-ancestors 'none'; sandbox"
+
 	upstream, requests := startSVGUpstream(t)
 	s, _, _ := startImageProxy(t, upstream)
 	target := "/v1/image/" + upstreamHost + "/drawing.svg/orig.orig"
@@ -64,10 +79,9 @@ func TestImageProxyServesSVGAsItIs(t *testing.T) {
 		}
 
 		policy := rec.Header().Get("Content-Security-Policy")
-		if !strings.Contains(policy, "script-src 'self'") ||
+		if policy != wantPolicy {
-			strings.Contains(policy, "unsafe-inline") {
+			t.Errorf("GET %s: Content-Security-Policy = %q, want %q", target,
-			t.Errorf("GET %s: Content-Security-Policy = %q, want script-src "+
+				policy, wantPolicy)
-				"'self' and no unsafe-inline", target, policy)
 		}
 	}
 
@@ -89,7 +103,7 @@ func TestImageProxyServesSVGAsItIs(t *testing.T) {
 
 // TestImageProxyRendersSVG requests an SVG source as each raster format
 // through pixa's router, upstream fetcher and image processor. Each answer
-// is an image in that format.
+// is an image in that format, with the middleware's Content-Security-Policy.
 func TestImageProxyRendersSVG(t *testing.T) {
 	t.Parallel()
 
@@ -113,5 +127,11 @@ func TestImageProxyRendersSVG(t *testing.T) {
 			t.Errorf("GET %s: %s, body in %q (%v); want %s", target,
 				rec.Header().Get("Content-Type"), detected, err, format.MIMEType())
 		}
+
+		policy := rec.Header().Get("Content-Security-Policy")
+		if policy != middleware.ContentSecurityPolicyValue {
+			t.Errorf("GET %s: Content-Security-Policy = %q, want %q", target,
+				policy, middleware.ContentSecurityPolicyValue)
+		}
 	}
 }

internal/templates/form_refused.html

@@ -0,0 +1,22 @@
+<!DOCTYPE html>
+<html lang="en">
+<head>
+    <meta charset="UTF-8">
+    <meta name="viewport" content="width=device-width, initial-scale=1.0">
+    <title>Pixa - Form Refused</title>
+    <link rel="stylesheet" href="/static/style.css">
+</head>
+<body class="login">
+    <div class="card">
+        <h1>Form Refused</h1>
+
+        <div class="error">
+            {{.Cause}}
+        </div>
+
+        <p>
+            <a href="/">Back to the start page</a>
+        </p>
+    </div>
+</body>
+</html>