perf: improve gateway startup diagnostics

This commit is contained in:
Peter Steinberger
2026-04-28 01:47:52 +01:00
parent 13d3777cf3
commit 75e126ef6a
7 changed files with 144 additions and 44 deletions

View File

@@ -480,6 +480,10 @@ function collectStartupTrace(line: string, startupTrace: Record<string, number>)
}
}
function hasGatewayReadyLog(line: string): boolean {
return /\[gateway\] (?:http server listening|ready \()/.test(line);
}
function parseStartupTraceMetrics(raw: string): Array<{ key: string; value: number }> {
const metrics: Array<{ key: string; value: number }> = [];
for (const part of raw.trim().split(/\s+/u)) {
@@ -576,7 +580,7 @@ async function runGatewaySample(options: {
output.splice(0, output.length - 20);
}
for (const line of text.split(/\r?\n/u)) {
if (line.includes("ready (") && readyLogMs == null) {
if (hasGatewayReadyLog(line) && readyLogMs == null) {
readyLogMs = performance.now() - startAt;
}
collectStartupTrace(line, startupTrace);

View File

@@ -352,10 +352,14 @@ function readProcessTreeCpuMs(rootPid) {
return totalCpuMs;
}
export function hasGatewayReadyLog(text) {
return /\[gateway\] (?:http server listening|ready \()/.test(text);
}
async function waitForGatewayReady(readText, timeoutMs) {
const deadline = Date.now() + timeoutMs;
while (Date.now() < deadline) {
if (/\[gateway\] ready \(/.test(readText())) {
if (hasGatewayReadyLog(readText())) {
return true;
}
await sleep(100);

View File

@@ -4,7 +4,7 @@ import process from "node:process";
import { fileURLToPath } from "node:url";
import { resolveStateDir } from "../config/paths.js";
import type { OpenClawConfig } from "../config/types.openclaw.js";
import { normalizeEnv } from "../infra/env.js";
import { isTruthyEnvValue, normalizeEnv } from "../infra/env.js";
import { isMainModule } from "../infra/is-main.js";
import { ensureOpenClawCliOnPath } from "../infra/path-env.js";
import { assertSupportedRuntime } from "../infra/runtime-guard.js";
@@ -37,6 +37,41 @@ export {
shouldUseRootHelpFastPath,
} from "./run-main-policy.js";
type Awaitable<T> = T | Promise<T>;
function createGatewayCliMainStartupTrace(argv: string[]) {
const enabled =
isTruthyEnvValue(process.env.OPENCLAW_GATEWAY_STARTUP_TRACE) &&
argv.slice(2).includes("gateway");
const started = performance.now();
let last = started;
const emit = (name: string, durationMs: number, totalMs: number) => {
if (!enabled) {
return;
}
process.stderr.write(
`[gateway] startup trace: cli.main.${name} ${durationMs.toFixed(1)}ms total=${totalMs.toFixed(1)}ms\n`,
);
};
return {
mark(name: string) {
const now = performance.now();
emit(name, now - last, now - started);
last = now;
},
async measure<T>(name: string, run: () => Awaitable<T>): Promise<T> {
const before = performance.now();
try {
return await run();
} finally {
const now = performance.now();
emit(name, now - before, now - started);
last = now;
}
},
};
}
async function closeCliMemoryManagers(): Promise<void> {
const { hasMemoryRuntime } = await import("../plugins/memory-state.js");
if (!hasMemoryRuntime()) {
@@ -98,6 +133,7 @@ async function ensureCliEnvProxyDispatcher(): Promise<void> {
export async function runCli(argv: string[] = process.argv) {
const originalArgv = normalizeWindowsArgv(argv);
const startupTrace = createGatewayCliMainStartupTrace(originalArgv);
const parsedContainer = parseCliContainerArgs(originalArgv);
if (!parsedContainer.ok) {
throw new Error(parsedContainer.error);
@@ -123,10 +159,13 @@ export async function runCli(argv: string[] = process.argv) {
return;
}
let normalizedArgv = parsedProfile.argv;
startupTrace.mark("argv");
if (shouldLoadCliDotEnv()) {
const { loadCliDotEnv } = await import("./dotenv.js");
loadCliDotEnv({ quiet: true });
await startupTrace.measure("dotenv", async () => {
const { loadCliDotEnv } = await import("./dotenv.js");
loadCliDotEnv({ quiet: true });
});
}
normalizeEnv();
if (shouldEnsureCliPath(normalizedArgv)) {
@@ -206,19 +245,18 @@ export async function runCli(argv: string[] = process.argv) {
const [
{ initializeDebugProxyCapture, finalizeDebugProxyCapture },
{ maybeWarnAboutDebugProxyCoverage },
] = await Promise.all([
import("../proxy-capture/runtime.js"),
import("../proxy-capture/coverage.js"),
]);
] = await startupTrace.measure("proxy-imports", () =>
Promise.all([import("../proxy-capture/runtime.js"), import("../proxy-capture/coverage.js")]),
);
initializeDebugProxyCapture("cli");
process.once("exit", () => {
finalizeDebugProxyCapture();
});
await ensureCliEnvProxyDispatcher();
await startupTrace.measure("proxy-dispatcher", () => ensureCliEnvProxyDispatcher());
maybeWarnAboutDebugProxyCoverage();
const { tryRouteCli } = await import("./route.js");
if (await tryRouteCli(normalizedArgv)) {
const { tryRouteCli } = await startupTrace.measure("route-import", () => import("./route.js"));
if (await startupTrace.measure("route", () => tryRouteCli(normalizedArgv))) {
return;
}
@@ -253,14 +291,16 @@ export async function runCli(argv: string[] = process.argv) {
isUncaughtExceptionHandled,
},
{ restoreTerminalState },
] = await Promise.all([
import("./program.js"),
import("../infra/errors.js"),
import("../infra/fatal-error-hooks.js"),
import("../infra/unhandled-rejections.js"),
import("../terminal/restore.js"),
]);
const program = buildProgram();
] = await startupTrace.measure("core-imports", () =>
Promise.all([
import("./program.js"),
import("../infra/errors.js"),
import("../infra/fatal-error-hooks.js"),
import("../infra/unhandled-rejections.js"),
import("../terminal/restore.js"),
]),
);
const program = await startupTrace.measure("build-program", () => buildProgram());
// Global error handlers to prevent silent crashes from unhandled rejections/exceptions.
// These log the error and exit gracefully instead of crashing without trace.
@@ -291,14 +331,16 @@ export async function runCli(argv: string[] = process.argv) {
// are correct even with lazy command registration.
const { primary } = invocation;
if (primary && shouldRegisterPrimaryCommandOnly(parseArgv)) {
const { getProgramContext } = await import("./program/program-context.js");
const ctx = getProgramContext(program);
if (ctx) {
const { registerCoreCliByName } = await import("./program/command-registry.js");
await registerCoreCliByName(program, ctx, primary, parseArgv);
}
const { registerSubCliByName } = await import("./program/register.subclis.js");
await registerSubCliByName(program, primary);
await startupTrace.measure("register-primary", async () => {
const { getProgramContext } = await import("./program/program-context.js");
const ctx = getProgramContext(program);
if (ctx) {
const { registerCoreCliByName } = await import("./program/command-registry.js");
await registerCoreCliByName(program, ctx, primary, parseArgv);
}
const { registerSubCliByName } = await import("./program/register.subclis.js");
await registerSubCliByName(program, primary);
});
}
const hasBuiltinPrimary =
@@ -312,17 +354,14 @@ export async function runCli(argv: string[] = process.argv) {
hasBuiltinPrimary,
});
if (!shouldSkipPluginRegistration) {
// Register plugin CLI commands before parsing
const { registerPluginCliCommandsFromValidatedConfig } = await import("../plugins/cli.js");
const config = await registerPluginCliCommandsFromValidatedConfig(
program,
undefined,
undefined,
{
const config = await startupTrace.measure("register-plugin-commands", async () => {
const { registerPluginCliCommandsFromValidatedConfig } =
await import("../plugins/cli.js");
return await registerPluginCliCommandsFromValidatedConfig(program, undefined, undefined, {
mode: "lazy",
primary,
},
);
});
});
if (config) {
if (
primary &&
@@ -349,7 +388,7 @@ export async function runCli(argv: string[] = process.argv) {
stopStartupProgress();
try {
await program.parseAsync(parseArgv);
await startupTrace.measure("parse", () => program.parseAsync(parseArgv));
} catch (error) {
if (!isCommanderParseExit(error)) {
throw error;

View File

@@ -13,7 +13,7 @@ import {
} from "./entry.compile-cache.js";
import { buildCliRespawnPlan } from "./entry.respawn.js";
import { tryHandleRootVersionFastPath } from "./entry.version-fast-path.js";
import { normalizeEnv } from "./infra/env.js";
import { isTruthyEnvValue, normalizeEnv } from "./infra/env.js";
import { isMainModule } from "./infra/is-main.js";
import { ensureOpenClawExecMarkerOnProcess } from "./infra/openclaw-exec-env.js";
import { installProcessWarningFilter } from "./infra/warning-filter.js";
@@ -34,6 +34,41 @@ function shouldForceReadOnlyAuthStore(argv: string[]): boolean {
return false;
}
function createGatewayEntryStartupTrace(argv: string[]) {
const enabled =
isTruthyEnvValue(process.env.OPENCLAW_GATEWAY_STARTUP_TRACE) &&
argv.slice(2).includes("gateway");
const started = performance.now();
let last = started;
const emit = (name: string, durationMs: number, totalMs: number) => {
if (!enabled) {
return;
}
process.stderr.write(
`[gateway] startup trace: entry.${name} ${durationMs.toFixed(1)}ms total=${totalMs.toFixed(1)}ms\n`,
);
};
return {
mark(name: string) {
const now = performance.now();
emit(name, now - last, now - started);
last = now;
},
async measure<T>(name: string, run: () => Promise<T>): Promise<T> {
const before = performance.now();
try {
return await run();
} finally {
const now = performance.now();
emit(name, now - before, now - started);
last = now;
}
},
};
}
const gatewayEntryStartupTrace = createGatewayEntryStartupTrace(process.argv);
// Guard: only run entry-point logic when this file is the main module.
// The bundler may import entry.js as a shared dependency when dist/index.js
// is the actual entry point; without this guard the top-level code below
@@ -60,6 +95,7 @@ if (
enableOpenClawCompileCache({
installRoot,
});
gatewayEntryStartupTrace.mark("bootstrap");
if (shouldForceReadOnlyAuthStore(process.argv)) {
process.env.OPENCLAW_AUTH_STORE_READONLY = "1";
@@ -130,6 +166,7 @@ if (
// Keep Commander and ad-hoc argv checks consistent.
process.argv = parsed.argv;
}
gatewayEntryStartupTrace.mark("argv");
if (!tryHandleRootVersionFastPath(process.argv)) {
await runMainOrRootHelp(process.argv);
@@ -185,7 +222,10 @@ async function runMainOrRootHelp(argv: string[]): Promise<void> {
return;
}
try {
const { runCli } = await import("./cli/run-main.js");
const { runCli } = await gatewayEntryStartupTrace.measure(
"run-main-import",
() => import("./cli/run-main.js"),
);
await runCli(argv);
} catch (error) {
console.error(

View File

@@ -4,7 +4,6 @@ import { disposeRegisteredAgentHarnesses } from "../agents/harness/registry.js";
import { disposeAllSessionMcpRuntimes } from "../agents/pi-bundle-mcp-tools.js";
import type { CanvasHostHandler, CanvasHostServer } from "../canvas-host/server.js";
import { type ChannelId, listChannelPlugins } from "../channels/plugins/index.js";
import { stopGmailWatcher } from "../hooks/gmail-watcher.js";
import { createInternalHookEvent, triggerInternalHook } from "../hooks/internal-hooks.js";
import type { HeartbeatRunner } from "../infra/heartbeat-runner.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
@@ -100,6 +99,11 @@ async function disposeAllBundleLspRuntimesOnDemand(): Promise<void> {
await disposeAllBundleLspRuntimes();
}
async function stopGmailWatcherOnDemand(): Promise<void> {
const { stopGmailWatcher } = await import("../hooks/gmail-watcher.js");
await stopGmailWatcher();
}
export async function runGatewayClosePrelude(params: {
stopDiagnostics?: () => void;
clearSkillsRefreshTimer?: () => void;
@@ -242,7 +246,7 @@ export function createGatewayCloseHandler(params: {
if (params.pluginServices) {
await params.pluginServices.stop().catch(() => {});
}
await stopGmailWatcher();
await stopGmailWatcherOnDemand();
params.cron.stop();
params.heartbeatRunner.stop();
try {

View File

@@ -5,8 +5,6 @@ import { getTotalPendingReplies } from "../auto-reply/reply/dispatcher-registry.
import type { CliDeps } from "../cli/deps.types.js";
import { isRestartEnabled } from "../config/commands.flags.js";
import type { OpenClawConfig } from "../config/types.openclaw.js";
import { startGmailWatcherWithLogs } from "../hooks/gmail-watcher-lifecycle.js";
import { stopGmailWatcher } from "../hooks/gmail-watcher.js";
import { isTruthyEnvValue } from "../infra/env.js";
import type { HeartbeatRunner } from "../infra/heartbeat-runner.js";
import { resetDirectoryCache } from "../infra/outbound/target-resolver.js";
@@ -269,6 +267,10 @@ export function createGatewayReloadHandlers(params: GatewayReloadHandlerParams)
}
if (plan.restartGmailWatcher) {
const [{ stopGmailWatcher }, { startGmailWatcherWithLogs }] = await Promise.all([
import("../hooks/gmail-watcher.js"),
import("../hooks/gmail-watcher-lifecycle.js"),
]);
await stopGmailWatcher().catch((err) => {
params.logHooks.warn(`gmail watcher stop failed during reload: ${String(err)}`);
});

View File

@@ -1,5 +1,6 @@
import { describe, expect, it } from "vitest";
import {
hasGatewayReadyLog,
isIgnoredDistRuntimeWatchPath,
shouldRefreshBuildStampForRestoredArtifacts,
} from "../../scripts/check-gateway-watch-regression.mjs";
@@ -23,6 +24,12 @@ describe("check-gateway-watch-regression", () => {
).toBe(false);
});
it("recognizes current and legacy gateway ready logs", () => {
expect(hasGatewayReadyLog("[gateway] http server listening (0 plugins, 0.8s)")).toBe(true);
expect(hasGatewayReadyLog("[gateway] ready (0 plugins, 0.8s)")).toBe(true);
expect(hasGatewayReadyLog("[gateway] starting HTTP server...")).toBe(false);
});
it("refreshes restored build stamps only for skip-build config mtime drift", () => {
expect(
shouldRefreshBuildStampForRestoredArtifacts({