Instrument startup with per-phase timings

Author: mattgodboltCreated Aug 20, 2026Updated Aug 20, 2026

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.

  1. A tiny phase timer used from initialiseApplication (lib/app/main.ts): mark('phase-name') at each boundary, recording elapsed time per phase.

  2. One logger.info line per phase as it completes, e.g. Startup phase 'create-compilers': 5012ms.

  3. 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, setupMetricsServer called late in initialiseApplication) is only scraped after startup completes, so set-at-end values are what any scrape sees. The nodes are already scraped by grafana-agent (infra grafana/agent.yaml, job compiler_explorer), so the phases are immediately chartable per env/instance in Grafana; nothing currently dashboards ce_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 of loadConfiguration (app.ts / lib/app/config.ts) - captures node boot + imports + config
  • aws-init / compilation-env: aws.initConfig + initializeCompilationEnvironment (lib/app/compilation-env.ts)
  • discovery-load: read + parse of the prediscovered JSON, or full find() when not prediscovered (lib/app/compiler-discovery.ts)
  • create-compilers: the Promise.all(compilers.map(c => this.create(c))) block in CompileHandler.setCompilers (lib/handlers/compile.ts:318)
  • possible-arguments: the loadFromStorage fan-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: initial onCompilerChange (lib/app/compiler-changes.ts) including options stringify/hash
  • listen: through startListening (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