chore(gateway): add startup trace attribution (#81738)

Adds owner-level startup trace attribution for gateway auth, plugin loading, lookup counts, and plugin sidecar services.

Verification:
- node scripts/run-vitest.mjs src/plugins/startup-trace-segment.test.ts src/plugins/services.test.ts src/plugins/loader.test.ts src/gateway/server-startup-config.secrets.test.ts
- pnpm build
- pnpm check

CI override:
- Red checks are unrelated baseline noise. The failed CI shard is src/cli/plugins-install-persist.test.ts, which fails on origin/main 336ba2a2b3 with the same missing resolveIsNixMode mock export. PR #81738 touches gateway/plugin startup trace files and CHANGELOG.md, not the failing CLI plugin install test.

Thanks @samzong.

Co-authored-by: samzong <13782141+samzong@users.noreply.github.com>
This commit is contained in:
samzong
2026-05-14 16:50:08 +08:00
committed by GitHub
parent 12b8db34ee
commit 1d121c1f08
12 changed files with 371 additions and 33 deletions

View File

@@ -11,6 +11,7 @@ Docs: https://docs.openclaw.ai
- Plugins: externalize Slack, OpenShell sandbox, and Anthropic Vertex so their runtime dependency cones install only when those plugins are installed.
- Control UI/WebChat: add a persisted auto-scroll mode selector so users can keep the current near-bottom behavior, always follow streaming output, or turn automatic streaming scroll off and use the New messages button manually. Fixes #7648 and #81287. Thanks @BunsDev.
- ACP: add `acp.fallbacks` so ACP turns can try configured backup runtime backends when the primary backend is unavailable before any output is emitted. (#69542) Thanks @kaseonedge.
- Gateway/startup: add owner-level startup trace attribution for auth, plugin loading, lookup counts, and plugin sidecar services. (#81738) Thanks @samzong.
### Fixes

View File

@@ -661,6 +661,8 @@ export function loadGatewayPlugins(params: {
["pluginIdsMs", pluginIdsMs],
["loadMs", 0],
["pluginIds", "0"],
["pluginCount", 0],
["gatewayHandlerCount", 0],
]);
return {
pluginRegistry,
@@ -692,6 +694,9 @@ export function loadGatewayPlugins(params: {
},
preferSetupRuntimeForChannelPlugins: params.preferSetupRuntimeForChannelPlugins,
preferBuiltPluginArtifacts: true,
...(params.startupTrace !== undefined && {
startupTrace: params.startupTrace,
}),
...(params.pluginLookUpTable?.manifestRegistry
? { manifestRegistry: params.pluginLookUpTable.manifestRegistry }
: {}),
@@ -706,7 +711,9 @@ export function loadGatewayPlugins(params: {
["pluginIdsMs", pluginIdsMs],
["loadMs", loadMs],
["pluginIds", String(pluginIds.length)],
["pluginCount", pluginIds.length],
["gatewayHandlers", String(pluginMethods.length)],
["gatewayHandlerCount", pluginMethods.length],
["loaderCallsCount", loaderStatsAfter.calls - loaderStatsBefore.calls],
["loaderNativeHitsCount", loaderStatsAfter.nativeHits - loaderStatsBefore.nativeHits],
["loaderNativeMissesCount", loaderStatsAfter.nativeMisses - loaderStatsBefore.nativeMisses],

View File

@@ -86,6 +86,41 @@ describe("gateway startup config secret preflight", () => {
}
});
it("measures startup auth subphases", async () => {
const prepareRuntimeSecretsSnapshot = vi.fn(async ({ config }) => preparedSnapshot(config));
const measured: string[] = [];
await prepareGatewayStartupConfig({
configSnapshot: buildSnapshot(gatewayTokenConfig({})),
activateRuntimeSecrets: createRuntimeSecretsActivator({
logSecrets: {
info: vi.fn(),
warn: vi.fn(),
error: vi.fn(),
},
emitStateEvent: vi.fn(),
prepareRuntimeSecretsSnapshot,
activateRuntimeSecretsSnapshot: vi.fn(),
}),
measure: async (name, run) => {
measured.push(name);
return await run();
},
});
expect(measured).toEqual([
"config.auth.snapshot-validate",
"config.auth.runtime-overrides",
"config.auth.startup-overrides",
"config.auth.secret-surface",
"config.auth.secret-preflight",
"config.auth.preflight-override",
"config.auth.ensure",
"config.auth.runtime-startup-overrides",
"config.auth.secrets-activate",
]);
});
it("wraps startup secret activation failures without emitting reload state events", async () => {
const error = new Error('Environment variable "OPENAI_API_KEY" is missing or empty.');
const prepareRuntimeSecretsSnapshot = vi.fn(async () => {

View File

@@ -234,24 +234,37 @@ export async function prepareGatewayStartupConfig(params: {
tailscaleOverride?: GatewayTailscaleConfig;
activateRuntimeSecrets: ActivateRuntimeSecrets;
persistStartupAuth?: boolean;
measure?: GatewayStartupConfigMeasure;
}): Promise<Awaited<ReturnType<typeof ensureGatewayStartupAuth>>> {
assertValidGatewayStartupConfigSnapshot(params.configSnapshot);
const measure = params.measure ?? (async (_name, run) => await run());
await measure("config.auth.snapshot-validate", () =>
assertValidGatewayStartupConfigSnapshot(params.configSnapshot),
);
const runtimeConfig = applyConfigOverrides(params.configSnapshot.config);
const startupPreflightConfig = applyGatewayAuthOverridesForStartupPreflight(runtimeConfig, {
auth: params.authOverride,
tailscale: params.tailscaleOverride,
const runtimeConfig = await measure("config.auth.runtime-overrides", () =>
applyConfigOverrides(params.configSnapshot.config),
);
const startupPreflightConfig = await measure("config.auth.startup-overrides", () =>
applyGatewayAuthOverridesForStartupPreflight(runtimeConfig, {
auth: params.authOverride,
tailscale: params.tailscaleOverride,
}),
);
const needsAuthSecretPreflight = await measure("config.auth.secret-surface", () =>
hasActiveGatewayAuthSecretRef(startupPreflightConfig),
);
const preflightConfig = await measure("config.auth.secret-preflight", async () => {
if (!needsAuthSecretPreflight) {
return startupPreflightConfig;
}
return (
await params.activateRuntimeSecrets(startupPreflightConfig, {
reason: "startup",
activate: false,
})
).config;
});
const needsAuthSecretPreflight = hasActiveGatewayAuthSecretRef(startupPreflightConfig);
const preflightConfig = needsAuthSecretPreflight
? (
await params.activateRuntimeSecrets(startupPreflightConfig, {
reason: "startup",
activate: false,
})
).config
: startupPreflightConfig;
const preflightAuthOverride =
const preflightAuthOverride = await measure("config.auth.preflight-override", () =>
typeof preflightConfig.gateway?.auth?.token === "string" ||
typeof preflightConfig.gateway?.auth?.password === "string"
? {
@@ -263,25 +276,32 @@ export async function prepareGatewayStartupConfig(params: {
? { password: preflightConfig.gateway.auth.password }
: {}),
}
: params.authOverride;
: params.authOverride,
);
const authBootstrap = await ensureGatewayStartupAuth({
cfg: runtimeConfig,
env: process.env,
authOverride: preflightAuthOverride,
tailscaleOverride: params.tailscaleOverride,
persist: params.persistStartupAuth ?? false,
baseHash: params.configSnapshot.hash,
});
const runtimeStartupConfig = applyGatewayAuthOverridesForStartupPreflight(authBootstrap.cfg, {
auth: params.authOverride,
tailscale: params.tailscaleOverride,
});
const authBootstrap = await measure("config.auth.ensure", () =>
ensureGatewayStartupAuth({
cfg: runtimeConfig,
env: process.env,
authOverride: preflightAuthOverride,
tailscaleOverride: params.tailscaleOverride,
persist: params.persistStartupAuth ?? false,
baseHash: params.configSnapshot.hash,
}),
);
const runtimeStartupConfig = await measure("config.auth.runtime-startup-overrides", () =>
applyGatewayAuthOverridesForStartupPreflight(authBootstrap.cfg, {
auth: params.authOverride,
tailscale: params.tailscaleOverride,
}),
);
const activatedConfig = (
await params.activateRuntimeSecrets(runtimeStartupConfig, {
reason: "startup",
activate: true,
})
await measure("config.auth.secrets-activate", () =>
params.activateRuntimeSecrets(runtimeStartupConfig, {
reason: "startup",
activate: true,
}),
)
).config;
return {
...authBootstrap,

View File

@@ -520,6 +520,7 @@ export async function startGatewaySidecars(params: {
registry: params.pluginRegistry,
config: params.cfg,
workspaceDir: params.defaultWorkspaceDir,
startupTrace: params.startupTrace,
});
} catch (err) {
params.log.warn(`plugin services failed to start: ${String(err)}`);

View File

@@ -583,6 +583,7 @@ export async function startGatewayServer(
authOverride: opts.auth,
tailscaleOverride: opts.tailscale,
activateRuntimeSecrets,
measure: (name, run) => startupTrace.measure(name, run),
}),
);
cfgAtStart = authBootstrap.cfg;
@@ -666,9 +667,13 @@ export async function startGatewayServer(
["ownerMapsMs", metrics.ownerMapsMs],
["totalMs", metrics.totalMs],
["indexPlugins", String(metrics.indexPluginCount)],
["indexPluginCount", metrics.indexPluginCount],
["manifestPlugins", String(metrics.manifestPluginCount)],
["manifestPluginCount", metrics.manifestPluginCount],
["startupPlugins", String(metrics.startupPluginCount)],
["startupPluginCount", metrics.startupPluginCount],
["deferredChannelPlugins", String(metrics.deferredChannelPluginCount)],
["deferredChannelPluginCount", metrics.deferredChannelPluginCount],
]);
}
let { pluginRegistry, baseGatewayMethods } = pluginBootstrap;

View File

@@ -46,6 +46,7 @@ import {
__testing,
clearPluginLoaderCache,
loadOpenClawPlugins,
type PluginLoadOptions,
PluginLoadReentryError,
resolveRuntimePluginRegistry,
} from "./loader.js";
@@ -96,6 +97,10 @@ let cachedBundledTelegramDir = "";
let cachedBundledMemoryDir = "";
type GlobalHookRunner = NonNullable<ReturnType<typeof getGlobalHookRunner>>;
type PluginStartupTraceDetail = {
name: string;
metrics: ReadonlyArray<readonly [string, number | string]>;
};
function countMatching<T>(items: readonly T[], predicate: (item: T) => boolean): number {
let count = 0;
@@ -913,6 +918,36 @@ function expectEscapingEntryRejected(params: {
return registry;
}
function createStartupTraceRecorder(): {
details: PluginStartupTraceDetail[];
startupTrace: NonNullable<PluginLoadOptions["startupTrace"]>;
} {
const details: PluginStartupTraceDetail[] = [];
return {
details,
startupTrace: {
detail: (name, metrics) => {
details.push({ name, metrics });
},
},
};
}
function collectStartupTraceMetrics(
details: readonly PluginStartupTraceDetail[],
name: string,
): Record<string, number | string> {
const matched = details.filter((entry) => entry.name === name);
expect(matched.length).toBeGreaterThan(0);
const metrics: Record<string, number | string> = {};
for (const entry of matched) {
for (const [key, value] of entry.metrics) {
metrics[key] = value;
}
}
return metrics;
}
afterEach(() => {
clearRuntimeConfigSnapshot();
runtimeRegistryLoaderTesting.resetPluginRegistryLoadedForTests();
@@ -926,6 +961,76 @@ afterAll(() => {
});
describe("loadOpenClawPlugins", () => {
it("emits loader startup trace timings for normal plugin load and register", () => {
useNoBundledPlugins();
const plugin = writePlugin({
id: "trace-plugin",
filename: "trace-plugin.cjs",
body: `module.exports = { id: "trace-plugin", register() {} };`,
});
const { details, startupTrace } = createStartupTraceRecorder();
loadRegistryFromSinglePlugin({
plugin,
pluginConfig: {
allow: ["trace-plugin"],
},
options: {
startupTrace,
},
});
const metrics = collectStartupTraceMetrics(details, "plugins.gateway-load.plugin.trace-plugin");
expect(metrics.loadMs).toEqual(expect.any(Number));
expect(metrics.loadFailedCount).toBe(0);
expect(metrics.registerMs).toEqual(expect.any(Number));
expect(metrics.registerFailedCount).toBe(0);
expect(metrics.loadAndRegisterMs).toEqual(expect.any(Number));
});
it("emits loader startup trace failure counts for load and register failures", () => {
useNoBundledPlugins();
const loadFailPlugin = writePlugin({
id: "trace-load-fail",
filename: "trace-load-fail.cjs",
body: `throw new Error("load boom");`,
});
const registerFailPlugin = writePlugin({
id: "trace-register-fail",
filename: "trace-register-fail.cjs",
body: `module.exports = { id: "trace-register-fail", register() { throw new Error("register boom"); } };`,
});
const { details, startupTrace } = createStartupTraceRecorder();
loadOpenClawPlugins({
cache: false,
config: {
plugins: {
load: { paths: [loadFailPlugin.file, registerFailPlugin.file] },
allow: ["trace-load-fail", "trace-register-fail"],
},
},
startupTrace,
});
const loadFailMetrics = collectStartupTraceMetrics(
details,
"plugins.gateway-load.plugin.trace-load-fail",
);
expect(loadFailMetrics.loadMs).toEqual(expect.any(Number));
expect(loadFailMetrics.loadFailedCount).toBe(1);
expect(loadFailMetrics.registerMs).toBeUndefined();
const registerFailMetrics = collectStartupTraceMetrics(
details,
"plugins.gateway-load.plugin.trace-register-fail",
);
expect(registerFailMetrics.loadFailedCount).toBe(0);
expect(registerFailMetrics.registerMs).toEqual(expect.any(Number));
expect(registerFailMetrics.registerFailedCount).toBe(1);
expect(registerFailMetrics.loadAndRegisterMs).toEqual(expect.any(Number));
});
it("can load scoped plugins from a supplied manifest registry without rereading manifests", () => {
useNoBundledPlugins();
const plugin = writePlugin({

View File

@@ -148,6 +148,7 @@ import {
shouldPreferNativeModuleLoad,
} from "./sdk-alias.js";
import { hasKind, kindsEqual } from "./slots.js";
import { encodeStartupTraceSegment } from "./startup-trace-segment.js";
import type {
OpenClawPluginApi,
OpenClawPluginDefinition,
@@ -172,6 +173,9 @@ export type PluginLoadOptions = {
coreGatewayMethodNames?: readonly string[];
hostServices?: PluginRegistryParams["hostServices"];
runtimeOptions?: CreatePluginRuntimeOptions;
startupTrace?: {
detail: (name: string, metrics: ReadonlyArray<readonly [string, number | string]>) => void;
};
pluginSdkResolution?: PluginSdkResolutionPreference;
cache?: boolean;
mode?: "full" | "validate";
@@ -196,6 +200,17 @@ export type PluginLoadOptions = {
manifestRegistry?: PluginManifestRegistry;
};
function detailPluginStartupTrace(
startupTrace: PluginLoadOptions["startupTrace"] | undefined,
pluginId: string,
metrics: ReadonlyArray<readonly [string, number | string]>,
): void {
startupTrace?.detail(
`plugins.gateway-load.plugin.${encodeStartupTraceSegment(pluginId)}`,
metrics,
);
}
const CLI_METADATA_ENTRY_BASENAMES = [
"cli-metadata.ts",
"cli-metadata.js",
@@ -2061,6 +2076,9 @@ export function loadOpenClawPlugins(options: PluginLoadOptions = {}): PluginRegi
fs.closeSync(opened.fd);
let mod: OpenClawPluginModule | null = null;
let moduleLoadMs = 0;
let moduleLoadFailed = false;
const beforeModuleLoad = performance.now();
try {
// Track the plugin as imported once module evaluation begins. Top-level
// code may have already executed even if evaluation later throws.
@@ -2085,7 +2103,14 @@ export function loadOpenClawPlugins(options: PluginLoadOptions = {}): PluginRegi
logPrefix: `[plugins] ${record.id} failed to load from ${record.source}: `,
diagnosticMessagePrefix: "failed to load plugin: ",
});
moduleLoadFailed = true;
continue;
} finally {
moduleLoadMs = performance.now() - beforeModuleLoad;
detailPluginStartupTrace(options.startupTrace, record.id, [
["loadMs", moduleLoadMs],
["loadFailedCount", moduleLoadFailed ? 1 : 0],
]);
}
if (registrationPlan.loadSetupEntry && manifestRecord.setupSource) {
@@ -2383,6 +2408,8 @@ export function loadOpenClawPlugins(options: PluginLoadOptions = {}): PluginRegi
const previousMemoryCorpusSupplements = listMemoryCorpusSupplements();
const previousMemoryPromptSupplements = listMemoryPromptSupplements();
const beforeRegister = performance.now();
let registerFailed = false;
try {
withProfile(
{ pluginId: record.id, source: record.source },
@@ -2427,6 +2454,14 @@ export function loadOpenClawPlugins(options: PluginLoadOptions = {}): PluginRegi
logPrefix: `[plugins] ${record.id} failed during register from ${record.source}: `,
diagnosticMessagePrefix: "plugin failed during register: ",
});
registerFailed = true;
} finally {
const registerMs = performance.now() - beforeRegister;
detailPluginStartupTrace(options.startupTrace, record.id, [
["registerMs", registerMs],
["loadAndRegisterMs", moduleLoadMs + registerMs],
["registerFailedCount", registerFailed ? 1 : 0],
]);
}
}

View File

@@ -90,11 +90,13 @@ async function startTrackingServices(params: {
services: OpenClawPluginService[];
config?: Parameters<typeof startPluginServices>[0]["config"];
workspaceDir?: string;
startupTrace?: Parameters<typeof startPluginServices>[0]["startupTrace"];
}) {
return startPluginServices({
registry: createRegistry(params.services),
config: params.config ?? createServiceConfig(),
...(params.workspaceDir ? { workspaceDir: params.workspaceDir } : {}),
...(params.startupTrace ? { startupTrace: params.startupTrace } : {}),
});
}
@@ -190,6 +192,71 @@ describe("startPluginServices", () => {
expect(stopThrows).toHaveBeenCalledOnce();
});
it("emits per-service startup trace spans and summary", async () => {
const measured: string[] = [];
const details: Array<{
name: string;
metrics: ReadonlyArray<readonly [string, number | string]>;
}> = [];
const startupTrace: NonNullable<Parameters<typeof startPluginServices>[0]["startupTrace"]> = {
measure: async (name, run) => {
measured.push(name);
return await run();
},
detail: (name, metrics) => {
details.push({ name, metrics });
},
};
await startTrackingServices({
services: [
createTrackingService("service-a"),
createTrackingService("service-fail", { failOnStart: true }),
],
startupTrace,
});
expect(measured).toEqual([
"sidecars.plugin-services.plugin~003Atest.service-a",
"sidecars.plugin-services.plugin~003Atest.service-fail",
]);
expect(details).toEqual([
{
name: "sidecars.plugin-services.summary",
metrics: [
["serviceCount", 2],
["startedCount", 1],
["failedCount", 1],
],
},
]);
});
it("keeps distinct service trace ownership keys non-colliding", async () => {
const measured: string[] = [];
const startupTrace: NonNullable<Parameters<typeof startPluginServices>[0]["startupTrace"]> = {
measure: async (name, run) => {
measured.push(name);
return await run();
},
};
await startPluginServices({
registry: createRegistry(
[createTrackingService("service:a"), createTrackingService("service_a")],
"plugin:test",
),
config: createServiceConfig(),
startupTrace,
});
expect(measured).toEqual([
"sidecars.plugin-services.plugin~003Atest.service~003Aa",
"sidecars.plugin-services.plugin~003Atest.service_a",
]);
expect(new Set(measured).size).toBe(measured.length);
});
it("grants internal diagnostics only to trusted diagnostics exporter services", async () => {
const contexts: OpenClawPluginServiceContext[] = [];
const diagnosticsService = createTrackingService("diagnostics-otel", { contexts });

View File

@@ -7,6 +7,7 @@ import {
import { createSubsystemLogger } from "../logging/subsystem.js";
import type { PluginServiceRegistration } from "./registry-types.js";
import type { PluginRegistry } from "./registry.js";
import { encodeStartupTraceSegment } from "./startup-trace-segment.js";
import type { OpenClawPluginServiceContext, PluginLogger } from "./types.js";
const log = createSubsystemLogger("plugins");
@@ -52,15 +53,22 @@ export type PluginServicesHandle = {
stop: () => Promise<void>;
};
type PluginServiceStartupTrace = {
detail?: (name: string, metrics: ReadonlyArray<readonly [string, number | string]>) => void;
measure: <T>(name: string, run: () => T | Promise<T>) => Promise<T>;
};
export async function startPluginServices(params: {
registry: PluginRegistry;
config: OpenClawConfig;
workspaceDir?: string;
startupTrace?: PluginServiceStartupTrace;
}): Promise<PluginServicesHandle> {
const running: Array<{
id: string;
stop?: () => void | Promise<void>;
}> = [];
let failedCount = 0;
for (const entry of params.registry.services) {
const service = entry.service;
const serviceContext = createServiceContext({
@@ -69,18 +77,30 @@ export async function startPluginServices(params: {
service: entry,
});
try {
await service.start(serviceContext);
const startService = () => service.start(serviceContext);
const traceName = `sidecars.plugin-services.${encodeStartupTraceSegment(entry.pluginId)}.${encodeStartupTraceSegment(service.id)}`;
if (params.startupTrace) {
await params.startupTrace.measure(traceName, startService);
} else {
await startService();
}
running.push({
id: service.id,
stop: service.stop ? () => service.stop?.(serviceContext) : undefined,
});
} catch (err) {
failedCount += 1;
const error = err as Error;
log.error(
`plugin service failed (${service.id}, plugin=${entry.pluginId}, root=${entry.rootDir ?? "unknown"}): ${error?.message ?? String(err)}`,
);
}
}
params.startupTrace?.detail?.("sidecars.plugin-services.summary", [
["serviceCount", params.registry.services.length],
["startedCount", running.length],
["failedCount", failedCount],
]);
return {
stop: async () => {

View File

@@ -0,0 +1,25 @@
import { describe, expect, it } from "vitest";
import { encodeStartupTraceSegment } from "./startup-trace-segment.js";
describe("encodeStartupTraceSegment", () => {
it("keeps distinct trace owner ids non-colliding", () => {
const encoded = [
encodeStartupTraceSegment("plugin:test"),
encodeStartupTraceSegment("plugin_test"),
encodeStartupTraceSegment("service/a"),
encodeStartupTraceSegment("service_a"),
encodeStartupTraceSegment(""),
encodeStartupTraceSegment("~"),
];
expect(encoded).toEqual([
"plugin~003Atest",
"plugin_test",
"service~002Fa",
"service_a",
"~",
"~007E",
]);
expect(new Set(encoded).size).toBe(encoded.length);
});
});

View File

@@ -0,0 +1,17 @@
const SAFE_STARTUP_TRACE_SEGMENT_CHAR = /^[A-Za-z0-9_-]$/u;
export function encodeStartupTraceSegment(value: string): string {
if (!value) {
return "~";
}
let encoded = "";
for (let index = 0; index < value.length; index += 1) {
const char = value[index] ?? "";
if (SAFE_STARTUP_TRACE_SEGMENT_CHAR.test(char)) {
encoded += char;
continue;
}
encoded += `~${value.charCodeAt(index).toString(16).toUpperCase().padStart(4, "0")}`;
}
return encoded;
}