From dcb32ab6973739506cd69158181a15d23aef0027 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Thu, 15 Oct 2026 04:34:08 +0000 Subject: [PATCH 1/6] 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 (https://git.eeqj.de/sneak/pixa/issues/243). Model: opus-5-5 --- .../imageprocessor/deadline_internal_test.go | 90 +++++++++++++++++++ 1 file changed, 90 insertions(+) create mode 100644 internal/imageprocessor/deadline_internal_test.go diff --git a/internal/imageprocessor/deadline_internal_test.go b/internal/imageprocessor/deadline_internal_test.go new file mode 100644 index 0000000..4d35ad0 --- /dev/null +++ b/internal/imageprocessor/deadline_internal_test.go @@ -0,0 +1,90 @@ +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) + } +} -- 2.54.0 From 0e0b4ba6541fac4bbb5857190c870fcdc39c22e6 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Thu, 15 Oct 2026 05:49:04 +0000 Subject: [PATCH 2/6] 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 --- README.md | 20 +++++++++-- TODO.md | 25 ++++++++++--- internal/imageprocessor/imageprocessor.go | 44 ++++++++++++++--------- 3 files changed, 65 insertions(+), 24 deletions(-) diff --git a/README.md b/README.md index eb9685a..ca76e4c 100644 --- a/README.md +++ b/README.md @@ -318,9 +318,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 image or its error, holding no upstream connection or processing slot of their own. A waiting request stops waiting when its own client goes away. The work -goes on for the others even if the first request's client goes away, until that -request's `downstream_timeout` ends. The shared fetch sends the first request's -ID upstream, and the lines logged for the fetch and the transcode carry that ID. +goes on for the others even if the first request's client goes away. The shared +fetch sends the first request's ID upstream, and the lines logged for the fetch +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 address, counting an IPv6 client by its /64; an attempt over the limit is diff --git a/TODO.md b/TODO.md index 97ccf43..62a60c2 100644 --- a/TODO.md +++ b/TODO.md @@ -86,6 +86,21 @@ P2: security: per-origin rate limiting 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 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 `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 @@ -549,11 +564,11 @@ P2: security: per-origin rate limiting 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 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 - nothing; each request counts one miss, and the processing counts its fetch and - transcode once; a panic while processing is reported to Sentry when - `sentry_dsn` is set and becomes an error for every waiting request instead of - stopping pixad; documented in `README.md`. + then, until it ends, which can be after its deadline; a request whose context + has already ended starts nothing; each request counts one miss, and the + processing counts its fetch and transcode once; a panic while processing is + reported to Sentry when `sentry_dsn` is set and becomes an error for every + waiting request instead of stopping pixad; documented in `README.md`. - 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 router root onto a `/v1` subrouter holding `/v1/image/` and `/v1/e/`, where it diff --git a/internal/imageprocessor/imageprocessor.go b/internal/imageprocessor/imageprocessor.go index 92cee8a..4a18aac 100644 --- a/internal/imageprocessor/imageprocessor.go +++ b/internal/imageprocessor/imageprocessor.go @@ -208,7 +208,9 @@ func New(params Params) *ImageProcessor { // Process transforms an image according to the request. When // MaxConcurrentProcessing images are already being processed, it waits up // 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( ctx context.Context, input io.Reader, @@ -290,7 +292,7 @@ func (p *ImageProcessor) Process( } // Encode to target format - output, err := p.encode(img, outputFormat, req.Quality) + output, err := p.encode(ctx, img, outputFormat, req.Quality) if err != nil { 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 // 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 -// one stops when ctx ends, as the rest of Process does not check ctx. +// it back. When ctx has ended by the time it has a slot, it gives the slot +// back and returns ctx's error. func (p *ImageProcessor) acquireSlot(ctx context.Context) (func(), error) { - release := func() { <-p.processingSemaphore } - select { case p.processingSemaphore <- struct{}{}: - return release, nil - default: - } - - select { - case p.processingSemaphore <- struct{}{}: - return release, nil case <-time.After(p.processingWaitTimeout): return nil, ErrTooManyImages case <-ctx.Done(): 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. @@ -527,10 +532,17 @@ func (p *ImageProcessor) resize( 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( - img *vips.ImageRef, format Format, quality int, + ctx context.Context, img *vips.ImageRef, format Format, quality int, ) ([]byte, error) { + err := ctx.Err() + if err != nil { + return nil, err + } + if quality <= 0 { quality = defaultQuality } @@ -540,7 +552,7 @@ func (p *ImageProcessor) encode( // 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. if img.HasICCProfile() { - err := img.TransformICCProfileWithFallback("srgb", "srgb") + err = img.TransformICCProfileWithFallback("srgb", "srgb") if err != nil { return nil, fmt.Errorf("failed to convert to sRGB: %w", err) } -- 2.54.0 From 1b0fa8981e87386b9fadc29616d3ecd5e149aa1d Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Thu, 15 Oct 2026 12:03:53 +0000 Subject: [PATCH 3/6] Test the 503 for a request waiting on a transcode stopped at a deadline 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 --- .../handlers/server_busy_internal_test.go | 38 +++++++++++++++++ .../imageprocessor/deadline_internal_test.go | 24 +++++++++-- .../concurrent_misses_internal_test.go | 42 +++++++++++++++++++ internal/imgcache/service.go | 6 +++ 4 files changed, 106 insertions(+), 4 deletions(-) diff --git a/internal/handlers/server_busy_internal_test.go b/internal/handlers/server_busy_internal_test.go index 2f3471c..58bae9b 100644 --- a/internal/handlers/server_busy_internal_test.go +++ b/internal/handlers/server_busy_internal_test.go @@ -1,6 +1,7 @@ package handlers import ( + "context" "fmt" "log/slog" "net/http" @@ -47,3 +48,40 @@ func TestServerBusyAnswers503(t *testing.T) { } } } + +// TestProcessingTimedOutAnswers503 checks that respondImageError and +// handleImageError, which answer the errors of the two 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. The request's source only goes +// into a log line, so it is left empty. +func TestProcessingTimedOutAnswers503(t *testing.T) { + t.Parallel() + + h := &Handlers{log: slog.New(slog.DiscardHandler)} + err := fmt.Errorf("%w: failed to encode: %w", + imgcache.ErrProcessingTimedOut, context.DeadlineExceeded) + + plain := httptest.NewRecorder() + h.respondImageError(plain, &imgcache.ImageRequest{}, err) + + encrypted := httptest.NewRecorder() + h.handleImageError(encrypted, err) + + for name, rec := range map[string]*httptest.ResponseRecorder{ + "respondImageError": plain, "handleImageError": encrypted, + } { + t.Logf("%s: status = %d, body = %q", name, rec.Code, rec.Body.String()) + + if rec.Code != http.StatusServiceUnavailable { + t.Errorf("%s: status = %d, want %d", + name, 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", + name, rec.Body.String()) + } + } +} diff --git a/internal/imageprocessor/deadline_internal_test.go b/internal/imageprocessor/deadline_internal_test.go index 4d35ad0..1bde965 100644 --- a/internal/imageprocessor/deadline_internal_test.go +++ b/internal/imageprocessor/deadline_internal_test.go @@ -28,11 +28,23 @@ func (r *readerAfterDeadline) Read(p []byte) (int, error) { return r.data.Read(p) } +// 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 +} + // 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. +// deadline has passed before it starts, then without reading its input, or +// while it reads its input. govips gives pixa no way to stop libvips once an +// encode has begun, so Process must not begin one for a request that has +// ended. func TestProcessStopsWhenDeadlinePassed(t *testing.T) { t.Parallel() @@ -45,7 +57,11 @@ func TestProcessStopsWhenDeadlinePassed(t *testing.T) { time.Now().Add(-time.Second)) defer cancel() - checkProcessStopsAtDeadline(ctx, t, bytes.NewReader(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 + for range 100 { + checkProcessStopsAtDeadline(ctx, t, inputNotToBeRead{t: t}) + } }) t.Run("while Process reads its input", func(t *testing.T) { diff --git a/internal/imgcache/concurrent_misses_internal_test.go b/internal/imgcache/concurrent_misses_internal_test.go index ad0e1b2..b81d63a 100644 --- a/internal/imgcache/concurrent_misses_internal_test.go +++ b/internal/imgcache/concurrent_misses_internal_test.go @@ -15,6 +15,7 @@ import ( "github.com/getsentry/sentry-go" "sneak.berlin/go/pixa/internal/httpfetcher" + "sneak.berlin/go/pixa/internal/imageprocessor" "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. type panickingFetcher struct{} diff --git a/internal/imgcache/service.go b/internal/imgcache/service.go index 57f4e82..2ba0e7f 100644 --- a/internal/imgcache/service.go +++ b/internal/imgcache/service.go @@ -129,6 +129,12 @@ func NewService(cfg *ServiceConfig) (*Service, error) { // ErrNegativeCached is returned when a URL is in the 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. // While its source URL is in the negative cache, a cached variant is still // served and a variant not in the cache is still made from a cached source; -- 2.54.0 From 6352b557ec15790f34edaffff0f9cbe13b4fc26c Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Thu, 15 Oct 2026 12:06:38 +0000 Subject: [PATCH 4/6] Answer 503 to a request waiting on a transcode stopped at a deadline A request that waited for another request's transcode got that request's deadline error when the transcode stopped at its deadline, and both image routes answered it 500, though the waiting request's own downstream_timeout had time left. The image service now returns ErrProcessingTimedOut for it, which both routes answer 503 "server busy, try again later", as when pixa is busy. README.md "Routes" says so. Model: opus-5-5 --- README.md | 26 ++++++++++++++------------ TODO.md | 33 ++++++++++++++++++--------------- internal/handlers/image.go | 3 ++- internal/handlers/imageenc.go | 3 ++- internal/imgcache/service.go | 6 ++++++ 5 files changed, 42 insertions(+), 29 deletions(-) diff --git a/README.md b/README.md index ca76e4c..74df4e1 100644 --- a/README.md +++ b/README.md @@ -323,18 +323,20 @@ fetch sends the first request's ID upstream, and the lines logged for the fetch 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 first request's) stops waiting for a processing slot, or, once it has one, +gives it back without beginning to encode. A request waiting for a shared +transcode that stops this way is answered 503 with the error +`server busy, try again later`, though its own `downstream_timeout` may not have +ended. 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 address, counting an IPv6 client by its /64; an attempt over the limit is diff --git a/TODO.md b/TODO.md index 62a60c2..bc5ac49 100644 --- a/TODO.md +++ b/TODO.md @@ -57,6 +57,24 @@ P2: security: per-origin rate limiting expired. The goroutine runs with the disk cache disabled (`cache_max_bytes: 0`) too, where it does nothing else, as the negative cache is used either way. +- 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. A request that waited for a shared transcode stopped at the first + request's deadline is answered 503 `server busy, try again later`, not 500, + though its own `downstream_timeout` may not have ended. 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 a cached variant is served while its source URL is in the negative cache (closes #245): `Get` checked the negative cache before the variant cache, so once a fetch of the source failed, as one does when another variant @@ -86,21 +104,6 @@ P2: security: per-origin rate limiting 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 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 `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 diff --git a/internal/handlers/image.go b/internal/handlers/image.go index aefde8e..9b28da1 100644 --- a/internal/handlers/image.go +++ b/internal/handlers/image.go @@ -240,7 +240,8 @@ func (s *Handlers) respondImageError( } if errors.Is(err, httpfetcher.ErrTooManyConnections) || - errors.Is(err, imageprocessor.ErrTooManyImages) { + errors.Is(err, imageprocessor.ErrTooManyImages) || + errors.Is(err, imgcache.ErrProcessingTimedOut) { s.respondError(w, "server busy, try again later", http.StatusServiceUnavailable) diff --git a/internal/handlers/imageenc.go b/internal/handlers/imageenc.go index 8da6d47..4da08eb 100644 --- a/internal/handlers/imageenc.go +++ b/internal/handlers/imageenc.go @@ -158,7 +158,8 @@ func (s *Handlers) handleImageError(w http.ResponseWriter, err error) { case errors.Is(err, httpfetcher.ErrUpstreamTimeout): s.respondError(w, "upstream timeout", http.StatusGatewayTimeout) case errors.Is(err, httpfetcher.ErrTooManyConnections), - errors.Is(err, imageprocessor.ErrTooManyImages): + errors.Is(err, imageprocessor.ErrTooManyImages), + errors.Is(err, imgcache.ErrProcessingTimedOut): s.respondError(w, "server busy, try again later", http.StatusServiceUnavailable) case errors.Is(err, httpfetcher.ErrInvalidContentType), diff --git a/internal/imgcache/service.go b/internal/imgcache/service.go index 2ba0e7f..1806a42 100644 --- a/internal/imgcache/service.go +++ b/internal/imgcache/service.go @@ -555,7 +555,13 @@ func (s *Service) processAndStore( FitMode: imageprocessor.FitMode(req.FitMode), } + // 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 := s.processor.Process(ctx, source, processReq) + if errors.Is(err, context.DeadlineExceeded) { + return nil, fmt.Errorf("%w: %w", ErrProcessingTimedOut, err) + } + if err != nil { return nil, fmt.Errorf("image processing failed: %w", err) } -- 2.54.0 From 754728bb792d57d47dceffeca2253722e78ca9a0 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Thu, 15 Oct 2026 12:07:12 +0000 Subject: [PATCH 5/6] Say govips gives pixa no way to stop an encode; give AVIF's worst case libvips can stop a running encode, but govips gives pixa no way to ask it to, which README.md "Routes" and the Process and encode comments now say in place of "libvips cannot stop an encode". The avifEffort comment gives its 51 seconds as the RGB time and 110 seconds with an alpha channel as the worst case, as README.md does. Model: opus-5-5 --- README.md | 21 +++++++++++---------- TODO.md | 20 ++++++++++---------- internal/imageprocessor/imageprocessor.go | 20 +++++++++++--------- 3 files changed, 32 insertions(+), 29 deletions(-) diff --git a/README.md b/README.md index 74df4e1..78b5b56 100644 --- a/README.md +++ b/README.md @@ -327,16 +327,17 @@ the first request's) stops waiting for a processing slot, or, once it has one, gives it back without beginning to encode. A request waiting for a shared transcode that stops this way is answered 503 with the error `server busy, try again later`, though its own `downstream_timeout` may not have -ended. 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. +ended. govips gives pixa no way to stop libvips once an encode 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 address, counting an IPv6 client by its /64; an attempt over the limit is diff --git a/TODO.md b/TODO.md index bc5ac49..813b5ab 100644 --- a/TODO.md +++ b/TODO.md @@ -65,16 +65,16 @@ P2: security: per-origin rate limiting slot back, when the context has ended by the time it has the slot or before it encodes. A request that waited for a shared transcode stopped at the first request's deadline is answered 503 `server busy, try again later`, not 500, - though its own `downstream_timeout` may not have ended. 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. + though its own `downstream_timeout` may not have ended. govips gives pixa no + way to stop libvips once an encode 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 a cached variant is served while its source URL is in the negative cache (closes #245): `Get` checked the negative cache before the variant cache, so once a fetch of the source failed, as one does when another variant diff --git a/internal/imageprocessor/imageprocessor.go b/internal/imageprocessor/imageprocessor.go index 4a18aac..ca033e7 100644 --- a/internal/imageprocessor/imageprocessor.go +++ b/internal/imageprocessor/imageprocessor.go @@ -209,8 +209,9 @@ func New(params Params) *ImageProcessor { // MaxConcurrentProcessing images are already being processed, it waits up // to ProcessingWaitTimeout for one to finish, then fails with // 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. +// encodes, it returns ctx's error and gives the slot back. govips gives pixa +// no way to stop libvips once an encode has begun, so an encode keeps its +// slot until it finishes. func (p *ImageProcessor) Process( ctx context.Context, input io.Reader, @@ -532,9 +533,9 @@ func (p *ImageProcessor) resize( const defaultQuality = 85 -// 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. +// encode encodes an image to the specified format. govips gives pixa no way +// to stop libvips once an encode has begun, so when ctx has ended encode +// returns ctx's error without beginning one. func (p *ImageProcessor) encode( ctx context.Context, img *vips.ImageRef, format Format, quality int, ) ([]byte, error) { @@ -644,10 +645,11 @@ func exportWebP(img *vips.ImageRef, quality int) ([]byte, error) { // avifEffort is the AVIF effort, from 0 (fastest) to 9; 1 is the lowest // govips can set. With one thread, as pixad runs libvips, 1 takes about 51 -// seconds to save an 8192x8192 image of random pixels, the worst case, -// against the default downstream_timeout of 60 seconds. On an image of -// milder noise, which 1 saves in about 12 seconds, 2 takes nearly a minute -// and libvips' default, 4, takes minutes. +// seconds to save an 8192x8192 RGB image of random pixels, and about 110 +// with an alpha channel, the worst case, against the default +// downstream_timeout of 60 seconds. On an image of milder noise, which 1 +// saves in about 12 seconds, 2 takes nearly a minute and libvips' default, +// 4, takes minutes. const avifEffort = 1 // avifBitdepth is the AVIF bit depth, 8 bits per sample for every image. -- 2.54.0 From 4c3bc19ca0c059ce2ee51422d3094b6af25f9290 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Thu, 15 Oct 2026 14:04:46 +0000 Subject: [PATCH 6/6] Put this PR's TODO.md entry back at the top of Completed Steps The rebase onto next placed it under the entry for the negative cache cleanup, as union merge keeps next's lines first. Model: opus-5-5 --- TODO.md | 36 ++++++++++++++++++------------------ 1 file changed, 18 insertions(+), 18 deletions(-) diff --git a/TODO.md b/TODO.md index 813b5ab..ec06a81 100644 --- a/TODO.md +++ b/TODO.md @@ -30,6 +30,24 @@ P2: security: per-origin rate limiting # Completed Steps +- 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. A request that waited for a shared transcode stopped at the first + request's deadline is answered 503 `server busy, try again later`, not 500, + though its own `downstream_timeout` may not have ended. govips gives pixa no + way to stop libvips once an encode 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 "Running under upaas" in `README.md` tells the operator to set `PIXA_CACHE_MAX_BYTES` (closes #251): it listed the variable as optional, but under upaas the volume is a directory on the host's filesystem. The default, @@ -57,24 +75,6 @@ P2: security: per-origin rate limiting expired. The goroutine runs with the disk cache disabled (`cache_max_bytes: 0`) too, where it does nothing else, as the negative cache is used either way. -- 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. A request that waited for a shared transcode stopped at the first - request's deadline is answered 503 `server busy, try again later`, not 500, - though its own `downstream_timeout` may not have ended. govips gives pixa no - way to stop libvips once an encode 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 a cached variant is served while its source URL is in the negative cache (closes #245): `Get` checked the negative cache before the variant cache, so once a fetch of the source failed, as one does when another variant -- 2.54.0