Files
Eric Allam 60d71da90e perf(webapp,run-engine): cut CPU on the engine-facing worker-action routes (#4746)
Cuts CPU on the `engine/v1/worker-actions/*` routes a managed supervisor
calls, and adds the benchmark harness the numbers come from.

Measured on a local stack: **on-CPU per completed run 9.07ms → 6.59ms
(−27%)**, busy fraction 45.6% → 33.8%, with every worker-action p50 down
23–27%. Load was 5,000 runs / 24 virtual supervisors / 90s window /
30,120 requests / 0 errors.

Query-count work from the same investigation is deliberately **not**
here — it will follow as a separate PR.

## The three changes

**1. Split the event-loop monitor in two (~14% of on-CPU, plus ~5pp of
GC).**

`eventLoopMonitor.server.ts` installs a global `async_hooks` hook:
`init` writes a `Map` entry for *every* async resource the process
creates, `before` calls `process.hrtime()` and `context.active()` on
every one. Enabling any async hook also puts V8 on the slow path for
promise instrumentation process-wide. `EVENT_LOOP_MONITOR_ENABLED`
defaulted to `"1"`, so this was the shipping configuration.

The blocked-loop detector is now opt-in (`EVENT_LOOP_MONITOR_ENABLED`,
default `0`). The event-loop *utilization* gauge — a single interval
timer with no per-request cost — moves to its own flag
(`EVENT_LOOP_UTILIZATION_MONITOR_ENABLED`, default `1`) and stays on, so
the useful half survives without the expensive half.

A/B under identical load:

| | monitor on | monitor off | change |
|---|---|---|---|
| on-CPU per run | 9.08ms | 7.25ms | −20% |
| GC self time | 9.80% | 5.05% | −4.75pp |
| dequeue p50 | 76.6ms | 62.8ms | −18% |
| attempts/start p50 | 56.3ms | 43.5ms | −23% |

**2. Bucket route matching by first static path segment (10.4% → 3.9% of
on-CPU).**

`patches/@remix-run__router@1.23.3.patch` already memoized flattened
branches and compiled path regexes. What remained was the linear scan:
`matchRouteBranch` walked the ranked branch list calling `matchPath` per
branch across 521 route files, so every worker-action request paid a
scan proportional to the whole route table.

Branches are now indexed by their lowercased leading segment, with one
always-considered list for branches whose leading segment is dynamic,
splat or optional (and for root/pathless paths). A request walks only
its own bucket merged with that list. Route-matching self time dropped
64% (3.6s → 1.3s over a 90s window).

Ordering is preserved exactly: both lists hold indexes into the already
rank-sorted branch array and are walked in ascending-index order, so the
first match found is the same branch the full scan would have found.
Bucketing lowercases on both sides, so case-insensitive matching still
resolves and `caseSensitive: true` routes are still rejected by
`matchPath` itself. A pathname whose own leading segment can't be
bucketed falls back to the full scan.

Verified equivalent to the unpatched matcher over 20,050 pathnames
(literal, dynamic, splat, optional, case variants, basenames,
percent-encoded) with zero mismatches.
`apps/webapp/test/routeMatchingPatch.test.ts` pins the matching
semantics rather than the optimisation, so it still passes without the
patch.

**3. Demote per-heartbeat and per-dequeue `info` logs to `debug`.**

These are the two highest-rate engine calls and each wrote a synchronous
structured log line on every request. Synchronous `console` writes can
block the loop when stdout backs up, which costs more than the ~1.3% CPU
share suggests.

## The harness

Two benchmarks, neither in the default suite (they run for minutes,
attach the V8 profiler, and report numbers rather than assert on them).
See `apps/webapp/test/bench/README.md`.

- `apps/webapp/test/bench/engineHttp.bench.test.ts` — spawns a real
webapp against throwaway Postgres/Redis containers, seeds a production
environment with a promoted managed deployment, and drives a closed-loop
supervisor pool through the full lifecycle. Profiling runs over CDP
rather than `--cpu-prof` so it covers only the measured window instead
of being swamped by boot, and `performance.eventLoopUtilization()` is
sampled *inside* the webapp process.
-
`internal-packages/run-engine/src/engine/bench/runEngineLifecycle.bench.test.ts`
— drives `RunEngine` directly, profiling enqueue and lifecycle
separately so engine cost isn't mixed with request-stack overhead.
- `apps/webapp/test/bench/analyzeProfile.ts` — dependency-free
`.cpuprofile` analyzer that symbolicates through the build's source maps
and ranks CPU by package, self time and total time. Percentages are
shares of on-CPU time (V8's `(idle)`/`(program)` excluded).

`startWebapp` gains `overrideEnv`, applied after the worker-disable
defaults, so the HTTP bench can re-enable the run engine worker that
drains the master queue into the worker queues a supervisor dequeues
from.

The local OTel collector gains a traces pipeline. It only defined a
metrics pipeline, so pointing `INTERNAL_OTEL_TRACE_EXPORTER_URL` at it
locally failed and the webapp silently fell back to the console span
logger.

## Configuration

For operators upgrading:

- `EVENT_LOOP_MONITOR_ENABLED` (now defaults to `0`) — the
per-async-resource blocked-loop detector. Set to `1` to restore the
previous behaviour and keep emitting `event-loop-blocked` spans.
- `EVENT_LOOP_UTILIZATION_MONITOR_ENABLED` (new, defaults to `1`) — the
`nodejs.event_loop.utilization` gauge. Unchanged in behaviour; it just
has its own flag now so it survives turning the detector off.

## Notes for review

- `pnpm-lock.yaml` changes only because the router patch content
changed, which changes its patch hash.
- One thing the profile ruled out: with a real OTLP collector receiving
spans, tracing costs ~1.7% of on-CPU at 100% sampling and ~0.8% at the
production rate. Span shipping is not a hidden cost, so nothing here
touches it.
- Caveats on the numbers: a laptop, not production hardware, so DB and
Redis *latency* are unrepresentative (client-side CPU is what's ranked);
single webapp process; throughput varies ~5% run to run, which is why
the claims rest on on-CPU per run rather than req/s.

## Verification

- 20,050-pathname router equivalence check vs the unpatched matcher,
zero mismatches
- `apps/webapp/test/routeMatchingPatch.test.ts` (12 cases) passes
- webapp e2e smoke suite (68 tests) passes through the patched router
- run-engine suites covering the snapshot/attempt paths pass
- `typecheck`, `format`, `lint`, `knip` clean
2026-08-21 11:53:16 +01:00

372 lines
14 KiB
TypeScript

import { createReadableStreamFromReadable, type EntryContext } from "@remix-run/node"; // or cloudflare/deno
import { RemixServer } from "@remix-run/react";
import * as Sentry from "@sentry/remix";
import { wrapHandleErrorWithSentry } from "@sentry/remix";
import { addTenantContextToEvent } from "~/utils/sentryTenantContext.server";
import { parseAcceptLanguage } from "intl-parse-accept-language";
import isbot from "isbot";
import { renderToPipeableStream } from "react-dom/server";
import { PassThrough } from "stream";
import { initMollifierDrainerWorker } from "~/v3/mollifierDrainerWorker.server";
import { initMollifierStaleSweepWorker } from "~/v3/mollifierStaleSweepWorker.server";
import { initBillingLimitWorker } from "~/v3/billingLimitWorker.server";
import { initLogsSearchProjectorWorker } from "~/v3/logsSearchProjectorWorker.server";
import { initQueueMetricsConsumer, initQueueMetricsEmitter } from "~/v3/queueMetrics.server";
import { bootstrap } from "./bootstrap";
import { LocaleContextProvider } from "./components/primitives/LocaleProvider";
import type { OperatingSystemPlatform } from "./components/primitives/OperatingSystemProvider";
import { OperatingSystemContextProvider } from "./components/primitives/OperatingSystemProvider";
import { assertRunOpsSplitSentinel, Prisma } from "./db.server";
import { env } from "./env.server";
import { eventLoopMonitor, eventLoopUtilizationMonitor } from "./eventLoopMonitor.server";
import { logger } from "./services/logger.server";
import { buildImgSrcDirective, parseCspImageOrigins, withImgSrc } from "./utils/cspImageOrigins";
import { singleton } from "./utils/singleton";
import { remoteBuildsEnabled } from "./v3/remoteImageBuilder.server";
import {
registerRunEngineEventBusHandlers,
setupBatchQueueCallbacks,
} from "./v3/runEngineHandlers.server";
import { registerRunChangeNotifierHandlers } from "./services/realtime/runChangeNotifierHandlers.server";
// Touch the sessions replication singleton at entry so it boots deterministically
// on webapp startup. The singleton's initializer wires start (gated on
// `clickhouseFactory.isReady()`) and SIGTERM/SIGINT shutdown — mirrors
// runsReplicationInstance.
//
// IMPORTANT: do NOT replace this with `void sessionsReplicationInstance;`.
// `apps/webapp/package.json` declares `"sideEffects": false`, so esbuild
// treats `void <identifier>;` as a pure expression statement and tree-shakes
// the entire import — the singleton's initializer never fires and the
// sessions→ClickHouse logical replication slot stops being consumed. Assigning
// to globalThis is an unambiguous side effect the bundler must preserve. See
// TRI-9864 for the incident write-up.
import { sessionsReplicationInstance } from "./services/sessionsReplicationInstance.server";
(globalThis as Record<string, unknown>).__sessionsReplicationInstance = sessionsReplicationInstance;
// Touch the webhook deliveries replication singleton at entry so it boots
// deterministically alongside the sessions replicator. Same `sideEffects: false`
// tree-shaking constraint applies — assign to globalThis, do NOT use `void`.
import { webhookDeliveriesReplicationInstance } from "./services/webhookDeliveriesReplicationInstance.server";
(globalThis as Record<string, unknown>).__webhookDeliveriesReplicationInstance =
webhookDeliveriesReplicationInstance;
// Touch the webhook engine singleton at entry so its redis-worker boots
// deterministically on webapp startup (the constructor calls worker.start()).
// Same `sideEffects: false` tree-shaking constraint applies: assign to
// globalThis, do NOT use `void`.
import { webhookEngine } from "./v3/webhookEngine.server";
(globalThis as Record<string, unknown>).__webhookEngine = webhookEngine;
import { globalFlagsRegistry } from "./v3/globalFlagsRegistry.server";
(globalThis as Record<string, unknown>).__globalFlagsRegistry = globalFlagsRegistry;
import { workerRegionRegistry } from "./v3/workerRegions.server";
(globalThis as Record<string, unknown>).__workerRegionRegistry = workerRegionRegistry;
const ABORT_DELAY = 30000;
/**
* Where a document may load images from. The markdown renderer that strips images
* ships in the stacked UI PR, so on this branch the policy is the only thing stopping
* a model- or customer-authored image from reaching a remote host.
*
* The hosts we store avatar URLs for, plus whatever `CSP_IMG_SRC_ALLOWLIST` adds
* (e.g. a self-hosted SSO avatar host).
*/
const IMG_SRC_DIRECTIVE = buildImgSrcDirective(
singleton("CspImageOrigins", () => {
const { origins, rejected } = parseCspImageOrigins(env.CSP_IMG_SRC_ALLOWLIST, {
allowHttp: env.NODE_ENV === "development",
});
for (const entry of rejected) {
logger.warn(
`⚠️ CSP_IMG_SRC_ALLOWLIST entry "${entry.value}" was ignored: it ${entry.reason}.`
);
}
return origins;
})
);
export default function handleRequest(
request: Request,
responseStatusCode: number,
responseHeaders: Headers,
remixContext: EntryContext
) {
const url = new URL(request.url);
// Stale documents reference /build asset hashes that 404 after a deploy —
// always revalidate HTML. Route-set headers win.
if (!responseHeaders.has("Cache-Control")) {
responseHeaders.set("Cache-Control", "no-cache");
}
if (url.pathname.startsWith("/login")) {
responseHeaders.set("X-Frame-Options", "SAMEORIGIN");
responseHeaders.set("Content-Security-Policy", "frame-ancestors 'self'");
}
responseHeaders.set(
"Content-Security-Policy",
withImgSrc(responseHeaders.get("Content-Security-Policy"), IMG_SRC_DIRECTIVE)
);
const acceptLanguage = request.headers.get("accept-language");
const locales = parseAcceptLanguage(acceptLanguage, {
validate: Intl.DateTimeFormat.supportedLocalesOf,
});
//get whether it's a mac or pc from the headers
const platform: OperatingSystemPlatform = request.headers.get("user-agent")?.includes("Mac")
? "mac"
: "windows";
// If the request is from a bot, we want to wait for the full
// response to render before sending it to the client. This
// ensures that bots can see the full page content.
if (isbot(request.headers.get("user-agent"))) {
return handleBotRequest(
request,
responseStatusCode,
responseHeaders,
remixContext,
locales,
platform
);
}
return handleBrowserRequest(
request,
responseStatusCode,
responseHeaders,
remixContext,
locales,
platform
);
}
function handleBotRequest(
request: Request,
responseStatusCode: number,
responseHeaders: Headers,
remixContext: EntryContext,
locales: string[],
platform: OperatingSystemPlatform
) {
return new Promise((resolve, reject) => {
let shellRendered = false;
// Timer handle is cleared in every terminal callback so the abort closure
// (which captures the full React render tree + remixContext) doesn't pin
// memory for 30s per successful request. See react-router PR #14200.
let abortTimer: NodeJS.Timeout | undefined;
const { pipe, abort } = renderToPipeableStream(
<OperatingSystemContextProvider platform={platform}>
<LocaleContextProvider locales={locales}>
<RemixServer context={remixContext} url={request.url} abortDelay={ABORT_DELAY} />,
</LocaleContextProvider>
</OperatingSystemContextProvider>,
{
onAllReady() {
shellRendered = true;
const body = new PassThrough();
const stream = createReadableStreamFromReadable(body);
responseHeaders.set("Content-Type", "text/html");
resolve(
new Response(stream, {
headers: responseHeaders,
status: responseStatusCode,
})
);
pipe(body);
clearTimeout(abortTimer);
},
onShellError(error: unknown) {
clearTimeout(abortTimer);
reject(error);
},
onError(error: unknown) {
responseStatusCode = 500;
// Log streaming rendering errors from inside the shell. Don't log
// errors encountered during initial shell rendering since they'll
// reject and get logged in handleDocumentRequest.
if (shellRendered) {
console.error(error);
}
},
}
);
abortTimer = setTimeout(abort, ABORT_DELAY);
});
}
function handleBrowserRequest(
request: Request,
responseStatusCode: number,
responseHeaders: Headers,
remixContext: EntryContext,
locales: string[],
platform: OperatingSystemPlatform
) {
return new Promise((resolve, reject) => {
let shellRendered = false;
// Timer handle is cleared in every terminal callback so the abort closure
// (which captures the full React render tree + remixContext) doesn't pin
// memory for 30s per successful request. See react-router PR #14200.
let abortTimer: NodeJS.Timeout | undefined;
const { pipe, abort } = renderToPipeableStream(
<OperatingSystemContextProvider platform={platform}>
<LocaleContextProvider locales={locales}>
<RemixServer context={remixContext} url={request.url} abortDelay={ABORT_DELAY} />
</LocaleContextProvider>
</OperatingSystemContextProvider>,
{
onShellReady() {
shellRendered = true;
const body = new PassThrough();
const stream = createReadableStreamFromReadable(body);
responseHeaders.set("Content-Type", "text/html");
resolve(
new Response(stream, {
headers: responseHeaders,
status: responseStatusCode,
})
);
pipe(body);
clearTimeout(abortTimer);
},
onShellError(error: unknown) {
clearTimeout(abortTimer);
reject(error);
},
onError(error: unknown) {
responseStatusCode = 500;
// Log streaming rendering errors from inside the shell. Don't log
// errors encountered during initial shell rendering since they'll
// reject and get logged in handleDocumentRequest.
if (shellRendered) {
console.error(error);
}
},
}
);
abortTimer = setTimeout(abort, ABORT_DELAY);
});
}
export const handleError = wrapHandleErrorWithSentry((error, { request }) => {
if (request instanceof Request) {
logger.debug("Error in handleError", {
error,
request: {
url: request.url,
method: request.method,
},
});
} else {
logger.debug("Error in handleError", {
error,
});
}
});
initMollifierDrainerWorker();
initMollifierStaleSweepWorker();
initBillingLimitWorker();
initLogsSearchProjectorWorker();
initQueueMetricsEmitter();
initQueueMetricsConsumer();
bootstrap().catch((error) => {
logError(error);
});
function logError(error: unknown, request?: Request) {
console.error(error);
}
process.on("uncaughtException", (error, origin) => {
if (
error instanceof Prisma.PrismaClientKnownRequestError ||
error instanceof Prisma.PrismaClientUnknownRequestError
) {
// Don't exit the process if the error is a Prisma error
logger.error("uncaughtException prisma error", {
error,
prismaMessage: error.message,
code: "code" in error ? error.code : undefined,
meta: "meta" in error ? error.meta : undefined,
stack: error.stack,
origin,
});
} else {
logger.error("uncaughtException", {
error: { name: error.name, message: error.message, stack: error.stack },
origin,
});
}
process.exit(1);
});
// Boot-time run-ops split interlock. Async, so it runs as a
// fire-and-forget at startup; a flag-on-but-sentinel-fails misconfig crashes
// the process loudly before any run-ops routing is wired.
singleton("AssertRunOpsSplitSentinel", () => {
assertRunOpsSplitSentinel().catch((error) => {
logger.error("Run-ops split sentinel assertion failed; refusing to start", { error });
process.exit(1);
});
return true;
});
singleton("RunEngineEventBusHandlers", registerRunEngineEventBusHandlers);
singleton("SetupBatchQueueCallbacks", setupBatchQueueCallbacks);
// Attach the realtime run-changed publish delegations to the engine event bus.
// No-ops (registers nothing) unless REALTIME_BACKEND_NATIVE_ENABLED=1.
singleton("RunChangeNotifierHandlers", registerRunChangeNotifierHandlers);
// Wrapped in singleton() so Remix's dev-mode CJS reloads don't append
// duplicate copies of the processor — Sentry's processor list lives in
// node_modules and persists across module reloads. Idempotent at runtime
// (the processor is a pure read+stamp), but the pattern matches the rest
// of this file.
singleton("SentryTenantContextProcessor", () => {
if (env.SENTRY_DSN) {
Sentry.addEventProcessor(addTenantContextToEvent);
}
// Return a truthy value — `singleton()` uses `??=` so a `void`
// callback would re-execute (and re-register) on every dev reload.
return true;
});
export { apiRateLimiter } from "./services/apiRateLimit.server";
export { dashboardAgentBodyCap } from "./services/dashboardAgentBodyCap.server";
export { deploymentRateLimiter } from "./services/deploymentRateLimit.server";
export { engineRateLimiter } from "./services/engineRateLimit.server";
export { otlpRateLimiter } from "./services/otlpRateLimit.server";
export { runWithHttpContext } from "./services/httpAsyncStorage.server";
export { tenantContextMiddleware } from "./services/tenantContextResolver.server";
export { webhookIngressIpRateLimiter } from "./services/webhookIngressIpRateLimit.server";
export { socketIo } from "./v3/handleSocketIo.server";
export { wss } from "./v3/handleWebsockets.server";
if (env.EVENT_LOOP_MONITOR_ENABLED === "1") {
eventLoopMonitor.enable();
}
if (env.EVENT_LOOP_UTILIZATION_MONITOR_ENABLED === "1") {
eventLoopUtilizationMonitor.enable();
}
if (remoteBuildsEnabled()) {
console.log("🏗️ Remote builds enabled");
} else {
console.log("🏗️ Local builds enabled");
}