Skip to content

Commit a48ffda

Browse files
shakkernerdshakkernerd
committed
chore: trace plugin lifecycle phases
1 parent 3d89b0f commit a48ffda

13 files changed

Lines changed: 566 additions & 244 deletions

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ Docs: https://docs.openclaw.ai
1212

1313
### Fixes
1414

15+
- 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.
1516
- fix(plugins): restrict bundled plugin dir resolution to trusted package roots. (#73275) Thanks @pgondhi987.
1617
- fix(security): prevent workspace PATH injection via service env and trash helpers. (#73264) Thanks @pgondhi987.
1718
- 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.

‎docs/cli/plugins.md‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,10 @@ openclaw plugins marketplace list <marketplace>
4848
openclaw plugins marketplace list <marketplace> --json
4949
```
5050

51+
For slow install, inspect, uninstall, or registry-refresh investigation, run the
52+
command with `OPENCLAW_PLUGIN_LIFECYCLE_TRACE=1`. The trace writes phase timings
53+
to stderr and keeps JSON output parseable. See [Debugging](/help/debugging#plugin-lifecycle-trace).
54+
5155
<Note>
5256
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`.
5357

‎docs/help/debugging.md‎

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -43,6 +43,32 @@ Use `/trace` for plugin diagnostics such as Active Memory debug summaries.
4343
Keep using `/verbose` for normal verbose status/tool output, and keep using
4444
`/debug` for runtime-only config overrides.
4545

46+
## Plugin lifecycle trace
47+
48+
Use `OPENCLAW_PLUGIN_LIFECYCLE_TRACE=1` when plugin lifecycle commands feel slow
49+
and you need a built-in phase breakdown for plugin metadata, discovery, registry,
50+
runtime mirror, config mutation, and refresh work. The trace is opt-in and writes
51+
to stderr, so JSON command output remains parseable.
52+
53+
Example:
54+
55+
```bash
56+
OPENCLAW_PLUGIN_LIFECYCLE_TRACE=1 openclaw plugins install tokenjuice --force
57+
```
58+
59+
Example output:
60+
61+
```text
62+
[plugins:lifecycle] phase="config read" ms=6.83 status=ok command="install"
63+
[plugins:lifecycle] phase="slot selection" ms=94.31 status=ok command="install" pluginId="tokenjuice"
64+
[plugins:lifecycle] phase="registry refresh" ms=51.56 status=ok command="install" reason="source-changed"
65+
```
66+
67+
Use this for plugin lifecycle investigation before reaching for a CPU profiler.
68+
If the command is running from a source checkout, prefer measuring the built
69+
runtime with `node dist/entry.js ...` after `pnpm build`; `pnpm openclaw ...`
70+
also measures source-runner overhead.
71+
4672
## Temporary CLI debug timing
4773

4874
OpenClaw keeps `src/cli/debug-timing.ts` as a small helper for local

‎src/cli/plugins-cli.ts‎

Lines changed: 75 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,10 @@ import { getRuntimeConfig, readConfigFileSnapshot, replaceConfigFile } from "../
55
import { resolveStateDir } from "../config/paths.js";
66
import type { OpenClawConfig } from "../config/types.openclaw.js";
77
import type { PluginInstallRecord } from "../config/types.plugins.js";
8+
import {
9+
tracePluginLifecyclePhase,
10+
tracePluginLifecyclePhaseAsync,
11+
} from "../plugins/plugin-lifecycle-trace.js";
812
import { formatPluginSourceForTable, resolvePluginSourceRoots } from "../plugins/source-display.js";
913
import type { PluginLogger } from "../plugins/types.js";
1014
import { defaultRuntime } from "../runtime.js";
@@ -264,18 +268,29 @@ export function registerPluginsCli(program: Command) {
264268
} = await import("../plugins/status.js");
265269
const { loadInstalledPluginIndexInstallRecords } =
266270
await import("../plugins/installed-plugin-index-records.js");
267-
const cfg = getRuntimeConfig();
268-
const installRecords = await loadInstalledPluginIndexInstallRecords();
271+
const cfg = tracePluginLifecyclePhase("config read", () => getRuntimeConfig(), {
272+
command: "inspect",
273+
});
274+
const installRecords = await tracePluginLifecyclePhaseAsync(
275+
"install records load",
276+
() => loadInstalledPluginIndexInstallRecords(),
277+
{ command: "inspect" },
278+
);
269279
const loggerParams = opts.json ? { logger: quietPluginJsonLogger } : {};
270280
if (opts.all) {
271281
if (id) {
272282
defaultRuntime.error("Pass either a plugin id or --all, not both.");
273283
return defaultRuntime.exit(1);
274284
}
275-
const report = buildPluginDiagnosticsReport({
276-
config: cfg,
277-
...loggerParams,
278-
});
285+
const report = tracePluginLifecyclePhase(
286+
"runtime plugin registry load",
287+
() =>
288+
buildPluginDiagnosticsReport({
289+
config: cfg,
290+
...loggerParams,
291+
}),
292+
{ command: "inspect", all: true },
293+
);
279294
const inspectAll = buildAllPluginInspectReports({
280295
config: cfg,
281296
...loggerParams,
@@ -344,22 +359,32 @@ export function registerPluginsCli(program: Command) {
344359
return defaultRuntime.exit(1);
345360
}
346361

347-
const snapshotReport = buildPluginSnapshotReport({
348-
config: cfg,
349-
...loggerParams,
350-
});
362+
const snapshotReport = tracePluginLifecyclePhase(
363+
"plugin registry snapshot",
364+
() =>
365+
buildPluginSnapshotReport({
366+
config: cfg,
367+
...loggerParams,
368+
}),
369+
{ command: "inspect" },
370+
);
351371
const targetPlugin = snapshotReport.plugins.find(
352372
(entry) => entry.id === id || entry.name === id,
353373
);
354374
if (!targetPlugin) {
355375
defaultRuntime.error(`Plugin not found: ${id}`);
356376
return defaultRuntime.exit(1);
357377
}
358-
const report = buildPluginDiagnosticsReport({
359-
config: cfg,
360-
...loggerParams,
361-
onlyPluginIds: [targetPlugin.id],
362-
});
378+
const report = tracePluginLifecyclePhase(
379+
"runtime plugin registry load",
380+
() =>
381+
buildPluginDiagnosticsReport({
382+
config: cfg,
383+
...loggerParams,
384+
onlyPluginIds: [targetPlugin.id],
385+
}),
386+
{ command: "inspect", pluginId: targetPlugin.id },
387+
);
363388
const inspect = buildPluginInspectReport({
364389
id: targetPlugin.id,
365390
config: cfg,
@@ -603,11 +628,23 @@ export function registerPluginsCli(program: Command) {
603628
await import("./plugins-registry-refresh.js");
604629
const { resolvePluginUninstallId } = await import("./plugins-uninstall-selection.js");
605630
const { promptYesNo } = await import("./prompt.js");
606-
const snapshot = await readConfigFileSnapshot();
631+
const snapshot = await tracePluginLifecyclePhaseAsync(
632+
"config read",
633+
() => readConfigFileSnapshot(),
634+
{ command: "uninstall" },
635+
);
607636
const sourceConfig = (snapshot.sourceConfig ?? snapshot.config) as OpenClawConfig;
608-
const installRecords = await loadInstalledPluginIndexInstallRecords();
637+
const installRecords = await tracePluginLifecyclePhaseAsync(
638+
"install records load",
639+
() => loadInstalledPluginIndexInstallRecords(),
640+
{ command: "uninstall" },
641+
);
609642
const cfg = withPluginInstallRecords(sourceConfig, installRecords);
610-
const report = buildPluginSnapshotReport({ config: cfg });
643+
const report = tracePluginLifecyclePhase(
644+
"plugin registry snapshot",
645+
() => buildPluginSnapshotReport({ config: cfg }),
646+
{ command: "uninstall" },
647+
);
611648
const extensionsDir = path.join(resolveStateDir(process.env, os.homedir), "extensions");
612649
const keepFiles = Boolean(opts.keepFiles || opts.keepConfig);
613650

@@ -702,12 +739,17 @@ export function registerPluginsCli(program: Command) {
702739

703740
const nextInstallRecords = removePluginInstallRecordFromRecords(installRecords, pluginId);
704741
const nextConfig = withoutPluginInstallRecords(plan.config);
705-
await commitPluginInstallRecordsWithConfig({
706-
previousInstallRecords: installRecords,
707-
nextInstallRecords,
708-
nextConfig,
709-
...(snapshot.hash !== undefined ? { baseHash: snapshot.hash } : {}),
710-
});
742+
await tracePluginLifecyclePhaseAsync(
743+
"config mutation",
744+
() =>
745+
commitPluginInstallRecordsWithConfig({
746+
previousInstallRecords: installRecords,
747+
nextInstallRecords,
748+
nextConfig,
749+
...(snapshot.hash !== undefined ? { baseHash: snapshot.hash } : {}),
750+
}),
751+
{ command: "uninstall" },
752+
);
711753
const directoryResult = await applyPluginUninstallDirectoryRemoval(plan.directoryRemoval);
712754
for (const warning of directoryResult.warnings) {
713755
defaultRuntime.log(theme.warn(warning));
@@ -716,6 +758,7 @@ export function registerPluginsCli(program: Command) {
716758
config: nextConfig,
717759
reason: "source-changed",
718760
installRecords: nextInstallRecords,
761+
traceCommand: "uninstall",
719762
logger: {
720763
warn: (message) => defaultRuntime.log(theme.warn(message)),
721764
},
@@ -764,8 +807,14 @@ export function registerPluginsCli(program: Command) {
764807
marketplace?: string;
765808
},
766809
) => {
767-
const { runPluginInstallCommand } = await import("./plugins-install-command.js");
768-
await runPluginInstallCommand({ raw, opts });
810+
await tracePluginLifecyclePhaseAsync(
811+
"install command",
812+
async () => {
813+
const { runPluginInstallCommand } = await import("./plugins-install-command.js");
814+
await runPluginInstallCommand({ raw, opts });
815+
},
816+
{ command: "install" },
817+
);
769818
},
770819
);
771820

‎src/cli/plugins-install-command.ts‎

Lines changed: 26 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@ import {
2020
installPluginFromMarketplace,
2121
resolveMarketplaceInstallShortcut,
2222
} from "../plugins/marketplace.js";
23+
import { tracePluginLifecyclePhaseAsync } from "../plugins/plugin-lifecycle-trace.js";
2324
import { validateJsonSchemaValue } from "../plugins/schema-validator.js";
2425
import { defaultRuntime } from "../runtime.js";
2526
import { theme } from "../terminal/theme.js";
@@ -394,7 +395,11 @@ async function loadConfigFromSnapshotForInstall(
394395
export async function loadConfigForInstall(
395396
request: PluginInstallRequestContext,
396397
): Promise<ConfigSnapshotForInstallPersist> {
397-
const snapshot = await readConfigFileSnapshot();
398+
const snapshot = await tracePluginLifecyclePhaseAsync(
399+
"config read",
400+
() => readConfigFileSnapshot(),
401+
{ command: "install" },
402+
);
398403
if (snapshot.valid) {
399404
return {
400405
config: snapshot.sourceConfig,
@@ -414,7 +419,11 @@ export async function runPluginInstallCommand(params: {
414419
};
415420
}) {
416421
const shorthand = !params.opts.marketplace
417-
? await resolveMarketplaceInstallShortcut(params.raw)
422+
? await tracePluginLifecyclePhaseAsync(
423+
"marketplace shortcut resolution",
424+
() => resolveMarketplaceInstallShortcut(params.raw),
425+
{ command: "install" },
426+
)
418427
: null;
419428
if (shorthand?.ok === false) {
420429
defaultRuntime.error(shorthand.error);
@@ -641,12 +650,21 @@ export async function runPluginInstallCommand(params: {
641650
findBundledSource: (lookup) => findBundledPluginSource({ lookup }),
642651
});
643652
if (bundledPreNpmPlan) {
644-
await installBundledPluginSource({
645-
snapshot,
646-
rawSpec: raw,
647-
bundledSource: bundledPreNpmPlan.bundledSource,
648-
warning: bundledPreNpmPlan.warning,
649-
});
653+
await tracePluginLifecyclePhaseAsync(
654+
"install execution",
655+
() =>
656+
installBundledPluginSource({
657+
snapshot,
658+
rawSpec: raw,
659+
bundledSource: bundledPreNpmPlan.bundledSource,
660+
warning: bundledPreNpmPlan.warning,
661+
}),
662+
{
663+
command: "install",
664+
source: "bundled",
665+
pluginId: bundledPreNpmPlan.bundledSource.pluginId,
666+
},
667+
);
650668
return;
651669
}
652670

‎src/cli/plugins-install-persist.ts‎

Lines changed: 23 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import {
88
withoutPluginInstallRecords,
99
} from "../plugins/installed-plugin-index-records.js";
1010
import type { PluginInstallUpdate } from "../plugins/installs.js";
11+
import { tracePluginLifecyclePhaseAsync } from "../plugins/plugin-lifecycle-trace.js";
1112
import { defaultRuntime } from "../runtime.js";
1213
import { theme } from "../terminal/theme.js";
1314
import {
@@ -78,26 +79,40 @@ export async function persistPluginInstall(params: {
7879
: enablePluginInConfig(installConfig, params.pluginId, {
7980
updateChannelConfig: false,
8081
}).config;
81-
const installRecords = await loadInstalledPluginIndexInstallRecords();
82+
const installRecords = await tracePluginLifecyclePhaseAsync(
83+
"install records load",
84+
() => loadInstalledPluginIndexInstallRecords(),
85+
{ command: "install" },
86+
);
8287
const nextInstallRecords = recordPluginInstallInRecords(installRecords, {
8388
pluginId: params.pluginId,
8489
...params.install,
8590
});
8691
const slotResult =
8792
params.enable === false
8893
? { config: next, warnings: [] }
89-
: applySlotSelectionForPlugin(next, params.pluginId);
94+
: await tracePluginLifecyclePhaseAsync(
95+
"slot selection",
96+
async () => applySlotSelectionForPlugin(next, params.pluginId),
97+
{ command: "install", pluginId: params.pluginId },
98+
);
9099
next = withoutPluginInstallRecords(slotResult.config);
91-
await commitPluginInstallRecordsWithConfig({
92-
previousInstallRecords: installRecords,
93-
nextInstallRecords,
94-
nextConfig: next,
95-
baseHash: params.snapshot.baseHash,
96-
});
100+
await tracePluginLifecyclePhaseAsync(
101+
"config mutation",
102+
() =>
103+
commitPluginInstallRecordsWithConfig({
104+
previousInstallRecords: installRecords,
105+
nextInstallRecords,
106+
nextConfig: next,
107+
baseHash: params.snapshot.baseHash,
108+
}),
109+
{ command: "install" },
110+
);
97111
await refreshPluginRegistryAfterConfigMutation({
98112
config: next,
99113
reason: "source-changed",
100114
installRecords: nextInstallRecords,
115+
traceCommand: "install",
101116
logger: {
102117
warn: (message) => defaultRuntime.log(theme.warn(message)),
103118
},

‎src/cli/plugins-registry-refresh.ts‎

Lines changed: 19 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ import type { OpenClawConfig } from "../config/types.openclaw.js";
22
import { formatErrorMessage } from "../infra/errors.js";
33
import { loadInstalledPluginIndexInstallRecords } from "../plugins/installed-plugin-index-records.js";
44
import type { InstalledPluginIndexRefreshReason } from "../plugins/installed-plugin-index.js";
5+
import { tracePluginLifecyclePhaseAsync } from "../plugins/plugin-lifecycle-trace.js";
56
import { refreshPluginRegistry } from "../plugins/plugin-registry.js";
67

78
export type PluginRegistryRefreshLogger = {
@@ -14,19 +15,29 @@ export async function refreshPluginRegistryAfterConfigMutation(params: {
1415
workspaceDir?: string;
1516
env?: NodeJS.ProcessEnv;
1617
installRecords?: Awaited<ReturnType<typeof loadInstalledPluginIndexInstallRecords>>;
18+
traceCommand?: string;
1719
logger?: PluginRegistryRefreshLogger;
1820
}): Promise<void> {
1921
try {
2022
const installRecords =
2123
params.installRecords ??
22-
(await loadInstalledPluginIndexInstallRecords(params.env ? { env: params.env } : {}));
23-
await refreshPluginRegistry({
24-
config: params.config,
25-
reason: params.reason,
26-
installRecords,
27-
...(params.workspaceDir ? { workspaceDir: params.workspaceDir } : {}),
28-
...(params.env ? { env: params.env } : {}),
29-
});
24+
(await tracePluginLifecyclePhaseAsync(
25+
"install records load",
26+
() => loadInstalledPluginIndexInstallRecords(params.env ? { env: params.env } : {}),
27+
{ command: params.traceCommand ?? "registry-refresh" },
28+
));
29+
await tracePluginLifecyclePhaseAsync(
30+
"registry refresh",
31+
() =>
32+
refreshPluginRegistry({
33+
config: params.config,
34+
reason: params.reason,
35+
installRecords,
36+
...(params.workspaceDir ? { workspaceDir: params.workspaceDir } : {}),
37+
...(params.env ? { env: params.env } : {}),
38+
}),
39+
{ command: params.traceCommand ?? "registry-refresh", reason: params.reason },
40+
);
3041
} catch (error) {
3142
params.logger?.warn?.(`Plugin registry refresh failed: ${formatErrorMessage(error)}`);
3243
}

0 commit comments

Comments
 (0)