Investigate the 30 to 40 second cold start after every production deploy

[charlesrhoward]

Problem

The first request to /api/control/sessions, /api/sandbox and /api/models after a deploy takes 30 to 40 seconds, and /api/github/owners returns one 503. During that window Control shows "No sessions yet". Two deploys on 2026-09-07 reproduced it.

Ruled out: Vercel is on Fluid compute in iad1, Neon is in us-east-1 with suspend_timeout_seconds: 0 (compute never sleeps). No module-scope pool creation or top-level await was found in the Control routes. The likely cause is the size of the import graph: app/api/control/chat/_lib/execute.ts pulls about 25 first-party modules that fan out into the full tool, harness and model-resolver tree, plus Sentry init in instrumentation.ts.

Where

• app/api/control/chat/_lib/execute.ts (import graph root)
• instrumentation.ts:5 (dynamic import of the Sentry server config)
• app/api/models/route.ts:227-243 (six parallel queries, no caching, on the hot path of every picker)

Fix

This is an investigation with a measured outcome, not a guessed change.

1. Measure. Use Vercel's runtime logs or a Sentry transaction on the first request after a deploy and record where the time goes: function init, first DB connection, first query, Sentry init.
2. Report the breakdown in this issue before changing code.
3. Then fix the largest bucket. Likely candidates: lazy-import the tool registry inside the handler instead of at module scope; cache /api/models per user for 60 seconds; warm the function with a post-deploy ping in deploy-production.yml.

Exit criteria

• A comment on this issue with the measured breakdown for one cold request.
• After the fix, first-request latency for /api/control/sessions after a deploy is under 5 seconds, measured the same way and posted here.
• No behaviour change to the routes other than latency.

Out of scope

The UI loading states. Those are covered by the session list and picker issues and should land regardless.

https://claude.ai/code/session_01SQ4nS96XYRztd5w9QkubPf

[charlesrhoward]

Read-only evidence refresh on 2026-10-03, before choosing a latency change:

The sampled production http.server spans for the named endpoint families over the last seven days do not reproduce the reported 30–40 second duration. The slowest recorded GET /api/sandbox in that result was 2,614.7 ms. These are sampled requests, not proof that every cold request meets the target.

One inspectable request at 2026-10-03 12:13:34 UTC, release 532861d6a19f596780194a902e5e39be999d746b:

Recorded span	Duration
GET /api/sandbox server span	2,116 ms
First displayed pg-pool.connect child	167 ms
First displayed neondb query child	54 ms
Function/module initialization	Not separately recorded in this trace
Sentry initialization	Not separately recorded in this trace

Inspect the trace.

The DB children above are individual spans, not an additive attribution of the full request. The trace covers a long browser session, and the request is not established as the first invocation of its deployed function. This is preliminary evidence only: the cold-request breakdown and same-method post-fix measurement remain outstanding. No TTL, warm-up, import or provider configuration changes were made from these samples.

Next measurement should correlate one first invocation with the serving deployment and runtime initialization evidence, then identify the largest measured bucket before changing code.

[charlesrhoward]

Provider-level evidence refresh (2026-10-03): Vercel now identifies real cold starts separately from hot and prewarmed requests. Queried the production project prj_hogvqIeDOeHf1C7e31hCfGmDbiKA with CLI 62.2.0, using the provider schema’s functionStartType dimension.

Route	Cold invocations	Maximum cold TTFB
/api/control/sessions	20	2,071 ms
/api/sandbox	205	2,450 ms

The requested seven-day window was rounded by Vercel to 2026-09-26 00:00 UTC through 2026-10-04 00:00 UTC; nonzero records began September 28. These are provider aggregates grouped by route and start type, not sampled Sentry spans. They do not establish the first authenticated request immediately after a production promotion or separate Sentry startup and DB timing.

