Every image request re-encodes: the artwork path is 240x slower than upstream #185

Closed
opened 2026-08-22 21:35:53 +02:00 by Claude · 1 comment
Collaborator

Measured for #117, over the anchor — 56k items, a real household's artwork —
with both servers native, pinned to their own cores, one request set, five
repetitions, and the gate agreeing on 8 of the 10 requests before anything was
timed.

point   metric                  upstream        ours   ours/up
c=1     throughput_per_second    4750.01       19.99      0.004
c=8     throughput_per_second   18613.10       76.21      0.004
c=128   throughput_per_second   18032.52       75.95      0.004
c=1     p50_ms                      0.16       42.39        265×
c=128   p50_ms                      4.28     1637.16        382×
c=128   p99_ms                     24.54     2392.21         97×
        bytes_per_response      284618.2    282512.2       0.99

Two hundred and forty times. And the response is the same picture — the
byte counts agree to within a percent — so nothing is being done differently
except how often it is done.

The shape says which: ours is flat at ~76 rps from c=8 to c=128 while its
latency grows linearly with concurrency, which is a queue in front of a
CPU-bound step. Upstream is flat at ~18,500 rps with a sub-millisecond median,
which is a file being sent.

Upstream resizes once and keeps it — ImageProcessor.ResizedImageCachePath is
<cache>/images/resized-images (upstream/src/Jellyfin.Drawing/ImageProcessor.cs:77,379),
and GetCachePath creates the directory on the way. This server has no such
cache: every request re-encodes. That is also why <cache>/images never exists
here, which is what #179 was about before it turned out the storage report was
answering correctly.

The read-path numbers in report.md are all in our favour. This is the one
that is not, and it is larger than any of them.

Where to start

crates/ephyra-http/src/routes/library/images/ serves these, and the resize
happens per request. Upstream's key is the source path, its date, the requested
dimensions and quality, and the output format — a file per combination under
<cache>/images/resized-images, swept by its own scheduled task.

