Instrument startup with per-phase timings
Startup profiling on prod (2026-08-20, 6232 compilers) broke a ~20.5s warm restart down roughly as:
| Phase | Time | What's happening |
|---|---|---|
| node boot, imports, config load, discovery JSON parse | ~2.7s | ESM imports, loadConfiguration, reading and JSON.parseing the ~74MB prediscovered compilers JSON |
| "Creating compilers" | ~5s | per-compiler create() including buildenv setup S3 GETs (lib/handlers/compile.ts setCompilers) |
| possible-arguments load | ~8s | possibleArguments.loadFromStorage S3 fan-out across all compilers |
| web server / routes | ~3s | partially unattributed: ~3s between the "using static files" log (lib/app/static-assets.ts) and route setup that nothing currently accounts for |
initial onCompilerChange |
~2s | JSON.stringify of all compilers, ClientOptionsHandler.setCompilers, and OPTIONS HASH computed twice (once in the ClientOptionsHandler constructor at lib/options-handler.ts:235, again in setCompilers at :534) |
Cold boots (image not warm in page cache etc.) run 34-51s. Fixes for the two big phases are in flight as draft PRs, and #8663 covers pre-baking the buildenv data into the discovery JSON. But today the only startup observability is a single ce_startup_seconds gauge plus a Startup duration: NNNms log line (lib/app/server-listening.ts:102-116), so we can't see which phase regressed when the total creeps up, and we couldn't have attributed that unknown 3s without ad-hoc profiling.
Proposal: instrument each startup phase.
A tiny phase timer used from
initialiseApplication(lib/app/main.ts):mark('phase-name')at each boundary, recording elapsed time per phase.One
logger.infoline per phase as it completes, e.g.Startup phase 'create-compilers': 5012ms.A labelled Prometheus gauge alongside the existing one, set once at listen time:
ce_startup_phase_seconds{phase="..."}A gauge is the right shape: startup happens once per process, and the metrics server (
lib/metrics-server.ts,setupMetricsServercalled late ininitialiseApplication) is only scraped after startup completes, so set-at-end values are what any scrape sees. The nodes are already scraped by grafana-agent (infragrafana/agent.yaml, jobcompiler_explorer), so the phases are immediately chartable per env/instance in Grafana; nothing currently dashboardsce_startup_seconds, and a stacked per-phase panel would be the thing worth building once this exists.
Suggested phases and hook points, following the existing flow in lib/app/main.ts:
config: process start to end ofloadConfiguration(app.ts/lib/app/config.ts) - captures node boot + imports + configaws-init/compilation-env:aws.initConfig+initializeCompilationEnvironment(lib/app/compilation-env.ts)discovery-load: read + parse of the prediscovered JSON, or fullfind()when not prediscovered (lib/app/compiler-discovery.ts)create-compilers: thePromise.all(compilers.map(c => this.create(c)))block inCompileHandler.setCompilers(lib/handlers/compile.ts:318)possible-arguments: theloadFromStoragefan-out immediately after it (lib/handlers/compile.ts:341-344)web-server:setupWebServer(lib/app/server.ts, includes static assets/render config - this is where the unattributed ~3s lives, so it may deserve sub-phases once measured)routes:setupRoutesAndApi(lib/app/routes-setup.ts)compiler-change: initialonCompilerChange(lib/app/compiler-changes.ts) including options stringify/hashlisten: throughstartListening(lib/app/server-listening.ts), where the totals get logged today
create-compilers and possible-arguments are inside CompileHandler.setCompilers rather than at initialiseApplication altitude, so either pass the timer down or record those two spans in place.
What this enables:
- Regression detection: once the in-flight startup-speed PRs and #8663 land, per-phase numbers in Grafana keep them from silently regressing, and give before/after evidence for each fix.
- Attribution of the unknown ~3s in web/routes setup, and visibility into oddities like the doubled OPTIONS HASH computation.
- Startup time directly affects deploy/scale-up latency (see compiler-explorer/infra#2058, ASG lifecycle hook to avoid 502s during instance startup); knowing which phase dominates on cold boot vs warm restart informs that work too.
Related: #8663 (pre-bake buildenv data), #6689 (S3 errors during these startup S3 phases lose all compilers), #3408 (formatter execution caching at startup), compiler-explorer/infra#2058.
Filed by Claude on behalf of @mattgodbolt.
Source: compiler-explorer/compiler-explorer