open-orienteering · ellmkay · Sep 24, 2026 · Sep 24, 2026
diff --git a/docs/bugfix-map-tile-cold-render-cloud-timeouts.md b/docs/bugfix-map-tile-cold-render-cloud-timeouts.md
@@ -0,0 +1,135 @@
+# Bugfix: map tiles timing out on Cloud Run after the colour-stack release
+
+**Date:** 2026-09-24
+**Affected:** `oxygen` Cloud Run revision `oxygen-00036-vwj` (image `:edge`,
+commit `7e6f0f9`, [PR #26](https://github.com/open-orienteering/oxygen/pull/26))
+**Symptom:** `/api/map-tile/...` requests dying at 299.99 s with HTTP 504;
+tRPC calls on the same instance 504-ing too; Cloud SQL connector
+handshake failures.
+
+## What happened
+
+The colour-stack release changed the tile format (`TILE_FORMAT = 2`) and
+folded it into the render key, so every tile already in `map_tiles` was
+orphaned on deploy and the first view of each map was a fully cold
+render. That part was expected. What wasn't: the first viewport on the
+`Testkarta` map produced 23 tiles at 36–40 s each and 71 requests that
+Cloud Run killed at its 300 s cap, and a second look 40 minutes later
+did the same. For comparison the *previous* revision had cold-rendered
+the same map that morning — p50 4.9 s, max 14.6 s, zero timeouts.
+
+```
+UTC 15:55  revision 00036 goes live
+UTC 15:56  23 × 200 (36–40 s)   71 × 504 (299.99 s)
+UTC 16:01  55 × 504
+UTC 16:36  23 × 200             90 × 504, 3 × 500
+UTC 16:38  "Cloud SQL connection failed", Prisma "Connection terminated
+           unexpectedly" on user.findUnique — connection budget gone
+```
+
+CPU never went above ~40 %. The instance was not busy; it was waiting.
+
+## Root cause 1 — the OCAD blob was read on every tile request
+
+`ensureEventMapRenderKey()` resolves an event's colour-stack settings and
+render key. Its `select` included `fileData` unconditionally so it could
+compute `file_hash` if missing — but the hash is missing only once per
+upload, and the select ran every time.
+
+On the tile route the helper was called **three times per cache miss**:
+in the handler, again inside `getMapSource`, and again inside
+`maybePreCache` (whose de-duplication flag was set *after* an `await`,
+so a burst of 20 tile requests all passed it). Cache hits called it once
+or twice. `Testkarta` is 9.8 MB, so one uncached viewport moved roughly
+2 GB through a `db-f1-micro` Cloud SQL instance over a pool capped at
+eight connections. Every other query on the instance — including the
+`user.findUnique` behind every authenticated request — queued behind
+those blob transfers. Locally the blob comes off loopback in ~250 ms,
+which is why nothing looked wrong in development.
+
+## Root cause 2 — two sequential rasters, parse-dominated
+
+Each block now rasterises a composite layer and an ink layer. They ran
+one after the other, each taking its own semaphore permit. Measured
+locally on the same map: composite 6.2 s (5.7 s of which is resvg
+*parsing* the 16.7 MB SVG — an 8-pixel-wide render costs the same), ink
+2.1 s. So ~8.5 s per block against ~6.2 s before, and on Cloud Run's
+2 vCPUs with three permits, considerably more.
+
+## Why it queued to 300 s
+
+Cloud Run admits 160 concurrent requests per instance and holds each for
+up to 300 s. The render semaphore allows 3. Nothing between the two said
+"no": every tile request that could not get a permit simply waited, and
+the blob traffic from root cause 1 made every step in front of the
+permit slow as well. Requests piled up until the platform killed them,
+and since they were still holding connections and admission slots while
+they waited, tRPC starved too.
+
+## The fix
+
+1. **Metadata-only reads** (`map-render-cache.ts`). `ensure*RenderKey`
+   and `refresh*RenderKey` select the stack columns only; `file_data` is
+   fetched by a second query solely when `file_hash` is null. A cache
+   hit no longer touches the blob at all.
+2. **One resolution per request** (`map-tiles.ts`). The handler resolves
+   `MapMeta` once and passes it to `getMapSource`, `renderBlock`,
+   `preCacheChunk` and `maybePreCache`. The `preCacheConsidered`
+   check-and-mark now happens before the first `await`.
+3. **Bounded queue → fast 503** (`map-render-limits.ts`, `map-tiles.ts`).
+   `Semaphore.run` takes `maxQueue`; a foreground block that finds
+   `MAP_RENDER_MAX_QUEUE` (default 4) waiters already in line throws
+   `RenderBusyError`, which the route turns into
+   `503 Retry-After: 5, Cache-Control: no-store`. `TileLayer` already
+   honours `Retry-After`, so tiles fill in progressively instead of the
+   request sitting in Cloud Run's admission queue. Background pre-cache
+   work is never refused.
+4. **Parallel rasters under one permit.** Composite and ink render side
+   by side, so a block costs roughly the slower of the two (~3.6 s
+   locally, was ~8.5 s). Memory per permit doubles; the doc's sizing
+   formula is updated.
+
+Adjacent hot paths found in the same sweep:
+
+- `course.mapFileInfo` selected `fileData` to report `.length` — every
+  page load downloaded the map. Now `octet_length(file_data)` in SQL.
+- `course.mapMetadata` re-read and re-parsed the OCAD on every call to
+  work out what an `auto` profile resolved to. The answer is a function
+  of the render key; it is now memoised per key (`map-profile-cache.ts`).
+
+## Before / after (local, same 9.8 MB map, zoom 16)
+
+| | Before | After |
+|---|---|---|
+| Cache hit | ~250 ms + 9.8 MB from DB | 7–9 ms, no blob |
+| Cold block | ~8.5 s (sequential rasters) | ~3.6 s |
+| First block ever on an instance | ~16 s (estimated from the step timings) | ~13.5 s (OCAD parse + 2 × `ocadToSvg` dominate) |
+| 20-tile burst over 5 uncached blocks | unbounded wait | 10.8 s, all 200 (queue depth ≤ 4) |
+| Surplus requests when the queue is full | wait for 300 s → 504 | immediate 503, retried after 5 s |
+
+## Tests
+
+- `map-render-cache.test.ts` — the helpers never select `fileData` when
+  a hash is stored; exactly one blob read when it is not.
+- `map-render-limits.test.ts` — `maxQueue` semantics: refuses foreground
+  beyond the bound, never refuses background, unbounded when unset.
+- `integration/map-tiles.test.ts` — four concurrent uncached blocks with
+  `MAP_RENDER_MAX_QUEUE=0`: permits' worth of 200s, the rest 503 with the
+  right headers, and the refused tile renders on retry.
+- `integration/course-maps.test.ts` — `mapFileInfo.size` equals the
+  fixture's byte length; `mapMetadata` resolves the same profile across
+  calls.
+
+## Operational notes
+
+- A render-key change is a full cache invalidation. Deploy it off-peak
+  or pre-warm; since tiles are content-addressed, rows rendered on any
+  machine for the same key are valid in production. See "Deploying a
+  render-key change" in [map-tile-rendering.md](map-tile-rendering.md).
+- If tiles 503 continuously rather than briefly, the renderer is
+  genuinely under-provisioned for the load — raise
+  `MAP_RENDER_CONCURRENCY` (CPU permitting) or `MAP_TILE_BLOCK_TILES`
+  (memory permitting), not `MAP_RENDER_MAX_QUEUE`.
+- The 504s on unrelated tRPC calls during the incident were starvation,
+  not bugs in those routes; the same pattern appears in
+  [bugfix-cloud-sql-handshake-eof.md](bugfix-cloud-sql-handshake-eof.md).
diff --git a/docs/deploy-gcp-cloud-run.md b/docs/deploy-gcp-cloud-run.md
@@ -288,13 +288,25 @@ image ships `postgresql-client`.
 - **Map tile memory.** The renderer rasterises one *window* — the region
 covered by a block of tiles — per render, so peak memory follows the
 block size rather than the map size. With the defaults (4×4 tiles,
-2× supersampling, 2 concurrent renders) that is a few hundred MB for any
-map. The knobs are in `packages/api/src/map-render-limits.ts` and all
-have env overrides (`MAP_TILE_BLOCK_TILES`, `MAP_TILE_SUPERSAMPLE`,
-`MAP_RENDER_CONCURRENCY`, `MAP_SVG_CACHE_EVENTS`,
+2× supersampling, 2 concurrent renders, composite + ink side by side)
+that is roughly 600 MB for any map. The knobs are in
+`packages/api/src/map-render-limits.ts` and all have env overrides
+(`MAP_TILE_BLOCK_TILES`, `MAP_TILE_SUPERSAMPLE`,
+`MAP_RENDER_CONCURRENCY`, `MAP_RENDER_MAX_QUEUE`, `MAP_SVG_CACHE_EVENTS`,
 `MAP_WINDOW_MAX_PIXELS`); none needs setting in normal operation.
 The 4 GiB allocation is headroom for parsing a large club OCAD into an
 SVG DOM, which still spikes, not for the tiles themselves.
+- **Tile requests never wait longer than the queue bound.** Cloud Run
+admits 160 requests per instance and holds each for up to 300 s, while
+the renderer runs 3 blocks at a time. Left unbounded, a cold viewport
+queued past the cap and every tile 504'd while the waiting requests
+starved tRPC of connections (September 2026, see
+[bugfix-map-tile-cold-render-cloud-timeouts.md](bugfix-map-tile-cold-render-cloud-timeouts.md)).
+The route now refuses with `503 Retry-After: 5` once
+`MAP_RENDER_MAX_QUEUE` (4) blocks are already waiting; the client backs
+off and the viewport fills in progressively. Brief 503 bursts right
+after a render-key change are expected; a steady stream means the
+renderer is under-provisioned for the load.
 - **`--cpu=2` and `MAP_RENDER_CONCURRENCY=3`.** Tile rendering is the
 only genuinely CPU-bound thing the service does, and on a single
 throttled vCPU a fresh club map took minutes to fill — the render

diff --git a/docs/map-tile-rendering.md b/docs/map-tile-rendering.md
@@ -123,12 +123,43 @@ map bug: unrelated queries time out while someone pans a map.
 | `map_tiles` table | Shared | The real cache. Written with `ON CONFLICT DO NOTHING`, so concurrent renders of the same block across instances are harmless. |
 | SVG cache | Per process | Parsed map SVGs, `MAP_SVG_CACHE_EVENTS` of them. Amortises the ~70 ms parse and the OCAD read. |
 | In-flight block map | Per process | A viewport fetches ~20 tiles at once; they collapse onto one render per block. |
-| Render semaphore | Per process | Bounds concurrent rasterisations (`MAP_RENDER_CONCURRENCY`). Foreground requests are served before pre-cache work, so background rendering never queues a user behind a whole sweep. |
+| Render semaphore | Per process | Bounds concurrent block renders (`MAP_RENDER_CONCURRENCY`). One permit covers a block's composite **and** ink rasters, run side by side. Foreground requests are served before pre-cache work, so background rendering never queues a user behind a whole sweep. |
+| Queue bound | Per process | At most `MAP_RENDER_MAX_QUEUE` foreground blocks may wait for a permit. Beyond that the tile route answers **503 + `Retry-After: 5`** immediately instead of letting the request sit until the platform kills it. |
 
 Everything above the database is a per-process optimisation, and losing
 it costs time rather than correctness. Nothing in the tile path requires
 a single instance.
 
+### What one tile request costs
+
+The request handler resolves the event's map settings **once** —
+`ensureEventMapRenderKey`, a metadata-only read of `map_files` — and
+threads that object through the render path and the pre-cache kick-off.
+The OCAD blob is read in exactly one place, `loadMapSource`, once per
+render key per process; `ensureEventMapRenderKey` only touches
+`file_data` when `file_hash` is still null (one-off backfill). A cache
+hit is therefore three or four indexed reads and no blob traffic. Keep
+it that way: in September 2026 the same helper selected `file_data`
+unconditionally and was called three times per miss, which pulled ~30 MB
+through Cloud SQL per tile and took the service down — see
+[bugfix-map-tile-cold-render-cloud-timeouts.md](bugfix-map-tile-cold-render-cloud-timeouts.md).
+
+### Where a cold block's time goes
+
+Measured on a 9.8 MB forest map (45 k objects, 16.7 MB composite SVG),
+one 4×4 block at zoom 15–16 on a dev machine:
+
+| Step | Cost | When |
+|---|---|---|
+| `readOcad` + `ocadToSvg` ×2 | ~7.5 s | Once per render key per process (`svgCache`) |
+| resvg composite raster | ~6 s, **~5.7 s of it parsing the SVG** | Every block |
+| resvg ink raster | ~2 s | Every block, in parallel with the composite |
+| Sample 16 tiles + PNG encode + insert | <1 s | Every block |
+
+resvg re-parses the whole SVG per call and exposes no way to reuse the
+tree, so the parse dominates and the block size is the lever: doubling
+`MAP_TILE_BLOCK_TILES` halves parses per tile at ~4× the window memory.
+
 Uploading a map fires `onMapUpload`, which drops the SVG cache entry and
 any in-flight blocks for that **render key**. `applyEventMap`, rotation
 changes, and colour-stack updates recompute `map_files.render_key` and
@@ -163,6 +194,26 @@ is already inside the key; `f=` stays for week-old browser caches.
 Backup / showcase dumps omit `map_tiles` (pure cache; regenerates on
 first view).
 
+### Deploying a render-key change
+
+Anything folded into the key — `TILE_FORMAT`, the colour-stack rules,
+the hash inputs — orphans **every** cached tile on deploy, and the first
+viewer of each map gets a fully cold render at every zoom they touch.
+The overview zooms refill themselves (the progress poll drives
+`preCacheChunk`; see below), but the deep zooms a course setter is
+actually looking at render on demand, block by block, under the queue
+bound. Plan for it:
+
+- Deploy when nobody is setting courses, or accept a few minutes of
+  progressive fill per map with tiles arriving under the 503/retry
+  cadence.
+- Because tiles are content-addressed, rows rendered anywhere are valid
+  everywhere. A dev machine that has already viewed the same map holds
+  rows with the identical `render_key`; copying them into the production
+  `map_tiles` table (`pg_dump -t oxygen.map_tiles --data-only`) is a
+  legitimate pre-warm.
+- Do not bump `TILE_FORMAT` for changes the key already covers.
+
 ## Pre-caching and progress
 
 After the first tile of an event renders, a background pass fills zooms
@@ -227,16 +278,22 @@ machine and a 4 GiB container.
 |---|---|---|
 | `MAP_TILE_BLOCK_TILES` | 4 | Tiles per side per window. Larger amortises the SVG parse further but squares the memory. |
 | `MAP_TILE_SUPERSAMPLE` | 2 | Window density relative to the tiles. 1 is cheaper and slightly softer. |
-| `MAP_RENDER_CONCURRENCY` | 2 | Concurrent rasterisations per process. Cloud Run runs 3 (see `scripts/gcp/deploy.sh`), which its 2 vCPUs can actually overlap. |
+| `MAP_RENDER_CONCURRENCY` | 2 | Concurrent block renders per process (each rasterises composite + ink in parallel). Cloud Run runs 3 (see `scripts/gcp/deploy.sh`), which its 2 vCPUs can actually overlap. |
+| `MAP_RENDER_MAX_QUEUE` | 4 | Foreground blocks allowed to wait for a permit before further tile requests get 503 + `Retry-After`. `0` refuses any queueing. Background (pre-cache) work is never refused. |
 | `MAP_SVG_CACHE_EVENTS` | 4 | Parsed map SVGs held in memory. |
 | `MAP_WINDOW_MAX_PIXELS` | 64M | Backstop against a pathological projection; normally never binds. |
 | `MAP_TILE_PRECACHE` | `on` | `off` disables background pre-rendering. |
 | `MAP_PRECACHE_MIN_ZOOM` / `MAP_PRECACHE_MAX_ZOOM` | 10 / 15 | Pre-cache zoom span. Also the span the progress endpoint reports. |
 | `MAP_PRECACHE_BLOCK_DELAY_MS` | 50 | Pause between pre-cache blocks. |
 
 Peak render memory is roughly
-`4 bytes × (blockTiles × 256 × supersample × √2)² × concurrency`, about
-300 MB at the defaults.
+`4 bytes × (blockTiles × 256 × supersample × √2)² × 2 layers × concurrency`,
+about 600 MB at the defaults.
+
+Sizing `MAP_RENDER_MAX_QUEUE`: a cold block costs 10–15 s on a 2 vCPU
+Cloud Run instance, so with concurrency 3 and four waiters the worst
+case is about a minute — well inside the platform's 300 s request
+timeout, which is what the unbounded queue used to run into.
 
 ## North: georeference, meridian lines, display
 
@@ -289,6 +346,7 @@ Current behaviour (`tile-fetcher.ts` + `tile-retry.ts`):
 |---|---|
 | Empty / out-of-map | Server 200 transparent PNG — normal success |
 | 429 | Back off, honour `Retry-After` when present |
+| 503 (renderer busy) | Server refused to queue the block; retry after `Retry-After` (5 s). Expected during a cold fill, not an error. |
 | 500 / network error | Back off 2s → 10s → 30s → 60s |
 | Concurrency | Max 12 fetches in flight, nearest-to-centre first |
 | Scroll-out | `AbortController` cancels queued/in-flight work |

diff --git a/packages/api/src/__tests__/integration/course-maps.test.ts b/packages/api/src/__tests__/integration/course-maps.test.ts
@@ -169,6 +169,33 @@ afterAll(async () => {
   await disconnect();
 });
 
+describe("map file info and metadata", () => {
+  // `size` is now computed in SQL (octet_length) so the query no longer
+  // ships the blob to the API just to read `.length`.
+  it("reports the uploaded file's exact byte size without fetching it", async () => {
+    const info = await caller.course.mapFileInfo();
+    expect(info).not.toBeNull();
+    expect(info!.fileName).toBe("test.ocd");
+    expect(info!.size).toBe(readFileSync(fixture).byteLength);
+    expect(Number.isInteger(info!.id)).toBe(true);
+  });
+
+  // The auto-profile classification reads and parses the OCAD; the
+  // result is memoised per render key so repeat calls agree and are cheap.
+  it("resolves the auto colour profile consistently across calls", async () => {
+    const first = await caller.course.mapMetadata();
+    const second = await caller.course.mapMetadata();
+    expect(first).not.toBeNull();
+    expect(first!.colorProfile).toBe("auto");
+    expect(["isom", "issprom", "isskiom", "ismtbom"]).toContain(
+      first!.resolvedProfile,
+    );
+    expect(second!.resolvedProfile).toBe(first!.resolvedProfile);
+    expect(second!.resolvedBy).toBe(first!.resolvedBy);
+    expect(second!.renderKey).toBe(first!.renderKey);
+  });
+});
+
 describe("map templates and course maps", () => {
   it("creates, duplicates and applies an event template idempotently", async () => {
     const template = await caller.mapTemplate.create({