ewilliams28/openclaw
1
0
Fork 0
mirror of https://github.com/openclaw/openclaw.git synced 2026-08-23 02:45:38 -06:00
Code Issues Packages Projects Releases Wiki Activity

perf(cli): attribute command startup stages (#117720)

Browse Source
This commit is contained in:
Vincent Koc
2026-08-02 09:48:14 +08:00
committed by GitHub
parent 95c037863f
commit 953db0456e
10 changed files with 236 additions and 28 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/cli/command-bootstrap.test.ts
+2
View File
@@ -35,6 +35,7 @@ describe("ensureCliCommandBootstrap", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime,
commandPath: ["agents", "list"],
measure: expect.any(Function),
allowInvalid: true,
suppressDoctorStdout: true,
});
@@ -58,6 +59,7 @@ describe("ensureCliCommandBootstrap", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime,
commandPath: ["gateway"],
measure: expect.any(Function),
skipPristineCoreStateMigrations: true,
skipPristineStartupStateMigrations: true,
});
src/cli/command-bootstrap.ts
+25 -17
View File
@@ -4,6 +4,7 @@ import type { RuntimeEnv } from "../runtime.js";
import { createLazyImportLoader } from "../shared/lazy-promise.js";
import type { CliPluginRegistryPolicy } from "./command-catalog.js";
import { resolveCliCommandPathPolicy } from "./command-path-policy.js";
import { measureCliCommandStartup } from "./command-startup-timing.js";
import { ensureCliPluginRegistryLoaded } from "./plugin-registry-loader.js";
const configGuardModuleLoader = createLazyImportLoader(() => import("./program/config-guard.js"));
@@ -26,19 +27,24 @@ export async function ensureCliCommandBootstrap(params: {
skipPristineStartupStateMigrations?: boolean;
}) {
if (!params.skipConfigGuard) {
const { ensureConfigReady } = await loadConfigGuardModule();
await ensureConfigReady({
runtime: params.runtime,
commandPath: params.commandPath,
...(params.allowInvalid ? { allowInvalid: true } : {}),
...(params.beforeStateMigrations
? { beforeStateMigrations: params.beforeStateMigrations }
: {}),
...(params.suppressDoctorStdout ? { suppressDoctorStdout: true } : {}),
...(params.skipPristineStartupStateMigrations
? { skipPristineStartupStateMigrations: true }
: {}),
...(params.skipPristineCoreStateMigrations ? { skipPristineCoreStateMigrations: true } : {}),
await measureCliCommandStartup("config-ready", async () => {
const { ensureConfigReady } = await loadConfigGuardModule();
await ensureConfigReady({
runtime: params.runtime,
commandPath: params.commandPath,
measure: (stage, run) => measureCliCommandStartup(stage, run),
...(params.allowInvalid ? { allowInvalid: true } : {}),
...(params.beforeStateMigrations
? { beforeStateMigrations: params.beforeStateMigrations }
: {}),
...(params.suppressDoctorStdout ? { suppressDoctorStdout: true } : {}),
...(params.skipPristineStartupStateMigrations
? { skipPristineStartupStateMigrations: true }
: {}),
...(params.skipPristineCoreStateMigrations
? { skipPristineCoreStateMigrations: true }
: {}),
});
});
}
if (!params.loadPlugins) {
@@ -46,8 +52,10 @@ export async function ensureCliCommandBootstrap(params: {
}
const pluginRegistryLoadPolicy =
params.pluginRegistry ?? resolveCliCommandPathPolicy(params.commandPath).pluginRegistry;
await ensureCliPluginRegistryLoaded({
scope: pluginRegistryLoadPolicy.scope,
routeLogsToStderr: params.suppressDoctorStdout,
});
await measureCliCommandStartup("plugin-registry", () =>
ensureCliPluginRegistryLoaded({
scope: pluginRegistryLoadPolicy.scope,
routeLogsToStderr: params.suppressDoctorStdout,
}),
);
}
src/cli/command-startup-timing.test.ts
+55
View File
@@ -0,0 +1,55 @@
import { mkdtemp, readFile, rm } from "node:fs/promises";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { afterEach, describe, expect, it } from "vitest";
import { measureCliCommandStartup } from "./command-startup-timing.js";
const tempDirs: string[] = [];
afterEach(async () => {
await Promise.all(tempDirs.splice(0).map((dir) => rm(dir, { recursive: true, force: true })));
});
describe("measureCliCommandStartup", () => {
it("runs directly when no timeline path is configured", async () => {
await expect(
measureCliCommandStartup("config-ready", async () => "ready", {
env: {
OPENCLAW_DIAGNOSTICS: "timeline",
},
}),
).resolves.toBe("ready");
});
it("records the command startup stage without changing the result", async () => {
const dir = await mkdtemp(join(tmpdir(), "openclaw-cli-command-startup-"));
tempDirs.push(dir);
const path = join(dir, "timeline.jsonl");
const env = {
OPENCLAW_DIAGNOSTICS: "timeline",
OPENCLAW_DIAGNOSTICS_TIMELINE_PATH: path,
} as NodeJS.ProcessEnv;
await expect(
measureCliCommandStartup("config-ready", async () => "ready", { env }),
).resolves.toBe("ready");
const events = (await readFile(path, "utf8"))
.trim()
.split("\n")
.map((line) => JSON.parse(line) as Record<string, unknown>);
expect(events).toHaveLength(2);
expect(events[0]).toMatchObject({
type: "span.start",
name: "cli.command-startup",
phase: "cli.command-startup",
attributes: { stage: "config-ready" },
});
expect(events[1]).toMatchObject({
type: "span.end",
name: "cli.command-startup",
phase: "cli.command-startup",
attributes: { stage: "config-ready" },
});
});
});
src/cli/command-startup-timing.ts
+38
View File
@@ -0,0 +1,38 @@
import type { OpenClawConfig } from "../config/types.openclaw.js";
type DiagnosticsTimelineModule = typeof import("../infra/diagnostics-timeline.js");
type CliCommandStartupTimingOptions = {
config?: OpenClawConfig;
env?: NodeJS.ProcessEnv;
};
let diagnosticsTimelineModulePromise: Promise<DiagnosticsTimelineModule> | undefined;
function hasDiagnosticsTimelinePath(env: NodeJS.ProcessEnv): boolean {
return Boolean(env.OPENCLAW_DIAGNOSTICS_TIMELINE_PATH?.trim());
}
function loadDiagnosticsTimelineModule(): Promise<DiagnosticsTimelineModule> {
diagnosticsTimelineModulePromise ??= import("../infra/diagnostics-timeline.js");
return diagnosticsTimelineModulePromise;
}
/** Measures command-specific work hidden inside Commander parse/action dispatch. */
export async function measureCliCommandStartup<T>(
stage: string,
run: () => Promise<T> | T,
options: CliCommandStartupTimingOptions = {},
): Promise<T> {
const env = options.env ?? process.env;
if (!hasDiagnosticsTimelinePath(env)) {
return await run();
}
const { measureDiagnosticsTimelineSpan } = await loadDiagnosticsTimelineModule();
return await measureDiagnosticsTimelineSpan("cli.command-startup", run, {
config: options.config,
env,
phase: "cli.command-startup",
attributes: { stage },
});
}
src/cli/program/config-guard.test.ts
+48
View File
@@ -4,6 +4,7 @@ import os from "node:os";
import path from "node:path";
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
import { note } from "../../../packages/terminal-core/src/note.js";
import type { ConfigSnapshotReadMeasure } from "../../config/io.js";
import { ExitError } from "../../runtime.js";
import { captureEnv, deleteTestEnvValue, setTestEnvValue } from "../../test-utils/env.js";
import { formatCliCommand } from "../command-format.js";
@@ -504,6 +505,53 @@ describe("ensureConfigReady", () => {
);
});
it("forwards config snapshot phase measurement", async () => {
const snapshot = makeSnapshot();
const measuredStages: string[] = [];
const measure: ConfigSnapshotReadMeasure = async (stage, run) => {
measuredStages.push(stage);
return await run();
};
readConfigFileSnapshotMock.mockImplementationOnce(
async (options?: { measure?: ConfigSnapshotReadMeasure }) => {
await options?.measure?.("config.snapshot.read.validate", async () => undefined);
return snapshot;
},
);
await ensureConfigReady({
runtime: makeRuntime() as never,
commandPath: ["health"],
measure,
});
expect(measuredStages).toEqual(["config.snapshot.read.validate"]);
});
it("forwards config snapshot phase measurement through doctor preflight", async () => {
const root = useTempOpenClawHome();
writeStateMarker(root, "plugins/installs.json");
const measuredStages: string[] = [];
const measure: ConfigSnapshotReadMeasure = async (stage, run) => {
measuredStages.push(stage);
return await run();
};
loadAndMaybeMigrateDoctorConfigMock.mockImplementationOnce(
async (options?: { measure?: ConfigSnapshotReadMeasure }) => {
await options?.measure?.("config.snapshot.read.validate", async () => undefined);
return { snapshot: makeSnapshot(), baseConfig: {} };
},
);
await ensureConfigReady({
runtime: makeRuntime() as never,
commandPath: ["agent"],
measure,
});
expect(measuredStages).toEqual(["config.snapshot.read.validate"]);
});
it("pins plugin listing config without loading state migration runtime", async () => {
const snapshot = {
...makeSnapshot(),
src/cli/program/config-guard.ts
+16 -5
View File
@@ -5,6 +5,7 @@ import path from "node:path";
import { withSuppressedNotes } from "../../../packages/terminal-core/src/note.js";
import { readConfigFileSnapshot, setRuntimeConfigSnapshot } from "../../config/config.js";
import { createInvalidConfigError } from "../../config/io.invalid-config.js";
import type { ConfigSnapshotReadMeasure } from "../../config/io.js";
import {
resolveIsNixMode,
resolveLegacyStateDirs,
@@ -189,16 +190,22 @@ function isGatewayStartupCommand(commandPath: string[]): boolean {
);
}
async function getConfigSnapshot(options?: { observe: false; skipPluginValidation?: true }) {
async function getConfigSnapshot(
options?: { observe: false; skipPluginValidation?: true },
measure?: ConfigSnapshotReadMeasure,
) {
if (options?.observe === false) {
return readConfigFileSnapshot(options);
return readConfigFileSnapshot({
...options,
...(measure ? { measure } : {}),
});
}
// Tests often mutate config fixtures; caching can make those flaky.
if (process.env.VITEST === "true") {
return readConfigFileSnapshot();
return readConfigFileSnapshot(measure ? { measure } : undefined);
}
if (!configSnapshotPromise) {
const pendingSnapshot = readConfigFileSnapshot();
const pendingSnapshot = readConfigFileSnapshot(measure ? { measure } : undefined);
configSnapshotPromise = pendingSnapshot;
pendingSnapshot.catch(() => {
if (configSnapshotPromise === pendingSnapshot) {
@@ -216,6 +223,7 @@ export async function ensureConfigReady(
suppressDoctorStdout?: boolean;
allowInvalid?: boolean;
beforeStateMigrations?: (snapshot?: ConfigFileSnapshot) => Promise<boolean>;
measure?: ConfigSnapshotReadMeasure;
skipPristineCoreStateMigrations?: boolean;
skipPristineStartupStateMigrations?: boolean;
},
@@ -234,6 +242,7 @@ export async function ensureConfigReady(
migrateState: true,
migrateLegacyConfig: false,
invalidConfigNote: false,
...(params.measure ? { measure: params.measure } : {}),
...(commandName === "status" ? { observe: false } : {}),
...(shouldRequireStartupMigrationCheckpoint(commandPath)
? { requireStartupMigrationCheckpoint: true }
@@ -276,7 +285,8 @@ export async function ensureConfigReady(
: commandName === "status" || (commandName === "gateway" && subcommandName === "call")
? ({ observe: false } as const)
: undefined;
let snapshot = preflightSnapshot ?? (await getConfigSnapshot(configSnapshotOptions));
let snapshot =
preflightSnapshot ?? (await getConfigSnapshot(configSnapshotOptions, params.measure));
if (
!preflightSnapshot &&
!didRunDoctorConfigFlow &&
@@ -392,6 +402,7 @@ export async function ensureConfigReady(
migrateState: false,
migrateLegacyConfig: false,
invalidConfigNote: false,
...(params.measure ? { measure: params.measure } : {}),
...configSnapshotOptions,
})
).snapshot;
src/cli/program/preaction.test.ts
+26
View File
@@ -311,6 +311,7 @@ describe("registerPreActionHooks", () => {
expect(setVerboseMock).toHaveBeenCalledWith(true);
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["status"],
});
expect(ensurePluginRegistryLoadedMock).not.toHaveBeenCalled();
@@ -326,6 +327,7 @@ describe("registerPreActionHooks", () => {
expect(process.env.NODE_NO_WARNINGS).toBe("1");
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["agents", "list"],
});
expect(ensurePluginRegistryLoadedMock).not.toHaveBeenCalled();
@@ -372,6 +374,7 @@ describe("registerPreActionHooks", () => {
expect.objectContaining({
beforeStateMigrations: expect.any(Function),
commandPath: ["gateway", "run"],
measure: expect.any(Function),
skipPristineCoreStateMigrations: true,
skipPristineStartupStateMigrations: true,
}),
@@ -403,6 +406,7 @@ describe("registerPreActionHooks", () => {
expect.objectContaining({
allowInvalid: true,
commandPath: ["gateway", "run"],
measure: expect.any(Function),
}),
);
});
@@ -415,6 +419,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["update"],
allowInvalid: true,
});
@@ -427,6 +432,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["update", "status"],
allowInvalid: true,
suppressDoctorStdout: true,
@@ -441,6 +447,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["agent"],
});
expect(ensurePluginRegistryLoadedMock).toHaveBeenCalledWith({
@@ -456,6 +463,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["agent"],
suppressDoctorStdout: true,
});
@@ -484,6 +492,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["onboard"],
});
expect(ensurePluginRegistryLoadedMock).not.toHaveBeenCalled();
@@ -496,6 +505,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["channels", "add"],
});
expect(ensurePluginRegistryLoadedMock).not.toHaveBeenCalled();
@@ -571,6 +581,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["plugins", "install"],
allowInvalid: true,
});
@@ -583,6 +594,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["plugins", "install"],
allowInvalid: true,
});
@@ -595,6 +607,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["plugins", "install"],
allowInvalid: true,
});
@@ -607,6 +620,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["plugins", "install"],
allowInvalid: true,
});
@@ -619,6 +633,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["plugins", "install"],
});
@@ -630,6 +645,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["plugins", "install"],
allowInvalid: true,
});
@@ -650,6 +666,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["plugins", "install"],
});
});
@@ -726,6 +743,7 @@ describe("registerPreActionHooks", () => {
expect.objectContaining({
runtime: runtimeMock,
commandPath: ["skills", action],
measure: expect.any(Function),
}),
);
});
@@ -738,6 +756,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["status"],
suppressDoctorStdout: true,
});
@@ -751,6 +770,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["update", "status"],
allowInvalid: true,
suppressDoctorStdout: true,
@@ -765,6 +785,7 @@ describe("registerPreActionHooks", () => {
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["config", "set"],
});
});
@@ -852,6 +873,7 @@ describe("registerPreActionHooks", () => {
expect(observedMachineOutputStdoutIsTTY).toBe(false);
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["machine"],
suppressDoctorStdout: true,
});
@@ -866,6 +888,7 @@ describe("registerPreActionHooks", () => {
expect(routeLogsToStderrMock).toHaveBeenCalledOnce();
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["acp"],
suppressDoctorStdout: true,
});
@@ -879,6 +902,7 @@ describe("registerPreActionHooks", () => {
expect(routeLogsToStderrMock).not.toHaveBeenCalled();
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["acp", "client"],
});
@@ -891,6 +915,7 @@ describe("registerPreActionHooks", () => {
expect(routeLogsToStderrMock).toHaveBeenCalledOnce();
expect(ensureConfigReadyMock).toHaveBeenCalledWith({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: ["mcp", "serve"],
suppressDoctorStdout: true,
});
@@ -918,6 +943,7 @@ describe("registerPreActionHooks", () => {
const bootstrap = ensureConfigReadyMock.mock.calls.at(-1)?.[0];
expect(bootstrap).toEqual({
runtime: runtimeMock,
measure: expect.any(Function),
commandPath: testCase.expectedPath,
suppressDoctorStdout: true,
});
src/cli/program/register.agent-turn.ts
+9 -6
View File
@@ -4,6 +4,7 @@ import type { Command } from "commander";
import { formatDocsLink } from "../../../packages/terminal-core/src/links.js";
import { theme } from "../../../packages/terminal-core/src/theme.js";
import { THINKING_LEVELS_HELP } from "../../auto-reply/thinking.shared.js";
import { measureCliCommandStartup } from "../command-startup-timing.js";
import { formatHelpExamples } from "../help-format.js";
type AgentViaGatewayModule = typeof import("../../commands/agent-via-gateway.js");
@@ -108,12 +109,14 @@ ${theme.muted("Docs:")} ${formatDocsLink("/cli/agent", "docs.openclaw.ai/cli/age
const verboseLevel =
typeof opts.verbose === "string" ? normalizeLowercaseStringOrEmpty(opts.verbose) : "";
const [defaultRuntime, runCommandWithRuntime, setVerbose, agentCliCommand] =
await Promise.all([
loadDefaultRuntime(),
loadRunCommandWithRuntime(),
loadSetVerbose(),
loadAgentCliCommand(),
]);
await measureCliCommandStartup("agent-action-imports", () =>
Promise.all([
loadDefaultRuntime(),
loadRunCommandWithRuntime(),
loadSetVerbose(),
loadAgentCliCommand(),
]),
);
await runCommandWithRuntime(defaultRuntime, async () => {
setVerbose(verboseLevel === "on");
await agentCliCommand(opts, defaultRuntime);