diff --git a/scripts/bench-gateway-startup.ts b/scripts/bench-gateway-startup.ts index 998d383ad67..541ace7cbd0 100644 --- a/scripts/bench-gateway-startup.ts +++ b/scripts/bench-gateway-startup.ts @@ -480,6 +480,10 @@ function collectStartupTrace(line: string, startupTrace: Record) } } +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); diff --git a/scripts/check-gateway-watch-regression.mjs b/scripts/check-gateway-watch-regression.mjs index 3d42d52a8c9..1fa143fbf5c 100644 --- a/scripts/check-gateway-watch-regression.mjs +++ b/scripts/check-gateway-watch-regression.mjs @@ -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); diff --git a/src/cli/run-main.ts b/src/cli/run-main.ts index 5dee18402c3..054ba60561d 100644 --- a/src/cli/run-main.ts +++ b/src/cli/run-main.ts @@ -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 | Promise; + +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(name: string, run: () => Awaitable): Promise { + 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 { const { hasMemoryRuntime } = await import("../plugins/memory-state.js"); if (!hasMemoryRuntime()) { @@ -98,6 +133,7 @@ async function ensureCliEnvProxyDispatcher(): Promise { 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; diff --git a/src/entry.ts b/src/entry.ts index 11a6db1d679..f22df4368ce 100644 --- a/src/entry.ts +++ b/src/entry.ts @@ -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(name: string, run: () => Promise): Promise { + 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 { 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( diff --git a/src/gateway/server-close.ts b/src/gateway/server-close.ts index f554d18968e..099ba1792e8 100644 --- a/src/gateway/server-close.ts +++ b/src/gateway/server-close.ts @@ -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 { await disposeAllBundleLspRuntimes(); } +async function stopGmailWatcherOnDemand(): Promise { + 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 { diff --git a/src/gateway/server-reload-handlers.ts b/src/gateway/server-reload-handlers.ts index 2468b0167e7..e6520231383 100644 --- a/src/gateway/server-reload-handlers.ts +++ b/src/gateway/server-reload-handlers.ts @@ -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)}`); }); diff --git a/test/scripts/check-gateway-watch-regression.test.ts b/test/scripts/check-gateway-watch-regression.test.ts index 61d42c880b8..411db26a079 100644 --- a/test/scripts/check-gateway-watch-regression.test.ts +++ b/test/scripts/check-gateway-watch-regression.test.ts @@ -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({