chore: trace plugin lifecycle phases

This commit is contained in:
Shakker
2026-04-28 15:54:25 +01:00
parent 3d89b0f2ec
commit a48ffda7f7
13 changed files with 566 additions and 244 deletions

View File

@@ -12,6 +12,7 @@ Docs: https://docs.openclaw.ai
### Fixes
- CLI/plugins: use plugin metadata snapshots for install slot selection and add opt-in plugin lifecycle timing traces, so plugin install avoids runtime-loading the plugin registry for metadata-only decisions. Thanks @shakkernerd.
- fix(plugins): restrict bundled plugin dir resolution to trusted package roots. (#73275) Thanks @pgondhi987.
- fix(security): prevent workspace PATH injection via service env and trash helpers. (#73264) Thanks @pgondhi987.
- Active Memory: allow `allowedChatTypes` to include explicit portal/webchat sessions and classify `agent:...:explicit:...` session keys before opaque session ids can shadow the chat type. Fixes #65775. (#66285) Thanks @Lidang-Jiang.

View File

@@ -48,6 +48,10 @@ openclaw plugins marketplace list <marketplace>
openclaw plugins marketplace list <marketplace> --json
```
For slow install, inspect, uninstall, or registry-refresh investigation, run the
command with `OPENCLAW_PLUGIN_LIFECYCLE_TRACE=1`. The trace writes phase timings
to stderr and keeps JSON output parseable. See [Debugging](/help/debugging#plugin-lifecycle-trace).
<Note>
Bundled plugins ship with OpenClaw. Some are enabled by default (for example bundled model providers, bundled speech providers, and the bundled browser plugin); others require `plugins enable`.

View File

@@ -43,6 +43,32 @@ Use `/trace` for plugin diagnostics such as Active Memory debug summaries.
Keep using `/verbose` for normal verbose status/tool output, and keep using
`/debug` for runtime-only config overrides.
## Plugin lifecycle trace
Use `OPENCLAW_PLUGIN_LIFECYCLE_TRACE=1` when plugin lifecycle commands feel slow
and you need a built-in phase breakdown for plugin metadata, discovery, registry,
runtime mirror, config mutation, and refresh work. The trace is opt-in and writes
to stderr, so JSON command output remains parseable.
Example:
```bash
OPENCLAW_PLUGIN_LIFECYCLE_TRACE=1 openclaw plugins install tokenjuice --force
```
Example output:
```text
[plugins:lifecycle] phase="config read" ms=6.83 status=ok command="install"
[plugins:lifecycle] phase="slot selection" ms=94.31 status=ok command="install" pluginId="tokenjuice"
[plugins:lifecycle] phase="registry refresh" ms=51.56 status=ok command="install" reason="source-changed"
```
Use this for plugin lifecycle investigation before reaching for a CPU profiler.
If the command is running from a source checkout, prefer measuring the built
runtime with `node dist/entry.js ...` after `pnpm build`; `pnpm openclaw ...`
also measures source-runner overhead.
## Temporary CLI debug timing
OpenClaw keeps `src/cli/debug-timing.ts` as a small helper for local

View File

@@ -5,6 +5,10 @@ import { getRuntimeConfig, readConfigFileSnapshot, replaceConfigFile } from "../
import { resolveStateDir } from "../config/paths.js";
import type { OpenClawConfig } from "../config/types.openclaw.js";
import type { PluginInstallRecord } from "../config/types.plugins.js";
import {
tracePluginLifecyclePhase,
tracePluginLifecyclePhaseAsync,
} from "../plugins/plugin-lifecycle-trace.js";
import { formatPluginSourceForTable, resolvePluginSourceRoots } from "../plugins/source-display.js";
import type { PluginLogger } from "../plugins/types.js";
import { defaultRuntime } from "../runtime.js";
@@ -264,18 +268,29 @@ export function registerPluginsCli(program: Command) {
} = await import("../plugins/status.js");
const { loadInstalledPluginIndexInstallRecords } =
await import("../plugins/installed-plugin-index-records.js");
const cfg = getRuntimeConfig();
const installRecords = await loadInstalledPluginIndexInstallRecords();
const cfg = tracePluginLifecyclePhase("config read", () => getRuntimeConfig(), {
command: "inspect",
});
const installRecords = await tracePluginLifecyclePhaseAsync(
"install records load",
() => loadInstalledPluginIndexInstallRecords(),
{ command: "inspect" },
);
const loggerParams = opts.json ? { logger: quietPluginJsonLogger } : {};
if (opts.all) {
if (id) {
defaultRuntime.error("Pass either a plugin id or --all, not both.");
return defaultRuntime.exit(1);
}
const report = buildPluginDiagnosticsReport({
config: cfg,
...loggerParams,
});
const report = tracePluginLifecyclePhase(
"runtime plugin registry load",
() =>
buildPluginDiagnosticsReport({
config: cfg,
...loggerParams,
}),
{ command: "inspect", all: true },
);
const inspectAll = buildAllPluginInspectReports({
config: cfg,
...loggerParams,
@@ -344,10 +359,15 @@ export function registerPluginsCli(program: Command) {
return defaultRuntime.exit(1);
}
const snapshotReport = buildPluginSnapshotReport({
config: cfg,
...loggerParams,
});
const snapshotReport = tracePluginLifecyclePhase(
"plugin registry snapshot",
() =>
buildPluginSnapshotReport({
config: cfg,
...loggerParams,
}),
{ command: "inspect" },
);
const targetPlugin = snapshotReport.plugins.find(
(entry) => entry.id === id || entry.name === id,
);
@@ -355,11 +375,16 @@ export function registerPluginsCli(program: Command) {
defaultRuntime.error(`Plugin not found: ${id}`);
return defaultRuntime.exit(1);
}
const report = buildPluginDiagnosticsReport({
config: cfg,
...loggerParams,
onlyPluginIds: [targetPlugin.id],
});
const report = tracePluginLifecyclePhase(
"runtime plugin registry load",
() =>
buildPluginDiagnosticsReport({
config: cfg,
...loggerParams,
onlyPluginIds: [targetPlugin.id],
}),
{ command: "inspect", pluginId: targetPlugin.id },
);
const inspect = buildPluginInspectReport({
id: targetPlugin.id,
config: cfg,
@@ -603,11 +628,23 @@ export function registerPluginsCli(program: Command) {
await import("./plugins-registry-refresh.js");
const { resolvePluginUninstallId } = await import("./plugins-uninstall-selection.js");
const { promptYesNo } = await import("./prompt.js");
const snapshot = await readConfigFileSnapshot();
const snapshot = await tracePluginLifecyclePhaseAsync(
"config read",
() => readConfigFileSnapshot(),
{ command: "uninstall" },
);
const sourceConfig = (snapshot.sourceConfig ?? snapshot.config) as OpenClawConfig;
const installRecords = await loadInstalledPluginIndexInstallRecords();
const installRecords = await tracePluginLifecyclePhaseAsync(
"install records load",
() => loadInstalledPluginIndexInstallRecords(),
{ command: "uninstall" },
);
const cfg = withPluginInstallRecords(sourceConfig, installRecords);
const report = buildPluginSnapshotReport({ config: cfg });
const report = tracePluginLifecyclePhase(
"plugin registry snapshot",
() => buildPluginSnapshotReport({ config: cfg }),
{ command: "uninstall" },
);
const extensionsDir = path.join(resolveStateDir(process.env, os.homedir), "extensions");
const keepFiles = Boolean(opts.keepFiles || opts.keepConfig);
@@ -702,12 +739,17 @@ export function registerPluginsCli(program: Command) {
const nextInstallRecords = removePluginInstallRecordFromRecords(installRecords, pluginId);
const nextConfig = withoutPluginInstallRecords(plan.config);
await commitPluginInstallRecordsWithConfig({
previousInstallRecords: installRecords,
nextInstallRecords,
nextConfig,
...(snapshot.hash !== undefined ? { baseHash: snapshot.hash } : {}),
});
await tracePluginLifecyclePhaseAsync(
"config mutation",
() =>
commitPluginInstallRecordsWithConfig({
previousInstallRecords: installRecords,
nextInstallRecords,
nextConfig,
...(snapshot.hash !== undefined ? { baseHash: snapshot.hash } : {}),
}),
{ command: "uninstall" },
);
const directoryResult = await applyPluginUninstallDirectoryRemoval(plan.directoryRemoval);
for (const warning of directoryResult.warnings) {
defaultRuntime.log(theme.warn(warning));
@@ -716,6 +758,7 @@ export function registerPluginsCli(program: Command) {
config: nextConfig,
reason: "source-changed",
installRecords: nextInstallRecords,
traceCommand: "uninstall",
logger: {
warn: (message) => defaultRuntime.log(theme.warn(message)),
},
@@ -764,8 +807,14 @@ export function registerPluginsCli(program: Command) {
marketplace?: string;
},
) => {
const { runPluginInstallCommand } = await import("./plugins-install-command.js");
await runPluginInstallCommand({ raw, opts });
await tracePluginLifecyclePhaseAsync(
"install command",
async () => {
const { runPluginInstallCommand } = await import("./plugins-install-command.js");
await runPluginInstallCommand({ raw, opts });
},
{ command: "install" },
);
},
);

View File

@@ -20,6 +20,7 @@ import {
installPluginFromMarketplace,
resolveMarketplaceInstallShortcut,
} from "../plugins/marketplace.js";
import { tracePluginLifecyclePhaseAsync } from "../plugins/plugin-lifecycle-trace.js";
import { validateJsonSchemaValue } from "../plugins/schema-validator.js";
import { defaultRuntime } from "../runtime.js";
import { theme } from "../terminal/theme.js";
@@ -394,7 +395,11 @@ async function loadConfigFromSnapshotForInstall(
export async function loadConfigForInstall(
request: PluginInstallRequestContext,
): Promise<ConfigSnapshotForInstallPersist> {
const snapshot = await readConfigFileSnapshot();
const snapshot = await tracePluginLifecyclePhaseAsync(
"config read",
() => readConfigFileSnapshot(),
{ command: "install" },
);
if (snapshot.valid) {
return {
config: snapshot.sourceConfig,
@@ -414,7 +419,11 @@ export async function runPluginInstallCommand(params: {
};
}) {
const shorthand = !params.opts.marketplace
? await resolveMarketplaceInstallShortcut(params.raw)
? await tracePluginLifecyclePhaseAsync(
"marketplace shortcut resolution",
() => resolveMarketplaceInstallShortcut(params.raw),
{ command: "install" },
)
: null;
if (shorthand?.ok === false) {
defaultRuntime.error(shorthand.error);
@@ -641,12 +650,21 @@ export async function runPluginInstallCommand(params: {
findBundledSource: (lookup) => findBundledPluginSource({ lookup }),
});
if (bundledPreNpmPlan) {
await installBundledPluginSource({
snapshot,
rawSpec: raw,
bundledSource: bundledPreNpmPlan.bundledSource,
warning: bundledPreNpmPlan.warning,
});
await tracePluginLifecyclePhaseAsync(
"install execution",
() =>
installBundledPluginSource({
snapshot,
rawSpec: raw,
bundledSource: bundledPreNpmPlan.bundledSource,
warning: bundledPreNpmPlan.warning,
}),
{
command: "install",
source: "bundled",
pluginId: bundledPreNpmPlan.bundledSource.pluginId,
},
);
return;
}

View File

@@ -8,6 +8,7 @@ import {
withoutPluginInstallRecords,
} from "../plugins/installed-plugin-index-records.js";
import type { PluginInstallUpdate } from "../plugins/installs.js";
import { tracePluginLifecyclePhaseAsync } from "../plugins/plugin-lifecycle-trace.js";
import { defaultRuntime } from "../runtime.js";
import { theme } from "../terminal/theme.js";
import {
@@ -78,7 +79,11 @@ export async function persistPluginInstall(params: {
: enablePluginInConfig(installConfig, params.pluginId, {
updateChannelConfig: false,
}).config;
const installRecords = await loadInstalledPluginIndexInstallRecords();
const installRecords = await tracePluginLifecyclePhaseAsync(
"install records load",
() => loadInstalledPluginIndexInstallRecords(),
{ command: "install" },
);
const nextInstallRecords = recordPluginInstallInRecords(installRecords, {
pluginId: params.pluginId,
...params.install,
@@ -86,18 +91,28 @@ export async function persistPluginInstall(params: {
const slotResult =
params.enable === false
? { config: next, warnings: [] }
: applySlotSelectionForPlugin(next, params.pluginId);
: await tracePluginLifecyclePhaseAsync(
"slot selection",
async () => applySlotSelectionForPlugin(next, params.pluginId),
{ command: "install", pluginId: params.pluginId },
);
next = withoutPluginInstallRecords(slotResult.config);
await commitPluginInstallRecordsWithConfig({
previousInstallRecords: installRecords,
nextInstallRecords,
nextConfig: next,
baseHash: params.snapshot.baseHash,
});
await tracePluginLifecyclePhaseAsync(
"config mutation",
() =>
commitPluginInstallRecordsWithConfig({
previousInstallRecords: installRecords,
nextInstallRecords,
nextConfig: next,
baseHash: params.snapshot.baseHash,
}),
{ command: "install" },
);
await refreshPluginRegistryAfterConfigMutation({
config: next,
reason: "source-changed",
installRecords: nextInstallRecords,
traceCommand: "install",
logger: {
warn: (message) => defaultRuntime.log(theme.warn(message)),
},

View File

@@ -2,6 +2,7 @@ import type { OpenClawConfig } from "../config/types.openclaw.js";
import { formatErrorMessage } from "../infra/errors.js";
import { loadInstalledPluginIndexInstallRecords } from "../plugins/installed-plugin-index-records.js";
import type { InstalledPluginIndexRefreshReason } from "../plugins/installed-plugin-index.js";
import { tracePluginLifecyclePhaseAsync } from "../plugins/plugin-lifecycle-trace.js";
import { refreshPluginRegistry } from "../plugins/plugin-registry.js";
export type PluginRegistryRefreshLogger = {
@@ -14,19 +15,29 @@ export async function refreshPluginRegistryAfterConfigMutation(params: {
workspaceDir?: string;
env?: NodeJS.ProcessEnv;
installRecords?: Awaited<ReturnType<typeof loadInstalledPluginIndexInstallRecords>>;
traceCommand?: string;
logger?: PluginRegistryRefreshLogger;
}): Promise<void> {
try {
const installRecords =
params.installRecords ??
(await loadInstalledPluginIndexInstallRecords(params.env ? { env: params.env } : {}));
await refreshPluginRegistry({
config: params.config,
reason: params.reason,
installRecords,
...(params.workspaceDir ? { workspaceDir: params.workspaceDir } : {}),
...(params.env ? { env: params.env } : {}),
});
(await tracePluginLifecyclePhaseAsync(
"install records load",
() => loadInstalledPluginIndexInstallRecords(params.env ? { env: params.env } : {}),
{ command: params.traceCommand ?? "registry-refresh" },
));
await tracePluginLifecyclePhaseAsync(
"registry refresh",
() =>
refreshPluginRegistry({
config: params.config,
reason: params.reason,
installRecords,
...(params.workspaceDir ? { workspaceDir: params.workspaceDir } : {}),
...(params.env ? { env: params.env } : {}),
}),
{ command: params.traceCommand ?? "registry-refresh", reason: params.reason },
);
} catch (error) {
params.logger?.warn?.(`Plugin registry refresh failed: ${formatErrorMessage(error)}`);
}

View File

@@ -1,6 +1,7 @@
import { createHash } from "node:crypto";
import fs from "node:fs";
import path from "node:path";
import { tracePluginLifecyclePhase } from "./plugin-lifecycle-trace.js";
const BUNDLED_RUNTIME_MIRROR_METADATA_FILE = ".openclaw-runtime-mirror.json";
const BUNDLED_RUNTIME_MIRROR_METADATA_VERSION = 1;
@@ -24,16 +25,22 @@ export function refreshBundledPluginRuntimeMirrorRoot(params: {
tempDirParent?: string;
precomputedSourceMetadata?: PrecomputedBundledRuntimeMirrorMetadata;
}): boolean {
if (path.resolve(params.sourceRoot) === path.resolve(params.targetRoot)) {
return false;
}
const metadata = createBundledRuntimeMirrorMetadata(params, params.precomputedSourceMetadata);
if (isBundledRuntimeMirrorRootFresh(params.targetRoot, metadata)) {
return false;
}
copyBundledPluginRuntimeRoot(params.sourceRoot, params.targetRoot);
writeBundledRuntimeMirrorMetadata(params.targetRoot, metadata);
return true;
return tracePluginLifecyclePhase(
"runtime mirror refresh",
() => {
if (path.resolve(params.sourceRoot) === path.resolve(params.targetRoot)) {
return false;
}
const metadata = createBundledRuntimeMirrorMetadata(params, params.precomputedSourceMetadata);
if (isBundledRuntimeMirrorRootFresh(params.targetRoot, metadata)) {
return false;
}
copyBundledPluginRuntimeRoot(params.sourceRoot, params.targetRoot);
writeBundledRuntimeMirrorMetadata(params.targetRoot, metadata);
return true;
},
{ pluginId: params.pluginId },
);
}
export function copyBundledPluginRuntimeRoot(sourceRoot: string, targetRoot: string): void {
@@ -218,9 +225,15 @@ function writeBundledRuntimeMirrorMetadata(
}
function fingerprintBundledRuntimeMirrorSourceRoot(sourceRoot: string): string {
const hash = createHash("sha256");
hashBundledRuntimeMirrorDirectory(hash, sourceRoot, sourceRoot);
return hash.digest("hex");
return tracePluginLifecyclePhase(
"runtime mirror fingerprint",
() => {
const hash = createHash("sha256");
hashBundledRuntimeMirrorDirectory(hash, sourceRoot, sourceRoot);
return hash.digest("hex");
},
{ sourceRoot },
);
}
function hashBundledRuntimeMirrorDirectory(

View File

@@ -24,6 +24,7 @@ import {
resolvePackageSetupSource,
} from "./package-entry-resolution.js";
import { formatPosixMode, isPathInside, safeRealpathSync, safeStatSync } from "./path-safety.js";
import { tracePluginLifecyclePhase } from "./plugin-lifecycle-trace.js";
import type { PluginOrigin } from "./plugin-origin.types.js";
import { resolvePluginCacheInputs, resolvePluginSourceRoots } from "./roots.js";
@@ -942,65 +943,70 @@ export function discoverOpenClawPlugins(params: {
env,
}),
env,
load: () => {
const result = createDiscoveryResult();
const seen = new Set<string>();
const realpathCache = new Map<string, string>();
const extra = params.extraPaths ?? [];
for (const extraPath of extra) {
if (typeof extraPath !== "string") {
continue;
}
const trimmed = extraPath.trim();
if (!trimmed) {
continue;
}
const bundledAlias = resolvePackagedBundledLoadPathAlias({
bundledRoot: roots.stock,
loadPath: resolveUserPath(trimmed, env),
});
if (bundledAlias) {
result.diagnostics.push({
level: "warn",
source: trimmed,
message: `ignored plugins.load.paths entry that points at OpenClaw's ${bundledAlias.kind} bundled plugin directory; remove this redundant path or run openclaw doctor --fix`,
});
continue;
}
discoverFromPath({
rawPath: trimmed,
origin: "config",
ownershipUid: params.ownershipUid,
workspaceDir,
env,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
}
const workspaceMatchesBundledRoot = resolvesToSameDirectory(
workspaceRoot,
roots.stock,
realpathCache,
);
if (roots.workspace && workspaceRoot && !workspaceMatchesBundledRoot) {
// Keep workspace auto-discovery constrained to the OpenClaw extensions root.
// Recursively scanning the full workspace treats arbitrary project folders as
// plugin candidates and causes noisy "plugin manifest not found" validation failures.
discoverInDirectory({
dir: roots.workspace,
origin: "workspace",
ownershipUid: params.ownershipUid,
workspaceDir: workspaceRoot,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
}
return result;
},
load: () =>
tracePluginLifecyclePhase(
"discovery scan",
() => {
const result = createDiscoveryResult();
const seen = new Set<string>();
const realpathCache = new Map<string, string>();
const extra = params.extraPaths ?? [];
for (const extraPath of extra) {
if (typeof extraPath !== "string") {
continue;
}
const trimmed = extraPath.trim();
if (!trimmed) {
continue;
}
const bundledAlias = resolvePackagedBundledLoadPathAlias({
bundledRoot: roots.stock,
loadPath: resolveUserPath(trimmed, env),
});
if (bundledAlias) {
result.diagnostics.push({
level: "warn",
source: trimmed,
message: `ignored plugins.load.paths entry that points at OpenClaw's ${bundledAlias.kind} bundled plugin directory; remove this redundant path or run openclaw doctor --fix`,
});
continue;
}
discoverFromPath({
rawPath: trimmed,
origin: "config",
ownershipUid: params.ownershipUid,
workspaceDir,
env,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
}
const workspaceMatchesBundledRoot = resolvesToSameDirectory(
workspaceRoot,
roots.stock,
realpathCache,
);
if (roots.workspace && workspaceRoot && !workspaceMatchesBundledRoot) {
// Keep workspace auto-discovery constrained to the OpenClaw extensions root.
// Recursively scanning the full workspace treats arbitrary project folders as
// plugin candidates and causes noisy "plugin manifest not found" validation failures.
discoverInDirectory({
dir: roots.workspace,
origin: "workspace",
ownershipUid: params.ownershipUid,
workspaceDir: workspaceRoot,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
}
return result;
},
{ scope: "scoped", extraPathCount: params.extraPaths?.length ?? 0 },
),
});
const sharedResult = getCachedDiscoveryResult({
cacheEnabled,
@@ -1009,56 +1015,61 @@ export function discoverOpenClawPlugins(params: {
env,
}),
env,
load: () => {
const result = createDiscoveryResult();
const seen = new Set<string>();
const realpathCache = new Map<string, string>();
for (const sourceOverlayDir of listBundledSourceOverlayDirs({
bundledRoot: roots.stock,
env,
})) {
discoverFromPath({
rawPath: sourceOverlayDir,
origin: "bundled",
ownershipUid: params.ownershipUid,
workspaceDir,
env,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
result.diagnostics.push({
level: "warn",
source: sourceOverlayDir,
message:
"using bind-mounted bundled plugin source overlay; this source overrides the packaged dist bundle for the same plugin id",
});
}
if (roots.stock) {
discoverInDirectory({
dir: roots.stock,
origin: "bundled",
ownershipUid: params.ownershipUid,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
}
// Keep auto-discovered global extensions behind bundled plugins.
// Users can still intentionally override via plugins.load.paths (origin=config).
discoverInDirectory({
dir: roots.global,
origin: "global",
ownershipUid: params.ownershipUid,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
return result;
},
load: () =>
tracePluginLifecyclePhase(
"discovery scan",
() => {
const result = createDiscoveryResult();
const seen = new Set<string>();
const realpathCache = new Map<string, string>();
for (const sourceOverlayDir of listBundledSourceOverlayDirs({
bundledRoot: roots.stock,
env,
})) {
discoverFromPath({
rawPath: sourceOverlayDir,
origin: "bundled",
ownershipUid: params.ownershipUid,
workspaceDir,
env,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
result.diagnostics.push({
level: "warn",
source: sourceOverlayDir,
message:
"using bind-mounted bundled plugin source overlay; this source overrides the packaged dist bundle for the same plugin id",
});
}
if (roots.stock) {
discoverInDirectory({
dir: roots.stock,
origin: "bundled",
ownershipUid: params.ownershipUid,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
}
// Keep auto-discovered global extensions behind bundled plugins.
// Users can still intentionally override via plugins.load.paths (origin=config).
discoverInDirectory({
dir: roots.global,
origin: "global",
ownershipUid: params.ownershipUid,
candidates: result.candidates,
diagnostics: result.diagnostics,
seen,
realpathCache,
});
return result;
},
{ scope: "shared" },
),
});
const result = createDiscoveryResult();
const seenSources = new Set<string>();

View File

@@ -14,6 +14,7 @@ import {
type OpenClawPackageManifest,
type PackageManifest,
} from "./manifest.js";
import { tracePluginLifecyclePhase } from "./plugin-lifecycle-trace.js";
const INSTALLED_MANIFEST_REGISTRY_FALLBACK_CACHE_MAX_ENTRIES = 64;
@@ -262,54 +263,64 @@ export function loadPluginManifestRegistryForInstalledIndex(params: {
includeDisabled?: boolean;
bundledChannelConfigCollector?: BundledChannelConfigCollector;
}): PluginManifestRegistry {
if (params.pluginIds && params.pluginIds.length === 0) {
return { plugins: [], diagnostics: [] };
}
const env = params.env ?? process.env;
const cacheKey = shouldUseInstalledManifestRegistryCache({
env,
bundledChannelConfigCollector: params.bundledChannelConfigCollector,
})
? buildInstalledManifestRegistryCacheKey({
index: params.index,
return tracePluginLifecyclePhase(
"manifest registry",
() => {
if (params.pluginIds && params.pluginIds.length === 0) {
return { plugins: [], diagnostics: [] };
}
const env = params.env ?? process.env;
const cacheKey = shouldUseInstalledManifestRegistryCache({
env,
bundledChannelConfigCollector: params.bundledChannelConfigCollector,
})
? buildInstalledManifestRegistryCacheKey({
index: params.index,
config: params.config,
workspaceDir: params.workspaceDir,
env,
pluginIds: params.pluginIds,
includeDisabled: params.includeDisabled,
})
: undefined;
if (cacheKey) {
const cached = getCachedInstalledManifestRegistry(cacheKey);
if (cached) {
return cached;
}
}
const pluginIdSet = params.pluginIds?.length ? new Set(params.pluginIds) : null;
const diagnostics = pluginIdSet
? params.index.diagnostics.filter((diagnostic) => {
const pluginId = diagnostic.pluginId;
return !pluginId || pluginIdSet.has(pluginId);
})
: params.index.diagnostics;
const candidates = params.index.plugins
.filter((plugin) => params.includeDisabled || plugin.enabled)
.filter((plugin) => !pluginIdSet || pluginIdSet.has(plugin.pluginId))
.map(toPluginCandidate);
const registry = loadPluginManifestRegistry({
config: params.config,
workspaceDir: params.workspaceDir,
env,
pluginIds: params.pluginIds,
includeDisabled: params.includeDisabled,
})
: undefined;
if (cacheKey) {
const cached = getCachedInstalledManifestRegistry(cacheKey);
if (cached) {
return cached;
}
}
const pluginIdSet = params.pluginIds?.length ? new Set(params.pluginIds) : null;
const diagnostics = pluginIdSet
? params.index.diagnostics.filter((diagnostic) => {
const pluginId = diagnostic.pluginId;
return !pluginId || pluginIdSet.has(pluginId);
})
: params.index.diagnostics;
const candidates = params.index.plugins
.filter((plugin) => params.includeDisabled || plugin.enabled)
.filter((plugin) => !pluginIdSet || pluginIdSet.has(plugin.pluginId))
.map(toPluginCandidate);
const registry = loadPluginManifestRegistry({
config: params.config,
workspaceDir: params.workspaceDir,
env,
cache: false,
candidates,
diagnostics: [...diagnostics],
installRecords: extractPluginInstallRecordsFromInstalledPluginIndex(params.index),
...(params.bundledChannelConfigCollector
? { bundledChannelConfigCollector: params.bundledChannelConfigCollector }
: {}),
});
if (cacheKey) {
setCachedInstalledManifestRegistry(cacheKey, registry);
}
return registry;
cache: false,
candidates,
diagnostics: [...diagnostics],
installRecords: extractPluginInstallRecordsFromInstalledPluginIndex(params.index),
...(params.bundledChannelConfigCollector
? { bundledChannelConfigCollector: params.bundledChannelConfigCollector }
: {}),
});
if (cacheKey) {
setCachedInstalledManifestRegistry(cacheKey, registry);
}
return registry;
},
{
includeDisabled: params.includeDisabled === true,
pluginIdCount: params.pluginIds?.length,
indexPluginCount: params.index.plugins.length,
},
);
}

View File

@@ -0,0 +1,79 @@
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
import {
tracePluginLifecyclePhase,
tracePluginLifecyclePhaseAsync,
} from "./plugin-lifecycle-trace.js";
describe("plugin lifecycle trace", () => {
const originalTraceEnv = process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE;
let errorSpy: ReturnType<typeof vi.spyOn>;
beforeEach(() => {
errorSpy = vi.spyOn(console, "error").mockImplementation(() => undefined);
});
afterEach(() => {
if (originalTraceEnv === undefined) {
delete process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE;
} else {
process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE = originalTraceEnv;
}
errorSpy.mockRestore();
});
it("does not emit when the trace env var is disabled", () => {
delete process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE;
expect(tracePluginLifecyclePhase("config read", () => "done")).toBe("done");
expect(errorSpy).not.toHaveBeenCalled();
});
it("emits a successful sync phase with details when enabled", () => {
process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE = "1";
expect(
tracePluginLifecyclePhase("config read", () => 42, {
command: "inspect",
includeDisabled: true,
skipped: undefined,
}),
).toBe(42);
expect(errorSpy).toHaveBeenCalledTimes(1);
expect(errorSpy.mock.calls[0]?.[0]).toMatch(
/^\[plugins:lifecycle\] phase="config read" ms=\d+\.\d{2} status=ok command="inspect" includeDisabled=true$/,
);
});
it("emits failed sync phases before rethrowing", () => {
process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE = "true";
const error = new Error("boom");
expect(() =>
tracePluginLifecyclePhase("registry refresh", () => {
throw error;
}),
).toThrow(error);
expect(errorSpy).toHaveBeenCalledTimes(1);
expect(errorSpy.mock.calls[0]?.[0]).toMatch(
/^\[plugins:lifecycle\] phase="registry refresh" ms=\d+\.\d{2} status=error$/,
);
});
it("emits failed async phases before rejecting", async () => {
process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE = "yes";
const error = new Error("async boom");
await expect(
tracePluginLifecyclePhaseAsync("manifest registry", async () => {
throw error;
}),
).rejects.toThrow(error);
expect(errorSpy).toHaveBeenCalledTimes(1);
expect(errorSpy.mock.calls[0]?.[0]).toMatch(
/^\[plugins:lifecycle\] phase="manifest registry" ms=\d+\.\d{2} status=error$/,
);
});
});

View File

@@ -0,0 +1,68 @@
type TraceDetails = Record<string, boolean | number | string | undefined>;
function isPluginLifecycleTraceEnabled(): boolean {
const raw = process.env.OPENCLAW_PLUGIN_LIFECYCLE_TRACE?.trim().toLowerCase();
return raw === "1" || raw === "true" || raw === "yes";
}
function formatTraceValue(value: boolean | number | string): string {
if (typeof value === "number" || typeof value === "boolean") {
return String(value);
}
return JSON.stringify(value);
}
function emitPluginLifecycleTrace(params: {
phase: string;
start: bigint;
status: "error" | "ok";
details?: TraceDetails;
}): void {
const elapsedMs = Number(process.hrtime.bigint() - params.start) / 1_000_000;
const detailText = Object.entries(params.details ?? {})
.filter((entry): entry is [string, boolean | number | string] => entry[1] !== undefined)
.map(([key, value]) => `${key}=${formatTraceValue(value)}`)
.join(" ");
const suffix = detailText ? ` ${detailText}` : "";
console.error(
`[plugins:lifecycle] phase=${JSON.stringify(params.phase)} ms=${elapsedMs.toFixed(2)} status=${params.status}${suffix}`,
);
}
export function tracePluginLifecyclePhase<T>(
phase: string,
fn: () => T,
details?: TraceDetails,
): T {
if (!isPluginLifecycleTraceEnabled()) {
return fn();
}
const start = process.hrtime.bigint();
let status: "error" | "ok" = "error";
try {
const result = fn();
status = "ok";
return result;
} finally {
emitPluginLifecycleTrace({ phase, start, status, details });
}
}
export async function tracePluginLifecyclePhaseAsync<T>(
phase: string,
fn: () => Promise<T>,
details?: TraceDetails,
): Promise<T> {
if (!isPluginLifecycleTraceEnabled()) {
return fn();
}
const start = process.hrtime.bigint();
let status: "error" | "ok" = "error";
try {
const result = await fn();
status = "ok";
return result;
} finally {
emitPluginLifecycleTrace({ phase, start, status, details });
}
}

View File

@@ -22,6 +22,7 @@ import { loadOpenClawPlugins } from "./loader.js";
import { loadPluginManifestRegistryForInstalledIndex } from "./manifest-registry-installed.js";
import type { PluginManifestRecord } from "./manifest-registry.js";
import type { PluginDiagnostic } from "./manifest-types.js";
import { tracePluginLifecyclePhase } from "./plugin-lifecycle-trace.js";
import {
loadPluginRegistrySnapshotWithMetadata,
type PluginRegistrySnapshotDiagnostic,
@@ -224,11 +225,16 @@ export function buildPluginRegistrySnapshotReport(
params?: PluginReportParams,
): PluginRegistryStatusReport {
const config = params?.config ?? getRuntimeConfig();
const result = loadPluginRegistrySnapshotWithMetadata({
config,
env: params?.env,
workspaceDir: params?.workspaceDir,
});
const result = tracePluginLifecyclePhase(
"plugin registry snapshot",
() =>
loadPluginRegistrySnapshotWithMetadata({
config,
env: params?.env,
workspaceDir: params?.workspaceDir,
}),
{ surface: "status" },
);
const manifestRegistry = loadPluginManifestRegistryForInstalledIndex({
index: result.snapshot,
config,
@@ -301,27 +307,37 @@ function buildPluginReport(
: [...params.onlyPluginIds];
const registry = loadModules
? loadOpenClawPlugins(
buildPluginRuntimeLoadOptions(context, {
config: runtimeCompatConfig,
activationSourceConfig: rawConfig,
workspaceDir,
env: params?.env,
loadModules,
activate: false,
cache: false,
onlyPluginIds,
}),
? tracePluginLifecyclePhase(
"runtime plugin registry load",
() =>
loadOpenClawPlugins(
buildPluginRuntimeLoadOptions(context, {
config: runtimeCompatConfig,
activationSourceConfig: rawConfig,
workspaceDir,
env: params?.env,
loadModules,
activate: false,
cache: false,
onlyPluginIds,
}),
),
{ surface: "status", onlyPluginCount: onlyPluginIds?.length },
)
: loadPluginMetadataRegistrySnapshot({
config: runtimeCompatConfig,
activationSourceConfig: rawConfig,
workspaceDir,
env: params?.env,
logger: params?.logger,
loadModules: false,
onlyPluginIds,
});
: tracePluginLifecyclePhase(
"plugin registry snapshot",
() =>
loadPluginMetadataRegistrySnapshot({
config: runtimeCompatConfig,
activationSourceConfig: rawConfig,
workspaceDir,
env: params?.env,
logger: params?.logger,
loadModules: false,
onlyPluginIds,
}),
{ surface: "status", onlyPluginCount: onlyPluginIds?.length },
);
const importedPluginIds = new Set([
...(loadModules
? registry.plugins