Fix production 5xx: cut per-request CPU under the Workers Free plan limit - #32
Merged
Conversation
The scenario now replays a real recorded browser session instead of a placeholder derived from source. Running it surfaced four harness bugs before any load finding was trusted: - buildWriteBody sent a semester-plan body for every write, so the two transcript writes 400'd. Excluded them in build-scenario.mjs; exclusions are method-aware so the legitimate GET survives. - Only 5xx was logged, so those 4xx were invisible behind a threshold breach. Every unexpected status is logged now, with its own counter. - formatLatency guarded on values.p95 where k6 uses values['p(95)'], printing n/a on every run while the data sat right there. - Tagged sub-metrics were collected and dropped; k6 only emits them when a threshold references the tag, so one is generated per endpoint. A semester-plan 404 is per-account state rather than app health, so those reads carry a responseCallback that keeps the expected 404 out of http_req_failed. Results: at 20 concurrent users the app stays correct — no wrong answers, no lockouts. Two identical runs disagreed on failures (0 and 56), which pins the fault as episodic rather than concurrency-triggered, and corrects an earlier claim in this report that 20 users cannot provoke it. The 56 were all the runtime cancelling hung requests at ~1ms CPU. The latency finding is that p95 is a flat ~2.5s on every endpoint regardless of the work it does, which makes it Pyodide start-up rather than per-endpoint cost — so tuning individual endpoints cannot move it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
verify_cloudflare_config imports tomllib, which is stdlib only from 3.11. On an older interpreter it raised ModuleNotFoundError at import time, so `npm run db:verify-config` and the predeploy:backend hook aborted before running a single check. The gate AGENTS.md requires before every deploy was silently doing nothing locally; it was only noticed because a deploy had to be verified by hand. Falls back to tomli, the same parser backported. CI pins 3.11 so the fallback never fires there. If neither is importable the script now exits with an instruction rather than a traceback, since this runs as a deploy hook where a bare ImportError reads as a broken script. Also removes a stray dev/null directory: a shell redirect created it as a literal path on Windows and Git LFS wrote hook copies into it. The real hooks are in .git/hooks and are untouched. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Two additions and one retraction. scenario.js now mirrors the frontend retry policy from api.ts, so the run reports what a user experienced rather than what the server did. The gap matters: splitting the 56 failures from run 2 by method gives 35 GET (retryable) against 16 PUT, 4 PATCH and 1 POST. Mutations are never retried, so 21 of 56 reached the user with no recourse — a failed semester-plan PUT means the edit did not save. Roughly one hard error per user per session during a bad window. The retraction is larger. Every latency number in phases B and C was measured 6-20 minutes after a deploy, which was not controlled for. Re-running the identical scripts a day later against the same version gives a 105ms median where it was 2620ms, and a 298ms p95 where it was 3073ms. So "p95 is a flat 2.5s, therefore Pyodide start-up is a chronic per-request cost" and "think time makes a single user the pessimal case" are both withdrawn. In steady state this is a 92ms median service. What caused the slow window is not established — association across two paired observations is not mechanism — so it is recorded as an open question with the experiment that would settle it, rather than as a finding. Also adds analyze-recording.mjs, which counts repeat GETs in a recording. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The assumed model - a race in isolate re-use scattering ~5% of requests across all users - does not survive the data that was already on disk. All 56 failures from run 2 carry the same cf.tlsClientRandom, so they came from one TLS connection. Their spacing (3137, 5194, 7592, 5322ms ...) sits entirely inside the 3-8s think-time window, so it is one VU failing on every request it made for five minutes. The path mix matches one VU's itinerary per iteration. A matching cluster exists in production client_error_log: eight different endpoints failing in the same second, all status 0, all at ~3250ms. isolate_identity.py makes the mechanism observable. Twelve requests over one keep-alive connection were served by one isolate, then rotated. So a connection binds to an isolate; when that isolate's event loop wedges, every request on the connection fails until it rotates, and nobody else is affected. Two consequences. Blast radius is "1 user in 20 completely broken, 19 fine" rather than a thin 5% spread. And the retry mitigation likely does not help, because retries reuse the same connection and reach the same dead isolate - so the earlier claim that 35 of 56 were absorbed is probably false. The id has to be generated lazily: at module scope the deploy fails with "Cannot get entropy outside of request context", because module-level code is captured in the Pyodide snapshot and restored into every isolate, which would make the id identical everywhere. Also enables Workers observability, so a failure no longer has to be caught live with wrangler tail. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
scenario.js now reads the x-isolate-* markers, logs the isolate id, its sequence number and age on every failure alongside the last healthy isolate that connection saw, and tracks isolate_seq as a metric. isolate_seq answers the latency question the earlier retraction left open. Under 20 sustained VUs an isolate serves a median of 53 responses before the connection rotates away, so start-up is amortised and the median is 102ms. Five sequential curls with no other traffic produced four distinct isolates for five requests - almost no reuse, and the full cost on nearly every request. So the variable is neither concurrency nor think time but whether a warm isolate exists when the request arrives, which follows recent traffic volume. A deploy destroys every warm isolate at once, which is why measurements taken minutes after one looked like a chronic 2.5s problem. That has an uncomfortable consequence: a study planner with a handful of concurrent students sits in the low-traffic regime most of the day, which is the expensive one. The 92ms median under 20 VUs is not what a lone user at 9pm gets, so the load test flattered the app. Run 4 was clean (1265 requests, 0 failures), leaving 4 runs at 0, 56, 0, 0. The isolate attribution has therefore not yet observed a wedge. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Run 5 at 40 VUs caused a production outage. Eight minutes in, every VU began failing simultaneously with Cloudflare error 1101 and no x-isolate-* headers, meaning the Worker died during Python start-up rather than in application code. The retry policy exhausted against it. It did not self-recover. With the load stopped and no traffic, production alternated 200/500 almost exactly, and every success carried a different isolate id - roughly every other isolate spawn was failing Pyodide init. A redeploy cleared it immediately. Three things follow. There is a concurrency ceiling between 20 and 40 users, since 20 VUs is clean across four runs. Exceeding it is not self-limiting: the Worker degrades and stays degraded until someone redeploys by hand. And this is almost certainly the mode behind the historical production 500s, which the operational notes already say are unwedged by redeploying. This is also a different failure mode from the connection-scoped wedge documented below, which affects one connection and leaves everyone else working. The bisect to locate the ceiling should run against staging, not production. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Bisected on staging at 45 VUs, same Pyodide build as production. probe 1 hello world, no imports 2450 requests, 0 failures probe 2 imports all 28 modules 2422 requests, 0 failures probe 3 no imports, no D1, ~0.9MB body hangs in seconds, 1101 + 1102 Probe 3 contains no application code - it builds a list of dicts and calls json.dumps - and that alone reproduces the fault. So the trigger is constructing and serialising a large response body under concurrency, not the import graph, not Pyodide start-up, not D1, not the router or auth. The earlier inference that our code was uninvolved, drawn from the hung requests showing 0-1ms CPU and no isolate headers, was wrong. The isolate is already under memory pressure from other concurrent large-payload requests, so an arriving request dies at its first await having done nothing itself. The victim and the cause are different requests. That is why /api/catalog/courses?limit=1000&period=all appeared in every sampled failing event: at 1.43MB it is the largest thing the Worker builds, and each VU fetches it on first load. This is fixable here with no upstream dependency - paginate the catalog, cache the serialised body, or precompute it and serve it from R2. The unsafe payload threshold is not yet established; probe 3 broke at ~0.9MB, so it is below 1.43MB and should be bisected before a page size is chosen. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The previous commit's conclusion overstates the evidence. Probes were run back to back without resetting the Worker, and this fault persists and accumulates, so every cross-run comparison was contaminated. The scale of the error: a payload sweep at fixed 45 VUs returned 95.67%, 95.07% and 95.84% hung at 100KB, 300KB and 600KB - flat regardless of size, and lower at 900KB than at 100KB. Not a dose-response, just a worker that was already broken. With no load at all, staging then served 5 of 6 requests as 500. Re-run with a deploy before each measurement, a real dose-response does appear: 0.00% at 10KB, 0.55% at 100KB, 5.36% at 900KB. So payload size contributes, but at ~5%, not ~95%. Caching the serialised body is falsified as a fix. At the same size it is worse than building per request (13.43% vs 5.36%), because faster responses raise throughput and each isolate retains ~1MB permanently. What dominates is progressive degradation. One deploy then three consecutive 45 VU runs gave 44.9%, 53.8%, 79.3% failures - monotonically worse, no self-recovery. The wall: two runs with identical configuration and a passing health check gave 0 and 835 failures. wrangler deploy does not immediately evict running isolates, and five sequential probes sample only one or two of them, so "deploy, see 200s, measure" is not a reset. A validated reset procedure is a prerequisite for any further A/B conclusion, including the probe bisect in the superseded section. Adds SKIP_CATALOG to scenario.js for the in-situ control. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The previous commit asserted that wrangler deploy does not evict running isolates, to explain why two identically configured runs gave 0 and 835 failures. That was an explanation invented to fit an inconsistency, not an observation. x-isolate-id makes it testable. Sampling before and after a deploy: 12 distinct isolates before, 14 after, 2 present in both. The ids are 64-bit random values generated per isolate, so those are the same isolates. So the claim holds in direction but was overstated. A deploy is a partial reset with roughly 17% survival in this sample, not a no-op. It also does not fully explain the discrepancy it was invented for: 17% carry-over should not turn 0 failures into 835. Either damaged isolates attract disproportionate traffic or something else is involved. Recorded as unresolved rather than papered over. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Holding total in-flight requests at 40, payload at 900KB and volume at ~900 requests, and varying only how they are distributed across connections (which pin to isolates): 40 connections x 1 in flight 4.85% hung 5 connections x 8 in flight 75.76% hung 1 connection x 40 in flight 94.43% hung 19x more failures for identical total load. It is load per isolate, not aggregate load. Concurrency and size are each harmless alone. 40 concurrent requests at 2KB is clean; 900KB spread one-per-isolate is 4.85%. What matters is the product, and the threshold is sharp: 4.0MB of concurrent response bytes in one isolate is clean twice, 5.6MB fails 56%, 7.2MB fails 78%. The production trigger is useHistoricalLecturerLookup, which fetches one full catalog per period in parallel via Promise.all. At ~1.43MB per period and 7 periods that is ~10MB requested at once, multiplexed by the browser onto one HTTP/2 connection and therefore one isolate - roughly double the threshold, from a single user opening the app. That matches the production client_error_log cluster exactly: eight requests failing in the same second, seven of them catalog fetches for different periods, all status 0 at ~3250ms. Every step of the chain is measured except the interpretation of the threshold as a memory ceiling; what is measured is the threshold itself. Adds batch-probe.js, which is also the check for any fix: concurrent bytes per isolate must stay under 4MB. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
useHistoricalLecturerLookup fetched every period's full catalog through Promise.all. Each response is ~1.43MB, so seven periods put ~10MB of concurrent response bodies onto one HTTP/2 connection, which pins to one Python Worker isolate. Measured, that isolate hangs above roughly 4MB of concurrent response bytes and stays hung, so every later request from that user fails too. Measured against the real pattern on a Worker with the same runtime: 7 parallel x 1.43MB 75.24% of requests hung serialised x 1.43MB 0.00% 7 parallel x 400KB 0.00% mapWithConcurrency caps in-flight requests instead of serialising, since this runs on session start and seven sequential 1.43MB fetches would be a visible stall. A limit of 2 is ~2.9MB, under the threshold. The helper is a pure utility with tests covering ordering, the peak concurrency bound, the catalog case against the measured threshold, sequential behaviour at limit 1, empty input and an invalid limit. This addresses the trigger, not the underlying fragility: the backend still hangs when enough large responses are concurrent in one isolate, and other callers could reintroduce it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Two numbers committed earlier today are wrong. The per-period catalog payload is ~530KB, not 1.43MB - the larger figure is the period=all response. Seven periods is ~3.7MB, not ~10MB. The mechanism stands but the margin is much tighter than claimed. More seriously, the threshold measured on the minimal probe does not transfer. Running the same batch probe against production's own catalog endpoint hangs 30% of requests at 2 concurrent (~1.1MB), where the minimal probe was clean at 4.0MB. Roughly 4x less headroom. That means the concurrency limit of 2 just shipped in mapWithConcurrency is probably not conservative enough: two concurrent period fetches is ~1.1MB, which is the configuration that hung 30% here. A limit of 1, or a smaller per-period payload, is likely needed. The fix cannot be called sufficient until this is re-measured. Also records two measurements as unreliable rather than reusing them: an attempt to separate payload size from D1 work returned 100% hung with med=0ms, meaning the requests never executed, while production tested healthy either side. The cause was a broken gate in the harness - the wait-until-healthy loop tried six times and then proceeded regardless, so it could never block a run. Any result obtained through it may have started dirty. The gate has to abort, not warn. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The report had become a chronological record with retractions interleaved among current claims, which is hard to resume from. Adds a handoff block at the top holding the current state: what is established with its evidence, what has been retracted and must not be rebuilt on, the four protocol traps that invalidated real work here, the next steps, and the tools. Also commits load-test/payload-probe, the standalone Python Worker used to separate response size from concurrency. It lived in a scratchpad, so the key instrument would have been lost. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The wrong cause was asserted in four places outside the report, where future readers would take it as settled. frontend/src/shared/utils/api.ts justified the retry policy with the claim that a faulting isolate hangs one request then serves the next normally. That premise is disproved: a keep-alive connection stays pinned to one isolate, so a retry can land on the same dead one. The retry is kept - it is cheap and cannot make things worse - but the comment now says the absorption rate is unverified rather than implying it works. load-test/README.md called the Pyodide GIL fault the source of the production 500s and said no change in this repo could fix it. Both wrong: the captured signature is TaskStepMethWrapper, not GIL/PyProxy, and the trigger was our own unbounded Promise.all. frontend/README.md justified calling the Worker directly by claiming service bindings crash Python Workers while external ingress is unaffected. Every hang was observed on direct workers.dev ingress. The default is unchanged, the reasoning is corrected. backend/wrangler.toml described the reverted compatibility-date bump as a fix for workerd#6624; it now records that as the belief at the time. Corrections are left visible rather than deleted, so anyone who acted on the old theory can see what changed. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The previous round of measurements could not distinguish the failure modes because it could only see request outcomes. These three tools read state back out of the isolate while loading it. - health-gate.mjs refuses to let a measurement start on a wedged Worker, and exits non-zero rather than warning. Runs started dirty are what invalidated several earlier results. - isolate-probe.mjs holds one HTTP/2 session, which is one isolate, so state can be set and then measured on the same isolate. It also measures that premise instead of assuming it: sequential requests pin, but the first concurrent batch forks to a second isolate, which silently invalidated the first ballast experiment. - The probe Worker gains ballast (resident memory that is never sent), discard (build the payload but return nothing), bytes (return the body pre-encoded), spin (pure CPU, no body) and a /heap route. Each isolates one variable that the original probe charged together. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Returning a Python `str` from a Worker makes Pyodide convert it at the JS
boundary, and that conversion is by far this Worker's largest CPU cost: about
112 ms of CPU per MB of body. Encoding to UTF-8 in Python first is roughly four
times cheaper for the same bytes on the wire.
Measured on staging with `wrangler tail`:
- probe, 2 MB body: 193 ms CPU as `str`, 44 ms pre-encoded
- real catalog endpoint, ~530 KB: 98.6 ms -> 67.7 ms
- probe, repeated 2 MB responses: dead after 21.5 MB as `str`; pre-encoded
served 249 MB with no failure
That matters because an isolate doing sustained CPU-heavy work is killed with
exceededCpu (1102) and is then permanently dead, returning 1101 "code had hung"
with 0-2 ms CPU to everything routed to it afterwards. The 1101s are the victim
signature, not the cause, which is why earlier sessions concluded this was not a
CPU kill.
Response bytes are unchanged and still UTF-8; verified on the live catalog that
umlauts survive as U+00DC/U+00FC with no replacement characters.
The docs are rewritten around this, including the claims it falsifies: the fault
needs neither concurrency nor a large payload, and it is not memory, not bytes
sent, and not a duty-cycle limit.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This account is on the Workers Free plan, where the documented CPU limit is 10 ms per invocation with "built-in flexibility" for infrequent overages. Measured, that flexibility is a fixed allowance: an isolate is terminated once sum(max(0, cpu_per_request - 10 ms)) reaches about 2000 ms, and it is then permanently dead. One constant explains both shapes of failure. An accidental infinite loop spends the allowance in a single request and dies at exactly 2020 ms; the catalog endpoint spends it 57 ms at a time and dies after 33. Debt at death across six workloads: 2020, 2038, 1917, 1921, 1960, 1904 ms. The decisive pair, both started on verified-fresh isolates: catalog limit=5 at 10.1 ms per request burned 3032 ms of CPU over 300 requests and survived, while limit=50 at 44.9 ms burned only 2467 ms and was dead after 55. Less total CPU killed it. Per-request CPU is the only thing that matters, and work split into sub-10 ms responses accrues no debt at all. That makes the response-encoding fix necessary but not sufficient: it slowed the bleed by ~35 % and extended isolate life from 23 requests to 33. A ten-user cohort still saw 17.3 % failures with it applied, concentrated in the users whose isolate died. Either the account moves to Workers Paid, where the limit is 30 s, or every response has to come in under 10 ms of CPU. cumulative now reports the serving isolate's x-isolate-seq, because a dead isolate can outlive a deploy and a live one carries earlier traffic's debt, which makes "requests until death" meaningless without a verified-fresh start. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Uses death rate on verified-fresh isolates as a CPU meter (cpu ~= 10ms + 2000/rounds), which needs no wrangler tail and costs least for exactly the endpoints that are dangerous. The first-load request, /api/catalog/courses?limit=1000&period=all, costs roughly 350-500 ms of CPU -- about 50x the free-plan per-request limit -- and killed a fresh isolate after 5, 7 and 6 requests across three runs. So roughly every fifth first page load permanently destroys a backend isolate. That is the "20 concurrent users" fragility in one line, and it has nothing to do with concurrency. Everything the app does below ~10 ms of CPU accrues no debt at all and runs indefinitely: /health survived 1400 requests, catalog periods 700, and a 5-course catalog page 300. Also records that single-shot samples measure cold-start cost -- catalog periods reads 58 ms cold and 2.8 ms warm -- so warm medians are required. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The first page load fetches /api/catalog/courses?limit=1000&period=all, which
cost roughly 350-500 ms of CPU. On the Workers Free plan an isolate is killed
once it accumulates about 2000 ms of CPU above the 10 ms per-request limit, so
that single request destroyed a fresh isolate every five or six calls, and a dead
isolate keeps failing every request routed to it. A handful of arriving users was
therefore enough to take isolates down.
Nearly all of that cost is rebuilding an identical answer: the D1 round-trips and
course_catalog._build_catalog_summary, which runs per course, for a catalog that
only changes when someone re-imports it. Caching the already-encoded bytes skips
both the rebuild and the UTF-8 conversion at the Python/JS boundary.
Measured on staging, on verified-fresh isolates:
- period=all went from dying after 5, 7 and 6 requests to surviving 120, with
one isolate serving over 240 -- implied CPU per request ~400 ms -> <=18 ms
- a 10-user cohort doing 30 period=all requests each: 300/300 ok, no user
affected. The same shape against the lighter period=229 endpoint, with only
the encoding fix, failed 17.3 % across 7 of 10 users
Correctness is checked, not assumed: repeated responses are byte-identical, and
24 interleaved requests over four limit/period keys each returned the right
course count, so cache keys do not collide. Searches are deliberately not cached
because their key space is unbounded, and the cache is capped at 8 entries.
Entries live as long as the isolate, so a catalog re-import can lag until isolates
recycle; the endpoint already advertises cache-control: max-age=300. Deploy the
Worker to force it.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Leaving searches uncached left the last big hazard in place. A broad two-character prefix against the whole catalog costs about 230 ms of CPU and killed a fresh isolate every ten requests, and broad prefixes are exactly what users type first, so the expensive responses were also the most repeated ones. The key now includes the normalised search term, so "Info", "info " and "info" share one entry. Because the key space is now caller-controlled, the bound is on bytes (16 MB) rather than entry count: one entry can be 1.5 MB and another 20 KB. A body larger than the whole budget is skipped rather than stored and immediately evicting everything else. Measured on staging, verified-fresh isolate: the worst-case search went from dying at round 10 to surviving 100. Correctness checked across three rounds of four different queries -- each returns its own stable byte-identical result, so keys do not collide. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
/api/me/progress costs 81 ms of CPU and /api/me/favorites 57 ms, so on the Free plan they exhaust an isolate after about 28 and 42 requests. Neither can use the catalog cache: the data is user-specific and changes on edit, so serving a stale copy would be a correctness bug rather than a slow response. Measured on production, because staging cannot validate production-minted sessions -- the two Workers have separate AUTH_TOKEN_SECRETs, which is why /api/me/* answers 401 there while the public catalog still responds. Earlier catalog measurements on staging are unaffected, since that endpoint never checked the cookie. With the catalog cached, one user's first load now costs roughly 160 ms of debt instead of ~500, so an isolate tolerates about a dozen first loads rather than five. Better, not fixed. /api/me/progress issues ~7 sequential D1 queries, which is the next lever if the account stays on Free. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…arts /api/me/progress was reported at 81 ms and /api/me/favorites at 57 ms, and those were used to argue they had become the dominant remaining cost. Both are wrong. Measured over a single reused connection, so every sample lands on the same warm isolate, progress costs 14-20 ms and favorites 4-8 ms. The earlier pass used separate curl invocations. Each opened its own connection and could therefore be served by a different cold isolate, and a cold isolate pays 60-70 ms on its first request. The same confound had already been observed for /api/catalog/periods, which reads 58 ms cold and 2.8 ms warm, and was simply not applied to the production inventory. Favorites is auth plus one query returning ids, which is what prompted the recheck: 57 ms was not a plausible warm cost for that code. This changes the conclusion. A first page load now costs about 13 ms of debt rather than ~160, so an isolate tolerates on the order of a hundred first loads instead of a dozen, and no per-user endpoint stands out as the next thing to optimise. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
fleet now accepts a comma-separated --path and walks it as a mini session, which exercises the cache the way a real mix does instead of hammering one endpoint. Twenty concurrent users, each doing a 20-request session across four catalog endpoints including period=all and the worst-case broad search: 400/400 ok, no user affected. Before the fixes, period=all alone killed a fresh isolate every five requests. The authenticated half of a session is not covered, because staging cannot validate production-minted sessions. Those endpoints were measured individually on production instead and are all at or under about 20 ms warm. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fix the production 5xx: cut per-request CPU on the Workers Free plan
Root cause
This account is on the Workers Free plan, where the CPU limit is 10 ms per
invocation with documented "flexibility" for infrequent overages. Measured, that
flexibility is a fixed allowance:
Those 1101s are the victim signature, not the cause, which is why earlier
sessions concluded this was not a CPU kill. One constant explains both shapes:
an accidental infinite loop spends the whole allowance in one request and dies at
exactly 2020 ms; the catalog endpoint spends it ~58 ms at a time and dies after
33. Debt at death across six workloads: 2020, 2038, 1917, 1921, 1960, 1904 ms.
Decisive pair, both on verified-fresh isolates:
limit=5limit=50Less total CPU killed it. Per-request CPU is everything; cumulative CPU is
irrelevant. Work split into sub-10 ms responses accrues zero debt.
The changes
http_utils.json_response).Returning a Python
strmakes Pyodide convert it at the JS boundary at~112 ms per MB. Same bytes on the wire, ~4x less CPU.
(
services/catalog_response_cache.py), keyed on limit, period and normalisedsearch term, bounded by bytes (16 MB) rather than entry count. The catalog
is a snapshot that only changes on re-import, so rebuilding it per request —
D1 round-trips plus
_build_catalog_summaryper course — was pure waste.Measured effect (staging, verified-fresh isolates)
period=all(every first load)q=in&period=allCorrectness
course count — keys do not collide.
Üsurvives as U+00DC, noreplacement characters.
One pre-existing failure,
test_client_error_log_migration, is a local SQLiteversion issue (
unknown function: unixepoch()), unrelated to this branch.What this does not fix
Per-user endpoints cannot use this cache — the data changes on edit, so a stale
answer would be a correctness bug. Warm, they are already cheap:
/api/me/progress14–20 ms,/api/me/favorites4–8 ms. A first page load nowcosts ~13 ms of debt instead of ~500.
Worth deciding separately: Workers Paid raises the per-invocation limit from
10 ms to 30 s and would remove this failure class outright, with no code. This PR
buys headroom inside a limit that is not meant for this workload.
Also in this branch
Diagnostic tooling used to reach the above, and documentation corrections.
load-test/health-gate.mjsaborts a measurement on a wedged Worker;load-test/isolate-probe.mjsdrives one isolate over a single HTTP/2 session andrefuses to measure on an isolate that already carries CPU debt. Several earlier
theories are retracted in
docs/load-test-2026-08.mdwith the experiments thatfalsified them: memory/ballast, concurrency, payload size, cumulative bytes, and
duty cycle.
🤖 Generated with Claude Code