Worth settling first: whether the cache is written on the request that missed
(upstream's shape) or filled ahead by a task, and what happens to a stale entry
when a picture is replaced — BaseItemImageInfos carries the date the tag is
built from, so a changed picture changes the tag and therefore the key.

How to know it is done

The same run: cargo xtask bench --fixture <anchor> --workload artwork-anchor
over a request set naming rows the anchor holds. A second request for one
picture is served without re-encoding it, the throughput ratio stops being
0.004, and <cache>/images is a directory with files in it.

Two of the ten requests in that run drop for an unrelated reason — a Person
image where upstream answers 404 and we answer with a picture — which wants
its own issue.

House rules

Tests run under cargo nextest; upstream's source is the checkout in
upstream/ at the pin. docs/benchmarks.md is the method, and a result
names the fixture it came from.

Measured for #117, over the anchor — 56k items, a real household's artwork — with both servers native, pinned to their own cores, one request set, five repetitions, and the gate agreeing on 8 of the 10 requests before anything was timed. ``` point metric upstream ours ours/up c=1 throughput_per_second 4750.01 19.99 0.004 c=8 throughput_per_second 18613.10 76.21 0.004 c=128 throughput_per_second 18032.52 75.95 0.004 c=1 p50_ms 0.16 42.39 265× c=128 p50_ms 4.28 1637.16 382× c=128 p99_ms 24.54 2392.21 97× bytes_per_response 284618.2 282512.2 0.99 ``` **Two hundred and forty times.** And the response is the same picture — the byte counts agree to within a percent — so nothing is being done differently except how often it is done. The shape says which: ours is **flat at ~76 rps from c=8 to c=128** while its latency grows linearly with concurrency, which is a queue in front of a CPU-bound step. Upstream is flat at ~18,500 rps with a sub-millisecond median, which is a file being sent. Upstream resizes once and keeps it — `ImageProcessor.ResizedImageCachePath` is `<cache>/images/resized-images` (`upstream/src/Jellyfin.Drawing/ImageProcessor.cs:77,379`), and `GetCachePath` creates the directory on the way. This server has no such cache: every request re-encodes. That is also why `<cache>/images` never exists here, which is what #179 was about before it turned out the storage report was answering correctly. The read-path numbers in `report.md` are all in our favour. This is the one that is not, and it is larger than any of them. ## Where to start `crates/ephyra-http/src/routes/library/images/` serves these, and the resize happens per request. Upstream's key is the source path, its date, the requested dimensions and quality, and the output format — a file per combination under `<cache>/images/resized-images`, swept by its own scheduled task. Worth settling first: whether the cache is written on the request that missed (upstream's shape) or filled ahead by a task, and what happens to a stale entry when a picture is replaced — `BaseItemImageInfos` carries the date the tag is built from, so a changed picture changes the tag and therefore the key. ## How to know it is done The same run: `cargo xtask bench --fixture <anchor> --workload artwork-anchor` over a request set naming rows the anchor holds. A second request for one picture is served without re-encoding it, the throughput ratio stops being 0.004, and `<cache>/images` is a directory with files in it. Two of the ten requests in that run drop for an unrelated reason — a `Person` image where upstream answers `404` and we answer with a picture — which wants its own issue. ### House rules Tests run under `cargo nextest`; upstream's source is the checkout in `upstream/` **at the pin**. `docs/benchmarks.md` is the method, and a result names the fixture it came from.
Author
Collaborator

Fixed in 365cd2c, measured over the anchor with 8 of 8 requests agreeing
before anything was timed.

point   metric                  before      after   upstream   ours/up
c=1     throughput_per_second    19.99    2088.05    4205.84      0.50
c=8     throughput_per_second    76.21    9782.64   18180.46      0.54
c=128   throughput_per_second    75.95   11191.85   17737.74      0.63
c=1     p50_ms                   42.39       0.36       0.19      1.90
c=128   p50_ms                 1637.16      11.34       4.89      2.32
c=128   p99_ms                 2392.21      14.24      25.32      0.56
        bytes_per_response    282512.2   262341.4   265117.9      0.99

147× the throughput at concurrency 128, and 144× off the median latency.
The ratio this issue was opened over — a flat 0.004 at every concurrency — is
now 0.50 to 0.63, and the flatness is gone: throughput climbs with concurrency
the way upstream's does, because the work is a file read rather than a decode.

At the tail we are now faster than upstream: p99 14.24 ms against 25.32 at
c=128, and p90 12.69 against 19.47. Ours is slower at the median and quicker
under load, which is the shape of a cheaper per-request path behind a slightly
slower one.

<cache>/images/resized-images/<first character>/<digest>.jpg holds entries on
both sides after the run — five of ours, ten of upstream's, from the same eight
requests. Ours are fewer because upstream keys on the request's own spelling of
a size and we key on the size actually served, so two spellings of one size
share an entry.

The bytes still differ by a percent, which is the resampler rather than the
cache — crates/ephyra-images/src/scaled.rs measures which half of that
disagrees with upstream.

One thing this does not do: upstream sweeps that directory from a scheduled
task and ours grows without bound.
Filed separately as #188.

The two requests that used to drop — a Person image where upstream answers
404 and we answer with a picture — are not in this request set; that
difference is recorded on #117 and is unrelated.

Fixed in `365cd2c`, measured over the anchor with **8 of 8 requests agreeing** before anything was timed. ``` point metric before after upstream ours/up c=1 throughput_per_second 19.99 2088.05 4205.84 0.50 c=8 throughput_per_second 76.21 9782.64 18180.46 0.54 c=128 throughput_per_second 75.95 11191.85 17737.74 0.63 c=1 p50_ms 42.39 0.36 0.19 1.90 c=128 p50_ms 1637.16 11.34 4.89 2.32 c=128 p99_ms 2392.21 14.24 25.32 0.56 bytes_per_response 282512.2 262341.4 265117.9 0.99 ``` **147× the throughput at concurrency 128, and 144× off the median latency.** The ratio this issue was opened over — a flat 0.004 at every concurrency — is now 0.50 to 0.63, and the flatness is gone: throughput climbs with concurrency the way upstream's does, because the work is a file read rather than a decode. At the tail we are now **faster than upstream**: p99 14.24 ms against 25.32 at c=128, and p90 12.69 against 19.47. Ours is slower at the median and quicker under load, which is the shape of a cheaper per-request path behind a slightly slower one. `<cache>/images/resized-images/<first character>/<digest>.jpg` holds entries on both sides after the run — five of ours, ten of upstream's, from the same eight requests. Ours are fewer because upstream keys on the request's own spelling of a size and we key on the size actually served, so two spellings of one size share an entry. The bytes still differ by a percent, which is the resampler rather than the cache — `crates/ephyra-images/src/scaled.rs` measures which half of that disagrees with upstream. One thing this does not do: **upstream sweeps that directory from a scheduled task and ours grows without bound.** Filed separately as #188. The two requests that used to drop — a `Person` image where upstream answers `404` and we answer with a picture — are not in this request set; that difference is recorded on #117 and is unrelated.
Sign in to join this conversation.
No description provided.