Current alias readback: mogplex.com serves READY deployment dpl_HosPr5RqxUEwhJShPaPHJRvF9HkW, commit 74b70f6b769952650540ebf3fca0213f4a7ae0a4. Opening Control loaded the saved sessions successfully. Its initial list request at 22:45:19.337 UTC finished in 1.7 seconds; the displayed middleware invocation was explicitly Hot. Subsequent session requests were fast. This is a live operational check, not a qualifying cold measurement.

The retained evidence does not reproduce the old 30–40 second symptom. No performance patch was selected, and the original exit criteria remain open: an identified cold request with startup/Sentry/DB attribution, followed by the same-method first-request measurement. Avoid adding caching or warm-up writes from these aggregates alone.

[charlesrhoward]

Measured an identified production cold invocation before selecting a performance change:

• Deployment dpl_HosPr5RqxUEwhJShPaPHJRvF9HkW, release 74b70f6b769952650540ebf3fca0213f4a7ae0a4.
• Authenticated GET /api/control/sessions?order=id, 2026-10-03 22:45:19.337 UTC, request pmb6l-1791067519337-854fe2027fcc, HTTP 200.
• The function Fluid details report Cold (509 ms), invocation 01M41Z2YDE7Q7C2GGR7NC2S05Z; the middleware start type is a separate measurement.
• Vercel function execution: 898 ms; middleware execution: 15 ms; response finished in 1.7 seconds. The metric query reports maximum cold TTFB 1,614 ms for this route/deployment in the 22:00 UTC hour.

Vercel request

The matching Sentry server span runs 22:45:20.142–22:45:21.024 UTC, 882 ms, with no errors. Its auth-related default span is 566 ms, the first displayed pg-pool.connect is 60 ms, and the first displayed neondb query is 5 ms. These nested spans must not be added to the enclosing execution duration; the connect span is pool acquisition and may include connection establishment.

This corrects the earlier limitation: the initial list request was confirmed cold at the function layer, even though middleware was hot. It already meets the under-five-second target. The original 30–40-second symptom is not reproduced by this invocation or the retained provider cold aggregates. Today's deployment also serves successful Control requests, but the inspected current request is hot and is not a replacement cold measurement.

Remaining attribution gap: Sentry configuration import and Sentry.init are not timed separately inside startup. Next step is a measurement-only patch that logs those two durations once per server initialization, then verifies the first Control request after the protected production release with the same Vercel/Sentry method. Configuration import includes init; SDK static module loading occurs before these application clocks and remains inside the provider startup bucket. No cache, warm-up, import refactor, auth change, or database change is justified by the current measurements.

[charlesrhoward]

PR #579 merged and deployed through the protected workflow. mogplex.com serves READY dpl_91zostmZrWq46kRwBZ9t5HJwNQu5, commit 0dff7e90595ab648c5606b7f69468b8878f87ec1; the matching Trigger deployment and production smoke checks passed.

The earliest retained Control request on this deployment is 47x5r-1791137971021-cf01f5331390, at 2026-10-04 18:19:31.021 UTC: HTTP 200, 1.2 s provider response duration, function Hot, 557 ms function execution. Chrome blocked rendering this direct API navigation after it reached the server; that browser result is not an application failure.

The app's initial list request lkf2t-1791138006284-1c7d2cb20156, 18:20:06.284 UTC, also returned 200: 1.2 s provider response duration and 1,191 ms browser header timing. Saved sessions loaded. This request had cold middleware (475 ms) but a hot function (24 ms execution). Its middleware startup records show sentry_init 18.95 ms and sentry_config_import 19.90 ms.

An identified cold function request on this release is trhv5-1791138007860-38987c90020f, 18:20:07.860 UTC, HTTP 200, invocation 01M442A2V7ZR9BBFEXH196WF8Y: 545 ms startup, 1.45 s function execution, 31 ms middleware execution, 1.7 s provider response duration. Its startup records show 8.93 ms sentry_init and 11.50 ms sentry_config_import. The import includes init; static SDK loading precedes the application clocks and remains in provider startup. Do not sum these nested durations.

