13 Commits
Author SHA1 Message Date
clawbot c2e32d987b Support SVG sources (closes #68)
check / check (push) Successful in 1m58s
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
2026-11-12 04:41:25 +01:00
clawbot 20874ba2af Answer 502 for an upstream host with no address or a failed fetch (closes #367)
check / check (push) Canceled after 0s
The image routes answered 500 and logged at error level when the upstream
host had no address, when the fetch failed before the upstream answered,
or when the fetcher refused a redirect. Such a failure is now
ErrInvalidHost or ErrUpstreamRequestFailed, which respondImageError
answers 502 "upstream error" and logs at warn level. A TLS handshake, an
address lookup or a connection that times out is now ErrUpstreamTimeout
and answers 504; its log line keeps the cause. A cancelled fetch or
address lookup is neither ErrUpstreamRequestFailed nor ErrInvalidHost.
README Routes lists these answers.

Model: opus-5-5
2026-11-12 00:25:45 +01:00
clawbot b32077c380 Name the cause on the page for a refused form (closes #358)
check / check (push) Canceled after 0s
The CSRF middleware answered a refused login or generator form with the
library's bare text, such as "Forbidden - origin invalid". It now answers
403 with a page that names the cause and what to do, and logs a warning
with the request ID and the library's reason. A page opened over plain
HTTP with debug off and a form from another host both fail the origin
check; the page tells them apart by the host in the Origin or Referer
header.

Model: opus-5-5
2026-11-11 22:55:39 +01:00
clawbot 9bccaaf85a README Getting Started ends with a signed image request (closes #357)
check / check (push) Canceled after 0s
Getting Started now runs script/bootstrap --cgo before make build, says
that logging in at http://localhost:8080/ needs debug, and ends with a
signed /v1/image/ request for an image on any public HTTPS server. Its
curl exits non-zero when pixa refuses the request.

Model: opus-5-5
2026-11-11 22:40:59 +01:00
clawbot 851a374e53 Test that pixad writes only its own errors to stderr (closes #359)
check / check (push) Canceled after 0s
Both tests run pixad as a child process. They fail against this code:
every start writes the dependency-injection library's event log to
stderr, and a startup error is printed twice inside its frames.

Model: opus-5-5
2026-11-11 22:26:52 +01:00
clawbot 0de6972c2d Run make devserver from environment variables, not a config file (closes #360)
check / check (push) Canceled after 0s
The target mounted config.dev.yml, which nothing creates, so Docker made
a directory in its place and pixad exited. It now passes a new random
PIXA_SIGNING_KEY each run, printed so the developer can log in, and
PIXA_DEBUG=true so the login form works over plain HTTP. The unused
.gitignore entry for config.dev.yml is removed.

Model: opus-5-5
2026-11-11 21:55:58 +01:00
clawbot 092176d917 Delete a negative-cache test that tests nothing (closes #347)
check / check (push) Canceled after 0s
TestProxy_Get_ReturnsErrorForNegativeCachedURL never called Get; it only
checked ErrNegativeCached against itself. The test above it covers Get
returning ErrNegativeCached. Deletion approved by sneak on the issue.

Model: opus-5-5
2026-11-11 16:56:21 +01:00
clawbot 7f87aa17ca Set the expiry in TestHandleImageEnc_MaxAge inside each subtest (closes #352)
check / check (push) Canceled after 0s
The table set the expiry when it was built. The parallel subtests can wait
more than 10 seconds behind other tests on a busy host, so the 60 second
case saw a max-age under 50. The table now holds the TTL, and each subtest
computes the expiry just before generating its token.

Model: opus-5-5
2026-11-11 16:25:44 +01:00
sneak fa2ec3da6a Export cache, eviction, upstream and transform metrics (closes #85)
check / check (push) Successful in 1m30s
New pixa_ metrics, none with labels:
- source cache hits and misses, counted once per variant made or checked;
  a source whose cached file cannot be used is a miss
- cache usage and limit gauges; usage is set each time eviction reads it
- eviction count and bytes, from the size_bytes the deleted row returns
- upstream fetch duration histogram and fetch error counter
- transform duration histogram and an in-progress gauge, both including
  the wait for a processing slot

Removing a damaged file during reconciliation is not counted as an
eviction. README lists every metric; the metrics config comment now says
the pixa_ metrics are measured whether or not /metrics is served.

Model: opus-5-5
2026-11-11 14:32:38 +00:00
sneak a041e73550 Test the eviction, source cache, upstream and transform metrics
The tests check the metrics on a variant hit, on misses that fetch or use
the cached source, on a failed fetch, and on both kinds of eviction. A
source whose cached file is gone must count as a source cache miss. A
transform waiting for a processing slot must count as in progress. The
tests fail until the metrics exist.

Model: opus-5-5
2026-11-11 14:31:03 +00:00
clawbot e34463acf8 Check cached sources with upstream after the cache TTL (closes #69) (#350)
check / check (push) Canceled after 0s
2026-11-11 13:37:15 +01:00
clawbot 1379497897 Keep only open work in TODO.md (closes #348) (#349)
check / check (push) Canceled after 0s
2026-11-11 13:07:16 +01:00
clawbot b3b8408d18 Rewrite README.md sentence by sentence (closes #327) (#345)
check / check (push) Canceled after 0s
2026-11-11 11:37:27 +01:00
58 changed files with 5105 additions and 2740 deletions

No files matched your search

-1
View File
@@ -70,4 +70,3 @@ vendor/
# Local dev configs
config.yml
config.yaml
config.dev.yml
+7 -4
View File
@@ -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 \
pixa:latest
@echo "pixad running at http://localhost:8080"
-e PIXA_SIGNING_KEY="$$key" -e PIXA_DEBUG=true \
pixa:latest >/dev/null && \
echo "pixad running at http://localhost:8080" && \
echo "signing key: $$key"
# Stop dev server
devserver-stop:
+1119 -837
View File
File diff suppressed because it is too large. Load diff
+3 -1396
View File
File diff suppressed because it is too large. Load diff
+13 -2
View File
@@ -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)
}
+3 -2
View File
@@ -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
# are measured and /metrics is served only when both are set.
# Username and password for /metrics, set together (default: unset). pixa
# serves /metrics, and measures HTTP requests, only when both are set. It
# measures the pixa_ metrics either way.
# metrics:
# username: "admin"
# password: "secret"
+1 -1
View File
@@ -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
+43 -2
View File
@@ -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
}
+65
View File
@@ -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)
}
}
+177
View File
@@ -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)
}
+24 -4
View File
@@ -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
+1 -1
View File
@@ -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()
+1 -1
View File
@@ -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()
@@ -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{}{}
+106 -2
View File
@@ -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 {
@@ -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)
}
}
+4 -2
View File
@@ -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),
+85 -1
View File
@@ -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()
+48 -7
View File
@@ -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
// Content-Type names is the upstream's error, not pixa's: the image
// service has logged it as a refused source.
if errors.Is(err, magic.ErrMagicByteMismatch) ||
errors.Is(err, magic.ErrUnknownFormat) ||
errors.Is(err, magic.ErrNotEnoughData) {
// The image service has logged this as a refused source
if isFirstBytesMismatch(err) {
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"
@@ -271,6 +269,12 @@ func (s *Handlers) respondImageError(
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 "+
@@ -280,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 "+
@@ -303,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
@@ -321,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
@@ -403,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))
@@ -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},
{"two-year TTL", time.Now().Add(2 * 365 * 24 * time.Hour), 31536000, 31536000},
{"no TTL", time.Time{}, 31536000, 31536000},
{"60 second TTL", time.Minute, 50, 60},
{"two-year TTL", 2 * 365 * 24 * time.Hour, 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)
}
@@ -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},
@@ -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
@@ -74,3 +74,40 @@ func TestSVGTooThinAnswers415(t *testing.T) {
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")
}
@@ -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)
}
}
@@ -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)
}
+4 -4
View File
@@ -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()
}
+119 -23
View File
@@ -69,7 +69,11 @@ var (
ErrInvalidContentType = errors.New("invalid or unsupported content type")
ErrUpstreamError = errors.New("upstream server error")
ErrUpstreamTimeout = errors.New("upstream request timeout")
ErrTooManyConnections = errors.New("too many concurrent upstream connections")
// 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")
)
// Internal fetcher errors.
@@ -80,8 +84,13 @@ var (
// Fetcher retrieves content from upstream origins.
type Fetcher interface {
// Fetch retrieves the content of the source image.
Fetch(ctx context.Context, source imagerequest.Source) (*FetchResult, error)
// Fetch retrieves the content of the source image. A non-empty
// 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),
}
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)
Header: requestHeaders(ctx, ifNoneMatch, ifModifiedSince),
}
// 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, ErrUpstreamTimeout
}
return nil, upstreamRequestError(err)
}
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
@@ -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)
}
@@ -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)
}
+3 -2
View File
@@ -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 {
@@ -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)
}
}
@@ -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)
}
+171 -70
View File
@@ -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"
@@ -129,6 +133,28 @@ var ErrSVGNotOriginalSize = errors.New(
// 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")
@@ -146,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
@@ -165,6 +195,8 @@ func New(params Params) *ImageProcessor {
maxInputBytes: params.MaxInputBytes,
processingSemaphore: make(chan struct{}, params.MaxConcurrentProcessing),
processingWaitTimeout: ProcessingWaitTimeout,
svgRenderTimeout: SVGRenderTimeout,
maxSVGRenderMemory: MaxSVGRenderMemory,
}
}
@@ -178,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,
@@ -197,11 +230,8 @@ func (p *ImageProcessor) Process(
return nil, err
}
// Input libvips would not load as sourceFormat is refused before it is
// decoded
err = checkInputFormat(data, sourceFormat)
if err != nil {
return nil, err
if sourceFormat == imagerequest.FormatSVG {
return p.processSVG(ctx, data, transform)
}
img, err := loadImage(data, sourceFormat)
@@ -213,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)
@@ -232,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, 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)
@@ -253,8 +266,104 @@ func (p *ImageProcessor) Process(
}
}
// Encode to target format
output, err := p.encode(ctx, img, outputFormat, transform.Quality)
return p.encodeResult(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)
}
@@ -262,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,
@@ -314,14 +423,19 @@ func resolveOutputFormat(
return format
}
// loadImage decodes data and turns the image upright: encode strips the EXIF
// orientation tag, and sizes must be worked out on the upright image. An
// image with a side above MaxInputDimension is ErrInputTooLarge, which guards
// against decompression bombs. An SVG is not checked: only its header has
// been read, and the output checks limit the size it is rendered at.
// loadImage refuses data that libvips would not load as sourceFormat, then
// decodes it and turns the image upright: encode strips the EXIF orientation
// tag, and sizes must be worked out on the upright image. An image with a
// side above MaxInputDimension is ErrInputTooLarge, which guards against
// 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)
@@ -334,8 +448,7 @@ func loadImage(
return nil, fmt.Errorf("failed to auto-rotate: %w", err)
}
if sourceFormat != imagerequest.FormatSVG &&
(img.Width() > MaxInputDimension || img.Height() > MaxInputDimension) {
if img.Width() > MaxInputDimension || img.Height() > MaxInputDimension {
img.Close()
return nil, ErrInputTooLarge
@@ -366,6 +479,19 @@ func svgAsItIs(
}, nil
}
// checkSVGOrigSize returns ErrSVGTooLargeForOrigSize when size is the orig
// size and the SVG source, of width x height, has a side above
// MaxOutputDimension. processSVG calls it after returning orig of the SVG, so
// 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)
}
return nil
}
// svgRenderSize returns the least size in the proportions of width x height,
// an SVG's own size, that covers outputWidth x outputHeight, so that resize
// hardly changes it. Neither side is above MaxInputDimension.
@@ -380,14 +506,13 @@ func svgRenderSize(width, height, outputWidth, outputHeight int) (int, int) {
}
// renderSVG renders the SVG data, whose own size is width x height, at
// svgRenderSize for outputWidth x outputHeight. An SVG with one side more
// than MaxInputDimension times the other is ErrSVGTooThin. 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 renderSVG(
data []byte, width, height, outputWidth, outputHeight int,
// 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)
@@ -396,38 +521,14 @@ func renderSVG(
renderWidth, renderHeight := svgRenderSize(width, height,
outputWidth, outputHeight)
img, err := vips.NewThumbnailWithSizeFromBuffer(data,
renderWidth, renderHeight, vips.InterestingNone, vips.SizeBoth)
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
}
// 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
return loadImage(png, imagerequest.FormatPNG)
}
// acquireSlot takes a slot in processingSemaphore, waiting at most
@@ -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()
@@ -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)
}
}
+224 -14
View File
@@ -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
// refers to an image and an external entity on a local server makes no
// request to that server.
// TestImageProcessor_SVGFetchesNothing checks that rendering an SVG draws no
// image it refers to: one at a URL on a local server, by href or xlink:href,
// 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,29 +167,75 @@ func TestImageProcessor_SVGFetchesNothing(t *testing.T) {
}))
t.Cleanup(server.Close)
pngPath := filepath.Join(t.TempDir(), "image.png")
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,
})
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" ` +
`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"/>` +
`<svg xmlns="http://www.w3.org/2000/svg" width="16" height="12">` +
`<text y="10">&outside;</text></svg>`
_, _, err := processSVG(t, svg, imagerequest.Transform{
// 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 as PNG: error = %v", err)
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_RendersSVGLargerThanMaxInputDimension checks that an
// SVG whose own size is above MaxInputDimension is limited only by the
// 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 ErrOutputTooLarge. The
// 1000000x1000000 one is rendered at a ten-thousandth of its own size.
// 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()
@@ -215,9 +269,9 @@ func TestImageProcessor_RendersSVGLargerThanMaxInputDimension(t *testing.T) {
_, _, err = processSVG(t, svg,
imagerequest.Transform{Format: imagerequest.FormatPNG})
if !errors.Is(err, ErrOutputTooLarge) {
if !errors.Is(err, ErrSVGTooLargeForOrigSize) {
t.Errorf("%s as PNG at its own size: error = %v, want %v", svg,
err, ErrOutputTooLarge)
err, ErrSVGTooLargeForOrigSize)
}
}
}
@@ -261,6 +315,162 @@ func TestImageProcessor_RefusesSVGTooThin(t *testing.T) {
}
}
// 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) {
@@ -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)
}
}
@@ -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")
}
+419 -78
View File
@@ -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
// New. They are kept in memory, so adding to one waits for nothing.
upstreamFetches prometheus.Counter
upstreamFetchBytes prometheus.Counter
transforms prometheus.Counter
// The metrics of upstream fetches and transforms, made and registered by
// 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{
p.upstreamFetches, p.upstreamFetchBytes, p.transforms,
for _, metric := range []prometheus.Collector{
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,
ContentLength: size,
ContentType: contentType,
Content: cached.Content,
ContentLength: cached.Size,
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
// if available.
// processFromSourceOrFetch makes the variant req asks for, from the cached
// 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.
// It counts the fetch with the bytes read from upstream, including when
// reading the response or a later step fails. It fetches nothing while the
// source URL is in the negative cache.
// recordFailedCheck logs a failed check of req's source with upstream, after
// which the image is still served from the cache. It puts the source URL in
// the negative cache, whatever the failure, a timeout included, so upstream
// 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
negHit, err := p.cache.Failure(ctx, req.Source)
if err != nil {
p.log.Warn("negative cache check failed", "error", err)
variant, madeFrom := p.cachedVariantIgnoringTTL(ctx, cacheKey)
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("failed to renew cached variant", "cache_key", cacheKey,
"error", err)
}
default:
p.recordFailedCheck(ctx, req, err)
}
if negHit {
p.log.Debug("negative cache hit",
"host", req.Source.Host,
"path", req.Source.Path,
)
return variant, nil
}
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
// 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() { _ = fetchResult.Content.Close() }()
if fetchResult.StatusCode == http.StatusNotModified {
_ = fetchResult.Content.Close()
p.log.Info("upstream source not modified",
"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
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,
)
p.logUpstreamFetch(ctx, req, fetchResult, fetchBytes)
// 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(
ctx, req, cacheKey, bytes.NewReader(sourceData), sourceFormat, fetchBytes,
return &fetchedSource{
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.
// A fetch that read no bytes is not counted.
func (p *Proxy) incrementUpstreamFetch(fetchBytes int64) {
// incrementUpstreamFetch counts one upstream fetch that read fetchBytes bytes
// and took duration. A fetch that read no bytes is not counted.
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,
&req.Transform)
processResult, err := p.transform(ctx, source, sourceFormat, &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.
func formatETag(key imagerequest.VariantKey) string {
// formatETag returns the quoted ETag of the variant of key: the first
// 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())
}
@@ -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()
@@ -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)
}
}
@@ -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")
}
}
+1 -1
View File
@@ -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),
+341 -55
View File
@@ -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
// least recently used images to keep the cache under its size limit.
// Each image is a file with a row in the database. A source is used, and its
// 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
// registerCounters (see counters.go)
cacheHits prometheus.Counter
cacheMisses prometheus.Counter
// The cache's metrics, made and registered by registerMetrics (see
// 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
// content type, read from the variant file's first bytes. It opens that one
// file and makes no database call. 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,
) (io.ReadCloser, int64, string, error) {
// VariantFile is the open file of a cached variant, as Variant,
// VariantIgnoringTTL and RenewVariant return it.
type VariantFile struct {
// Content reads the file. The caller closes it.
Content io.ReadCloser
// Size is the file's size in bytes.
Size int64
// ContentType is the MIME type of the variant's format, read from the
// file's first bytes.
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
// it in the size accounting. 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).
// SetVariantCheckedAt records checkedAt as when upstream last sent the source
// bytes the cached variant of cacheKey was made from, or answered that they
// had not changed. It sets the variant file's modification time to checkedAt,
// 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)
VALUES (?, ?)
INSERT INTO variant_content (cache_key, size_bytes, checked_at,
upstream_etag, upstream_last_modified)
VALUES (?, ?, ?, ?, ?)
ON CONFLICT(cache_key) DO UPDATE SET
size_bytes = excluded.size_bytes,
last_accessed_at = CURRENT_TIMESTAMP
`, string(cacheKey), size)
last_accessed_at = CURRENT_TIMESTAMP,
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
// 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.
// SourceInfo is what the cache keeps in a cached source's row besides its
// size and access time.
type SourceInfo struct {
// FetchedAt is when the cached bytes were fetched.
FetchedAt time.Time
// 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)
VALUES (?, ?)
INSERT INTO source_content (source_key, size_bytes, fetched_at,
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
`, string(key), size)
last_accessed_at = CURRENT_TIMESTAMP,
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
+13 -5
View File
@@ -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)
-31
View File
@@ -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
}
@@ -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)
}
}
}
+163 -28
View File
@@ -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
// no-op when the cache is disabled.
// tracked usage is at or below the configured MaxBytes limit. It sets the
// 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
// file, so the database never references a deleted file.
// evictVariant removes one variant (see removeVariant) and counts the
// eviction with the size its row recorded.
func (c *Cache) evictVariant(
ctx context.Context, cacheKey imagerequest.VariantKey,
) error {
_, err := c.db.ExecContext(ctx,
`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))
sizeBytes, err := c.removeVariant(ctx, cacheKey)
if err != nil {
return err
}
c.countEviction(sizeBytes)
return nil
}
// evictSourceBlob removes one source: its row first, then its file, as
// evictVariant does for a variant. 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) evictSourceBlob(ctx context.Context, key imagerequest.SourceKey) error {
_, err := c.db.ExecContext(ctx,
`DELETE FROM source_content WHERE source_key = ?`, string(key))
// removeVariant removes one variant: accounting row first, then the
// file, so the database never references a deleted file. It returns the
// size the row recorded, or 0 when the variant had no row.
func (c *Cache) removeVariant(
ctx context.Context, cacheKey imagerequest.VariantKey,
) (int64, error) {
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
// periodic tick thereafter, reconciles the database accounting with the
// removes the expired negative cache rows, and the sources and variants not
// 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)
VALUES (?, ?, ?)
`, string(cacheKey), info.Size(), modTime)
INSERT INTO variant_content (cache_key, size_bytes, last_accessed_at,
checked_at)
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
+6 -4
View File
@@ -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)
}
+21 -8
View File
@@ -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
// missing file is ErrNotFound.
func (s *FileStore) Open(key string) (*os.File, int64, error) {
// Open opens the file for key and returns it with its information, which
// gives its size and its modification time. A missing file is ErrNotFound.
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))
+3 -3
View File
@@ -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)) {
t.Errorf("Open() size = %d, want %d", size, len(content))
if info.Size() != int64(len(content)) {
t.Errorf("Open() size = %d, want %d", info.Size(), len(content))
}
loaded, err := io.ReadAll(r)
+88
View File
@@ -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))
}
+137
View File
@@ -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)
}
}
}
@@ -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)
}
+6 -6
View File
@@ -40,15 +40,15 @@ func TestSourceAndVariant_ReadSVG(t *testing.T) {
t.Fatalf("storing the variant file: %v", err)
}
reader, _, contentType, err := cache.Variant(key)
t.Logf("Variant() content type = %q, error = %v", contentType, err)
variant, err := cache.Variant(key)
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 {
_ = reader.Close()
if variant.Content != nil {
_ = variant.Content.Close()
}
}
+2 -1
View File
@@ -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)
+29 -9
View File
@@ -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
// the SVG cannot run, as the Content-Security-Policy allows no inline
// script. orig at another size is refused with 400.
// format, the second from the cache; the upstream is asked once. Both carry
// the Content-Security-Policy of an SVG response in place of the
// 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'") ||
strings.Contains(policy, "unsafe-inline") {
t.Errorf("GET %s: Content-Security-Policy = %q, want script-src "+
"'self' and no unsafe-inline", target, policy)
if policy != wantPolicy {
t.Errorf("GET %s: Content-Security-Policy = %q, want %q", target,
policy, wantPolicy)
}
}
@@ -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)
}
}
}
+22
View File
@@ -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>