From 3dde11c3922ce54792eb0bf72aa1998e78678603 Mon Sep 17 00:00:00 2001 From: Dax Raad Date: Sat, 12 Sep 2026 03:36:30 -0400 Subject: [PATCH] chore(tui): log stalled plugin startup --- packages/tui/src/plugin/context.tsx | 87 +++++++++++++++++++++++++---- 1 file changed, 75 insertions(+), 12 deletions(-) diff --git a/packages/tui/src/plugin/context.tsx b/packages/tui/src/plugin/context.tsx index a3a578b6ecf..e249730d69f 100644 --- a/packages/tui/src/plugin/context.tsx +++ b/packages/tui/src/plugin/context.tsx @@ -34,6 +34,7 @@ import { discoverPluginTargets, localSource } from "./discovery" import { createPluginSources } from "./source" import { isMissingPath } from "../util/config-directories" import { createMarkdownRenderer } from "./markdown" +import { useLog, type LogTags } from "../context/log" export interface PackageSource { readonly prepare: (spec: string, install?: boolean) => Promise @@ -81,11 +82,13 @@ type Registration = { // One entry of the desired plugin generation produced by the resolve phase. type Desired = Pick & { enabled: boolean } +type Trace = (stage: string, tags: LogTags, task: () => Promise) => Promise const PluginContext = createContext() export function PluginProvider(props: ParentProps<{ packages: PackageSource; directories: string[] }>) { const host = usePluginHost() + const log = useLog({ component: "plugin" }) const config = useConfig() const lifecycle = useTuiLifecycle() const client = useClient() @@ -108,6 +111,34 @@ export function PluginProvider(props: ParentProps<{ packages: PackageSource; dir // One save can emit several watch events. Remember setup failures so those // events do not repeatedly tear down and restore the last good generation. const setupFailures = new Map() + let operationID = 0 + const trace: Trace = (stage, tags, task) => { + const id = ++operationID + const started = Date.now() + log.debug("plugin operation started", { id, stage, ...tags }) + const stalled = setTimeout( + () => log.warn("plugin operation stalled", { id, stage, elapsedMs: Date.now() - started, ...tags }), + 5_000, + ) + return task() + .then( + (value) => { + log.debug("plugin operation completed", { id, stage, durationMs: Date.now() - started, ...tags }) + return value + }, + (error) => { + log.warn("plugin operation failed", { + id, + stage, + durationMs: Date.now() - started, + error: errorMessage(error), + ...tags, + }) + throw error + }, + ) + .finally(() => clearTimeout(stalled)) + } const markdown = createMarkdownRenderer(() => Object.values(store.registrations).flatMap((registration) => (registration.active ? [registration.markdown] : [])), ) @@ -149,7 +180,9 @@ export function PluginProvider(props: ParentProps<{ packages: PackageSource; dir active: () => Boolean(store.registrations[id]?.active), }, }) - const cleanup = await setup(item.plugin, context, owned).catch((error) => { + const cleanup = await trace("setup", { plugin: id, target: item.target }, () => + setup(item.plugin, context, owned), + ).catch((error) => { clearContributions(id) if (item.target) setupFailures.set(item.target, { @@ -181,7 +214,9 @@ export function PluginProvider(props: ParentProps<{ packages: PackageSource; dir setStore("registrations", id, "active", false) setStore("registrations", id, "cleanups", []) }) - await disposeAll(cleanups).finally(() => + await trace("cleanup", { plugin: id, target: item.target, cleanups: cleanups.length }, () => + disposeAll(cleanups), + ).finally(() => batch(() => { if (store.registrations[id]) { clearContributions(id) @@ -243,10 +278,20 @@ export function PluginProvider(props: ParentProps<{ packages: PackageSource; dir // Package resolution failures would otherwise retry a full npm install on // every watch event; remember them until the configuration changes. const npmFailures = new Map() + let reconciliationID = 0 const reconcile = async () => { - await Promise.all(props.directories.map(watcher.wait)) + const id = ++reconciliationID + const started = Date.now() + log.info("plugin reconciliation started", { id }) + await trace("watch", { reconciliation: id, directories: props.directories }, () => + Promise.all(props.directories.map(watcher.wait)).then(() => undefined), + ) const entries = [ - ...(await discoverPluginTargets(props.directories)).map((entry) => ({ + ...( + await trace("discover", { reconciliation: id, directories: props.directories }, () => + discoverPluginTargets(props.directories), + ) + ).map((entry) => ({ entry, install: true, optional: true, @@ -295,12 +340,20 @@ export function PluginProvider(props: ParentProps<{ packages: PackageSource; dir const memo = local ? undefined : npmFailures.get(target) const resolved = memo ? { status: "failed" as const, error: memo } - : await resolvePlugin(target, local, options, previous, props.packages, source.install, sources.read).catch( - (error) => ({ - status: "failed" as const, - error: errorMessage(error), - }), - ) + : await resolvePlugin( + target, + local, + options, + previous, + props.packages, + source.install, + sources.read, + trace, + id, + ).catch((error) => ({ + status: "failed" as const, + error: errorMessage(error), + })) if (resolved.status === "unsupported") { if (source.optional) continue failures.push({ target, status: "unsupported" }) @@ -426,6 +479,7 @@ export function PluginProvider(props: ParentProps<{ packages: PackageSource; dir action: { label: "Open plugins", run: () => host.keymap.dispatch("plugins.list") }, }) setStore("states", reconcileStore(states)) + log.info("plugin reconciliation completed", { id, durationMs: Date.now() - started, plugins: desired.size }) } const slotItems = new WeakMap>() // The mounted slot tree: path -> live instance count. Reference @@ -598,17 +652,26 @@ async function resolvePlugin( packages: PackageSource, install: boolean, readSource: ReturnType["read"], + trace: Trace, + reconciliation: number, ) { // Package entrypoints never change within a session, so a loaded previous // version needs no re-resolution (which could otherwise hit npm). if (!local && previous && sameOptions(previous.options, options)) return { status: "unchanged" as const, plugin: previous.plugin, version: previous.version } - const target = local ? { directory: fileURLToPath(local) } : await packages.prepare(spec, install) + const target = local + ? { directory: fileURLToPath(local) } + : await trace("prepare", { reconciliation, target: spec, install }, () => packages.prepare(spec, install)) const entrypoint = Host.resolve(target).tui if (!entrypoint) return { status: "unsupported" as const } // Content remains stable across the several mtimes one save may expose to // filesystem watchers, while the generation keeps reverted modules fresh. - let source = local ? await readSource(entrypoint) : { version: entrypoint, module: await Host.load(entrypoint) } + let source = local + ? await trace("read", { reconciliation, target: spec, entrypoint }, () => readSource(entrypoint)) + : { + version: entrypoint, + module: await trace("load", { reconciliation, target: spec, entrypoint }, () => Host.load(entrypoint)), + } while (true) { const version = source.version if (previous && previous.version === version && sameOptions(previous.options, options))