Vercel cold function request

The first-request target is met, and the original 30–40-second symptom remains unobserved. Remaining measurement gap: ordinary Sentry sampling omitted this cold request's DB spans. The existing pre-change cold trace records DB pool acquisition 60 ms and first displayed query 5 ms, but those must not be substituted into this release's cold request. Next measurement-only change will retain the first Control GET trace per production server instance so the DB and startup buckets can be attributed to the same invocation. No latency optimization is justified by the measured target so far.

[charlesrhoward]

Completed the same-request attribution and post-deploy check after #579 and #580.

Production is serving c1d18924453304246a377ff01b4e82cfd2a3a8d5 on READY deployment dpl_G95b12Rr6Vdfwynq3iKWeJmq1MLP, ready at 2026-10-04 18:53:18.912 UTC. The protected production workflow passed all seven smoke checks. The matching Trigger worker is deployed at version 20261004.14, with 24 tasks and SDK/CLI 4.5.12.

The first recorded Control request on this deployment was the authenticated GET /api/control/sessions?order=id at 18:53:35.415 UTC, request 9jv87-1791140015415-7ba9d47ce7f2. The deployment-scoped runtime-log query from deployment creation contains this request followed by four later Control requests, with no earlier Control entry. It returned HTTP 200, loaded saved sessions, and cleared the loading state without the empty-state or error screen.

Measurement on that request	Duration
Vercel response finished	1.8 s
Browser response headers received	1,793.702 ms
Vercel function cold start	560 ms
Vercel function execution display	1.48 s
Middleware execution	14 ms
Sentry config-import timer	16.18 ms
Sentry.init timer	13.40 ms
Sentry HTTP server span	909.095 ms
First observed pg-pool.connect	36.370 ms
First observed database query	2.976 ms

The function, separately from middleware, is explicitly Cold (560ms) in Vercel, invocation 01M4447BAWGDNR3MY75RA6SRBC. Request metadata and startup records.

The retained Sentry server span is f2ff676c2306c6c8 in trace e013f0ac337f7cb552515902bfb175bd, on the same release and route. It starts at 18:53:36.271 UTC, immediately after the function startup records at 18:53:36.262, and ends at 18:53:37.180095, before the next Control request starts at 18:53:37.210. Its 14 descendants include:

• Better Auth /get-session work inside a 565.664 ms span (02c3fda0f1a6ddd8).
• First connection 9b126d205872b975, 18:53:37.121–37.157370, 36.370 ms.
• First query 16af0131a107bc1c, 18:53:37.158–37.160976, 2.976 ms; the next query is 4.187 ms.
• Zero errors.

These are overlapping/nested observations, not additive buckets. The DB spans are the first observed database operations during authentication, not a separate measurement of only the Control-list SQL. The config-import timer includes Sentry.init; both clocks exclude static SDK module loading, which remains within provider startup. The provider execution display and HTTP span also overlap. No residual time is assigned to an unmeasured import or SDK component.

The pre-change cold request recorded above was 1.7 s by the same Vercel runtime-log method; #579 yielded 1.2 s for its first recorded request and 1.7 s for a confirmed cold function. This release's first recorded request is itself confirmed cold and 1.8 s, below the 5 s exit target. The reported September 30–40-second stall was not reproduced, and these results do not establish its historical cause. The largest currently observed components are function startup and authentication, both around half a second; the measurements do not justify a speculative latency optimization.

#579 adds startup measurements; #580 preserves the first production Control trace per server instance while later requests retain normal sampling. Route auth, queries, and responses are unchanged. Exact-head review, all required PR and merge-queue checks, and all four browser shards passed. #580 additionally has 100% changed-line coverage and 100% mutation score (22 killed); CI passed 2,113 library, 4,186 unit (two existing environment skips), and 495 database tests.

The measured investigation and current exit criteria are complete. Closing with the retained measurements in place so a recurrence can be attributed to its actual invocation.