Author SHA1 Message Date
sneak bd38f29254 Test the 503 for a request waiting on a transcode stopped at a deadline
check / check (push) Canceled after 0s
A request that waited for another request's transcode, stopped at that
request's deadline, must get ErrProcessingTimedOut, which both image
routes answer 503. Declares that error so the tests build. Also tests
that Process, past its deadline before it starts, never reads its input.

Model: opus-5-5
2026-10-15 08:26:30 +00:00
clawbot 639a86a4a8 Stop a transcode whose request has ended before it encodes (closes #243)
Process looked at its context only while it waited for a processing
slot, so a transcode went on decoding and encoding, holding its slot,
however long after its request's downstream_timeout that took.
acquireSlot now gives the slot back and returns the context's error
when the context has ended by the time it has a slot, and encode
returns that error without beginning. libvips cannot stop an encode
once it has begun, so that encode keeps its slot until it finishes.
README.md gives how long that can take per output format at the 8192
limits and no longer says the work stops when downstream_timeout ends;
TODO.md is corrected the same way.

Model: opus-5-5
2026-10-15 07:44:23 +00:00
clawbot 7789701831 Test that Process stops once its deadline has passed
Process looks at its context only while it waits for a processing
slot, so a request whose deadline has passed, before Process starts or
while it reads its input, still has its image decoded and encoded while
it holds the slot. The new test fails until Process returns
context.DeadlineExceeded in both cases and gives the slot back
(#243).

Model: opus-5-5
2026-10-15 07:44:23 +00:00
10 changed files with 284 additions and 267 deletions
+22 -14
View File
@@ -198,11 +198,9 @@ path under `/v1/` answers 200, in maintenance mode too.
redirects to, is `localhost`, ends in `.localhost` or `.local`, or has an redirects to, is `localhost`, ends in `.localhost` or `.local`, or has an
address in a blocked network (see `blocked_networks`); 429 over address in a blocked network (see `blocked_networks`); 429 over
`image_requests_per_minute` (below); 415 when the upstream answers with a `image_requests_per_minute` (below); 415 when the upstream answers with a
`Content-Type` that is not one of the source formats (below), with a body `Content-Type` that is not one of the source formats (below), or with an image
whose first bytes are not those of the format its `Content-Type` names, or whose first bytes libvips reads as another format; 502 when the upstream
with an image whose first bytes libvips reads as another format; 502 when the answered with an error status, and for 5 minutes after that for the same
upstream answered with an error status, and for 5 minutes after that, or after
a body whose first bytes are not those of its `Content-Type`, for the same
source URL; 503 when pixa is busy or in maintenance mode; 500 for any other source URL; 503 when pixa is busy or in maintenance mode; 500 for any other
failure. failure.
- `GET` or `HEAD` `/v1/e/<token>/<name>` — an image through an encrypted URL - `GET` or `HEAD` `/v1/e/<token>/<name>` — an image through an encrypted URL
@@ -281,12 +279,8 @@ above 8192.
The source image may be JPEG, PNG, GIF, WebP, AVIF or JPEG XL. The upstream's The source image may be JPEG, PNG, GIF, WebP, AVIF or JPEG XL. The upstream's
`Content-Type` must name its format, and the image's first bytes must match it. `Content-Type` must name its format, and the image's first bytes must match it.
An upstream answering with any other `Content-Type`, SVG included, is refused An upstream answering with any other `Content-Type`, SVG included, is refused
with 415. So is a body whose first bytes are not those of the format its with 415, and so is an image whose first bytes libvips reads as another format,
`Content-Type` names, such as a JPEG sent as `image/png`, text sent as an image, such as an SVG whose first bytes pass the check for AVIF.
or an empty body. pixa then does not fetch that source URL again for 5 minutes,
and answers 502 for it meanwhile, as after an upstream error status. An image
whose first bytes libvips reads as another format, such as an SVG whose first
bytes pass the check for AVIF, is refused with 415 too.
With the format `auto`, pixa chooses the format for each request from its With the format `auto`, pixa chooses the format for each request from its
`Accept` header, in this order: `Accept` header, in this order:
@@ -319,9 +313,23 @@ cache at once, they share one upstream fetch (or one read of the cached source)
and one transcode: the first request does the work, and the others wait for its and one transcode: the first request does the work, and the others wait for its
image or its error, holding no upstream connection or processing slot of their image or its error, holding no upstream connection or processing slot of their
own. A waiting request stops waiting when its own client goes away. The work own. A waiting request stops waiting when its own client goes away. The work
goes on for the others even if the first request's client goes away, until that goes on for the others even if the first request's client goes away. The shared
request's `downstream_timeout` ends. The shared fetch sends the first request's fetch sends the first request's ID upstream, and the lines logged for the fetch
ID upstream, and the lines logged for the fetch and the transcode carry that ID. and the transcode carry that ID.
A transcode whose request's `downstream_timeout` has ended (for a shared one,
the first request's) stops when it gets its processing slot or before it begins
encoding, and gives the slot back. libvips cannot stop an encode once it has
begun, so an encode keeps its slot until it finishes, which can be after
`downstream_timeout`. The limit of 8192 on each side of the source and of the
output bounds how long that takes. With one libvips thread, as pixad runs it,
encoding 8192x8192 random pixels takes up to about 1 second as JPEG, 15 as PNG,
16 as GIF, 63 as WebP, 110 as AVIF and 96 as JPEG XL, the slowest of 8 or 16
bits per sample, with or without an alpha channel. WebP, AVIF and JPEG XL are
that slow only with an alpha channel: 8-bit RGB takes about 44, 53 and 28
seconds. Decoding such a source adds up to about 11 seconds. A WebP, AVIF or
JPEG XL encode can therefore hold its slot past the default `downstream_timeout`
of 60 seconds.
The login form (`POST /`) is limited to 5 attempts per minute per client The login form (`POST /`) is limited to 5 attempts per minute per client
address, counting an IPv6 client by its /64; an attempt over the limit is address, counting an IPv6 client by its /64; an attempt over the limit is
+20 -14
View File
@@ -30,15 +30,6 @@ P2: security: per-origin rate limiting
# Completed Steps # Completed Steps
- 2026-10-15 a source whose first bytes do not match its `Content-Type` answers
415 (closes #253): a body whose first bytes are not those of the format its
`Content-Type` names, such as a JPEG sent as `image/png`, text, or a body
under 12 bytes, answered 500 on both image routes and was logged as an error
of pixa's, and each request for it fetched the whole body again. Both routes
now answer 415, and the image service logs it at warning level as a refused
source. It also gets a negative cache entry, as an upstream error status does,
so the source URL is not fetched again for 5 minutes and answers 502
meanwhile.
- 2026-10-15 a `:` in the source path or query no longer moves where the path - 2026-10-15 a `:` in the source path or query no longer moves where the path
ends and the query begins (closes #247): the signed data and the cache key ends and the query begins (closes #247): the signed data and the cache key
joined host, path and query with `:` and no escaping, so a URL signed for joined host, path and query with `:` and no escaping, so a URL signed for
@@ -47,6 +38,21 @@ P2: security: per-origin rate limiting
and the query now have each `%` written as `%25` and each `:` as `%3A`; a path and the query now have each `%` written as `%25` and each `:` as `%3A`; a path
and query holding neither are signed and keyed as before. Signature and query holding neither are signed and keyed as before. Signature
Specification in `README.md` says so. Specification in `README.md` says so.
- 2026-10-15 a transcode stops once its request's `downstream_timeout` has
ended, unless it has begun encoding (closes #243): the image processor looked
at its context only while it waited for a processing slot, so an image was
decoded and encoded, holding the slot, however long after its request's
deadline that took. `Process` now returns the context's error, and gives the
slot back, when the context has ended by the time it has the slot or before it
encodes. libvips cannot stop an encode once it has begun, so that encode keeps
its slot until it finishes; the limit of 8192 on each side of the source and
of the output bounds how long that takes. With one libvips thread, 8192x8192
random pixels take up to about 1 second to encode as JPEG, 15 as PNG, 16 as
GIF, 63 as WebP, 110 as AVIF and 96 as JPEG XL, the last three with an alpha
channel, plus up to about 11 seconds to decode the source; `README.md` gives
these times and no longer says the work stops when `downstream_timeout` ends.
The settings of the WebP, AVIF and JPEG XL encoders, which can hold a slot
past the default `downstream_timeout` of 60 seconds, are unchanged.
- 2026-10-15 the example config allowlists no host (closes #249): it allowlisted - 2026-10-15 the example config allowlists no host (closes #249): it allowlisted
`github.com` and `user-images.githubusercontent.com`, where anyone can put an `github.com` and `user-images.githubusercontent.com`, where anyone can put an
image, so a deployment set up as Getting Started says served those images to image, so a deployment set up as Getting Started says served those images to
@@ -510,11 +516,11 @@ P2: security: per-origin rate limiting
cancellation but keeps its deadline, and the others wait for its image or cancellation but keeps its deadline, and the others wait for its image or
error holding no upstream connection or processing slot, and stop waiting when error holding no upstream connection or processing slot, and stop waiting when
their own context ends; the request doing the processing waits for it even their own context ends; the request doing the processing waits for it even
then, up to its deadline; a request whose context has already ended starts then, until it ends, which can be after its deadline; a request whose context
nothing; each request counts one miss, and the processing counts its fetch and has already ended starts nothing; each request counts one miss, and the
transcode once; a panic while processing is reported to Sentry when processing counts its fetch and transcode once; a panic while processing is
`sentry_dsn` is set and becomes an error for every waiting request instead of reported to Sentry when `sentry_dsn` is set and becomes an error for every
stopping pixad; documented in `README.md`. waiting request instead of stopping pixad; documented in `README.md`.
- 2026-09-29 only the image routes send CORS headers (closes #98): the CORS - 2026-09-29 only the image routes send CORS headers (closes #98): the CORS
middleware, with the `access_control_allow_origin` origin, moved from the middleware, with the `access_control_allow_origin` origin, moved from the
router root onto a `/v1` subrouter holding `/v1/image/` and `/v1/e/`, where it router root onto a `/v1` subrouter holding `/v1/image/` and `/v1/e/`, where it
@@ -1,180 +0,0 @@
package handlers
import (
"bytes"
"encoding/json"
"image/color"
"log/slog"
"net/http"
"slices"
"testing"
"testing/fstest"
"time"
"github.com/go-chi/chi/v5"
"sneak.berlin/go/pixa/internal/encurl"
"sneak.berlin/go/pixa/internal/httpfetcher"
"sneak.berlin/go/pixa/internal/imgcache"
)
// mismatchedSourcePath is the path of the source that
// TestFirstBytesNotMatchingContentType serves on allowlistedHost. The mock
// fetcher names a file's Content-Type from its extension, so the source is
// sent as image/png.
const mismatchedSourcePath = "/images/source.png"
// newRoutesFetchingThrough returns both image routes, and the Handlers behind
// them, whose image service fetches through fetcher and has allowlistedHost on
// its allowlist. The handlers and the image service log to log.
func newRoutesFetchingThrough(
t *testing.T, fetcher httpfetcher.Fetcher, log *slog.Logger,
) (*Handlers, http.Handler) {
t.Helper()
cache, err := imgcache.NewCache(setupTestDB(t), imgcache.CacheConfig{
StateDir: t.TempDir(),
NegativeTTL: 5 * time.Minute,
})
if err != nil {
t.Fatalf("imgcache.NewCache() error = %v", err)
}
svc, err := imgcache.NewService(&imgcache.ServiceConfig{
Cache: cache,
Fetcher: fetcher,
SigningKey: testSigningKey,
Allowlist: []string{allowlistedHost},
Logger: log,
})
if err != nil {
t.Fatalf("imgcache.NewService() error = %v", err)
}
encGen, err := encurl.NewGenerator(testSigningKey)
if err != nil {
t.Fatalf("encurl.NewGenerator() error = %v", err)
}
h := &Handlers{log: log, imgSvc: svc, encGen: encGen}
r := chi.NewRouter()
r.Get("/v1/image/*", h.HandleImage())
r.Get("/v1/e/{token}/*", h.HandleImageEnc())
return h, r
}
// mismatchedSourcePlainURL returns the /v1/image/ URL of mismatchedSourcePath
// on allowlistedHost at 50x50 as a JPEG.
func mismatchedSourcePlainURL(*testing.T, *Handlers) string {
return "/v1/image/" + allowlistedHost + mismatchedSourcePath + "/50x50.jpeg"
}
// mismatchedSourceEncURL returns an encrypted /v1/e/ URL, made with h's
// generator, of mismatchedSourcePath on allowlistedHost at 50x50 as a JPEG.
func mismatchedSourceEncURL(t *testing.T, h *Handlers) string {
t.Helper()
token, err := h.encGen.Generate(&encurl.Payload{
SourceHost: allowlistedHost,
SourcePath: mismatchedSourcePath,
Width: 50,
Height: 50,
Format: imgcache.FormatJPEG,
})
if err != nil {
t.Fatalf("Generate() error = %v", err)
}
return "/v1/e/" + token + "/img.jpg"
}
// loggedLevels reads the JSON log lines in logs and returns the messages
// logged at each level.
func loggedLevels(t *testing.T, logs *bytes.Buffer) map[string][]string {
t.Helper()
t.Logf("logged:\n%s", logs.String())
messages := make(map[string][]string)
dec := json.NewDecoder(logs)
for dec.More() {
var line struct {
Level string `json:"level"`
Msg string `json:"msg"`
}
err := dec.Decode(&line)
if err != nil {
t.Fatalf("decoding log line: %v", err)
}
messages[line.Level] = append(messages[line.Level], line.Msg)
}
return messages
}
// TestFirstBytesNotMatchingContentType checks that both image routes answer
// 415 for an upstream body whose first bytes are not those of the format its
// Content-Type names, and log it as a refused source, not as an error of
// pixa's. The next request for that source must answer 502 without fetching
// it again, as after an upstream error status.
func TestFirstBytesNotMatchingContentType(t *testing.T) {
t.Parallel()
bodies := map[string][]byte{
"JPEG sent as image/png": generateTestJPEG(t, 10, 10, color.Black),
"text sent as image/png": []byte("This is just text, not a PNG"),
"body too short to name a format": []byte("short"),
}
// The source's URL on each image route.
sourceURLs := map[string]func(*testing.T, *Handlers) string{
"plain URL": mismatchedSourcePlainURL,
"encrypted URL": mismatchedSourceEncURL,
}
for bodyName, body := range bodies {
for urlName, sourceURL := range sourceURLs {
t.Run(urlName+", "+bodyName, func(t *testing.T) {
t.Parallel()
fetcher := &countingFetcher{
Fetcher: httpfetcher.NewMock(fstest.MapFS{
allowlistedHost + mismatchedSourcePath: &fstest.MapFile{
Data: body,
},
}),
}
var logs bytes.Buffer
h, routes := newRoutesFetchingThrough(t, fetcher,
slog.New(slog.NewJSONHandler(&logs, nil)))
target := sourceURL(t, h)
checkErrorBody(t, sendGet(t, routes, target),
http.StatusUnsupportedMediaType, "unsupported source format")
levels := loggedLevels(t, &logs)
if len(levels[slog.LevelError.String()]) != 0 {
t.Errorf("logged at error level: %q",
levels[slog.LevelError.String()])
}
if !slices.Contains(levels[slog.LevelWarn.String()], "source refused") {
t.Error(`no "source refused" line logged at warning level`)
}
checkErrorBody(t, sendGet(t, routes, target),
http.StatusBadGateway, "upstream error")
if n := fetcher.fetches.Load(); n != 1 {
t.Errorf("upstream fetched %d times, want 1", n)
}
})
}
}
}
-13
View File
@@ -15,7 +15,6 @@ import (
"sneak.berlin/go/pixa/internal/httpfetcher" "sneak.berlin/go/pixa/internal/httpfetcher"
"sneak.berlin/go/pixa/internal/imageprocessor" "sneak.berlin/go/pixa/internal/imageprocessor"
"sneak.berlin/go/pixa/internal/imgcache" "sneak.berlin/go/pixa/internal/imgcache"
"sneak.berlin/go/pixa/internal/magic"
) )
// HandleImage handles the main image proxy route: // HandleImage handles the main image proxy route:
@@ -221,18 +220,6 @@ func (s *Handlers) HandleTooManyRequests() http.HandlerFunc {
func (s *Handlers) respondImageError( func (s *Handlers) respondImageError(
w http.ResponseWriter, req *imgcache.ImageRequest, err error, w http.ResponseWriter, req *imgcache.ImageRequest, 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) {
s.respondError(w, "unsupported source format",
http.StatusUnsupportedMediaType)
return
}
s.log.Error("failed to get image", s.log.Error("failed to get image",
"host", req.SourceHost, "host", req.SourceHost,
"path", req.SourcePath, "path", req.SourcePath,
+1 -5
View File
@@ -15,7 +15,6 @@ import (
"sneak.berlin/go/pixa/internal/httpfetcher" "sneak.berlin/go/pixa/internal/httpfetcher"
"sneak.berlin/go/pixa/internal/imageprocessor" "sneak.berlin/go/pixa/internal/imageprocessor"
"sneak.berlin/go/pixa/internal/imgcache" "sneak.berlin/go/pixa/internal/imgcache"
"sneak.berlin/go/pixa/internal/magic"
) )
// HandleImageEnc handles requests to /v1/e/{token}/* for encrypted // HandleImageEnc handles requests to /v1/e/{token}/* for encrypted
@@ -163,10 +162,7 @@ func (s *Handlers) handleImageError(w http.ResponseWriter, err error) {
s.respondError(w, "server busy, try again later", s.respondError(w, "server busy, try again later",
http.StatusServiceUnavailable) http.StatusServiceUnavailable)
case errors.Is(err, httpfetcher.ErrInvalidContentType), case errors.Is(err, httpfetcher.ErrInvalidContentType),
errors.Is(err, imageprocessor.ErrUnsupportedInputFormat), errors.Is(err, imageprocessor.ErrUnsupportedInputFormat):
errors.Is(err, magic.ErrMagicByteMismatch),
errors.Is(err, magic.ErrUnknownFormat),
errors.Is(err, magic.ErrNotEnoughData):
s.respondError(w, "unsupported source format", s.respondError(w, "unsupported source format",
http.StatusUnsupportedMediaType) http.StatusUnsupportedMediaType)
case errors.Is(err, imageprocessor.ErrOutputTooLarge): case errors.Is(err, imageprocessor.ErrOutputTooLarge):
@@ -1,6 +1,7 @@
package handlers package handlers
import ( import (
"context"
"fmt" "fmt"
"log/slog" "log/slog"
"net/http" "net/http"
@@ -47,3 +48,39 @@ func TestServerBusyAnswers503(t *testing.T) {
} }
} }
} }
// TestProcessingTimedOutAnswers503 checks that both image routes answer 503
// with the server busy error when the image service reports that processing
// stopped at the deadline of the request doing it, wrapped as the service
// wraps it. A request that waited for that processing gets this error while
// its own deadline may have time left.
func TestProcessingTimedOutAnswers503(t *testing.T) {
t.Parallel()
h := &Handlers{log: slog.New(slog.DiscardHandler)}
req := &imgcache.ImageRequest{SourceHost: "img.example.com", SourcePath: "/a.jpg"}
err := fmt.Errorf("%w: failed to encode: %w",
imgcache.ErrProcessingTimedOut, context.DeadlineExceeded)
plain := httptest.NewRecorder()
h.respondImageError(plain, req, err)
encrypted := httptest.NewRecorder()
h.handleImageError(encrypted, err)
for route, rec := range map[string]*httptest.ResponseRecorder{
"/v1/image/": plain, "/v1/e/": encrypted,
} {
t.Logf("%s: status = %d, body = %q", route, rec.Code, rec.Body.String())
if rec.Code != http.StatusServiceUnavailable {
t.Errorf("%s: status = %d, want %d",
route, rec.Code, http.StatusServiceUnavailable)
}
if !strings.Contains(rec.Body.String(), "server busy, try again later") {
t.Errorf("%s: body = %q, want the server busy error",
route, rec.Body.String())
}
}
}
@@ -0,0 +1,118 @@
package imageprocessor
import (
"bytes"
"context"
"errors"
"io"
"testing"
"time"
)
// readerAfterDeadline is a Process input whose first Read waits until done
// is closed, so the deadline passes after Process has taken its slot and
// before it encodes.
type readerAfterDeadline struct {
data *bytes.Reader
done <-chan struct{}
waited bool
}
func (r *readerAfterDeadline) Read(p []byte) (int, error) {
if !r.waited {
r.waited = true
<-r.done
}
return r.data.Read(p)
}
// TestProcessStopsWhenDeadlinePassed checks that Process returns
// context.DeadlineExceeded, and holds no slot afterwards, when its context's
// deadline has passed before it starts or while it reads its input. libvips
// cannot stop an encode once it has begun, so Process must not begin one for
// a request that has ended.
func TestProcessStopsWhenDeadlinePassed(t *testing.T) {
t.Parallel()
input := createTestJPEG(t, 50, 50)
t.Run("before Process starts", func(t *testing.T) {
t.Parallel()
ctx, cancel := context.WithDeadline(t.Context(),
time.Now().Add(-time.Second))
defer cancel()
checkProcessStopsAtDeadline(ctx, t, bytes.NewReader(input))
})
t.Run("while Process reads its input", func(t *testing.T) {
t.Parallel()
ctx, cancel := context.WithTimeout(t.Context(), 100*time.Millisecond)
defer cancel()
checkProcessStopsAtDeadline(ctx, t, &readerAfterDeadline{
data: bytes.NewReader(input), done: ctx.Done(),
})
})
}
// checkProcessStopsAtDeadline runs Process on input with ctx, whose deadline
// has passed by the time Process could encode, and fails the test unless
// Process returns context.DeadlineExceeded and gives its slot back.
func checkProcessStopsAtDeadline(
ctx context.Context, t *testing.T, input io.Reader,
) {
t.Helper()
proc := New(Params{MaxConcurrentProcessing: 1})
result, err := proc.Process(ctx, input, smallJPEGRequest())
if result != nil {
t.Logf("Process() made a %dx%d image after its deadline passed",
result.Width, result.Height)
_ = result.Content.Close()
}
t.Logf("Process() error = %v", err)
if !errors.Is(err, context.DeadlineExceeded) {
t.Errorf("Process() error = %v, want context.DeadlineExceeded", err)
}
if held := len(proc.processingSemaphore); held != 0 {
t.Errorf("%d slots still held after Process() returned", held)
}
}
// inputNotToBeRead is a Process input that fails the test when it is read.
type inputNotToBeRead struct {
t *testing.T
}
func (r inputNotToBeRead) Read([]byte) (int, error) {
r.t.Error("Process read its input although its deadline had passed")
return 0, io.EOF
}
// TestProcessReadsNoInputOnceDeadlinePassed checks that Process, called with
// a context whose deadline passed before it starts, gives its slot back
// without reading its input. With a slot free, the select in acquireSlot
// takes the slot or sees the ended context at random, so Process is called
// many times.
func TestProcessReadsNoInputOnceDeadlinePassed(t *testing.T) {
t.Parallel()
ctx, cancel := context.WithDeadline(t.Context(),
time.Now().Add(-time.Second))
defer cancel()
for range 100 {
checkProcessStopsAtDeadline(ctx, t, inputNotToBeRead{t: t})
}
}
+28 -16
View File
@@ -208,7 +208,9 @@ func New(params Params) *ImageProcessor {
// Process transforms an image according to the request. When // Process transforms an image according to the request. When
// MaxConcurrentProcessing images are already being processed, it waits up // MaxConcurrentProcessing images are already being processed, it waits up
// to ProcessingWaitTimeout for one to finish, then fails with // to ProcessingWaitTimeout for one to finish, then fails with
// ErrTooManyImages. // ErrTooManyImages. When ctx has ended once Process has a slot, or before it
// encodes, it returns ctx's error and gives the slot back. libvips cannot stop
// an encode once it has begun, so an encode keeps its slot until it finishes.
func (p *ImageProcessor) Process( func (p *ImageProcessor) Process(
ctx context.Context, ctx context.Context,
input io.Reader, input io.Reader,
@@ -290,7 +292,7 @@ func (p *ImageProcessor) Process(
} }
// Encode to target format // Encode to target format
output, err := p.encode(img, outputFormat, req.Quality) output, err := p.encode(ctx, img, outputFormat, req.Quality)
if err != nil { if err != nil {
return nil, fmt.Errorf("failed to encode: %w", err) return nil, fmt.Errorf("failed to encode: %w", err)
} }
@@ -417,25 +419,28 @@ func (p *ImageProcessor) WaitForProcessing(ctx context.Context) int {
// acquireSlot takes a slot in processingSemaphore, waiting at most // acquireSlot takes a slot in processingSemaphore, waiting at most
// processingWaitTimeout for one to free up, and returns the func that gives // processingWaitTimeout for one to free up, and returns the func that gives
// it back. A free slot is taken even when ctx has ended; only the wait for // it back. When ctx has ended by the time it has a slot, it gives the slot
// one stops when ctx ends, as the rest of Process does not check ctx. // back and returns ctx's error.
func (p *ImageProcessor) acquireSlot(ctx context.Context) (func(), error) { func (p *ImageProcessor) acquireSlot(ctx context.Context) (func(), error) {
release := func() { <-p.processingSemaphore }
select { select {
case p.processingSemaphore <- struct{}{}: case p.processingSemaphore <- struct{}{}:
return release, nil
default:
}
select {
case p.processingSemaphore <- struct{}{}:
return release, nil
case <-time.After(p.processingWaitTimeout): case <-time.After(p.processingWaitTimeout):
return nil, ErrTooManyImages return nil, ErrTooManyImages
case <-ctx.Done(): case <-ctx.Done():
return nil, ctx.Err() return nil, ctx.Err()
} }
release := func() { <-p.processingSemaphore }
// select takes the slot even when ctx has ended at the same moment
err := ctx.Err()
if err != nil {
release()
return nil, err
}
return release, nil
} }
// detectFormat returns the format string for a govips image type. // detectFormat returns the format string for a govips image type.
@@ -527,10 +532,17 @@ func (p *ImageProcessor) resize(
const defaultQuality = 85 const defaultQuality = 85
// encode encodes an image to the specified format. // encode encodes an image to the specified format. libvips cannot stop an
// encode once it has begun, so when ctx has ended encode returns ctx's error
// without beginning one.
func (p *ImageProcessor) encode( func (p *ImageProcessor) encode(
img *vips.ImageRef, format Format, quality int, ctx context.Context, img *vips.ImageRef, format Format, quality int,
) ([]byte, error) { ) ([]byte, error) {
err := ctx.Err()
if err != nil {
return nil, err
}
if quality <= 0 { if quality <= 0 {
quality = defaultQuality quality = defaultQuality
} }
@@ -540,7 +552,7 @@ func (p *ImageProcessor) encode(
// libvips' built-in profile; govips' own sRGB path variable is set on // libvips' built-in profile; govips' own sRGB path variable is set on
// first use but read without a lock, so concurrent requests race on it. // first use but read without a lock, so concurrent requests race on it.
if img.HasICCProfile() { if img.HasICCProfile() {
err := img.TransformICCProfileWithFallback("srgb", "srgb") err = img.TransformICCProfileWithFallback("srgb", "srgb")
if err != nil { if err != nil {
return nil, fmt.Errorf("failed to convert to sRGB: %w", err) return nil, fmt.Errorf("failed to convert to sRGB: %w", err)
} }
@@ -15,6 +15,7 @@ import (
"github.com/getsentry/sentry-go" "github.com/getsentry/sentry-go"
"sneak.berlin/go/pixa/internal/httpfetcher" "sneak.berlin/go/pixa/internal/httpfetcher"
"sneak.berlin/go/pixa/internal/imageprocessor"
"sneak.berlin/go/pixa/internal/magic" "sneak.berlin/go/pixa/internal/magic"
) )
@@ -435,6 +436,47 @@ func TestService_Get_ReturnsByItsDeadline(t *testing.T) {
} }
} }
// TestService_Get_WaiterGetsProcessingTimedOut has a request with no deadline
// join the held fetch of a first request with a short one. With the only
// processing slot held, the first request's transcode waits for it until the
// first request's deadline ends, and stops then. The waiting request, whose
// own context has not ended, must get ErrProcessingTimedOut, which the image
// routes answer 503 as when pixa is busy.
func TestService_Get_WaiterGetsProcessingTimedOut(t *testing.T) {
t.Parallel()
svc, fixtures, fetcher := setupHeldFetchService(t)
svc.processor = imageprocessor.New(
imageprocessor.Params{MaxConcurrentProcessing: 1},
)
holdProcessingSlot(t, svc.processor)
const firstTimeout = 500 * time.Millisecond
firstCtx, cancelFirst := context.WithTimeout(t.Context(), firstTimeout)
defer cancelFirst()
first := startGet(firstCtx, svc, photoVariant(fixtures, 85, FitCover))
<-fetcher.started
waiter := startGet(t.Context(), svc, photoVariant(fixtures, 85, FitCover))
time.Sleep(arrivalWait)
fetcher.releaseFetches()
t.Logf("first request: Get() error = %v", (<-first).err)
got := <-waiter
t.Logf("waiting request: Get() error = %v", got.err)
if !errors.Is(got.err, ErrProcessingTimedOut) {
t.Errorf("waiting request: Get() error = %v, want %v",
got.err, ErrProcessingTimedOut)
}
}
// panickingFetcher panics on every fetch. // panickingFetcher panics on every fetch.
type panickingFetcher struct{} type panickingFetcher struct{}
+16 -25
View File
@@ -128,6 +128,12 @@ func NewService(cfg *ServiceConfig) (*Service, error) {
// ErrNegativeCached is returned when a URL is in the negative cache (recently failed). // ErrNegativeCached is returned when a URL is in the negative cache (recently failed).
var ErrNegativeCached = errors.New("request is in negative cache (recently failed)") var ErrNegativeCached = errors.New("request is in negative cache (recently failed)")
// ErrProcessingTimedOut is returned when processing an image stopped because
// the downstream_timeout of the request doing it ended, to that request and to
// every request that waited for its image.
var ErrProcessingTimedOut = errors.New(
"image processing stopped at the deadline of the request doing it")
// Get retrieves a processed image, fetching and processing if necessary. // Get retrieves a processed image, fetching and processing if necessary.
func (s *Service) Get(ctx context.Context, req *ImageRequest) (*ImageResponse, error) { func (s *Service) Get(ctx context.Context, req *ImageRequest) (*ImageResponse, error) {
// Propagate AllowHTTP setting to the request // Propagate AllowHTTP setting to the request
@@ -438,7 +444,13 @@ func (s *Service) fetchAndProcess(
if err != nil { if err != nil {
// Store negative cache for certain errors // Store negative cache for certain errors
if isNegativeCacheable(err) { if isNegativeCacheable(err) {
s.storeNegative(ctx, req, extractStatusCode(err), err) statusCode := extractStatusCode(err)
storeErr := s.cache.StoreNegative(ctx, req, statusCode, err.Error())
if storeErr != nil {
s.log.Warn("failed to store negative cache entry",
"host", req.SourceHost, "path", req.SourcePath, "error", storeErr)
}
} }
return nil, fmt.Errorf("upstream fetch failed: %w", err) return nil, fmt.Errorf("upstream fetch failed: %w", err)
@@ -484,16 +496,9 @@ func (s *Service) fetchAndProcess(
"cipher", fetchResult.TLSCipherSuite, "cipher", fetchResult.TLSCipherSuite,
) )
// Validate magic bytes match content type. A body that does not is the // Validate magic bytes match content type
// upstream's error, so it gets a negative cache entry, as an upstream
// error status does.
err = magic.ValidateMagicBytes(sourceData, fetchResult.ContentType) err = magic.ValidateMagicBytes(sourceData, fetchResult.ContentType)
if err != nil { if err != nil {
s.log.Warn("source refused", "request_id", middleware.GetReqID(ctx),
"host", req.SourceHost, "path", req.SourcePath,
"content_type", fetchResult.ContentType, "error", err)
s.storeNegative(ctx, req, httpStatusUnsupportedMediaType, err)
return nil, fmt.Errorf("content validation failed: %w", err) return nil, fmt.Errorf("content validation failed: %w", err)
} }
@@ -509,19 +514,6 @@ func (s *Service) fetchAndProcess(
) )
} }
// storeNegative stores a negative cache entry for req's source, whose fetch
// failed with err, so the source is not fetched again until the entry
// expires. A failure to store the entry is only logged.
func (s *Service) storeNegative(
ctx context.Context, req *ImageRequest, statusCode int, err error,
) {
storeErr := s.cache.StoreNegative(ctx, req, statusCode, err.Error())
if storeErr != nil {
s.log.Warn("failed to store negative cache entry",
"host", req.SourceHost, "path", req.SourcePath, "error", storeErr)
}
}
// processedVariant is a variant as processAndStore made it. Each request that // processedVariant is a variant as processAndStore made it. Each request that
// shared its processing serves it through a reader of its own. // shared its processing serves it through a reader of its own.
type processedVariant struct { type processedVariant struct {
@@ -630,9 +622,8 @@ func signatureRequest(req *ImageRequest) *signature.Request {
// HTTP status codes for error responses. // HTTP status codes for error responses.
const ( const (
httpStatusBadGateway = 502 httpStatusBadGateway = 502
httpStatusInternalError = 500 httpStatusInternalError = 500
httpStatusUnsupportedMediaType = 415
) )
// isNegativeCacheable returns true if the error should be cached. // isNegativeCacheable returns true if the error should be cached.