diff --git a/packages/coding-agent/CHANGELOG.md b/packages/coding-agent/CHANGELOG.md index dec7e4595..043eb9759 100644 --- a/packages/coding-agent/CHANGELOG.md +++ b/packages/coding-agent/CHANGELOG.md @@ -1,6 +1,21 @@ # Changelog ## [Unreleased] + +### Breaking Changes + +- Removed support for local Python kernel gateway startup; shared gateway is now required + +### Added + +- Added Python prelude caching to improve startup performance by storing compiled prelude helpers and module metadata +- Added `OMP_DEBUG_STARTUP` environment variable for conditional startup performance debugging output + +### Changed + +- Changed Python kernel initialization to require shared gateway mode; local gateway startup has been removed +- Changed shared gateway error handling to retry on server errors (5xx status codes) before failing + ### Fixed - Fixed glob search returning no results when all files are ignored by gitignore by automatically retrying without gitignore filtering diff --git a/packages/coding-agent/src/capability/index.ts b/packages/coding-agent/src/capability/index.ts index 5fa2eb324..e2609abc8 100644 --- a/packages/coding-agent/src/capability/index.ts +++ b/packages/coding-agent/src/capability/index.ts @@ -8,6 +8,12 @@ */ import * as os from "node:os"; import * as path from "node:path"; + +/** Conditional startup debug prints (stderr) when OMP_DEBUG_STARTUP is set */ +const debugStartup = process.env.OMP_DEBUG_STARTUP + ? (stage: string) => process.stderr.write(`[startup] ${stage}\n`) + : () => {}; + import type { Settings } from "../config/settings"; import { clearCache as clearFsCache, cacheStats as fsCacheStats, invalidate as invalidateFs } from "./fs"; import type { @@ -109,9 +115,12 @@ async function loadImpl( const results = await Promise.all( providers.map(async provider => { try { + debugStartup(`capability:${capability.id}:${provider.id}:start`); const result = await provider.load(ctx); + debugStartup(`capability:${capability.id}:${provider.id}:done`); return { provider, result }; } catch (error) { + debugStartup(`capability:${capability.id}:${provider.id}:error`); return { provider, error }; } }), diff --git a/packages/coding-agent/src/ipy/executor.ts b/packages/coding-agent/src/ipy/executor.ts index de7ea2401..0ef299e07 100644 --- a/packages/coding-agent/src/ipy/executor.ts +++ b/packages/coding-agent/src/ipy/executor.ts @@ -1,4 +1,6 @@ -import { logger } from "@oh-my-pi/pi-utils"; +import * as path from "node:path"; +import { isEnoent, logger } from "@oh-my-pi/pi-utils"; +import { getAgentDir } from "../config"; import { OutputSink } from "../session/streaming-output"; import { time } from "../utils/timings"; import { shutdownSharedGateway } from "./gateway-coordinator"; @@ -10,6 +12,12 @@ import { type PreludeHelper, PythonKernel, } from "./kernel"; +import { discoverPythonModules } from "./modules"; +import { PYTHON_PRELUDE } from "./prelude"; + +const debugStartup = process.env.OMP_DEBUG_STARTUP + ? (stage: string) => process.stderr.write(`[startup] ${stage}\n`) + : () => {}; const IDLE_TIMEOUT_MS = 5 * 60 * 1000; // 5 minutes const MAX_KERNEL_SESSIONS = 4; @@ -86,6 +94,72 @@ const kernelSessions = new Map(); let cachedPreludeDocs: PreludeHelper[] | null = null; let cleanupTimer: NodeJS.Timeout | null = null; +interface PreludeCacheSource { + path: string; + hash: string; +} + +interface PreludeCachePayload { + helpers: PreludeHelper[]; + sources: PreludeCacheSource[]; +} + +interface PreludeCacheState { + cacheKey: string; + cachePath: string; + sources: PreludeCacheSource[]; +} + +const PRELUDE_CACHE_DIR = "pycache"; + +function hashPreludeContent(content: string): string { + return Bun.hash(content).toString(16); +} + +async function buildPreludeCacheState(cwd: string): Promise { + const modules = await discoverPythonModules({ cwd }); + const moduleSources = modules + .map(module => ({ path: module.path, hash: hashPreludeContent(module.content) })) + .sort((a, b) => a.path.localeCompare(b.path)); + const sources: PreludeCacheSource[] = [ + { path: "omp:prelude", hash: hashPreludeContent(PYTHON_PRELUDE) }, + ...moduleSources, + ]; + const composite = sources.map(source => `${source.path}:${source.hash}`).join("|"); + const cacheKey = Bun.hash(composite).toString(16); + const cachePath = path.join(getAgentDir(), PRELUDE_CACHE_DIR, `${cacheKey}.json`); + return { cacheKey, cachePath, sources }; +} + +async function readPreludeCache(state: PreludeCacheState): Promise { + let raw: string; + try { + raw = await Bun.file(state.cachePath).text(); + } catch (err) { + if (isEnoent(err)) return null; + logger.warn("Failed to read Python prelude cache", { path: state.cachePath, error: String(err) }); + return null; + } + try { + const parsed = JSON.parse(raw) as PreludeCachePayload | PreludeHelper[]; + const helpers = Array.isArray(parsed) ? parsed : parsed.helpers; + if (!Array.isArray(helpers) || helpers.length === 0) return null; + return helpers; + } catch (err) { + logger.warn("Failed to parse Python prelude cache", { path: state.cachePath, error: String(err) }); + return null; + } +} + +async function writePreludeCache(state: PreludeCacheState, helpers: PreludeHelper[]): Promise { + const payload: PreludeCachePayload = { helpers, sources: state.sources }; + try { + await Bun.write(state.cachePath, JSON.stringify(payload)); + } catch (err) { + logger.warn("Failed to write Python prelude cache", { path: state.cachePath, error: String(err) }); + } +} + function startCleanupTimer(): void { if (cleanupTimer) return; cleanupTimer = setInterval(() => { @@ -153,19 +227,34 @@ export async function warmPythonEnvironment( useSharedGateway?: boolean, sessionFile?: string, ): Promise<{ ok: boolean; reason?: string; docs: PreludeHelper[] }> { + let cacheState: PreludeCacheState | null = null; try { + debugStartup("warmPython:ensureKernel:start"); await ensureKernelAvailable(cwd); + debugStartup("warmPython:ensureKernel:done"); time("warmPython:ensureKernelAvailable"); } catch (err: unknown) { const reason = err instanceof Error ? err.message : String(err); cachedPreludeDocs = []; return { ok: false, reason, docs: [] }; } + try { + cacheState = await buildPreludeCacheState(cwd); + const cached = await readPreludeCache(cacheState); + if (cached) { + cachedPreludeDocs = cached; + return { ok: true, docs: cached }; + } + } catch (err) { + logger.warn("Failed to resolve Python prelude cache", { error: String(err) }); + cacheState = null; + } if (cachedPreludeDocs && cachedPreludeDocs.length > 0) { return { ok: true, docs: cachedPreludeDocs }; } const resolvedSessionId = sessionId ?? `session:${cwd}`; try { + debugStartup("warmPython:withKernelSession:start"); const docs = await withKernelSession( resolvedSessionId, cwd, @@ -173,8 +262,13 @@ export async function warmPythonEnvironment( useSharedGateway, sessionFile, ); + debugStartup("warmPython:withKernelSession:done"); time("warmPython:withKernelSession"); cachedPreludeDocs = docs; + if (docs.length > 0) { + const state = cacheState ?? (await buildPreludeCacheState(cwd)); + await writePreludeCache(state, docs); + } return { ok: true, docs }; } catch (err: unknown) { const reason = err instanceof Error ? err.message : String(err); @@ -226,6 +320,7 @@ async function createKernelSession( artifactsDir?: string, isRetry?: boolean, ): Promise { + debugStartup("kernel:createSession:entry"); const env: Record | undefined = sessionFile || artifactsDir ? { @@ -236,7 +331,9 @@ async function createKernelSession( let kernel: PythonKernel; try { + debugStartup("kernel:PythonKernel.start:start"); kernel = await PythonKernel.start({ cwd, useSharedGateway, env }); + debugStartup("kernel:PythonKernel.start:done"); time("createKernelSession:PythonKernel.start"); } catch (err) { if (!isRetry && isResourceExhaustionError(err)) { @@ -314,6 +411,7 @@ async function withKernelSession( sessionFile?: string, artifactsDir?: string, ): Promise { + debugStartup("kernel:withSession:entry"); let session = kernelSessions.get(sessionId); if (!session) { // Evict oldest session if at capacity @@ -321,17 +419,21 @@ async function withKernelSession( await evictOldestSession(); } session = await createKernelSession(sessionId, cwd, useSharedGateway, sessionFile, artifactsDir); + debugStartup("kernel:withSession:created"); kernelSessions.set(sessionId, session); startCleanupTimer(); } const run = async (): Promise => { + debugStartup("kernel:withSession:run"); session!.lastUsedAt = Date.now(); if (session!.dead || !session!.kernel.isAlive()) { await restartKernelSession(session!, cwd, useSharedGateway, sessionFile, artifactsDir); } try { + debugStartup("kernel:withSession:handler:start"); const result = await handler(session!.kernel); + debugStartup("kernel:withSession:handler:done"); session!.restartCount = 0; return result; } catch (err) { diff --git a/packages/coding-agent/src/ipy/kernel.ts b/packages/coding-agent/src/ipy/kernel.ts index 30786658f..05476e897 100644 --- a/packages/coding-agent/src/ipy/kernel.ts +++ b/packages/coding-agent/src/ipy/kernel.ts @@ -1,24 +1,32 @@ -import { createServer } from "node:net"; -import * as path from "node:path"; -import { logger, ptree } from "@oh-my-pi/pi-utils"; +import { logger } from "@oh-my-pi/pi-utils"; import { $ } from "bun"; import { nanoid } from "nanoid"; import { Settings } from "../config/settings"; -import { getOrCreateSnapshot } from "../utils/shell-snapshot"; import { time } from "../utils/timings"; import { htmlToBasicMarkdown } from "../web/scrapers/types"; -import { acquireSharedGateway, releaseSharedGateway } from "./gateway-coordinator"; +import { acquireSharedGateway, releaseSharedGateway, shutdownSharedGateway } from "./gateway-coordinator"; import { loadPythonModules } from "./modules"; import { PYTHON_PRELUDE } from "./prelude"; import { filterEnv, resolvePythonRuntime } from "./runtime"; const TEXT_ENCODER = new TextEncoder(); const TEXT_DECODER = new TextDecoder(); -const GATEWAY_STARTUP_TIMEOUT_MS = 30000; -const GATEWAY_STARTUP_ATTEMPTS = 3; const TRACE_IPC = process.env.OMP_PYTHON_IPC_TRACE === "1"; const PRELUDE_INTROSPECTION_SNIPPET = "import json\nprint(json.dumps(__omp_prelude_docs__()))"; +const debugStartup = process.env.OMP_DEBUG_STARTUP + ? (stage: string) => process.stderr.write(`[startup] ${stage}\n`) + : () => {}; + +class SharedGatewayCreateError extends Error { + readonly status: number; + + constructor(status: number, message: string) { + super(message); + this.status = status; + } +} + interface ExternalGatewayConfig { url: string; token?: string; @@ -178,31 +186,6 @@ async function checkExternalGatewayAvailability(config: ExternalGatewayConfig): } } -async function allocatePort(): Promise { - const { promise, resolve, reject } = Promise.withResolvers(); - const server = createServer(); - server.unref(); - server.on("error", reject); - server.listen(0, "127.0.0.1", () => { - const address = server.address(); - if (address && typeof address === "object") { - const port = address.port; - server.close((err: Error | null | undefined) => { - if (err) { - reject(err); - } else { - resolve(port); - } - }); - } else { - server.close(); - reject(new Error("Failed to allocate port")); - } - }); - - return promise; -} - function normalizeDisplayText(text: string): string { return text.endsWith("\n") ? text : `${text}\n`; } @@ -287,7 +270,6 @@ export function serializeWebSocketMessage(msg: JupyterMessage): ArrayBuffer { export class PythonKernel { readonly id: string; readonly kernelId: string; - readonly gatewayProcess: ptree.ChildProcess | null; readonly gatewayUrl: string; readonly sessionId: string; readonly username: string; @@ -304,7 +286,6 @@ export class PythonKernel { private constructor( id: string, kernelId: string, - gatewayProcess: ptree.ChildProcess | null, gatewayUrl: string, sessionId: string, username: string, @@ -313,18 +294,11 @@ export class PythonKernel { ) { this.id = id; this.kernelId = kernelId; - this.gatewayProcess = gatewayProcess; this.gatewayUrl = gatewayUrl; this.sessionId = sessionId; this.username = username; this.isSharedGateway = isSharedGateway; this.#authToken = authToken; - - if (this.gatewayProcess) { - this.gatewayProcess.exited.then(() => { - this.#alive = false; - }); - } } #authHeaders(): Record { @@ -333,7 +307,9 @@ export class PythonKernel { } static async start(options: KernelStartOptions): Promise { + debugStartup("PythonKernel.start:entry"); const availability = await checkPythonKernelAvailability(options.cwd); + debugStartup("PythonKernel.start:availCheck"); time("PythonKernel.start:availabilityCheck"); if (!availability.ok) { throw new Error(availability.reason ?? "Python kernel unavailable"); @@ -344,24 +320,40 @@ export class PythonKernel { return PythonKernel.startWithExternalGateway(externalConfig, options.cwd, options.env); } - // Try shared gateway first (unless explicitly disabled) - if (options.useSharedGateway !== false) { + if (options.useSharedGateway === false) { + throw new Error("Shared Python gateway required; local gateways are disabled"); + } + + for (let attempt = 0; attempt < 2; attempt += 1) { try { + debugStartup("PythonKernel.start:acquireShared:start"); const sharedResult = await acquireSharedGateway(options.cwd); + debugStartup("PythonKernel.start:acquireShared:done"); time("PythonKernel.start:acquireSharedGateway"); - if (sharedResult) { - const kernel = await PythonKernel.startWithSharedGateway(sharedResult.url, options.cwd, options.env); - time("PythonKernel.start:startWithSharedGateway"); - return kernel; + if (!sharedResult) { + throw new Error("Shared Python gateway unavailable"); } + debugStartup("PythonKernel.start:startShared:start"); + const kernel = await PythonKernel.startWithSharedGateway(sharedResult.url, options.cwd, options.env); + debugStartup("PythonKernel.start:startShared:done"); + time("PythonKernel.start:startWithSharedGateway"); + return kernel; } catch (err) { - logger.warn("Failed to acquire shared gateway, falling back to local", { + debugStartup("PythonKernel.start:sharedFailed"); + if (attempt === 0 && err instanceof SharedGatewayCreateError && err.status >= 500) { + logger.warn("Shared gateway kernel creation failed, retrying", { + status: err.status, + }); + continue; + } + logger.warn("Failed to acquire shared gateway", { error: err instanceof Error ? err.message : String(err), }); + throw err; } } - return PythonKernel.startWithLocalGateway(options); + throw new Error("Shared Python gateway unavailable after retry"); } private static async startWithExternalGateway( @@ -387,7 +379,7 @@ export class PythonKernel { const kernelInfo = (await createResponse.json()) as { id: string }; const kernelId = kernelInfo.id; - const kernel = new PythonKernel(nanoid(), kernelId, null, config.url, nanoid(), "omp", false, config.token); + const kernel = new PythonKernel(nanoid(), kernelId, config.url, nanoid(), "omp", false, config.token); try { await kernel.connectWebSocket(); @@ -409,34 +401,54 @@ export class PythonKernel { cwd: string, env?: Record, ): Promise { + debugStartup("sharedGateway:fetch:start"); const createResponse = await fetch(`${gatewayUrl}/api/kernels`, { method: "POST", headers: { "Content-Type": "application/json" }, body: JSON.stringify({ name: "python3" }), }); + debugStartup("sharedGateway:fetch:done"); time("startWithSharedGateway:createKernel"); if (!createResponse.ok) { - await releaseSharedGateway(); - throw new Error(`Failed to create kernel on shared gateway: ${await createResponse.text()}`); + debugStartup(`sharedGateway:fetch:notOk:${createResponse.status}`); + await shutdownSharedGateway(); + debugStartup("sharedGateway:fetch:shutdown"); + const text = await createResponse.text(); + debugStartup("sharedGateway:fetch:textRead"); + throw new SharedGatewayCreateError( + createResponse.status, + `Failed to create kernel on shared gateway: ${text}`, + ); } + debugStartup("sharedGateway:json:start"); const kernelInfo = (await createResponse.json()) as { id: string }; + debugStartup("sharedGateway:json:done"); const kernelId = kernelInfo.id; - const kernel = new PythonKernel(nanoid(), kernelId, null, gatewayUrl, nanoid(), "omp", true); + const kernel = new PythonKernel(nanoid(), kernelId, gatewayUrl, nanoid(), "omp", true); + debugStartup("sharedGateway:kernelCreated"); try { + debugStartup("sharedGateway:connectWS:start"); await kernel.connectWebSocket(); + debugStartup("sharedGateway:connectWS:done"); time("startWithSharedGateway:connectWS"); + debugStartup("sharedGateway:initEnv:start"); await kernel.initializeKernelEnvironment(cwd, env); + debugStartup("sharedGateway:initEnv:done"); time("startWithSharedGateway:initEnv"); + debugStartup("sharedGateway:prelude:start"); const preludeResult = await kernel.execute(PYTHON_PRELUDE, { silent: true, storeHistory: false }); + debugStartup("sharedGateway:prelude:done"); time("startWithSharedGateway:prelude"); if (preludeResult.cancelled || preludeResult.status === "error") { throw new Error("Failed to initialize Python kernel prelude"); } + debugStartup("sharedGateway:loadModules:start"); await loadPythonModules(kernel, { cwd }); + debugStartup("sharedGateway:loadModules:done"); time("startWithSharedGateway:loadModules"); return kernel; } catch (err: unknown) { @@ -445,120 +457,6 @@ export class PythonKernel { } } - private static async startWithLocalGateway(options: KernelStartOptions): Promise { - const settings = await Settings.init(); - const { shell, env } = settings.getShellConfig(); - const filteredEnv = filterEnv(env); - const runtime = resolvePythonRuntime(options.cwd, filteredEnv); - const snapshotPath = await getOrCreateSnapshot(shell, env).catch((err: unknown) => { - logger.warn("Failed to resolve shell snapshot for Python kernel", { - error: err instanceof Error ? err.message : String(err), - }); - return null; - }); - - const kernelEnv: Record = { - ...runtime.env, - ...options.env, - PYTHONUNBUFFERED: "1", - OMP_SHELL_SNAPSHOT: snapshotPath ?? undefined, - }; - - const pythonPathParts = [options.cwd, kernelEnv.PYTHONPATH].filter(Boolean).join(path.delimiter); - if (pythonPathParts) { - kernelEnv.PYTHONPATH = pythonPathParts; - } - - let gatewayProcess: ptree.ChildProcess | null = null; - let gatewayUrl: string | null = null; - let lastError: string | null = null; - - for (let attempt = 0; attempt < GATEWAY_STARTUP_ATTEMPTS; attempt += 1) { - const gatewayPort = await allocatePort(); - const candidateUrl = `http://127.0.0.1:${gatewayPort}`; - const candidateProcess = ptree.spawn( - [ - runtime.pythonPath, - "-m", - "kernel_gateway", - "--KernelGatewayApp.ip=127.0.0.1", - `--KernelGatewayApp.port=${gatewayPort}`, - "--KernelGatewayApp.port_retries=0", - "--KernelGatewayApp.allow_origin=*", - "--JupyterApp.answer_yes=true", - ], - { - cwd: options.cwd, - env: kernelEnv, - }, - ); - - let exited = false; - candidateProcess.exited - .then(() => { - exited = true; - }) - .catch(() => { - exited = true; - }); - - const startTime = Date.now(); - while (Date.now() - startTime < GATEWAY_STARTUP_TIMEOUT_MS) { - if (exited) break; - try { - const response = await fetch(`${candidateUrl}/api/kernelspecs`); - if (response.ok) { - gatewayProcess = candidateProcess; - gatewayUrl = candidateUrl; - break; - } - } catch { - // Gateway not ready yet - } - await Bun.sleep(100); - } - - if (gatewayProcess && gatewayUrl) break; - - candidateProcess.kill(); - lastError = exited ? "Kernel gateway process exited during startup" : "Kernel gateway failed to start"; - } - - if (!gatewayProcess || !gatewayUrl) { - throw new Error(lastError ?? "Kernel gateway failed to start"); - } - - const createResponse = await fetch(`${gatewayUrl}/api/kernels`, { - method: "POST", - headers: { "Content-Type": "application/json" }, - body: JSON.stringify({ name: "python3" }), - }); - - if (!createResponse.ok) { - gatewayProcess.kill(); - throw new Error(`Failed to create kernel: ${await createResponse.text()}`); - } - - const kernelInfo = (await createResponse.json()) as { id: string }; - const kernelId = kernelInfo.id; - - const kernel = new PythonKernel(nanoid(), kernelId, gatewayProcess, gatewayUrl, nanoid(), "omp", false); - - try { - await kernel.connectWebSocket(); - await kernel.initializeKernelEnvironment(options.cwd, options.env); - const preludeResult = await kernel.execute(PYTHON_PRELUDE, { silent: true, storeHistory: false }); - if (preludeResult.cancelled || preludeResult.status === "error") { - throw new Error("Failed to initialize Python kernel prelude"); - } - await loadPythonModules(kernel, { cwd: options.cwd }); - return kernel; - } catch (err: unknown) { - await kernel.shutdown(); - throw err; - } - } - private async connectWebSocket(): Promise { const wsBase = this.gatewayUrl.replace(/^http/, "ws"); let wsUrl = `${wsBase}/api/kernels/${this.kernelId}/channels`; @@ -949,14 +847,6 @@ export class PythonKernel { if (this.isSharedGateway) { await releaseSharedGateway(); - } else if (this.gatewayProcess) { - try { - this.gatewayProcess.kill(); - } catch (err: unknown) { - logger.warn("Failed to terminate gateway process", { - error: err instanceof Error ? err.message : String(err), - }); - } } } diff --git a/packages/coding-agent/src/main.ts b/packages/coding-agent/src/main.ts index 105c99a2f..88a3ee0ea 100644 --- a/packages/coding-agent/src/main.ts +++ b/packages/coding-agent/src/main.ts @@ -42,6 +42,11 @@ import { resolvePromptInput } from "./system-prompt"; import { getChangelogPath, getNewEntries, parseChangelog } from "./utils/changelog"; import { printTimings, time } from "./utils/timings"; +/** Conditional startup debug prints (stderr) when OMP_DEBUG_STARTUP is set */ +const debugStartup = process.env.OMP_DEBUG_STARTUP + ? (stage: string) => process.stderr.write(`[startup] ${stage}\n`) + : () => {}; + async function checkForNewVersion(currentVersion: string): Promise { try { const response = await fetch("https://registry.npmjs.org/@oh-my-pi/pi-coding-agent/latest"); @@ -477,10 +482,12 @@ async function buildSessionOptions( export async function main(args: string[]) { time("start"); + debugStartup("main:entry"); // Initialize theme early with defaults (CLI commands need symbols) // Will be re-initialized with user preferences later await initTheme(); + debugStartup("main:initTheme"); // Handle plugin subcommand before regular parsing const pluginCmd = parsePluginArgs(args); @@ -582,15 +589,18 @@ export async function main(args: string[]) { } const parsed = parseArgs(args); + debugStartup("main:parseArgs"); time("parseArgs"); await maybeAutoChdir(parsed); // Run migrations (pass cwd for project-local migrations) const { migratedAuthProviders: migratedProviders, deprecationWarnings } = await runMigrations(process.cwd()); + debugStartup("main:runMigrations"); // Create AuthStorage and ModelRegistry upfront const authStorage = await discoverAuthStorage(); const modelRegistry = discoverModels(authStorage); + debugStartup("main:discoverModels"); time("discoverModels"); if (parsed.version) { @@ -629,6 +639,7 @@ export async function main(args: string[]) { const cwd = process.cwd(); await Settings.init({ cwd }); + debugStartup("main:Settings.init"); time("Settings.init"); const pipedInput = await readPipedInput(); let { initialMessage, initialImages } = await prepareInitialMessage(parsed, settings.get("images.autoResize")); @@ -657,6 +668,7 @@ export async function main(args: string[]) { } await initTheme(settings.get("theme"), isInteractive, settings.get("symbolPreset"), settings.get("colorBlindMode")); + debugStartup("main:initTheme2"); time("initTheme"); // Show deprecation warnings in interactive mode @@ -676,6 +688,7 @@ export async function main(args: string[]) { // Create session manager based on CLI flags let sessionManager = await createSessionManager(parsed, cwd); + debugStartup("main:createSessionManager"); time("createSessionManager"); // Handle --resume: show session picker @@ -696,6 +709,7 @@ export async function main(args: string[]) { } const sessionOptions = await buildSessionOptions(parsed, scopedModels, sessionManager, modelRegistry); + debugStartup("main:buildSessionOptions"); sessionOptions.authStorage = authStorage; sessionOptions.modelRegistry = modelRegistry; sessionOptions.hasUI = isInteractive; @@ -712,6 +726,7 @@ export async function main(args: string[]) { time("buildSessionOptions"); const { session, setToolUIContext, modelFallbackMessage, lspServers, mcpManager } = await createAgentSession(sessionOptions); + debugStartup("main:createAgentSession"); time("createAgentSession"); // Re-parse CLI args with extension flags and apply values @@ -729,6 +744,7 @@ export async function main(args: string[]) { } } time("applyExtensionFlags"); + debugStartup("main:applyExtensionFlags"); if (!isInteractive && !session.model) { writeStderr(chalk.red("No models available.")); @@ -769,6 +785,7 @@ export async function main(args: string[]) { } printTimings(); + debugStartup("main:runInteractiveMode:start"); await runInteractiveMode( session, VERSION, diff --git a/packages/coding-agent/src/modes/interactive-mode.ts b/packages/coding-agent/src/modes/interactive-mode.ts index b9ee1dab9..34f282905 100644 --- a/packages/coding-agent/src/modes/interactive-mode.ts +++ b/packages/coding-agent/src/modes/interactive-mode.ts @@ -53,6 +53,11 @@ import { getEditorTheme, getMarkdownTheme, onThemeChange, theme } from "./theme/ import type { CompactionQueuedMessage, InteractiveModeContext, TodoItem } from "./types"; import { UiHelpers } from "./utils/ui-helpers"; +/** Conditional startup debug prints (stderr) when OMP_DEBUG_STARTUP is set */ +const debugStartup = process.env.OMP_DEBUG_STARTUP + ? (stage: string) => process.stderr.write(`[startup] ${stage}\n`) + : () => {}; + const TODO_FILE_NAME = "todos.json"; /** Options for creating an InteractiveMode instance (for future API use) */ @@ -261,14 +266,18 @@ export class InteractiveMode implements InteractiveModeContext { async init(): Promise { if (this.isInitialized) return; + debugStartup("InteractiveMode.init:entry"); this.keybindings = await KeybindingsManager.create(); + debugStartup("InteractiveMode.init:keybindings"); // Register session manager flush for signal handlers (SIGINT, SIGTERM, SIGHUP) this.cleanupUnsubscribe = postmortem.register("session-manager-flush", () => this.sessionManager.flush()); + debugStartup("InteractiveMode.init:cleanupRegistered"); // Load and convert file commands to SlashCommand format (async) const fileCommands = await loadSlashCommands({ cwd: process.cwd() }); + debugStartup("InteractiveMode.init:slashCommands"); this.fileSlashCommands = new Set(fileCommands.map(cmd => cmd.name)); const fileSlashCommands: SlashCommand[] = fileCommands.map(cmd => ({ name: cmd.name, @@ -291,6 +300,7 @@ export class InteractiveMode implements InteractiveModeContext { name: s.name, timeAgo: s.timeAgo, })); + debugStartup("InteractiveMode.init:recentSessions"); // Convert LSP servers to welcome format const lspServerInfo = @@ -304,7 +314,9 @@ export class InteractiveMode implements InteractiveModeContext { if (!startupQuiet) { // Add welcome header + debugStartup("InteractiveMode.init:welcomeComponent:start"); const welcome = new WelcomeComponent(this.version, modelName, providerName, recentSessions, lspServerInfo); + debugStartup("InteractiveMode.init:welcomeComponent:created"); // Setup UI layout this.ui.addChild(new Spacer(1)); diff --git a/packages/coding-agent/src/sdk.ts b/packages/coding-agent/src/sdk.ts index caeb44a93..0b9914b68 100644 --- a/packages/coding-agent/src/sdk.ts +++ b/packages/coding-agent/src/sdk.ts @@ -111,6 +111,11 @@ import { wrapToolsWithMetaNotice } from "./tools/output-meta"; import { EventBus } from "./utils/event-bus"; import { time } from "./utils/timings"; +/** Conditional startup debug prints (stderr) when OMP_DEBUG_STARTUP is set */ +const debugStartup = process.env.OMP_DEBUG_STARTUP + ? (stage: string) => process.stderr.write(`[startup] ${stage}\n`) + : () => {}; + // Types export interface CreateAgentSessionOptions { /** Working directory for project-local discovery. Default: process.cwd() */ @@ -568,6 +573,7 @@ function createCustomToolsExtension(tools: CustomTool[]): ExtensionFactory { * ``` */ export async function createAgentSession(options: CreateAgentSessionOptions = {}): Promise { + debugStartup("sdk:createAgentSession:entry"); const cwd = options.cwd ?? process.cwd(); const agentDir = options.agentDir ?? getDefaultAgentDir(); const eventBus = options.eventBus ?? new EventBus(); @@ -681,6 +687,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} skillWarnings = discovered.warnings; } time("discoverSkills"); + debugStartup("sdk:discoverSkills"); // Discover rules const ttsrSettings = settingsInstance.getGroup("ttsr"); @@ -703,6 +710,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} time("filterRulebookRules"); const contextFiles = options.contextFiles ?? (await discoverContextFiles(cwd, agentDir)); + debugStartup("sdk:discoverContextFiles"); time("discoverContextFiles"); let agent: Agent; @@ -766,11 +774,14 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} toolSession.getArtifactsDir = getArtifactsDir; toolSession.agentOutputManager = new AgentOutputManager(getArtifactsDir); + debugStartup("sdk:createTools:start"); // Create and wrap tools with meta notice formatting const rawBuiltinTools = await createTools(toolSession, options.toolNames); const builtinTools = wrapToolsWithMetaNotice(rawBuiltinTools); + debugStartup("sdk:createTools"); time("createAllTools"); + debugStartup("sdk:discoverMCP:start"); // Discover MCP tools from .mcp.json files let mcpManager: MCPManager | undefined; const enableMCP = options.enableMCP ?? true; @@ -791,6 +802,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} cacheStorage: settingsInstance.getStorage(), }); time("discoverAndLoadMCPTools"); + debugStartup("sdk:discoverAndLoadMCPTools"); mcpManager = mcpResult.manager; toolSession.mcpManager = mcpManager; @@ -810,6 +822,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} } } + debugStartup("sdk:geminiImageTools:start"); // Add Gemini image tools if GEMINI_API_KEY (or GOOGLE_API_KEY) is available const geminiImageTools = await getGeminiImageTools(); if (geminiImageTools.length > 0) { @@ -837,6 +850,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} inlineExtensions.push(createCustomToolsExtension(customTools)); } + debugStartup("sdk:loadExtensions:start"); // Load extensions (discovers from standard locations + configured paths) let extensionsResult: LoadExtensionsResult; if (options.disableExtensionDiscovery) { @@ -861,6 +875,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} (settingsInstance.get("disabledExtensions") as string[]) ?? [], ); time("discoverAndLoadExtensions"); + debugStartup("sdk:discoverAndLoadExtensions"); for (const { path, error } of extensionsResult.errors) { logger.error("Failed to load extension", { path, error }); } @@ -1023,6 +1038,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} } const systemPrompt = await rebuildSystemPrompt(initialToolNames, toolRegistry); + debugStartup("sdk:buildSystemPrompt:done"); time("buildSystemPrompt"); const promptTemplates = options.promptTemplates ?? (await discoverPromptTemplates(cwd, agentDir)); @@ -1109,6 +1125,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} cursorExecHandlers, }); cursorEventEmitter = event => agent.emitExternalEvent(event); + debugStartup("sdk:createAgent"); time("createAgent"); // Restore messages if session has existing data @@ -1139,12 +1156,14 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} rebuildSystemPrompt, ttsrManager, }); + debugStartup("sdk:createAgentSession"); time("createAgentSession"); // Warm up LSP servers (connects to detected servers) let lspServers: CreateAgentSessionResult["lspServers"]; if (enableLsp && settingsInstance.get("lsp.diagnosticsOnWrite")) { try { + debugStartup("sdk:warmupLspServers:start"); const result = await warmupLspServers(cwd, { onConnecting: serverNames => { if (options.hasUI && serverNames.length > 0) { @@ -1152,6 +1171,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} } }, }); + debugStartup("sdk:warmupLspServers:done"); lspServers = result.servers; time("warmupLspServers"); } catch (error) { @@ -1159,6 +1179,7 @@ export async function createAgentSession(options: CreateAgentSessionOptions = {} } } + debugStartup("sdk:return"); return { session, extensionsResult, diff --git a/scripts/repro-stuck.ts b/scripts/repro-stuck.ts new file mode 100644 index 000000000..d5f35c779 --- /dev/null +++ b/scripts/repro-stuck.ts @@ -0,0 +1,189 @@ +#!/usr/bin/env bun +/** + * Spawns many instances of the CLI to reproduce rare stuck/hang issues. + * Healthy instances (that produce TUI output) are killed. + * Stuck instances (no output after timeout) are kept alive for debugging. + * + * Usage: bun scripts/repro-stuck.ts [options] + * + * Options: + * --count=N Instances per batch (default: 50) + * --timeout=N Ms to wait for output (default: 15000) + * --rounds=N Max rounds to try (default: 1000) + */ + +import * as path from "node:path"; + +const CLI_PATH = path.resolve(import.meta.dir, "../packages/coding-agent/src/cli.ts"); +const TRACE_LOADER = path.resolve(import.meta.dir, "trace-loader.ts"); +const POLL_INTERVAL = 200; + +interface Args { + count: number; + timeout: number; + rounds: number; +} + +function parseArgs(): Args { + const args: Args = { count: 50, timeout: 15000, rounds: 1000 }; + for (const arg of process.argv.slice(2)) { + const [key, val] = arg.replace(/^--/, "").split("="); + if (key === "count") args.count = parseInt(val, 10); + if (key === "timeout") args.timeout = parseInt(val, 10); + if (key === "rounds") args.rounds = parseInt(val, 10); + } + return args; +} + +interface Instance { + proc: ReturnType; + port: number; + stdout: string; + stderr: string; + status: "pending" | "launched" | "exited" | "stuck"; +} + +/** Check if stdout contains the TUI (success indicator) */ +function hasLaunched(stdout: string): boolean { + return stdout.includes("omp v") || stdout.includes("ā–€ā–ˆ") || stdout.includes("Welcome back"); +} + +/** Non-blocking drain of a stream */ +async function drainStream(stream: ReadableStream): Promise { + const reader = stream.getReader(); + const decoder = new TextDecoder(); + let result = ""; + try { + while (true) { + const read = reader.read(); + const timeout = Bun.sleep(10).then(() => ({ done: true, value: undefined, timedOut: true })); + const chunk = (await Promise.race([read, timeout])) as { done: boolean; value?: Uint8Array; timedOut?: boolean }; + if (chunk.timedOut || chunk.done) break; + if (chunk.value) result += decoder.decode(chunk.value); + } + } finally { + reader.releaseLock(); + } + return result; +} + +async function spawnBatch(count: number, basePort: number, timeout: number): Promise { + const instances: Instance[] = []; + + // Spawn all + for (let i = 0; i < count; i++) { + const port = basePort + i; + const proc = Bun.spawn(["bun", "--preload", TRACE_LOADER, `--inspect=127.0.0.1:${port}`, CLI_PATH], { + stdout: "pipe", + stderr: "pipe", + stdin: "pipe", + env: { ...process.env, NO_COLOR: "1", OMP_DEBUG_STARTUP: "1" }, + }); + instances.push({ proc, port, stdout: "", stderr: "", status: "pending" }); + } + + const start = Date.now(); + + // Poll until all resolved or timeout + while (Date.now() - start < timeout) { + let allResolved = true; + + for (const inst of instances) { + if (inst.status !== "pending") continue; + + // Check if exited + if (inst.proc.exitCode !== null) { + inst.status = "exited"; + continue; + } + + // Drain available output + try { + inst.stdout += await drainStream(inst.proc.stdout as ReadableStream); + inst.stderr += await drainStream(inst.proc.stderr as ReadableStream); + } catch {} + + // Check if launched + if (hasLaunched(inst.stdout)) { + inst.status = "launched"; + inst.proc.kill(); + continue; + } + + allResolved = false; + } + + if (allResolved) break; + await Bun.sleep(POLL_INTERVAL); + } + + // Mark remaining pending as stuck + for (const inst of instances) { + if (inst.status === "pending") { + // Final drain + try { + inst.stdout += await drainStream(inst.proc.stdout as ReadableStream); + inst.stderr += await drainStream(inst.proc.stderr as ReadableStream); + } catch {} + inst.status = inst.proc.exitCode !== null ? "exited" : "stuck"; + } + } + + // Find and report stuck instances + let stuck: Instance | null = null; + for (const inst of instances) { + if (inst.status === "stuck") { + stuck = inst; + console.log(`\n\nšŸŽÆ STUCK INSTANCE FOUND!`); + console.log(` PID: ${inst.proc.pid}`); + console.log(` Inspector: ws://127.0.0.1:${inst.port}`); + console.log(` Stdout: ${inst.stdout.slice(0, 200) || "(none)"}`); + + const traceLines = inst.stderr.split("\n").filter(l => l.startsWith("[") && !l.includes("Bun Inspector")); + if (traceLines.length > 0) { + console.log(` Last traces (${traceLines.length} total):`); + for (const line of traceLines.slice(-15)) { + console.log(` ${line}`); + } + } + } else if (inst.status !== "launched") { + inst.proc.kill(); + } + } + + return stuck; +} + +async function main() { + const args = parseArgs(); + + console.log(`šŸ” Hunting for stuck process...`); + console.log(` Batch size: ${args.count}`); + console.log(` Timeout: ${args.timeout}ms`); + console.log(); + + let basePort = 9230; + let totalSpawned = 0; + + for (let round = 1; round <= args.rounds; round++) { + process.stdout.write(`\rRound ${round}/${args.rounds} (${totalSpawned} spawned)...`); + + const stuck = await spawnBatch(args.count, basePort, args.timeout); + totalSpawned += args.count; + + if (stuck) { + console.log(`\nāœ… Found after ${round} rounds, ${totalSpawned} total spawns`); + console.log(`\nTo debug: chrome://inspect ā†’ Configure ā†’ 127.0.0.1:${stuck.port}`); + console.log(`Press Ctrl+C to exit`); + await new Promise(() => {}); + } + + basePort += args.count; + if (basePort > 60000) basePort = 9230; + } + + console.log(`\n\nāŒ No stuck process found after ${totalSpawned} spawns`); + process.exit(1); +} + +main().catch(console.error); diff --git a/scripts/trace-loader.ts b/scripts/trace-loader.ts new file mode 100644 index 000000000..29dd9d6f8 --- /dev/null +++ b/scripts/trace-loader.ts @@ -0,0 +1,33 @@ +/** + * Bun preload script that traces module resolution. + * Usage: bun --preload ./scripts/trace-loader.ts