Repository navigation
[pull] main from UsefulSoftwareCo:main - #39
Merged
Merged
Conversation
…rk (#1670) workerd freezes Date.now() until I/O completes, so any delta taken across a request's first I/O silently includes queueing, isolate start and module evaluation. That artifact made every phase before the first await read 0ms and whichever await came first read multi-second, regardless of what it actually did. Await scheduler.wait(0) at handler entry to force the clock forward, and log the delta it absorbs. That delta is the pre-work time; everything measured after it is honest. Temporary, to be reverted.
With the clock synced at entry these deltas are real durations, so they separate 'the Cache API is slow' from 'every outbound subrequest is slow'.
Cache and timer probes come back in single-digit ms while the same requests take 4-6s wall, so local I/O is not the cost. Neither probe leaves the isolate. Time a real outbound subrequest, the class the docs proxy implicates (0.098s direct vs 3-6s through the Worker).
fetch() resolves when headers arrive, so the earlier probe returned ~1ms without ever reading a body. Both genuinely slow operations read one: the docs proxy reads a 179KB page and the JWKS store calls hit.json(). Time headers and body separately on the exact upstream the docs proxy uses, gated to /robots.txt so normal traffic never pays for it.
The standing explanation is that Start's lazy loadEntries import of the 2.56MB server graph costs seconds on the first Start-handled request per isolate. Module evaluation is CPU work, but these requests report 45-72ms CPU against 4s wall, so that does not fit. Wrap fetchHandler to record whether this isolate had already served a Start request, plus the time inside it. Cold slow + warm fast confirms the module load; both slow refutes it.
A handler that performs no I/O leaves Date.now() pinned, so the first run reported handlerMs 0 against 6002ms wall. Sync before and after.
…1677) A cold isolate pays both: evaluating the 2.56MB module graph and building the app's Effect layers for the first time. Those have different fixes. Import the same virtual ids loadEntries uses so its cache finds the module already evaluated, leaving handlerMs to cover only the rest.
Both are pure passthroughs to an external origin — they never touch the router, React, or the Effect app — but they lived in Start's request middleware, so each paid Start's lazy loadEntries import of the whole server graph before it could forward. Measured in production by timing the two costs apart on a cold isolate: the graph import is p50 3.1s while the request's own work is p50 33ms. Essentially every request is cold — worker.dispatch ran 1,666 requests across 1,608 isolates — because /mcp dispatches before fetchHandler and so never warms the graph. A /docs page took 3-6s through the Worker against 0.098s straight from the upstream. Move matching and forwarding into edge/passthrough.ts, which imports neither Start nor any app module, and dispatch it from the Worker entry next to marketing. The middleware wrappers stay registered and now source their matching from the same module, so local dev is unchanged and the two cannot drift. Also reverts the temporary latency probes from server.ts.
Fix Google OAuth service policies
Timing the import apart from the request's own work in production: the loadEntries import is p50 3.1s, the request's work is p50 33ms, and a warm isolate answers in 9-104ms. The same bundle in local workerd serves the same path in ~3ms, so this is a cold-isolate cost on production metal, not slow code. Nearly every page request pays it: /mcp dispatches before fetchHandler, so MCP traffic creates and occupies isolates without ever loading the graph, and worker.dispatch ran 1,666 requests across 1,608 isolates. #1628 warmed on every isolate's first fetch and was reverted because it pulled the SSR graph into every isolate including single-shot MCP ones, taking memory kills from ~500-900 to 3.7k-9.4k per 5min. Wait for evidence the isolate persists instead: warm only after it has served a couple of fetches. START_GRAPH_WARM=false disables without a deploy.
Page latency was p50 19-49ms daily up to 2026-08-16 and 2728ms the day after the 21:20 deploy. Not load: 2026-08-11 served more total traffic (5.43M vs 4.38M) with pages at p50 41ms, so the volume explanation does not hold. What changed is where MCP work runs. The old hibernatable Agent bridge handed /mcp to the DO almost immediately; the v2 stack authenticates and dispatches in the worker, spinning far more worker isolates. /mcp returns before fetchHandler, so those isolates never load the Start graph, and page requests land on them cold paying loadEntries: p50 3.1s, against 33ms for the request's own work and 9-104ms warm. Re-lands #1628. Its revert came during the Aug 17 storm (11.67M requests against a 2.6-4.3M baseline); volume is back to baseline and exceededMemory is currently zero. START_GRAPH_WARM=false disables it.
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 subscribe to this conversation on GitHub.
Already have an account?
Sign in.
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.
See Commits and Changes for more details.
Created by
pull[bot] (v2.0.0-alpha.4)
Can you help keep this open source service alive? 💖 Please sponsor : )