From c3d78ca6a26b50b82ff1fb66ee687a1d90206a58 Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Sat, 14 Mar 2026 23:32:15 +0000 Subject: [PATCH 1/8] fix(mcp): Harden server lifecycle shutdown Attach MCP shutdown handlers before async startup, add broken-pipe and crash handling, and explicitly stop the Xcode watcher during teardown. This closes lifecycle gaps that could leave MCP processes running after clients disappear and adds concrete shutdown reasons for investigation. Add lifecycle Sentry metrics, richer session diagnostics, and a repro script so process age, peer counts, memory, and active runtime state are visible when this issue recurs in the wild. Fixes #273 Co-Authored-By: Codex --- CHANGELOG.md | 5 +- package.json | 1 + scripts/repro-mcp-lifecycle-leak.ts | 225 +++++++++ .../__tests__/session-status.test.ts | 14 + src/server/__tests__/mcp-lifecycle.test.ts | 151 ++++++ src/server/bootstrap.ts | 16 +- src/server/mcp-lifecycle.ts | 432 ++++++++++++++++++ src/server/start-mcp-server.ts | 223 ++++++--- src/utils/sentry.ts | 76 +++ src/utils/session-status.ts | 43 ++ 10 files changed, 1114 insertions(+), 72 deletions(-) create mode 100644 scripts/repro-mcp-lifecycle-leak.ts create mode 100644 src/server/__tests__/mcp-lifecycle.test.ts create mode 100644 src/server/mcp-lifecycle.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index 559ce30b..01cbd95e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,10 @@ - Clarified configuration layering: `session_set_defaults` overrides `config.yaml`, which overrides env-based bootstrap values. See [docs/CONFIGURATION.md](docs/CONFIGURATION.md) ([#268](https://github.com/getsentry/XcodeBuildMCP/pull/268) by [@detailobsessed](https://github.com/detailobsessed)). +### Fixed + +- Fixed orphaned MCP server processes by attaching shutdown handlers before async startup, explicitly stopping the Xcode watcher during teardown, and adding lifecycle diagnostics for memory and peer-process anomalies ([#273](https://github.com/getsentry/XcodeBuildMCP/issues/273)). + ## [2.2.1] - Fix AXe bundling issue. @@ -406,4 +410,3 @@ Please note that the UI automation features are an early preview and currently i ## [v1.0.1] - 2025-04-02 - Initial release of XcodeBuildMCP - Basic support for building iOS and macOS applications - diff --git a/package.json b/package.json index 1df71f3e..b4742254 100644 --- a/package.json +++ b/package.json @@ -21,6 +21,7 @@ "prepare": "node scripts/install-git-hooks.js", "hooks:install": "node scripts/install-git-hooks.js", "generate:version": "npx tsx scripts/generate-version.ts", + "repro:mcp-lifecycle-leak": "npm run build && npx tsx scripts/repro-mcp-lifecycle-leak.ts", "bundle:axe": "scripts/bundle-axe.sh", "package:macos": "scripts/package-macos-portable.sh", "package:macos:universal": "scripts/package-macos-portable.sh --universal", diff --git a/scripts/repro-mcp-lifecycle-leak.ts b/scripts/repro-mcp-lifecycle-leak.ts new file mode 100644 index 00000000..a7233b92 --- /dev/null +++ b/scripts/repro-mcp-lifecycle-leak.ts @@ -0,0 +1,225 @@ +import { spawn } from 'node:child_process'; +import process from 'node:process'; + +interface CliOptions { + iterations: number; + closeDelayMs: number; + settleMs: number; +} + +interface PeerProcess { + pid: number; + ageSeconds: number; + rssKb: number; + command: string; +} + +function parseArgs(argv: string[]): CliOptions { + const options: CliOptions = { + iterations: 20, + closeDelayMs: 0, + settleMs: 2000, + }; + + for (let index = 0; index < argv.length; index += 1) { + const arg = argv[index]; + const value = argv[index + 1]; + + if (arg === '--iterations' && value) { + options.iterations = Number(value); + index += 1; + } else if (arg === '--close-delay-ms' && value) { + options.closeDelayMs = Number(value); + index += 1; + } else if (arg === '--settle-ms' && value) { + options.settleMs = Number(value); + index += 1; + } + } + + if (!Number.isFinite(options.iterations) || options.iterations < 1) { + throw new Error('--iterations must be a positive number'); + } + if (!Number.isFinite(options.closeDelayMs) || options.closeDelayMs < 0) { + throw new Error('--close-delay-ms must be a non-negative number'); + } + if (!Number.isFinite(options.settleMs) || options.settleMs < 0) { + throw new Error('--settle-ms must be a non-negative number'); + } + + return options; +} + +function delay(ms: number): Promise { + return new Promise((resolve) => setTimeout(resolve, ms)); +} + +function isLikelyMcpCommand(command: string): boolean { + const normalized = command.toLowerCase(); + return ( + /(^|\s)mcp(\s|$)/.test(normalized) && + !/(^|\s)daemon(\s|$)/.test(normalized) && + (normalized.includes('xcodebuildmcp') || + normalized.includes('build/cli.js') || + normalized.includes('/cli.js')) + ); +} + +function parseElapsedSeconds(value: string): number | null { + const trimmed = value.trim(); + if (!trimmed) { + return null; + } + + const daySplit = trimmed.split('-'); + const timePart = daySplit.length === 2 ? daySplit[1] : daySplit[0]; + const dayCount = daySplit.length === 2 ? Number(daySplit[0]) : 0; + const parts = timePart.split(':').map((part) => Number(part)); + + if (!Number.isFinite(dayCount) || parts.some((part) => !Number.isFinite(part))) { + return null; + } + + if (parts.length === 1) { + return dayCount * 86400 + parts[0]; + } + if (parts.length === 2) { + return dayCount * 86400 + parts[0] * 60 + parts[1]; + } + if (parts.length === 3) { + return dayCount * 86400 + parts[0] * 3600 + parts[1] * 60 + parts[2]; + } + + return null; +} + +async function sampleMcpProcesses(): Promise { + return new Promise((resolve, reject) => { + const child = spawn('ps', ['-axo', 'pid=,etime=,rss=,command='], { + stdio: ['ignore', 'pipe', 'pipe'], + }); + let stdout = ''; + let stderr = ''; + + child.stdout.on('data', (chunk: Buffer) => { + stdout += chunk.toString(); + }); + child.stderr.on('data', (chunk: Buffer) => { + stderr += chunk.toString(); + }); + child.on('error', reject); + child.on('close', (code) => { + if (code !== 0) { + reject(new Error(stderr || `ps exited with code ${code}`)); + return; + } + + const processes = stdout + .split('\n') + .map((line) => line.trim()) + .filter(Boolean) + .map((line) => { + const match = line.match(/^(\d+)\s+(\S+)\s+(\d+)\s+(.+)$/); + if (!match) { + return null; + } + const ageSeconds = parseElapsedSeconds(match[2]); + return { + pid: Number(match[1]), + ageSeconds, + rssKb: Number(match[3]), + command: match[4], + }; + }) + .filter((entry): entry is PeerProcess => { + return ( + entry !== null && + Number.isFinite(entry.pid) && + Number.isFinite(entry.ageSeconds) && + Number.isFinite(entry.rssKb) && + isLikelyMcpCommand(entry.command) + ); + }); + + resolve(processes); + }); + }); +} + +async function runIteration(closeDelayMs: number): Promise { + return new Promise((resolve) => { + const child = spawn(process.execPath, ['build/cli.js', 'mcp'], { + cwd: process.cwd(), + stdio: ['pipe', 'ignore', 'ignore'], + }); + + let exited = false; + child.once('close', () => { + exited = true; + resolve(true); + }); + child.once('error', () => { + exited = true; + resolve(false); + }); + + setTimeout(() => { + child.stdin.end(); + }, closeDelayMs); + + setTimeout( + () => { + if (!exited) { + resolve(false); + } + }, + Math.max(1000, closeDelayMs + 1000), + ); + }); +} + +async function main(): Promise { + const options = parseArgs(process.argv.slice(2)); + const before = await sampleMcpProcesses(); + const baselinePids = new Set(before.map((entry) => entry.pid)); + + let exitedCount = 0; + for (let index = 0; index < options.iterations; index += 1) { + const exited = await runIteration(options.closeDelayMs); + if (exited) { + exitedCount += 1; + } + } + + await delay(options.settleMs); + + const after = await sampleMcpProcesses(); + const lingering = after.filter((entry) => !baselinePids.has(entry.pid)); + + console.log( + JSON.stringify( + { + iterations: options.iterations, + exitedCount, + baselineProcessCount: before.length, + finalProcessCount: after.length, + lingeringProcessCount: lingering.length, + lingering: lingering.map(({ pid, ageSeconds, rssKb, command }) => ({ + pid, + ageSeconds, + rssKb, + command, + })), + }, + null, + 2, + ), + ); + + process.exit(lingering.length === 0 ? 0 : 1); +} + +void main().catch((error) => { + console.error(error instanceof Error ? error.message : String(error)); + process.exit(1); +}); diff --git a/src/mcp/resources/__tests__/session-status.test.ts b/src/mcp/resources/__tests__/session-status.test.ts index 433305df..a074d230 100644 --- a/src/mcp/resources/__tests__/session-status.test.ts +++ b/src/mcp/resources/__tests__/session-status.test.ts @@ -1,19 +1,25 @@ import { describe, it, expect, beforeEach, afterEach } from 'vitest'; +import { clearDaemonActivityRegistry } from '../../../daemon/activity-registry.ts'; import { getDefaultDebuggerManager } from '../../../utils/debugger/index.ts'; import { activeLogSessions } from '../../../utils/log_capture.ts'; import { activeDeviceLogSessions } from '../../../utils/log-capture/device-log-sessions.ts'; +import { clearAllProcesses } from '../../tools/swift-package/active-processes.ts'; import sessionStatusResource, { sessionStatusResourceLogic } from '../session-status.ts'; describe('session-status resource', () => { beforeEach(async () => { activeLogSessions.clear(); activeDeviceLogSessions.clear(); + clearAllProcesses(); + clearDaemonActivityRegistry(); await getDefaultDebuggerManager().disposeAll(); }); afterEach(async () => { activeLogSessions.clear(); activeDeviceLogSessions.clear(); + clearAllProcesses(); + clearDaemonActivityRegistry(); await getDefaultDebuggerManager().disposeAll(); }); @@ -48,6 +54,14 @@ describe('session-status resource', () => { expect(parsed.logging.device.activeSessionIds).toEqual([]); expect(parsed.debug.currentSessionId).toBe(null); expect(parsed.debug.sessionIds).toEqual([]); + expect(parsed.watcher).toEqual({ running: false, watchedPath: null }); + expect(parsed.video.activeSessionIds).toEqual([]); + expect(parsed.swiftPackage.activePids).toEqual([]); + expect(parsed.activity).toEqual({ activeOperationCount: 0, byCategory: {} }); + expect(parsed.process.pid).toBeTypeOf('number'); + expect(parsed.process.uptimeMs).toBeTypeOf('number'); + expect(parsed.process.rssBytes).toBeTypeOf('number'); + expect(parsed.process.heapUsedBytes).toBeTypeOf('number'); }); }); }); diff --git a/src/server/__tests__/mcp-lifecycle.test.ts b/src/server/__tests__/mcp-lifecycle.test.ts new file mode 100644 index 00000000..fb46e33f --- /dev/null +++ b/src/server/__tests__/mcp-lifecycle.test.ts @@ -0,0 +1,151 @@ +import { EventEmitter } from 'node:events'; +import { beforeEach, describe, expect, it, vi } from 'vitest'; +import { createMockExecutor } from '../../test-utils/mock-executors.ts'; +import { + buildMcpLifecycleSnapshot, + classifyMcpLifecycleAnomalies, + createMcpLifecycleCoordinator, +} from '../mcp-lifecycle.ts'; + +class TestStdin extends EventEmitter { + override once(event: string, listener: (...args: unknown[]) => void): this { + return super.once(event, listener); + } + + override removeListener(event: string, listener: (...args: unknown[]) => void): this { + return super.removeListener(event, listener); + } +} + +class TestProcess extends EventEmitter { + readonly stdin = new TestStdin(); + readonly stdout = new TestStdin(); + + override once(event: string, listener: (...args: unknown[]) => void): this { + return super.once(event, listener); + } + + override removeListener(event: string, listener: (...args: unknown[]) => void): this { + return super.removeListener(event, listener); + } +} + +describe('mcp lifecycle coordinator', () => { + beforeEach(() => { + vi.restoreAllMocks(); + }); + + it('deduplicates shutdown requests from stdin end and close', async () => { + const processRef = new TestProcess(); + const onShutdown = vi.fn().mockResolvedValue(undefined); + const coordinator = createMcpLifecycleCoordinator({ + commandExecutor: createMockExecutor({ output: '' }), + processRef, + onShutdown, + }); + + coordinator.attachProcessHandlers(); + processRef.stdin.emit('end'); + processRef.stdin.emit('close'); + await vi.waitFor(() => { + expect(onShutdown).toHaveBeenCalledTimes(1); + }); + + expect(onShutdown.mock.calls[0]?.[0]?.reason).toBe('stdin-end'); + }); + + it('shuts down cleanly even if stdin closes before a server is registered', async () => { + const processRef = new TestProcess(); + const onShutdown = vi.fn().mockResolvedValue(undefined); + const coordinator = createMcpLifecycleCoordinator({ + commandExecutor: createMockExecutor({ output: '' }), + processRef, + onShutdown, + }); + + coordinator.attachProcessHandlers(); + processRef.stdin.emit('close'); + await vi.waitFor(() => { + expect(onShutdown).toHaveBeenCalledTimes(1); + }); + + expect(onShutdown.mock.calls[0]?.[0]?.server).toBe(null); + }); + + it('maps unhandled rejections to crash shutdowns', async () => { + const processRef = new TestProcess(); + const onShutdown = vi.fn().mockResolvedValue(undefined); + const coordinator = createMcpLifecycleCoordinator({ + commandExecutor: createMockExecutor({ output: '' }), + processRef, + onShutdown, + }); + + coordinator.attachProcessHandlers(); + processRef.emit('unhandledRejection', new Error('boom')); + await vi.waitFor(() => { + expect(onShutdown).toHaveBeenCalledTimes(1); + }); + + expect(onShutdown.mock.calls[0]?.[0]?.reason).toBe('unhandled-rejection'); + }); + + it('maps broken stdout pipes to shutdowns', async () => { + const processRef = new TestProcess(); + const onShutdown = vi.fn().mockResolvedValue(undefined); + const coordinator = createMcpLifecycleCoordinator({ + commandExecutor: createMockExecutor({ output: '' }), + processRef, + onShutdown, + }); + + coordinator.attachProcessHandlers(); + processRef.stdout.emit('error', Object.assign(new Error('broken pipe'), { code: 'EPIPE' })); + await vi.waitFor(() => { + expect(onShutdown).toHaveBeenCalledTimes(1); + }); + + expect(onShutdown.mock.calls[0]?.[0]?.reason).toBe('stdout-error'); + }); +}); + +describe('mcp lifecycle snapshot', () => { + it('classifies peer-count and memory anomalies', () => { + expect( + classifyMcpLifecycleAnomalies({ + uptimeMs: 10 * 60 * 1000, + rssBytes: 600 * 1024 * 1024, + matchingMcpProcessCount: 4, + matchingMcpPeerSummary: [{ pid: 11, ageSeconds: 180, rssKb: 1000 }], + }), + ).toEqual(['high-rss', 'long-lived-high-rss', 'peer-age-high', 'peer-count-high']); + }); + + it('samples matching MCP peer processes from ps output', async () => { + vi.spyOn(process, 'memoryUsage').mockReturnValue({ + rss: 64 * 1024 * 1024, + heapTotal: 8, + heapUsed: 4, + external: 0, + arrayBuffers: 0, + }); + const startedAtMs = Date.now() - 1000; + + const snapshot = await buildMcpLifecycleSnapshot({ + phase: 'running', + shutdownReason: null, + startedAtMs, + commandExecutor: createMockExecutor({ + output: [ + `${process.pid} 00:05 65536 node /tmp/build/cli.js mcp`, + `999 03:00 1024 node /tmp/build/cli.js mcp`, + `321 00:07 2048 node /tmp/build/cli.js daemon`, + ].join('\n'), + }), + }); + + expect(snapshot.matchingMcpProcessCount).toBe(2); + expect(snapshot.matchingMcpPeerSummary).toEqual([{ pid: 999, ageSeconds: 180, rssKb: 1024 }]); + expect(snapshot.anomalies).toEqual(['peer-age-high']); + }); +}); diff --git a/src/server/bootstrap.ts b/src/server/bootstrap.ts index 292ad189..9aafde72 100644 --- a/src/server/bootstrap.ts +++ b/src/server/bootstrap.ts @@ -24,7 +24,7 @@ export interface BootstrapOptions { } export interface BootstrapResult { - runDeferredInitialization: () => Promise; + runDeferredInitialization: (options?: { isShutdownRequested?: () => boolean }) => Promise; } export async function bootstrapServer( @@ -104,8 +104,9 @@ export async function bootstrapServer( profiler.mark('registerResources', stageStartMs); return { - runDeferredInitialization: async (): Promise => { + runDeferredInitialization: async (options = {}): Promise => { const deferredProfiler = createStartupProfiler('bootstrap-deferred'); + const isShutdownRequested = options.isShutdownRequested; if (!xcodeDetection.runningUnderXcode) { return; @@ -115,6 +116,10 @@ export async function bootstrapServer( const { projectPath, workspacePath } = sessionStore.getAll(); + if (isShutdownRequested?.()) { + return; + } + let deferredStageStartMs = getStartupProfileNowMs(); const xcodeState = await readXcodeIdeState({ executor, @@ -125,6 +130,10 @@ export async function bootstrapServer( }); deferredProfiler.mark('readXcodeIdeState', deferredStageStartMs); + if (isShutdownRequested?.()) { + return; + } + if (xcodeState.error) { log('debug', `[xcode] Could not read Xcode IDE state: ${xcodeState.error}`); } else { @@ -162,6 +171,9 @@ export async function bootstrapServer( } if (!result.runtime.config.disableXcodeAutoSync) { + if (isShutdownRequested?.()) { + return; + } deferredStageStartMs = getStartupProfileNowMs(); const watcherStarted = await startXcodeStateWatcher({ executor, diff --git a/src/server/mcp-lifecycle.ts b/src/server/mcp-lifecycle.ts new file mode 100644 index 00000000..9c3f15cc --- /dev/null +++ b/src/server/mcp-lifecycle.ts @@ -0,0 +1,432 @@ +import process from 'node:process'; +import type { McpServer } from '@modelcontextprotocol/sdk/server/mcp.js'; +import { getDefaultDebuggerManager } from '../utils/debugger/index.ts'; +import { activeLogSessions } from '../utils/log_capture.ts'; +import { activeDeviceLogSessions } from '../utils/log-capture/device-log-sessions.ts'; +import { activeProcesses } from '../mcp/tools/swift-package/active-processes.ts'; +import { getDaemonActivitySnapshot } from '../daemon/activity-registry.ts'; +import { listActiveVideoCaptureSessionIds } from '../utils/video_capture.ts'; +import { getDefaultCommandExecutor } from '../utils/execution/index.ts'; +import type { CommandExecutor } from '../utils/execution/index.ts'; +import { getWatchedPath, isWatcherRunning } from '../utils/xcode-state-watcher.ts'; + +export type McpStartupPhase = + | 'initializing' + | 'hydrating-sentry-config' + | 'initializing-sentry' + | 'creating-server' + | 'bootstrapping-server' + | 'starting-stdio-transport' + | 'running' + | 'deferred-initialization' + | 'shutting-down' + | 'stopped'; + +export type McpShutdownReason = + | 'stdin-end' + | 'stdin-close' + | 'stdout-error' + | 'sigint' + | 'sigterm' + | 'startup-failure' + | 'uncaught-exception' + | 'unhandled-rejection'; + +export type McpLifecycleAnomaly = + | 'peer-count-high' + | 'peer-age-high' + | 'high-rss' + | 'long-lived-high-rss'; + +export interface McpPeerProcessSummary { + pid: number; + ageSeconds: number; + rssKb: number; +} + +export interface McpLifecycleSnapshot { + pid: number; + phase: McpStartupPhase; + shutdownReason: McpShutdownReason | null; + uptimeMs: number; + rssBytes: number; + heapUsedBytes: number; + watcherRunning: boolean; + watchedPath: string | null; + activeOperationCount: number; + activeOperationByCategory: Record; + debuggerSessionCount: number; + simulatorLogSessionCount: number; + deviceLogSessionCount: number; + videoCaptureSessionCount: number; + swiftPackageProcessCount: number; + matchingMcpProcessCount: number | null; + matchingMcpPeerSummary: McpPeerProcessSummary[]; + anomalies: McpLifecycleAnomaly[]; +} + +interface PeerProcessSample { + count: number | null; + peers: McpPeerProcessSummary[]; +} + +interface LifecycleStdinLike { + once(event: string, listener: (...args: unknown[]) => void): this; + removeListener(event: string, listener: (...args: unknown[]) => void): this; +} + +interface LifecycleStdoutLike { + once(event: string, listener: (...args: unknown[]) => void): this; + removeListener(event: string, listener: (...args: unknown[]) => void): this; +} + +interface LifecycleProcessLike { + stdin: LifecycleStdinLike; + stdout?: LifecycleStdoutLike; + once(event: string, listener: (...args: unknown[]) => void): this; + removeListener(event: string, listener: (...args: unknown[]) => void): this; +} + +interface McpLifecycleState { + startedAtMs: number; + phase: McpStartupPhase; + shutdownReason: McpShutdownReason | null; + shutdownPromise: Promise | null; + shutdownRequested: boolean; + server: McpServer | null; +} + +export interface McpLifecycleCoordinator { + attachProcessHandlers(): void; + detachProcessHandlers(): void; + markPhase(phase: McpStartupPhase): void; + registerServer(server: McpServer): void; + isShutdownRequested(): boolean; + getSnapshot(): Promise; + shutdown(reason: McpShutdownReason, error?: unknown): Promise; +} + +export interface McpLifecycleCoordinatorOptions { + commandExecutor?: CommandExecutor; + processRef?: LifecycleProcessLike; + onShutdown: (context: { + reason: McpShutdownReason; + error?: unknown; + snapshot: McpLifecycleSnapshot; + server: McpServer | null; + }) => Promise; +} + +const HIGH_RSS_BYTES = 512 * 1024 * 1024; +const LONG_LIVED_HIGH_RSS_BYTES = 256 * 1024 * 1024; +const LONG_LIVED_UPTIME_MS = 5 * 60 * 1000; +const PEER_AGE_HIGH_SECONDS = 120; +const PEER_COUNT_HIGH_THRESHOLD = 2; + +function parseElapsedSeconds(value: string): number | null { + const trimmed = value.trim(); + if (!trimmed) { + return null; + } + + const daySplit = trimmed.split('-'); + const timePart = daySplit.length === 2 ? daySplit[1] : daySplit[0]; + const dayCount = daySplit.length === 2 ? Number(daySplit[0]) : 0; + const parts = timePart.split(':').map((part) => Number(part)); + + if (!Number.isFinite(dayCount) || parts.some((part) => !Number.isFinite(part))) { + return null; + } + + if (parts.length === 1) { + return dayCount * 86400 + parts[0]; + } + if (parts.length === 2) { + return dayCount * 86400 + parts[0] * 60 + parts[1]; + } + if (parts.length === 3) { + return dayCount * 86400 + parts[0] * 3600 + parts[1] * 60 + parts[2]; + } + + return null; +} + +export function classifyMcpLifecycleAnomalies( + snapshot: Pick< + McpLifecycleSnapshot, + 'uptimeMs' | 'rssBytes' | 'matchingMcpProcessCount' | 'matchingMcpPeerSummary' + >, +): McpLifecycleAnomaly[] { + const anomalies = new Set(); + const peerCount = Math.max(0, (snapshot.matchingMcpProcessCount ?? 0) - 1); + + if (peerCount >= PEER_COUNT_HIGH_THRESHOLD) { + anomalies.add('peer-count-high'); + } + if (snapshot.matchingMcpPeerSummary.some((peer) => peer.ageSeconds >= PEER_AGE_HIGH_SECONDS)) { + anomalies.add('peer-age-high'); + } + if (snapshot.rssBytes >= HIGH_RSS_BYTES) { + anomalies.add('high-rss'); + } + if (snapshot.uptimeMs >= LONG_LIVED_UPTIME_MS && snapshot.rssBytes >= LONG_LIVED_HIGH_RSS_BYTES) { + anomalies.add('long-lived-high-rss'); + } + + return Array.from(anomalies.values()).sort(); +} + +function isLikelyMcpProcessCommand(command: string): boolean { + const normalized = command.toLowerCase(); + const hasMcpArg = /(^|\s)mcp(\s|$)/.test(normalized); + if (!hasMcpArg) { + return false; + } + + if (/(^|\s)daemon(\s|$)/.test(normalized)) { + return false; + } + + return ( + normalized.includes('xcodebuildmcp') || + normalized.includes('build/cli.js') || + normalized.includes('/cli.js') + ); +} + +function isBrokenPipeLikeError(error: unknown): boolean { + if (!(error instanceof Error)) { + return false; + } + + const code = 'code' in error ? String((error as Error & { code?: unknown }).code ?? '') : ''; + return code === 'EPIPE' || code === 'ERR_STREAM_DESTROYED'; +} + +async function sampleMcpPeerProcesses( + commandExecutor: CommandExecutor, + currentPid: number, +): Promise { + try { + const result = await commandExecutor( + ['ps', '-axo', 'pid=,etime=,rss=,command='], + 'Sample MCP lifecycle peer processes', + false, + ); + if (!result.success) { + return { count: null, peers: [] }; + } + + const matched = result.output + .split('\n') + .map((line) => line.trim()) + .filter(Boolean) + .map((line) => { + const match = line.match(/^(\d+)\s+(\S+)\s+(\d+)\s+(.+)$/); + if (!match) { + return null; + } + const [, pidRaw, elapsedRaw, rssRaw, command] = match; + const ageSeconds = parseElapsedSeconds(elapsedRaw); + return { + pid: Number(pidRaw), + ageSeconds, + rssKb: Number(rssRaw), + command, + }; + }) + .filter( + (entry): entry is { pid: number; ageSeconds: number; rssKb: number; command: string } => { + return ( + entry !== null && + Number.isFinite(entry.pid) && + Number.isFinite(entry.ageSeconds) && + Number.isFinite(entry.rssKb) && + isLikelyMcpProcessCommand(entry.command) + ); + }, + ); + + const peers = matched + .filter((entry) => entry.pid !== currentPid) + .map(({ pid, ageSeconds, rssKb }) => ({ pid, ageSeconds, rssKb })) + .sort((left, right) => { + if (right.ageSeconds !== left.ageSeconds) { + return right.ageSeconds - left.ageSeconds; + } + return right.rssKb - left.rssKb; + }) + .slice(0, 5); + + return { + count: matched.length, + peers, + }; + } catch { + return { count: null, peers: [] }; + } +} + +export async function buildMcpLifecycleSnapshot(options: { + phase: McpStartupPhase; + shutdownReason: McpShutdownReason | null; + startedAtMs: number; + commandExecutor?: CommandExecutor; +}): Promise { + const memoryUsage = process.memoryUsage(); + const activitySnapshot = getDaemonActivitySnapshot(); + const peerSample = await sampleMcpPeerProcesses( + options.commandExecutor ?? getDefaultCommandExecutor(), + process.pid, + ); + + const snapshotWithoutAnomalies = { + pid: process.pid, + phase: options.phase, + shutdownReason: options.shutdownReason, + uptimeMs: Math.max(0, Date.now() - options.startedAtMs), + rssBytes: memoryUsage.rss, + heapUsedBytes: memoryUsage.heapUsed, + watcherRunning: isWatcherRunning(), + watchedPath: getWatchedPath(), + activeOperationCount: activitySnapshot.activeOperationCount, + activeOperationByCategory: activitySnapshot.byCategory, + debuggerSessionCount: getDefaultDebuggerManager().listSessions().length, + simulatorLogSessionCount: activeLogSessions.size, + deviceLogSessionCount: activeDeviceLogSessions.size, + videoCaptureSessionCount: listActiveVideoCaptureSessionIds().length, + swiftPackageProcessCount: activeProcesses.size, + matchingMcpProcessCount: peerSample.count, + matchingMcpPeerSummary: peerSample.peers, + }; + + return { + ...snapshotWithoutAnomalies, + anomalies: classifyMcpLifecycleAnomalies(snapshotWithoutAnomalies), + }; +} + +export function createMcpLifecycleCoordinator( + options: McpLifecycleCoordinatorOptions, +): McpLifecycleCoordinator { + const processRef = options.processRef ?? (process as LifecycleProcessLike); + const state: McpLifecycleState = { + startedAtMs: Date.now(), + phase: 'initializing', + shutdownReason: null, + shutdownPromise: null, + shutdownRequested: false, + server: null, + }; + + const handleSigterm = (): void => { + void coordinator.shutdown('sigterm'); + }; + const handleSigint = (): void => { + void coordinator.shutdown('sigint'); + }; + const handleStdinEnd = (): void => { + void coordinator.shutdown('stdin-end'); + }; + const handleStdinClose = (): void => { + void coordinator.shutdown('stdin-close'); + }; + const handleStdoutError = (error: unknown): void => { + if (!isBrokenPipeLikeError(error)) { + return; + } + void coordinator.shutdown('stdout-error', error); + }; + const handleUncaughtException = (error: unknown): void => { + void coordinator.shutdown('uncaught-exception', error); + }; + const handleUnhandledRejection = (reason: unknown): void => { + void coordinator.shutdown('unhandled-rejection', reason); + }; + + let handlersAttached = false; + + const coordinator: McpLifecycleCoordinator = { + attachProcessHandlers(): void { + if (handlersAttached) { + return; + } + handlersAttached = true; + + processRef.once('SIGTERM', handleSigterm); + processRef.once('SIGINT', handleSigint); + processRef.stdin.once('end', handleStdinEnd); + processRef.stdin.once('close', handleStdinClose); + processRef.stdout?.once('error', handleStdoutError); + processRef.once('uncaughtException', handleUncaughtException); + processRef.once('unhandledRejection', handleUnhandledRejection); + }, + + detachProcessHandlers(): void { + if (!handlersAttached) { + return; + } + handlersAttached = false; + + processRef.removeListener('SIGTERM', handleSigterm); + processRef.removeListener('SIGINT', handleSigint); + processRef.stdin.removeListener('end', handleStdinEnd); + processRef.stdin.removeListener('close', handleStdinClose); + processRef.stdout?.removeListener('error', handleStdoutError); + processRef.removeListener('uncaughtException', handleUncaughtException); + processRef.removeListener('unhandledRejection', handleUnhandledRejection); + }, + + markPhase(phase: McpStartupPhase): void { + state.phase = phase; + }, + + registerServer(server: McpServer): void { + state.server = server; + }, + + isShutdownRequested(): boolean { + return state.shutdownRequested; + }, + + async getSnapshot(): Promise { + return buildMcpLifecycleSnapshot({ + phase: state.phase, + shutdownReason: state.shutdownReason, + startedAtMs: state.startedAtMs, + commandExecutor: options.commandExecutor, + }); + }, + + async shutdown(reason: McpShutdownReason, error?: unknown): Promise { + if (state.shutdownPromise) { + return state.shutdownPromise; + } + + state.shutdownRequested = true; + state.shutdownReason = reason; + const phaseAtShutdown = state.phase; + state.phase = 'shutting-down'; + + state.shutdownPromise = (async (): Promise => { + const snapshot = await buildMcpLifecycleSnapshot({ + phase: phaseAtShutdown, + shutdownReason: state.shutdownReason, + startedAtMs: state.startedAtMs, + commandExecutor: options.commandExecutor, + }); + await options.onShutdown({ + reason, + error, + snapshot, + server: state.server, + }); + state.phase = 'stopped'; + })(); + + return state.shutdownPromise; + }, + }; + + return coordinator; +} diff --git a/src/server/start-mcp-server.ts b/src/server/start-mcp-server.ts index 88ebf67f..9bd15594 100644 --- a/src/server/start-mcp-server.ts +++ b/src/server/start-mcp-server.ts @@ -13,6 +13,8 @@ import { enrichSentryContext, flushAndCloseSentry, initSentry, + recordMcpLifecycleAnomalyMetric, + recordMcpLifecycleMetric, setSentryRuntimeContext, } from '../utils/sentry.ts'; import { getDefaultDebuggerManager } from '../utils/debugger/index.ts'; @@ -24,6 +26,8 @@ import { createStartupProfiler, getStartupProfileNowMs } from './startup-profile import { getConfig } from '../utils/config-store.ts'; import { getRegisteredWorkflows } from '../utils/tool-registry.ts'; import { hydrateSentryDisabledEnvFromProjectConfig } from '../utils/sentry-config.ts'; +import { stopXcodeStateWatcher } from '../utils/xcode-state-watcher.ts'; +import { createMcpLifecycleCoordinator } from './mcp-lifecycle.ts'; /** * Start the MCP server. @@ -31,6 +35,110 @@ import { hydrateSentryDisabledEnvFromProjectConfig } from '../utils/sentry-confi * sets up signal handlers for graceful shutdown, and starts the server. */ export async function startMcpServer(): Promise { + const lifecycle = createMcpLifecycleCoordinator({ + onShutdown: async ({ reason, error, snapshot, server }) => { + const isCrash = reason === 'uncaught-exception' || reason === 'unhandled-rejection'; + const event = isCrash ? 'crash' : 'shutdown'; + const exitCode = + reason === 'stdin-end' || + reason === 'stdin-close' || + reason === 'stdout-error' || + reason === 'sigint' || + reason === 'sigterm' + ? 0 + : 1; + + if (reason === 'stdin-end') { + log('info', 'MCP stdin ended; shutting down MCP server'); + } else if (reason === 'stdin-close') { + log('info', 'MCP stdin closed; shutting down MCP server'); + } else if (reason === 'stdout-error') { + log('info', 'MCP stdout pipe broke; shutting down MCP server'); + } else { + log('info', `MCP shutdown requested: ${reason}`); + } + + log( + 'info', + `[mcp-lifecycle] ${event} ${JSON.stringify(snapshot)}`, + isCrash || snapshot.anomalies.length > 0 ? { sentry: true } : undefined, + ); + + recordMcpLifecycleMetric({ + event, + phase: snapshot.phase, + reason, + uptimeMs: snapshot.uptimeMs, + rssBytes: snapshot.rssBytes, + matchingMcpProcessCount: snapshot.matchingMcpProcessCount, + activeOperationCount: snapshot.activeOperationCount, + watcherRunning: snapshot.watcherRunning, + }); + + for (const anomaly of snapshot.anomalies) { + recordMcpLifecycleAnomalyMetric({ + kind: anomaly, + phase: snapshot.phase, + reason, + }); + } + + if (snapshot.anomalies.length > 0) { + log('warn', `[mcp-lifecycle] observed anomalies: ${snapshot.anomalies.join(', ')}`, { + sentry: true, + }); + } + + if (error !== undefined) { + log('error', `MCP shutdown due to ${reason}: ${String(error)}`, { sentry: true }); + } + + if (reason === 'stdin-end' || reason === 'stdin-close') { + await new Promise((resolve) => setTimeout(resolve, 250)); + } + + let cleanupExitCode = exitCode; + + try { + await stopXcodeStateWatcher(); + } catch (shutdownError) { + cleanupExitCode = 1; + log('error', `Failed to stop Xcode watcher: ${String(shutdownError)}`, { sentry: true }); + } + + try { + await shutdownXcodeToolsBridge(); + } catch (shutdownError) { + cleanupExitCode = 1; + log('error', `Failed to shutdown Xcode tools bridge: ${String(shutdownError)}`, { + sentry: true, + }); + } + + try { + await getDefaultDebuggerManager().disposeAll(); + } catch (shutdownError) { + cleanupExitCode = 1; + log('error', `Failed to dispose debugger sessions: ${String(shutdownError)}`, { + sentry: true, + }); + } + + try { + await server?.close(); + } catch (shutdownError) { + cleanupExitCode = 1; + log('error', `Failed to close MCP server: ${String(shutdownError)}`, { sentry: true }); + } + + lifecycle.detachProcessHandlers(); + await flushAndCloseSentry(2000); + process.exit(cleanupExitCode); + }, + }); + + lifecycle.attachProcessHandlers(); + try { const profiler = createStartupProfiler('start-mcp-server'); @@ -38,21 +146,27 @@ export async function startMcpServer(): Promise { // Clients can override via logging/setLevel MCP request setLogLevel('info'); + lifecycle.markPhase('hydrating-sentry-config'); await hydrateSentryDisabledEnvFromProjectConfig(); let stageStartMs = getStartupProfileNowMs(); + lifecycle.markPhase('initializing-sentry'); initSentry({ mode: 'mcp' }); profiler.mark('initSentry', stageStartMs); stageStartMs = getStartupProfileNowMs(); + lifecycle.markPhase('creating-server'); const server = createServer(); + lifecycle.registerServer(server); profiler.mark('createServer', stageStartMs); stageStartMs = getStartupProfileNowMs(); + lifecycle.markPhase('bootstrapping-server'); const bootstrap = await bootstrapServer(server); profiler.mark('bootstrapServer', stageStartMs); stageStartMs = getStartupProfileNowMs(); + lifecycle.markPhase('starting-stdio-transport'); await startServer(server); profiler.mark('startServer', stageStartMs); @@ -69,84 +183,55 @@ export async function startMcpServer(): Promise { xcodeIdeWorkflowEnabled: enabledWorkflows.includes('xcode-ide'), }); - void bootstrap.runDeferredInitialization().catch((error) => { + lifecycle.markPhase('running'); + const startupSnapshot = await lifecycle.getSnapshot(); + log('info', `[mcp-lifecycle] start ${JSON.stringify(startupSnapshot)}`); + recordMcpLifecycleMetric({ + event: 'start', + phase: startupSnapshot.phase, + uptimeMs: startupSnapshot.uptimeMs, + rssBytes: startupSnapshot.rssBytes, + matchingMcpProcessCount: startupSnapshot.matchingMcpProcessCount, + activeOperationCount: startupSnapshot.activeOperationCount, + watcherRunning: startupSnapshot.watcherRunning, + }); + for (const anomaly of startupSnapshot.anomalies) { + recordMcpLifecycleAnomalyMetric({ + kind: anomaly, + phase: startupSnapshot.phase, + }); + } + if (startupSnapshot.anomalies.length > 0) { log( 'warn', - `Deferred bootstrap initialization failed: ${error instanceof Error ? error.message : String(error)}`, + `[mcp-lifecycle] startup anomalies observed: ${startupSnapshot.anomalies.join(', ')}`, + { sentry: true }, ); - }); + } + + lifecycle.markPhase('deferred-initialization'); + void bootstrap + .runDeferredInitialization({ + isShutdownRequested: () => lifecycle.isShutdownRequested(), + }) + .catch((error) => { + log( + 'warn', + `Deferred bootstrap initialization failed: ${error instanceof Error ? error.message : String(error)}`, + ); + }) + .finally(() => { + if (!lifecycle.isShutdownRequested()) { + lifecycle.markPhase('running'); + } + }); setImmediate(() => { enrichSentryContext(); }); - type ShutdownReason = NodeJS.Signals | 'stdin-end' | 'stdin-close'; - - let shuttingDown = false; - const shutdown = async (reason: ShutdownReason): Promise => { - if (shuttingDown) return; - shuttingDown = true; - - if (reason === 'stdin-end') { - log('info', 'MCP stdin ended; shutting down MCP server'); - } else if (reason === 'stdin-close') { - log('info', 'MCP stdin closed; shutting down MCP server'); - } else { - log('info', `Received ${reason}; shutting down MCP server`); - } - - let exitCode = 0; - - if (reason === 'stdin-end' || reason === 'stdin-close') { - // Allow span completion/export to settle after the client closes stdin. - await new Promise((resolve) => setTimeout(resolve, 250)); - } - - try { - await shutdownXcodeToolsBridge(); - } catch (error) { - exitCode = 1; - log('error', `Failed to shutdown Xcode tools bridge: ${String(error)}`, { sentry: true }); - } - - try { - await getDefaultDebuggerManager().disposeAll(); - } catch (error) { - exitCode = 1; - log('error', `Failed to dispose debugger sessions: ${String(error)}`, { sentry: true }); - } - - try { - await server.close(); - } catch (error) { - exitCode = 1; - log('error', `Failed to close MCP server: ${String(error)}`, { sentry: true }); - } - - await flushAndCloseSentry(2000); - process.exit(exitCode); - }; - - process.once('SIGTERM', () => { - void shutdown('SIGTERM'); - }); - - process.once('SIGINT', () => { - void shutdown('SIGINT'); - }); - - process.stdin.once('end', () => { - void shutdown('stdin-end'); - }); - - process.stdin.once('close', () => { - void shutdown('stdin-close'); - }); - log('info', `XcodeBuildMCP server (version ${version}) started successfully`); } catch (error) { - log('error', `Fatal error in startMcpServer(): ${String(error)}`, { sentry: true }); console.error('Fatal error in startMcpServer():', error); - await flushAndCloseSentry(2000); - process.exit(1); + await lifecycle.shutdown('startup-failure', error); } } diff --git a/src/utils/sentry.ts b/src/utils/sentry.ts index d8783675..77bf636e 100644 --- a/src/utils/sentry.ts +++ b/src/utils/sentry.ts @@ -16,6 +16,7 @@ export type SentryToolRuntime = 'cli' | 'daemon' | 'mcp'; export type SentryToolTransport = 'direct' | 'daemon' | 'xcode-ide-daemon'; export type SentryToolInvocationOutcome = 'completed' | 'infra_error'; export type SentryDaemonLifecycleEvent = 'start' | 'shutdown' | 'crash'; +export type SentryMcpLifecycleEvent = 'start' | 'shutdown' | 'crash'; export interface SentryRuntimeContext { mode: SentryRuntimeMode; @@ -380,6 +381,7 @@ interface InternalErrorMetric { } type DaemonGaugeMetricName = 'inflight_requests' | 'active_sessions' | 'idle_timeout_ms'; + function sanitizeTagValue(value: string): string { const trimmed = value.trim().toLowerCase(); if (!trimmed) { @@ -484,3 +486,77 @@ export function recordDaemonGaugeMetric(metricName: DaemonGaugeMetricName, value // Metrics are best effort and must never affect runtime behavior. } } + +interface McpLifecycleMetric { + event: SentryMcpLifecycleEvent; + phase: string; + reason?: string; + uptimeMs: number; + rssBytes: number; + matchingMcpProcessCount?: number | null; + activeOperationCount: number; + watcherRunning: boolean; +} + +interface McpLifecycleAnomalyMetric { + kind: string; + phase: string; + reason?: string; +} + +export function recordMcpLifecycleMetric(metric: McpLifecycleMetric): void { + if (!shouldEmitMetrics()) { + return; + } + + const attributes = { + runtime: 'mcp', + event: sanitizeTagValue(metric.event), + phase: sanitizeTagValue(metric.phase), + ...(metric.reason ? { reason: sanitizeTagValue(metric.reason) } : {}), + watcher_running: String(metric.watcherRunning), + has_active_operations: String(metric.activeOperationCount > 0), + }; + + try { + Sentry.metrics.count('xcodebuildmcp.mcp.lifecycle.count', 1, { attributes }); + Sentry.metrics.distribution( + 'xcodebuildmcp.mcp.lifecycle.uptime_ms', + Math.max(0, metric.uptimeMs), + { attributes }, + ); + Sentry.metrics.distribution( + 'xcodebuildmcp.mcp.lifecycle.rss_bytes', + Math.max(0, metric.rssBytes), + { attributes }, + ); + if (metric.matchingMcpProcessCount != null) { + Sentry.metrics.distribution( + 'xcodebuildmcp.mcp.lifecycle.process_count', + Math.max(0, metric.matchingMcpProcessCount), + { attributes }, + ); + } + } catch { + // Metrics are best effort and must never affect runtime behavior. + } +} + +export function recordMcpLifecycleAnomalyMetric(metric: McpLifecycleAnomalyMetric): void { + if (!shouldEmitMetrics()) { + return; + } + + try { + Sentry.metrics.count('xcodebuildmcp.mcp.lifecycle.anomaly.count', 1, { + attributes: { + runtime: 'mcp', + kind: sanitizeTagValue(metric.kind), + phase: sanitizeTagValue(metric.phase), + ...(metric.reason ? { reason: sanitizeTagValue(metric.reason) } : {}), + }, + }); + } catch { + // Metrics are best effort and must never affect runtime behavior. + } +} diff --git a/src/utils/session-status.ts b/src/utils/session-status.ts index 55bd2ab4..d2fa4d9c 100644 --- a/src/utils/session-status.ts +++ b/src/utils/session-status.ts @@ -1,6 +1,10 @@ import { getDefaultDebuggerManager } from './debugger/index.ts'; import { listActiveSimulatorLogSessionIds } from './log-capture/index.ts'; import { activeDeviceLogSessions } from './log-capture/device-log-sessions.ts'; +import { getDaemonActivitySnapshot } from '../daemon/activity-registry.ts'; +import { activeProcesses } from '../mcp/tools/swift-package/active-processes.ts'; +import { listActiveVideoCaptureSessionIds } from './video_capture.ts'; +import { getWatchedPath, isWatcherRunning } from './xcode-state-watcher.ts'; export type SessionRuntimeStatusSnapshot = { logging: { @@ -11,14 +15,36 @@ export type SessionRuntimeStatusSnapshot = { currentSessionId: string | null; sessionIds: string[]; }; + watcher: { + running: boolean; + watchedPath: string | null; + }; + video: { + activeSessionIds: string[]; + }; + swiftPackage: { + activePids: number[]; + }; + activity: { + activeOperationCount: number; + byCategory: Record; + }; + process: { + pid: number; + uptimeMs: number; + rssBytes: number; + heapUsedBytes: number; + }; }; export function getSessionRuntimeStatusSnapshot(): SessionRuntimeStatusSnapshot { const debuggerManager = getDefaultDebuggerManager(); + const activitySnapshot = getDaemonActivitySnapshot(); const sessionIds = debuggerManager .listSessions() .map((session) => session.id) .sort(); + const memoryUsage = process.memoryUsage(); return { logging: { @@ -33,5 +59,22 @@ export function getSessionRuntimeStatusSnapshot(): SessionRuntimeStatusSnapshot currentSessionId: debuggerManager.getCurrentSessionId(), sessionIds, }, + watcher: { + running: isWatcherRunning(), + watchedPath: getWatchedPath(), + }, + video: { + activeSessionIds: listActiveVideoCaptureSessionIds(), + }, + swiftPackage: { + activePids: Array.from(activeProcesses.keys()).sort((left, right) => left - right), + }, + activity: activitySnapshot, + process: { + pid: process.pid, + uptimeMs: Math.max(0, Math.round(process.uptime() * 1000)), + rssBytes: memoryUsage.rss, + heapUsedBytes: memoryUsage.heapUsed, + }, }; } From db34445844530011220dfd52a0eed84281d30bec Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Sun, 15 Mar 2026 20:09:45 +0000 Subject: [PATCH 2/8] fix(mcp): Bound fast-exit server close on stdio disconnect When the MCP parent process exits abruptly with in-flight requests, shutdown can block indefinitely waiting for server.close(). This keeps npm exec wrapper processes alive and allows the child node process to climb in RSS. Add a transport-disconnect fast-exit path that detaches lifecycle handlers, races server.close() against a short timeout, and then exits immediately. This preserves normal shutdown behavior for other reasons and keeps Sentry enabled. Also add focused unit tests for the bounded close helper outcomes. Fixes #273 --- package-lock.json | 272 ++++++++++++------ package.json | 2 +- src/server/__tests__/start-mcp-server.test.ts | 39 +++ src/server/start-mcp-server.ts | 42 ++- 4 files changed, 269 insertions(+), 86 deletions(-) create mode 100644 src/server/__tests__/start-mcp-server.test.ts diff --git a/package-lock.json b/package-lock.json index 1d824189..3a7b336b 100644 --- a/package-lock.json +++ b/package-lock.json @@ -12,7 +12,7 @@ "@clack/prompts": "^1.0.1", "@modelcontextprotocol/sdk": "^1.25.1", "@sentry/cli": "^3.1.0", - "@sentry/node": "^10.38.0", + "@sentry/node": "^10.43.0", "bplist-parser": "^0.3.2", "chokidar": "^5.0.0", "uuid": "^11.1.0", @@ -63,23 +63,6 @@ "node": ">=6.0.0" } }, - "node_modules/@apm-js-collab/code-transformer": { - "version": "0.8.2", - "resolved": "https://registry.npmjs.org/@apm-js-collab/code-transformer/-/code-transformer-0.8.2.tgz", - "integrity": "sha512-YRjJjNq5KFSjDUoqu5pFUWrrsvGOxl6c3bu+uMFc9HNNptZ2rNU/TI2nLw4jnhQNtka972Ee2m3uqbvDQtPeCA==", - "license": "Apache-2.0" - }, - "node_modules/@apm-js-collab/tracing-hooks": { - "version": "0.3.1", - "resolved": "https://registry.npmjs.org/@apm-js-collab/tracing-hooks/-/tracing-hooks-0.3.1.tgz", - "integrity": "sha512-Vu1CbmPURlN5fTboVuKMoJjbO5qcq9fA5YXpskx3dXe/zTBvjODFoerw+69rVBlRLrJpwPqSDqEuJDEKIrTldw==", - "license": "Apache-2.0", - "dependencies": { - "@apm-js-collab/code-transformer": "^0.8.0", - "debug": "^4.4.1", - "module-details-from-path": "^1.0.4" - } - }, "node_modules/@babel/helper-string-parser": { "version": "7.27.1", "resolved": "https://registry.npmjs.org/@babel/helper-string-parser/-/helper-string-parser-7.27.1.tgz", @@ -789,6 +772,96 @@ "xmlbuilder": "^14.0.0" } }, + "node_modules/@fastify/otel": { + "version": "0.16.0", + "resolved": "https://registry.npmjs.org/@fastify/otel/-/otel-0.16.0.tgz", + "integrity": "sha512-2304BdM5Q/kUvQC9qJO1KZq3Zn1WWsw+WWkVmFEaj1UE2hEIiuFqrPeglQOwEtw/ftngisqfQ3v70TWMmwhhHA==", + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "MIT", + "dependencies": { + "@opentelemetry/core": "^2.0.0", + "@opentelemetry/instrumentation": "^0.208.0", + "@opentelemetry/semantic-conventions": "^1.28.0", + "minimatch": "^10.0.3" + }, + "peerDependencies": { + "@opentelemetry/api": "^1.9.0" + } + }, + "node_modules/@fastify/otel/node_modules/@opentelemetry/api-logs": { + "version": "0.208.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/api-logs/-/api-logs-0.208.0.tgz", + "integrity": "sha512-CjruKY9V6NMssL/T1kAFgzosF1v9o6oeN+aX5JB/C/xPNtmgIJqcXHG7fA82Ou1zCpWGl4lROQUKwUNE1pMCyg==", + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api": "^1.3.0" + }, + "engines": { + "node": ">=8.0.0" + } + }, + "node_modules/@fastify/otel/node_modules/@opentelemetry/instrumentation": { + "version": "0.208.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/instrumentation/-/instrumentation-0.208.0.tgz", + "integrity": "sha512-Eju0L4qWcQS+oXxi6pgh7zvE2byogAkcsVv0OjHF/97iOz1N/aKE6etSGowYkie+YA1uo6DNwdSxaaNnLvcRlA==", + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api-logs": "0.208.0", + "import-in-the-middle": "^2.0.0", + "require-in-the-middle": "^8.0.0" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + }, + "peerDependencies": { + "@opentelemetry/api": "^1.3.0" + } + }, + "node_modules/@fastify/otel/node_modules/balanced-match": { + "version": "4.0.4", + "resolved": "https://registry.npmjs.org/balanced-match/-/balanced-match-4.0.4.tgz", + "integrity": "sha512-BLrgEcRTwX2o6gGxGOCNyMvGSp35YofuYzw9h1IMTRmKqttAZZVU67bdb9Pr2vUHA8+j3i2tJfjO6C6+4myGTA==", + "license": "MIT", + "engines": { + "node": "18 || 20 || >=22" + } + }, + "node_modules/@fastify/otel/node_modules/brace-expansion": { + "version": "5.0.4", + "resolved": "https://registry.npmjs.org/brace-expansion/-/brace-expansion-5.0.4.tgz", + "integrity": "sha512-h+DEnpVvxmfVefa4jFbCf5HdH5YMDXRsmKflpf1pILZWRFlTbJpxeU55nJl4Smt5HQaGzg1o6RHFPJaOqnmBDg==", + "license": "MIT", + "dependencies": { + "balanced-match": "^4.0.2" + }, + "engines": { + "node": "18 || 20 || >=22" + } + }, + "node_modules/@fastify/otel/node_modules/minimatch": { + "version": "10.2.4", + "resolved": "https://registry.npmjs.org/minimatch/-/minimatch-10.2.4.tgz", + "integrity": "sha512-oRjTw/97aTBN0RHbYCdtF1MQfvusSIBQM0IZEgzl6426+8jSC0nF1a/GmnVLpfB9yyr6g6FTqWqiZVbxrtaCIg==", + "license": "BlueOak-1.0.0", + "dependencies": { + "brace-expansion": "^5.0.2" + }, + "engines": { + "node": "18 || 20 || >=22" + }, + "funding": { + "url": "https://github.com/sponsors/isaacs" + } + }, "node_modules/@hono/node-server": { "version": "1.19.10", "resolved": "https://registry.npmjs.org/@hono/node-server/-/node-server-1.19.10.tgz", @@ -1056,9 +1129,9 @@ } }, "node_modules/@opentelemetry/context-async-hooks": { - "version": "2.5.0", - "resolved": "https://registry.npmjs.org/@opentelemetry/context-async-hooks/-/context-async-hooks-2.5.0.tgz", - "integrity": "sha512-uOXpVX0ZjO7heSVjhheW2XEPrhQAWr2BScDPoZ9UDycl5iuHG+Usyc3AIfG6kZeC1GyLpMInpQ6X5+9n69yOFw==", + "version": "2.6.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/context-async-hooks/-/context-async-hooks-2.6.0.tgz", + "integrity": "sha512-L8UyDwqpTcbkIK5cgwDRDYDoEhQoj8wp8BwsO19w3LB1Z41yEQm2VJyNfAi9DrLP/YTqXqWpKHyZfR9/tFYo1Q==", "license": "Apache-2.0", "engines": { "node": "^18.19.0 || >=20.6.0" @@ -1476,12 +1549,12 @@ } }, "node_modules/@opentelemetry/resources": { - "version": "2.5.0", - "resolved": "https://registry.npmjs.org/@opentelemetry/resources/-/resources-2.5.0.tgz", - "integrity": "sha512-F8W52ApePshpoSrfsSk1H2yJn9aKjCrbpQF1M9Qii0GHzbfVeFUB+rc3X4aggyZD8x9Gu3Slua+s6krmq6Dt8g==", + "version": "2.6.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/resources/-/resources-2.6.0.tgz", + "integrity": "sha512-D4y/+OGe3JSuYUCBxtH5T9DSAWNcvCb/nQWIga8HNtXTVPQn59j0nTBAgaAXxUVBDl40mG3Tc76b46wPlZaiJQ==", "license": "Apache-2.0", "dependencies": { - "@opentelemetry/core": "2.5.0", + "@opentelemetry/core": "2.6.0", "@opentelemetry/semantic-conventions": "^1.29.0" }, "engines": { @@ -1491,14 +1564,29 @@ "@opentelemetry/api": ">=1.3.0 <1.10.0" } }, + "node_modules/@opentelemetry/resources/node_modules/@opentelemetry/core": { + "version": "2.6.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/core/-/core-2.6.0.tgz", + "integrity": "sha512-HLM1v2cbZ4TgYN6KEOj+Bbj8rAKriOdkF9Ed3tG25FoprSiQl7kYc+RRT6fUZGOvx0oMi5U67GoFdT+XUn8zEg==", + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/semantic-conventions": "^1.29.0" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.0.0 <1.10.0" + } + }, "node_modules/@opentelemetry/sdk-trace-base": { - "version": "2.5.0", - "resolved": "https://registry.npmjs.org/@opentelemetry/sdk-trace-base/-/sdk-trace-base-2.5.0.tgz", - "integrity": "sha512-VzRf8LzotASEyNDUxTdaJ9IRJ1/h692WyArDBInf5puLCjxbICD6XkHgpuudis56EndyS7LYFmtTMny6UABNdQ==", + "version": "2.6.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/sdk-trace-base/-/sdk-trace-base-2.6.0.tgz", + "integrity": "sha512-g/OZVkqlxllgFM7qMKqbPV9c1DUPhQ7d4n3pgZFcrnrNft9eJXZM2TNHTPYREJBrtNdRytYyvwjgL5geDKl3EQ==", "license": "Apache-2.0", "dependencies": { - "@opentelemetry/core": "2.5.0", - "@opentelemetry/resources": "2.5.0", + "@opentelemetry/core": "2.6.0", + "@opentelemetry/resources": "2.6.0", "@opentelemetry/semantic-conventions": "^1.29.0" }, "engines": { @@ -1508,6 +1596,21 @@ "@opentelemetry/api": ">=1.3.0 <1.10.0" } }, + "node_modules/@opentelemetry/sdk-trace-base/node_modules/@opentelemetry/core": { + "version": "2.6.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/core/-/core-2.6.0.tgz", + "integrity": "sha512-HLM1v2cbZ4TgYN6KEOj+Bbj8rAKriOdkF9Ed3tG25FoprSiQl7kYc+RRT6fUZGOvx0oMi5U67GoFdT+XUn8zEg==", + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/semantic-conventions": "^1.29.0" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.0.0 <1.10.0" + } + }, "node_modules/@opentelemetry/semantic-conventions": { "version": "1.39.0", "resolved": "https://registry.npmjs.org/@opentelemetry/semantic-conventions/-/semantic-conventions-1.39.0.tgz", @@ -2128,23 +2231,24 @@ } }, "node_modules/@sentry/core": { - "version": "10.38.0", - "resolved": "https://registry.npmjs.org/@sentry/core/-/core-10.38.0.tgz", - "integrity": "sha512-1pubWDZE5y5HZEPMAZERP4fVl2NH3Ihp1A+vMoVkb3Qc66Diqj1WierAnStlZP7tCx0TBa0dK85GTW/ZFYyB9g==", + "version": "10.43.0", + "resolved": "https://registry.npmjs.org/@sentry/core/-/core-10.43.0.tgz", + "integrity": "sha512-l0SszQAPiQGWl/ferw8GP3ALyHXiGiRKJaOvNmhGO+PrTQyZTZ6OYyPnGijAFRg58dE1V3RCH/zw5d2xSUIiNg==", "license": "MIT", "engines": { "node": ">=18" } }, "node_modules/@sentry/node": { - "version": "10.38.0", - "resolved": "https://registry.npmjs.org/@sentry/node/-/node-10.38.0.tgz", - "integrity": "sha512-wriyDtWDAoatn8EhOj0U4PJR1WufiijTsCGALqakOHbFiadtBJANLe6aSkXoXT4tegw59cz1wY4NlzHjYksaPw==", + "version": "10.43.0", + "resolved": "https://registry.npmjs.org/@sentry/node/-/node-10.43.0.tgz", + "integrity": "sha512-oNwXcuZUc4uTTr0WbHZBBIKsKwAKvNMTgbXwxfB37CfzV18wbTirbQABZ/Ir3WNxSgi6ZcnC6UE013jF5XWPqw==", "license": "MIT", "dependencies": { + "@fastify/otel": "0.16.0", "@opentelemetry/api": "^1.9.0", - "@opentelemetry/context-async-hooks": "^2.5.0", - "@opentelemetry/core": "^2.5.0", + "@opentelemetry/context-async-hooks": "^2.5.1", + "@opentelemetry/core": "^2.5.1", "@opentelemetry/instrumentation": "^0.211.0", "@opentelemetry/instrumentation-amqplib": "0.58.0", "@opentelemetry/instrumentation-connect": "0.54.0", @@ -2168,29 +2272,27 @@ "@opentelemetry/instrumentation-redis": "0.59.0", "@opentelemetry/instrumentation-tedious": "0.30.0", "@opentelemetry/instrumentation-undici": "0.21.0", - "@opentelemetry/resources": "^2.5.0", - "@opentelemetry/sdk-trace-base": "^2.5.0", + "@opentelemetry/resources": "^2.5.1", + "@opentelemetry/sdk-trace-base": "^2.5.1", "@opentelemetry/semantic-conventions": "^1.39.0", "@prisma/instrumentation": "7.2.0", - "@sentry/core": "10.38.0", - "@sentry/node-core": "10.38.0", - "@sentry/opentelemetry": "10.38.0", - "import-in-the-middle": "^2.0.6", - "minimatch": "^9.0.0" + "@sentry/core": "10.43.0", + "@sentry/node-core": "10.43.0", + "@sentry/opentelemetry": "10.43.0", + "import-in-the-middle": "^2.0.6" }, "engines": { "node": ">=18" } }, "node_modules/@sentry/node-core": { - "version": "10.38.0", - "resolved": "https://registry.npmjs.org/@sentry/node-core/-/node-core-10.38.0.tgz", - "integrity": "sha512-ErXtpedrY1HghgwM6AliilZPcUCoNNP1NThdO4YpeMq04wMX9/GMmFCu46TnCcg6b7IFIOSr2S4yD086PxLlHQ==", + "version": "10.43.0", + "resolved": "https://registry.npmjs.org/@sentry/node-core/-/node-core-10.43.0.tgz", + "integrity": "sha512-w2H3NSkNMoYOS7o7mR55BM7+xL++dPxMSv1/XDfsra9FYHGppO+Mxk667Ee5k+uDi+wNIioICIh+5XOvZh4+HQ==", "license": "MIT", "dependencies": { - "@apm-js-collab/tracing-hooks": "^0.3.1", - "@sentry/core": "10.38.0", - "@sentry/opentelemetry": "10.38.0", + "@sentry/core": "10.43.0", + "@sentry/opentelemetry": "10.43.0", "import-in-the-middle": "^2.0.6" }, "engines": { @@ -2204,51 +2306,53 @@ "@opentelemetry/resources": "^1.30.1 || ^2.1.0", "@opentelemetry/sdk-trace-base": "^1.30.1 || ^2.1.0", "@opentelemetry/semantic-conventions": "^1.39.0" - } - }, - "node_modules/@sentry/node/node_modules/balanced-match": { - "version": "4.0.4", - "resolved": "https://registry.npmjs.org/balanced-match/-/balanced-match-4.0.4.tgz", - "integrity": "sha512-BLrgEcRTwX2o6gGxGOCNyMvGSp35YofuYzw9h1IMTRmKqttAZZVU67bdb9Pr2vUHA8+j3i2tJfjO6C6+4myGTA==", - "license": "MIT", - "engines": { - "node": "18 || 20 || >=22" - } - }, - "node_modules/@sentry/node/node_modules/brace-expansion": { - "version": "5.0.3", - "resolved": "https://registry.npmjs.org/brace-expansion/-/brace-expansion-5.0.3.tgz", - "integrity": "sha512-fy6KJm2RawA5RcHkLa1z/ScpBeA762UF9KmZQxwIbDtRJrgLzM10depAiEQ+CXYcoiqW1/m96OAAoke2nE9EeA==", - "license": "MIT", - "dependencies": { - "balanced-match": "^4.0.2" }, - "engines": { - "node": "18 || 20 || >=22" + "peerDependenciesMeta": { + "@opentelemetry/api": { + "optional": true + }, + "@opentelemetry/context-async-hooks": { + "optional": true + }, + "@opentelemetry/core": { + "optional": true + }, + "@opentelemetry/instrumentation": { + "optional": true + }, + "@opentelemetry/resources": { + "optional": true + }, + "@opentelemetry/sdk-trace-base": { + "optional": true + }, + "@opentelemetry/semantic-conventions": { + "optional": true + } } }, - "node_modules/@sentry/node/node_modules/minimatch": { - "version": "9.0.7", - "resolved": "https://registry.npmjs.org/minimatch/-/minimatch-9.0.7.tgz", - "integrity": "sha512-MOwgjc8tfrpn5QQEvjijjmDVtMw2oL88ugTevzxQnzRLm6l3fVEF2gzU0kYeYYKD8C66+IdGX6peJ4MyUlUnPg==", - "license": "ISC", + "node_modules/@sentry/node/node_modules/@opentelemetry/core": { + "version": "2.6.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/core/-/core-2.6.0.tgz", + "integrity": "sha512-HLM1v2cbZ4TgYN6KEOj+Bbj8rAKriOdkF9Ed3tG25FoprSiQl7kYc+RRT6fUZGOvx0oMi5U67GoFdT+XUn8zEg==", + "license": "Apache-2.0", "dependencies": { - "brace-expansion": "^5.0.2" + "@opentelemetry/semantic-conventions": "^1.29.0" }, "engines": { - "node": ">=16 || 14 >=14.17" + "node": "^18.19.0 || >=20.6.0" }, - "funding": { - "url": "https://github.com/sponsors/isaacs" + "peerDependencies": { + "@opentelemetry/api": ">=1.0.0 <1.10.0" } }, "node_modules/@sentry/opentelemetry": { - "version": "10.38.0", - "resolved": "https://registry.npmjs.org/@sentry/opentelemetry/-/opentelemetry-10.38.0.tgz", - "integrity": "sha512-YPVhWfYmC7nD3EJqEHGtjp4fp5LwtAbE5rt9egQ4hqJlYFvr8YEz9sdoqSZxO0cZzgs2v97HFl/nmWAXe52G2Q==", + "version": "10.43.0", + "resolved": "https://registry.npmjs.org/@sentry/opentelemetry/-/opentelemetry-10.43.0.tgz", + "integrity": "sha512-+fIcnnLdvBHdq4nKq23t9v/B9D4L97fPWEDksXbpGs11o6BsqY4Tlzmce6cP95iiQhPckCEag3FthSND+BYtYQ==", "license": "MIT", "dependencies": { - "@sentry/core": "10.38.0" + "@sentry/core": "10.43.0" }, "engines": { "node": ">=18" diff --git a/package.json b/package.json index b4742254..f904319c 100644 --- a/package.json +++ b/package.json @@ -76,7 +76,7 @@ "@clack/prompts": "^1.0.1", "@modelcontextprotocol/sdk": "^1.25.1", "@sentry/cli": "^3.1.0", - "@sentry/node": "^10.38.0", + "@sentry/node": "^10.43.0", "bplist-parser": "^0.3.2", "chokidar": "^5.0.0", "uuid": "^11.1.0", diff --git a/src/server/__tests__/start-mcp-server.test.ts b/src/server/__tests__/start-mcp-server.test.ts new file mode 100644 index 00000000..789a6a12 --- /dev/null +++ b/src/server/__tests__/start-mcp-server.test.ts @@ -0,0 +1,39 @@ +import { afterEach, describe, expect, it, vi } from 'vitest'; +import { __closeServerForFastExitForTests } from '../start-mcp-server.ts'; + +describe('fast-exit server close', () => { + afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + it('returns skipped when server is not available', async () => { + await expect(__closeServerForFastExitForTests(undefined)).resolves.toBe('skipped'); + }); + + it('returns closed when server close resolves quickly', async () => { + const close = vi.fn(async () => undefined); + await expect(__closeServerForFastExitForTests({ close }, 50)).resolves.toBe('closed'); + expect(close).toHaveBeenCalledTimes(1); + }); + + it('returns rejected when server close throws', async () => { + const close = vi.fn(async () => { + throw new Error('close failed'); + }); + + await expect(__closeServerForFastExitForTests({ close }, 50)).resolves.toBe('rejected'); + expect(close).toHaveBeenCalledTimes(1); + }); + + it('times out when server close never settles', async () => { + vi.useFakeTimers(); + const close = vi.fn(() => new Promise(() => undefined)); + + const outcomePromise = __closeServerForFastExitForTests({ close }, 50); + await vi.advanceTimersByTimeAsync(50); + + await expect(outcomePromise).resolves.toBe('timed_out'); + expect(close).toHaveBeenCalledTimes(1); + }); +}); diff --git a/src/server/start-mcp-server.ts b/src/server/start-mcp-server.ts index 9bd15594..a17646b1 100644 --- a/src/server/start-mcp-server.ts +++ b/src/server/start-mcp-server.ts @@ -20,6 +20,7 @@ import { import { getDefaultDebuggerManager } from '../utils/debugger/index.ts'; import { version } from '../version.ts'; import process from 'node:process'; +import type { McpServer } from '@modelcontextprotocol/sdk/server/mcp.js'; import { bootstrapServer } from './bootstrap.ts'; import { shutdownXcodeToolsBridge } from '../integrations/xcode-tools-bridge/index.ts'; import { createStartupProfiler, getStartupProfileNowMs } from './startup-profiler.ts'; @@ -29,6 +30,38 @@ import { hydrateSentryDisabledEnvFromProjectConfig } from '../utils/sentry-confi import { stopXcodeStateWatcher } from '../utils/xcode-state-watcher.ts'; import { createMcpLifecycleCoordinator } from './mcp-lifecycle.ts'; +const FAST_EXIT_SERVER_CLOSE_TIMEOUT_MS = 100; + +interface ClosableMcpServer { + close(): Promise; +} + +type FastExitCloseOutcome = 'skipped' | 'closed' | 'rejected' | 'timed_out'; + +function isTransportDisconnectReason(reason: string): boolean { + return reason === 'stdin-end' || reason === 'stdin-close' || reason === 'stdout-error'; +} + +export async function __closeServerForFastExitForTests( + server: ClosableMcpServer | null | undefined, + timeoutMs = FAST_EXIT_SERVER_CLOSE_TIMEOUT_MS, +): Promise { + if (!server) { + return 'skipped'; + } + + const closePromise = server + .close() + .then(() => 'closed') + .catch(() => 'rejected'); + + const timeoutPromise = new Promise((resolve) => { + setTimeout(() => resolve('timed_out'), timeoutMs); + }); + + return Promise.race([closePromise, timeoutPromise]); +} + /** * Start the MCP server. * This function initializes Sentry, creates and bootstraps the server, @@ -37,6 +70,7 @@ import { createMcpLifecycleCoordinator } from './mcp-lifecycle.ts'; export async function startMcpServer(): Promise { const lifecycle = createMcpLifecycleCoordinator({ onShutdown: async ({ reason, error, snapshot, server }) => { + const closeableServer: Pick | null = server; const isCrash = reason === 'uncaught-exception' || reason === 'unhandled-rejection'; const event = isCrash ? 'crash' : 'shutdown'; const exitCode = @@ -64,6 +98,12 @@ export async function startMcpServer(): Promise { isCrash || snapshot.anomalies.length > 0 ? { sentry: true } : undefined, ); + if (isTransportDisconnectReason(reason)) { + lifecycle.detachProcessHandlers(); + await __closeServerForFastExitForTests(closeableServer); + process.exit(exitCode); + } + recordMcpLifecycleMetric({ event, phase: snapshot.phase, @@ -125,7 +165,7 @@ export async function startMcpServer(): Promise { } try { - await server?.close(); + await closeableServer?.close(); } catch (shutdownError) { cleanupExitCode = 1; log('error', `Failed to close MCP server: ${String(shutdownError)}`, { sentry: true }); From 7756e9e30416b98698889762b048c5adfc9bcb90 Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Sun, 15 Mar 2026 20:56:49 +0000 Subject: [PATCH 3/8] build(deps): Upgrade MCP SDK to 1.27.1 Update @modelcontextprotocol/sdk from ^1.25.1 to ^1.27.1 so local and harness testing run on the latest SDK behavior. Add /repros to .gitignore to keep lifecycle repro artifacts out of source control during repeated leak investigations. Refs #273 Co-Authored-By: Codex --- .gitignore | 1 + package-lock.json | 8 ++++---- package.json | 2 +- 3 files changed, 6 insertions(+), 5 deletions(-) diff --git a/.gitignore b/.gitignore index b1bb9f21..39bb0601 100644 --- a/.gitignore +++ b/.gitignore @@ -111,3 +111,4 @@ bundled/ DerivedData .derivedData /.pr-learning +/repros diff --git a/package-lock.json b/package-lock.json index 3a7b336b..ca7831d6 100644 --- a/package-lock.json +++ b/package-lock.json @@ -10,7 +10,7 @@ "license": "MIT", "dependencies": { "@clack/prompts": "^1.0.1", - "@modelcontextprotocol/sdk": "^1.25.1", + "@modelcontextprotocol/sdk": "^1.27.1", "@sentry/cli": "^3.1.0", "@sentry/node": "^10.43.0", "bplist-parser": "^0.3.2", @@ -1008,9 +1008,9 @@ } }, "node_modules/@modelcontextprotocol/sdk": { - "version": "1.26.0", - "resolved": "https://registry.npmjs.org/@modelcontextprotocol/sdk/-/sdk-1.26.0.tgz", - "integrity": "sha512-Y5RmPncpiDtTXDbLKswIJzTqu2hyBKxTNsgKqKclDbhIgg1wgtf1fRuvxgTnRfcnxtvvgbIEcqUOzZrJ6iSReg==", + "version": "1.27.1", + "resolved": "https://registry.npmjs.org/@modelcontextprotocol/sdk/-/sdk-1.27.1.tgz", + "integrity": "sha512-sr6GbP+4edBwFndLbM60gf07z0FQ79gaExpnsjMGePXqFcSSb7t6iscpjk9DhFhwd+mTEQrzNafGP8/iGGFYaA==", "license": "MIT", "dependencies": { "@hono/node-server": "^1.19.9", diff --git a/package.json b/package.json index f904319c..3e1910ef 100644 --- a/package.json +++ b/package.json @@ -74,7 +74,7 @@ }, "dependencies": { "@clack/prompts": "^1.0.1", - "@modelcontextprotocol/sdk": "^1.25.1", + "@modelcontextprotocol/sdk": "^1.27.1", "@sentry/cli": "^3.1.0", "@sentry/node": "^10.43.0", "bplist-parser": "^0.3.2", From 28bd7c4394f9b2c0fe6c7eb74c621793e9bbb9bf Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Sun, 15 Mar 2026 20:57:40 +0000 Subject: [PATCH 4/8] Update mcp.json --- .vscode/mcp.json | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/.vscode/mcp.json b/.vscode/mcp.json index ac5ac9c3..8236aa3d 100644 --- a/.vscode/mcp.json +++ b/.vscode/mcp.json @@ -1,11 +1,12 @@ -{ +{ "servers": { "XcodeBuildMCP": { "type": "stdio", "command": "npx", "args": [ "-y", - "xcodebuildmcp@latest" + "xcodebuildmcp@latest", + "mcp" ], "env": { "XCODEBUILDMCP_DEBUG": "true", From 3bfa481a52711501c154eabb924ec7a9d9d97d17 Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Mon, 16 Mar 2026 14:25:17 +0000 Subject: [PATCH 5/8] fix(server): Redesign MCP shutdown with bounded Sentry flush Move MCP shutdown orchestration into a dedicated bounded runner and stop using Sentry.close in MCP shutdown paths. Suppress stdio immediately on transport disconnect, capture one shutdown summary event, seal further capture, then perform bounded Sentry.flush before explicit exit. Add shared bulk cleanup helpers for tracked runtime resources and wire shutdown through those helpers. This keeps shutdown deterministic under parent/disconnect teardown while preserving high-value shutdown telemetry. Co-Authored-By: OpenAI Codex --- package.json | 1 + scripts/repro-mcp-lifecycle-leak.ts | 148 ++++++- src/mcp/tools/logging/stop_device_log_cap.ts | 212 ++------- .../__tests__/swift_package_stop.test.ts | 405 +++--------------- .../tools/swift-package/active-processes.ts | 115 ++++- .../tools/swift-package/swift_package_stop.ts | 59 +-- src/server/__tests__/mcp-lifecycle.test.ts | 39 ++ src/server/__tests__/mcp-shutdown.test.ts | 104 +++++ src/server/__tests__/start-mcp-server.test.ts | 10 +- src/server/mcp-lifecycle.ts | 28 ++ src/server/mcp-shutdown.ts | 200 +++++++++ src/server/start-mcp-server.ts | 146 ++----- src/utils/__tests__/logger.test.ts | 11 +- src/utils/__tests__/shutdown-state.test.ts | 27 ++ src/utils/debugger/debugger-manager.ts | 31 +- src/utils/log-capture/device-log-sessions.ts | 118 +++++ src/utils/log-capture/index.ts | 9 +- src/utils/log_capture.ts | 126 +++++- src/utils/logger.ts | 11 +- src/utils/sentry.ts | 78 +++- src/utils/shutdown-state.ts | 88 ++++ src/utils/video_capture.ts | 196 +++++---- 22 files changed, 1342 insertions(+), 820 deletions(-) create mode 100644 src/server/__tests__/mcp-shutdown.test.ts create mode 100644 src/server/mcp-shutdown.ts create mode 100644 src/utils/__tests__/shutdown-state.test.ts create mode 100644 src/utils/shutdown-state.ts diff --git a/package.json b/package.json index 3e1910ef..b5a8bcc3 100644 --- a/package.json +++ b/package.json @@ -22,6 +22,7 @@ "hooks:install": "node scripts/install-git-hooks.js", "generate:version": "npx tsx scripts/generate-version.ts", "repro:mcp-lifecycle-leak": "npm run build && npx tsx scripts/repro-mcp-lifecycle-leak.ts", + "repro:sentry-mcp-teardown": "cd repros/sentry-mcp-teardown && npm run harness", "bundle:axe": "scripts/bundle-axe.sh", "package:macos": "scripts/package-macos-portable.sh", "package:macos:universal": "scripts/package-macos-portable.sh --universal", diff --git a/scripts/repro-mcp-lifecycle-leak.ts b/scripts/repro-mcp-lifecycle-leak.ts index a7233b92..c06aa7ec 100644 --- a/scripts/repro-mcp-lifecycle-leak.ts +++ b/scripts/repro-mcp-lifecycle-leak.ts @@ -5,10 +5,12 @@ interface CliOptions { iterations: number; closeDelayMs: number; settleMs: number; + shutdownMode: 'graceful-stdin' | 'parent-hard-exit'; } interface PeerProcess { pid: number; + ppid: number; ageSeconds: number; rssKb: number; command: string; @@ -19,6 +21,7 @@ function parseArgs(argv: string[]): CliOptions { iterations: 20, closeDelayMs: 0, settleMs: 2000, + shutdownMode: 'parent-hard-exit', }; for (let index = 0; index < argv.length; index += 1) { @@ -34,6 +37,12 @@ function parseArgs(argv: string[]): CliOptions { } else if (arg === '--settle-ms' && value) { options.settleMs = Number(value); index += 1; + } else if (arg === '--shutdown-mode' && value) { + if (value !== 'graceful-stdin' && value !== 'parent-hard-exit') { + throw new Error('--shutdown-mode must be graceful-stdin or parent-hard-exit'); + } + options.shutdownMode = value; + index += 1; } } @@ -95,7 +104,7 @@ function parseElapsedSeconds(value: string): number | null { async function sampleMcpProcesses(): Promise { return new Promise((resolve, reject) => { - const child = spawn('ps', ['-axo', 'pid=,etime=,rss=,command='], { + const child = spawn('ps', ['-axo', 'pid=,ppid=,etime=,rss=,command='], { stdio: ['ignore', 'pipe', 'pipe'], }); let stdout = ''; @@ -119,16 +128,17 @@ async function sampleMcpProcesses(): Promise { .map((line) => line.trim()) .filter(Boolean) .map((line) => { - const match = line.match(/^(\d+)\s+(\S+)\s+(\d+)\s+(.+)$/); + const match = line.match(/^(\d+)\s+(\d+)\s+(\S+)\s+(\d+)\s+(.+)$/); if (!match) { return null; } - const ageSeconds = parseElapsedSeconds(match[2]); + const ageSeconds = parseElapsedSeconds(match[3]); return { pid: Number(match[1]), + ppid: Number(match[2]), ageSeconds, - rssKb: Number(match[3]), - command: match[4], + rssKb: Number(match[4]), + command: match[5], }; }) .filter((entry): entry is PeerProcess => { @@ -146,21 +156,33 @@ async function sampleMcpProcesses(): Promise { }); } -async function runIteration(closeDelayMs: number): Promise { +interface IterationResult { + helperExited: boolean; + childExited: boolean; + childPid: number | null; +} + +async function runGracefulStdinIteration(closeDelayMs: number): Promise { return new Promise((resolve) => { const child = spawn(process.execPath, ['build/cli.js', 'mcp'], { cwd: process.cwd(), stdio: ['pipe', 'ignore', 'ignore'], }); - let exited = false; + let settled = false; + const finish = (result: IterationResult): void => { + if (settled) { + return; + } + settled = true; + resolve(result); + }; + child.once('close', () => { - exited = true; - resolve(true); + finish({ helperExited: true, childExited: true, childPid: child.pid ?? null }); }); child.once('error', () => { - exited = true; - resolve(false); + finish({ helperExited: false, childExited: false, childPid: child.pid ?? null }); }); setTimeout(() => { @@ -169,25 +191,94 @@ async function runIteration(closeDelayMs: number): Promise { setTimeout( () => { - if (!exited) { - resolve(false); - } + finish({ helperExited: false, childExited: false, childPid: child.pid ?? null }); }, Math.max(1000, closeDelayMs + 1000), ); }); } +async function runParentHardExitIteration(closeDelayMs: number): Promise { + return new Promise((resolve) => { + const helper = spawn( + process.execPath, + [ + 'scripts/repro-mcp-parent-exit-helper.mjs', + process.execPath, + 'build/cli.js', + process.cwd(), + String(closeDelayMs), + ], + { + cwd: process.cwd(), + stdio: ['ignore', 'pipe', 'pipe'], + }, + ); + + let childPid: number | null = null; + let settled = false; + let stdout = ''; + + const finish = (result: IterationResult): void => { + if (settled) { + return; + } + settled = true; + resolve(result); + }; + + helper.stdout.on('data', (chunk: Buffer) => { + stdout += chunk.toString(); + const candidate = stdout.split('\n')[0]?.trim(); + if (candidate && /^\d+$/.test(candidate)) { + childPid = Number(candidate); + } + }); + + helper.once('error', () => { + finish({ helperExited: false, childExited: false, childPid }); + }); + + helper.once('close', (code) => { + finish({ helperExited: code === 0, childExited: false, childPid }); + }); + + setTimeout( + () => { + finish({ helperExited: false, childExited: false, childPid }); + }, + Math.max(1500, closeDelayMs + 1500), + ); + }); +} + +async function runIteration(options: CliOptions): Promise { + if (options.shutdownMode === 'parent-hard-exit') { + return runParentHardExitIteration(options.closeDelayMs); + } + + return runGracefulStdinIteration(options.closeDelayMs); +} + async function main(): Promise { const options = parseArgs(process.argv.slice(2)); const before = await sampleMcpProcesses(); const baselinePids = new Set(before.map((entry) => entry.pid)); - let exitedCount = 0; + let helperExitedCount = 0; + let childExitedCount = 0; + const spawnedChildPids = new Set(); + for (let index = 0; index < options.iterations; index += 1) { - const exited = await runIteration(options.closeDelayMs); - if (exited) { - exitedCount += 1; + const result = await runIteration(options); + if (result.helperExited) { + helperExitedCount += 1; + } + if (result.childExited) { + childExitedCount += 1; + } + if (result.childPid !== null) { + spawnedChildPids.add(result.childPid); } } @@ -195,28 +286,43 @@ async function main(): Promise { const after = await sampleMcpProcesses(); const lingering = after.filter((entry) => !baselinePids.has(entry.pid)); + const lingeringSpawned = lingering.filter((entry) => spawnedChildPids.has(entry.pid)); console.log( JSON.stringify( { + shutdownMode: options.shutdownMode, iterations: options.iterations, - exitedCount, + helperExitedCount, + childExitedCount, + spawnedChildPidCount: spawnedChildPids.size, baselineProcessCount: before.length, finalProcessCount: after.length, lingeringProcessCount: lingering.length, - lingering: lingering.map(({ pid, ageSeconds, rssKb, command }) => ({ + lingeringSpawnedProcessCount: lingeringSpawned.length, + lingeringSpawned: lingeringSpawned.map(({ pid, ppid, ageSeconds, rssKb, command }) => ({ + pid, + ppid, + ageSeconds, + rssKb, + command, + })), + lingering: lingering.map(({ pid, ppid, ageSeconds, rssKb, command }) => ({ pid, + ppid, ageSeconds, rssKb, command, })), + orphanedLingeringCount: lingering.filter((entry) => entry.ppid === 1).length, + maxLingeringRssKb: lingering.reduce((max, entry) => Math.max(max, entry.rssKb), 0), }, null, 2, ), ); - process.exit(lingering.length === 0 ? 0 : 1); + process.exit(lingeringSpawned.length === 0 ? 0 : 1); } void main().catch((error) => { diff --git a/src/mcp/tools/logging/stop_device_log_cap.ts b/src/mcp/tools/logging/stop_device_log_cap.ts index e3a2fdc9..dc96a825 100644 --- a/src/mcp/tools/logging/stop_device_log_cap.ts +++ b/src/mcp/tools/logging/stop_device_log_cap.ts @@ -8,85 +8,52 @@ import * as fs from 'fs'; import * as z from 'zod'; import { log } from '../../../utils/logging/index.ts'; import { - activeDeviceLogSessions, - type DeviceLogSession, + stopDeviceLogSessionById, + stopAllDeviceLogCaptures, } from '../../../utils/log-capture/device-log-sessions.ts'; import type { ToolResponse } from '../../../types/common.ts'; import { getDefaultFileSystemExecutor, getDefaultCommandExecutor } from '../../../utils/command.ts'; import type { FileSystemExecutor } from '../../../utils/FileSystemExecutor.ts'; import { createTypedTool } from '../../../utils/typed-tool-factory.ts'; -// Define schema as ZodObject const stopDeviceLogCapSchema = z.object({ logSessionId: z.string(), }); -// Use z.infer for type safety type StopDeviceLogCapParams = z.infer; -/** - * Business logic for stopping device log capture session - */ export async function stop_device_log_capLogic( params: StopDeviceLogCapParams, fileSystemExecutor: FileSystemExecutor, ): Promise { const { logSessionId } = params; - const session = activeDeviceLogSessions.get(logSessionId); - if (!session) { - log('warn', `Device log session not found: ${logSessionId}`); - return { - content: [ - { - type: 'text', - text: `Failed to stop device log capture session ${logSessionId}: Device log capture session not found: ${logSessionId}`, - }, - ], - isError: true, - }; - } - try { log('info', `Attempting to stop device log capture session: ${logSessionId}`); - const shouldSignalStop = - !(session.hasEnded ?? false) && - session.process.killed !== true && - session.process.exitCode == null; - - if (shouldSignalStop) { - session.process.kill?.('SIGTERM'); - } - - await waitForSessionToFinish(session); - - if (session.logStream) { - await ensureStreamClosed(session.logStream); - } - - const logFilePath = session.logFilePath; - session.releaseActivity?.(); - activeDeviceLogSessions.delete(logSessionId); + const result = await stopDeviceLogSessionById(logSessionId, fileSystemExecutor, { + timeoutMs: 1000, + readLogContent: true, + }); - // Check file access - if (!fileSystemExecutor.existsSync(logFilePath)) { - throw new Error(`Log file not found: ${logFilePath}`); + if (result.error) { + log('error', `Failed to stop device log capture session ${logSessionId}: ${result.error}`); + return { + content: [ + { + type: 'text', + text: `Failed to stop device log capture session ${logSessionId}: ${result.error}`, + }, + ], + isError: true, + }; } - const fileContent = await fileSystemExecutor.readFile(logFilePath, 'utf-8'); - log('info', `Successfully read device log content from ${logFilePath}`); - - log( - 'info', - `Device log capture session ${logSessionId} stopped. Log file retained at: ${logFilePath}`, - ); - return { content: [ { type: 'text', - text: `✅ Device log capture session stopped successfully\n\nSession ID: ${logSessionId}\n\n--- Captured Logs ---\n${fileContent}`, + text: `✅ Device log capture session stopped successfully\n\nSession ID: ${logSessionId}\n\n--- Captured Logs ---\n${result.logContent}`, }, ], }; @@ -105,98 +72,24 @@ export async function stop_device_log_capLogic( } } -type WriteStreamWithClosed = fs.WriteStream & { closed?: boolean }; - -async function ensureStreamClosed(stream: fs.WriteStream): Promise { - const typedStream = stream as WriteStreamWithClosed; - if (typedStream.destroyed || typedStream.closed) { - return; - } - - await new Promise((resolve) => { - const onClose = (): void => resolve(); - typedStream.once('close', onClose); - typedStream.end(); - }).catch(() => { - // Ignore cleanup errors – best-effort close - }); -} - -async function waitForSessionToFinish(session: DeviceLogSession): Promise { - if (session.hasEnded) { - return; - } - - if (session.process.exitCode != null) { - session.hasEnded = true; - return; - } - - if (typeof session.process.once === 'function') { - await new Promise((resolve) => { - const onClose = (): void => { - clearTimeout(timeout); - session.hasEnded = true; - resolve(); - }; - - const timeout = setTimeout(() => { - session.process.removeListener?.('close', onClose); - session.hasEnded = true; - resolve(); - }, 1000); - - session.process.once('close', onClose); - - if (session.hasEnded || session.process.exitCode != null) { - session.process.removeListener?.('close', onClose); - onClose(); - } - }); - return; - } - - // Fallback polling for minimal mock processes (primarily in tests) - for (let i = 0; i < 20; i += 1) { - if (session.hasEnded || session.process.exitCode != null) { - session.hasEnded = true; - break; - } - await new Promise((resolve) => setTimeout(resolve, 50)); - } -} - -/** - * Type guard to check if an object has fs-like promises interface - */ function hasPromisesInterface(obj: unknown): obj is { promises: typeof fs.promises } { return typeof obj === 'object' && obj !== null && 'promises' in obj; } -/** - * Type guard to check if an object has existsSync method - */ function hasExistsSyncMethod(obj: unknown): obj is { existsSync: typeof fs.existsSync } { return typeof obj === 'object' && obj !== null && 'existsSync' in obj; } -/** - * Type guard to check if an object has createWriteStream method - */ function hasCreateWriteStreamMethod( obj: unknown, ): obj is { createWriteStream: typeof fs.createWriteStream } { return typeof obj === 'object' && obj !== null && 'createWriteStream' in obj; } -/** - * Legacy support for backward compatibility - */ export async function stopDeviceLogCapture( logSessionId: string, fileSystem?: unknown, ): Promise<{ logContent: string; error?: string }> { - // For backward compatibility, create a mock FileSystemExecutor from the fileSystem parameter const fsToUse = fileSystem ?? fs; const mockFileSystemExecutor: FileSystemExecutor = { async mkdir(path: string, options?: { recursive?: boolean }): Promise { @@ -248,19 +141,17 @@ export async function stopDeviceLogCapture( if (options?.withFileTypes === true) { const result = await fsToUse.promises.readdir(path, { withFileTypes: true }); return Array.isArray(result) ? result : []; - } else { - const result = await fsToUse.promises.readdir(path); - return Array.isArray(result) ? result : []; - } - } else { - if (options?.withFileTypes === true) { - const result = await fs.promises.readdir(path, { withFileTypes: true }); - return Array.isArray(result) ? result : []; - } else { - const result = await fs.promises.readdir(path); - return Array.isArray(result) ? result : []; } + const result = await fsToUse.promises.readdir(path); + return Array.isArray(result) ? result : []; } + + if (options?.withFileTypes === true) { + const result = await fs.promises.readdir(path, { withFileTypes: true }); + return Array.isArray(result) ? result : []; + } + const result = await fs.promises.readdir(path); + return Array.isArray(result) ? result : []; }, async rm(path: string, options?: { recursive?: boolean; force?: boolean }): Promise { if (hasPromisesInterface(fsToUse)) { @@ -272,62 +163,43 @@ export async function stopDeviceLogCapture( existsSync(path: string): boolean { if (hasExistsSyncMethod(fsToUse)) { return fsToUse.existsSync(path); - } else { - return fs.existsSync(path); } + return fs.existsSync(path); }, async stat(path: string): Promise<{ isDirectory(): boolean; mtimeMs: number }> { if (hasPromisesInterface(fsToUse)) { const result = await fsToUse.promises.stat(path); return result as { isDirectory(): boolean; mtimeMs: number }; - } else { - const result = await fs.promises.stat(path); - return result as { isDirectory(): boolean; mtimeMs: number }; } + const result = await fs.promises.stat(path); + return result as { isDirectory(): boolean; mtimeMs: number }; }, async mkdtemp(prefix: string): Promise { if (hasPromisesInterface(fsToUse)) { - return await fsToUse.promises.mkdtemp(prefix); - } else { - return await fs.promises.mkdtemp(prefix); + return fsToUse.promises.mkdtemp(prefix); } + return fs.promises.mkdtemp(prefix); }, tmpdir(): string { return '/tmp'; }, }; - const result = await stop_device_log_capLogic({ logSessionId }, mockFileSystemExecutor); - - if (result.isError) { - const errorText = result.content[0]?.text; - const errorMessage = - typeof errorText === 'string' - ? errorText.replace(`Failed to stop device log capture session ${logSessionId}: `, '') - : 'Unknown error occurred'; + const result = await stopDeviceLogSessionById(logSessionId, mockFileSystemExecutor, { + timeoutMs: 1000, + readLogContent: true, + }); - return { - logContent: '', - error: errorMessage, - }; + if (result.error) { + return { logContent: '', error: result.error }; } - // Extract log content from successful response - const successText = result.content[0]?.text; - if (typeof successText !== 'string') { - return { - logContent: '', - error: 'Invalid response format: expected text content', - }; - } - - const logContentMatch = successText.match(/--- Captured Logs ---\n([\s\S]*)$/); - const logContent = logContentMatch?.[1] ?? ''; - - return { logContent }; + return { logContent: result.logContent }; } -export const schema = stopDeviceLogCapSchema.shape; // MCP SDK compatibility +export { stopAllDeviceLogCaptures }; + +export const schema = stopDeviceLogCapSchema.shape; export const handler = createTypedTool( stopDeviceLogCapSchema, diff --git a/src/mcp/tools/swift-package/__tests__/swift_package_stop.test.ts b/src/mcp/tools/swift-package/__tests__/swift_package_stop.test.ts index 0ba8c883..c7e69e52 100644 --- a/src/mcp/tools/swift-package/__tests__/swift_package_stop.test.ts +++ b/src/mcp/tools/swift-package/__tests__/swift_package_stop.test.ts @@ -1,56 +1,11 @@ -/** - * Tests for swift_package_stop plugin - * Following CLAUDE.md testing standards with pure dependency injection - * No vitest mocking - using dependency injection pattern - */ - -import { describe, it, expect } from 'vitest'; -import * as z from 'zod'; +import { describe, it, expect, vi } from 'vitest'; import { schema, handler, createMockProcessManager, swift_package_stopLogic, - type ProcessManager, } from '../swift_package_stop.ts'; -/** - * Mock process implementation for testing - */ -class MockProcess { - public killed = false; - public killSignal: string | undefined; - public exitCallback: (() => void) | undefined; - public shouldThrowOnKill = false; - public killError: Error | string | undefined; - public pid: number; - - constructor(pid: number) { - this.pid = pid; - } - - kill(signal?: string): void { - if (this.shouldThrowOnKill) { - throw this.killError ?? new Error('Process kill failed'); - } - this.killed = true; - this.killSignal = signal; - } - - on(event: string, callback: () => void): void { - if (event === 'exit') { - this.exitCallback = callback; - } - } - - // Simulate immediate exit for test control - simulateExit(): void { - if (this.exitCallback) { - this.exitCallback(); - } - } -} - describe('swift_package_stop plugin', () => { describe('Export Field Validation (Literal)', () => { it('should have handler function', () => { @@ -58,27 +13,19 @@ describe('swift_package_stop plugin', () => { }); it('should validate schema correctly', () => { - // Test valid inputs expect(schema.pid.safeParse(12345).success).toBe(true); - expect(schema.pid.safeParse(0).success).toBe(true); - expect(schema.pid.safeParse(-1).success).toBe(true); - - // Test invalid inputs expect(schema.pid.safeParse('not-a-number').success).toBe(false); - expect(schema.pid.safeParse(null).success).toBe(false); - expect(schema.pid.safeParse(undefined).success).toBe(false); - expect(schema.pid.safeParse({}).success).toBe(false); - expect(schema.pid.safeParse([]).success).toBe(false); }); }); - describe('Handler Behavior (Complete Literal Returns)', () => { - it('should return exact error for process not found', async () => { - const mockProcessManager = createMockProcessManager({ - getProcess: () => undefined, - }); - - const result = await swift_package_stopLogic({ pid: 99999 }, mockProcessManager); + describe('Handler Behavior', () => { + it('returns not-found response when process is missing', async () => { + const result = await swift_package_stopLogic( + { pid: 99999 }, + createMockProcessManager({ + getProcess: () => undefined, + }), + ); expect(result).toEqual({ content: [ @@ -91,39 +38,29 @@ describe('swift_package_stop plugin', () => { }); }); - it('should successfully stop a process that exits gracefully', async () => { - const mockProcess = new MockProcess(12345); + it('returns success response when termination succeeds', async () => { const startedAt = new Date('2023-01-01T10:00:00.000Z'); - - const mockProcessManager = createMockProcessManager({ - getProcess: (pid: number) => - pid === 12345 - ? { - process: mockProcess, - startedAt: startedAt, - } - : undefined, - removeProcess: () => true, - }); - - // Set up the process to exit immediately when exit handler is registered - const originalOn = mockProcess.on.bind(mockProcess); - mockProcess.on = (event: string, callback: () => void) => { - originalOn(event, callback); - if (event === 'exit') { - // Simulate immediate graceful exit - setImmediate(() => callback()); - } - }; + const terminateTrackedProcess = vi.fn(async () => ({ + status: 'terminated' as const, + startedAt, + })); const result = await swift_package_stopLogic( { pid: 12345 }, - mockProcessManager, - 10, // Very short timeout for testing + createMockProcessManager({ + getProcess: () => ({ + process: { + kill: () => undefined, + on: () => undefined, + pid: 12345, + }, + startedAt, + }), + terminateTrackedProcess, + }), ); - expect(mockProcess.killed).toBe(true); - expect(mockProcess.killSignal).toBe('SIGTERM'); + expect(terminateTrackedProcess).toHaveBeenCalledWith(12345, 5000); expect(result).toEqual({ content: [ { @@ -138,77 +75,26 @@ describe('swift_package_stop plugin', () => { }); }); - it('should force kill process if graceful termination fails', async () => { - const mockProcess = new MockProcess(67890); - const startedAt = new Date('2023-02-15T14:30:00.000Z'); - - const mockProcessManager = createMockProcessManager({ - getProcess: (pid: number) => - pid === 67890 - ? { - process: mockProcess, - startedAt: startedAt, - } - : undefined, - removeProcess: () => true, - }); - - // Mock the process to NOT exit gracefully (no callback invocation) - const killCalls: string[] = []; - const originalKill = mockProcess.kill.bind(mockProcess); - mockProcess.kill = (signal?: string) => { - killCalls.push(signal ?? 'default'); - originalKill(signal); - }; - - // Set up timeout to trigger SIGKILL after SIGTERM - const originalOn = mockProcess.on.bind(mockProcess); - mockProcess.on = (event: string, callback: () => void) => { - originalOn(event, callback); - // Do NOT call the callback to simulate hanging process - }; - + it('returns error response when termination reports an error', async () => { + const startedAt = new Date('2023-01-01T10:00:00.000Z'); const result = await swift_package_stopLogic( - { pid: 67890 }, - mockProcessManager, - 10, // Very short timeout for testing + { pid: 54321 }, + createMockProcessManager({ + getProcess: () => ({ + process: { + kill: () => undefined, + on: () => undefined, + pid: 54321, + }, + startedAt, + }), + terminateTrackedProcess: async () => ({ + status: 'terminated', + error: 'ESRCH: No such process', + }), + }), ); - expect(killCalls).toEqual(['SIGTERM', 'SIGKILL']); - expect(result).toEqual({ - content: [ - { - type: 'text', - text: '✅ Stopped executable (was running since 2023-02-15T14:30:00.000Z)', - }, - { - type: 'text', - text: '💡 Process terminated. You can now run swift_package_run again if needed.', - }, - ], - }); - }); - - it('should handle process kill error and return error response', async () => { - const mockProcess = new MockProcess(54321); - const startedAt = new Date('2023-03-20T09:15:00.000Z'); - - // Configure process to throw error on kill - mockProcess.shouldThrowOnKill = true; - mockProcess.killError = new Error('ESRCH: No such process'); - - const mockProcessManager = createMockProcessManager({ - getProcess: (pid: number) => - pid === 54321 - ? { - process: mockProcess, - startedAt: startedAt, - } - : undefined, - }); - - const result = await swift_package_stopLogic({ pid: 54321 }, mockProcessManager); - expect(result).toEqual({ content: [ { @@ -220,192 +106,37 @@ describe('swift_package_stop plugin', () => { }); }); - it('should handle non-Error exception in catch block', async () => { - const mockProcess = new MockProcess(11111); - const startedAt = new Date('2023-04-10T16:45:00.000Z'); - - // Configure process to throw non-Error object - mockProcess.shouldThrowOnKill = true; - mockProcess.killError = 'Process termination failed'; - - const mockProcessManager = createMockProcessManager({ - getProcess: (pid: number) => - pid === 11111 - ? { - process: mockProcess, - startedAt: startedAt, - } - : undefined, - }); - - const result = await swift_package_stopLogic({ pid: 11111 }, mockProcessManager); - - expect(result).toEqual({ - content: [ - { - type: 'text', - text: 'Error: Failed to stop process\nDetails: Process termination failed', - }, - ], - isError: true, - }); - }); - - it('should handle process found but exit event never fires and timeout occurs', async () => { - const mockProcess = new MockProcess(22222); - const startedAt = new Date('2023-05-05T12:00:00.000Z'); - - const mockProcessManager = createMockProcessManager({ - getProcess: (pid: number) => - pid === 22222 - ? { - process: mockProcess, - startedAt: startedAt, - } - : undefined, - removeProcess: () => true, - }); - - const killCalls: string[] = []; - const originalKill = mockProcess.kill.bind(mockProcess); - mockProcess.kill = (signal?: string) => { - killCalls.push(signal ?? 'default'); - originalKill(signal); - }; - - // Mock process.on to register the exit handler but never call it (timeout scenario) - const originalOn = mockProcess.on.bind(mockProcess); - mockProcess.on = (event: string, callback: () => void) => { - originalOn(event, callback); - // Handler is registered but callback never called (simulates hanging process) - }; - - const result = await swift_package_stopLogic( - { pid: 22222 }, - mockProcessManager, - 10, // Very short timeout for testing - ); - - expect(killCalls).toEqual(['SIGTERM', 'SIGKILL']); - expect(result).toEqual({ - content: [ - { - type: 'text', - text: '✅ Stopped executable (was running since 2023-05-05T12:00:00.000Z)', - }, - { - type: 'text', - text: '💡 Process terminated. You can now run swift_package_run again if needed.', - }, - ], - }); - }); - - it('should handle edge case with pid 0', async () => { - const mockProcessManager = createMockProcessManager({ - getProcess: () => undefined, - }); - - const result = await swift_package_stopLogic({ pid: 0 }, mockProcessManager); - - expect(result).toEqual({ - content: [ - { - type: 'text', - text: '⚠️ No running process found with PID 0. Use swift_package_run to check active processes.', - }, - ], - isError: true, - }); - }); - - it('should handle edge case with negative pid', async () => { - const mockProcessManager = createMockProcessManager({ - getProcess: () => undefined, - }); - - const result = await swift_package_stopLogic({ pid: -1 }, mockProcessManager); - - expect(result).toEqual({ - content: [ - { - type: 'text', - text: '⚠️ No running process found with PID -1. Use swift_package_run to check active processes.', - }, - ], - isError: true, - }); - }); - - it('should handle process that exits after first SIGTERM call', async () => { - const mockProcess = new MockProcess(33333); - const startedAt = new Date('2023-06-01T08:30:00.000Z'); - - const mockProcessManager = createMockProcessManager({ - getProcess: (pid: number) => - pid === 33333 - ? { - process: mockProcess, - startedAt: startedAt, - } - : undefined, - removeProcess: () => true, - }); - - const killCalls: string[] = []; - const originalKill = mockProcess.kill.bind(mockProcess); - mockProcess.kill = (signal?: string) => { - killCalls.push(signal ?? 'default'); - originalKill(signal); - }; - - // Set up the process to exit immediately when exit handler is registered - const originalOn = mockProcess.on.bind(mockProcess); - mockProcess.on = (event: string, callback: () => void) => { - originalOn(event, callback); - if (event === 'exit') { - // Simulate immediate graceful exit - setImmediate(() => callback()); - } - }; + it('uses custom timeout when provided', async () => { + const startedAt = new Date('2023-01-01T10:00:00.000Z'); + const terminateTrackedProcess = vi.fn(async () => ({ + status: 'terminated' as const, + startedAt, + })); - const result = await swift_package_stopLogic( - { pid: 33333 }, - mockProcessManager, - 10, // Very short timeout for testing + await swift_package_stopLogic( + { pid: 12345 }, + createMockProcessManager({ + getProcess: () => ({ + process: { + kill: () => undefined, + on: () => undefined, + pid: 12345, + }, + startedAt, + }), + terminateTrackedProcess, + }), + 10, ); - expect(killCalls).toEqual(['SIGTERM']); // Should not call SIGKILL - expect(result).toEqual({ - content: [ - { - type: 'text', - text: '✅ Stopped executable (was running since 2023-06-01T08:30:00.000Z)', - }, - { - type: 'text', - text: '💡 Process terminated. You can now run swift_package_run again if needed.', - }, - ], - }); + expect(terminateTrackedProcess).toHaveBeenCalledWith(12345, 10); }); - it('should handle undefined pid parameter', async () => { - const mockProcessManager = createMockProcessManager({ - getProcess: () => undefined, - }); - - const result = await swift_package_stopLogic({} as any, mockProcessManager); + it('returns validation error from handler', async () => { + const result = await handler({ pid: 'bad' }); - expect(result).toEqual({ - content: [ - { - type: 'text', - text: '⚠️ No running process found with PID undefined. Use swift_package_run to check active processes.', - }, - ], - isError: true, - }); + expect(result.isError).toBe(true); + expect(result.content[0]?.text).toContain('Parameter validation failed'); }); }); }); diff --git a/src/mcp/tools/swift-package/active-processes.ts b/src/mcp/tools/swift-package/active-processes.ts index 7dd450c3..a5807b2b 100644 --- a/src/mcp/tools/swift-package/active-processes.ts +++ b/src/mcp/tools/swift-package/active-processes.ts @@ -4,22 +4,26 @@ * between swift_package_run and swift_package_stop tools */ +interface TrackedProcess { + kill: (signal?: string) => void; + on: (event: string, callback: () => void) => void; + once?: (event: string, callback: () => void) => void; + removeListener?: (event: string, callback: () => void) => void; + pid?: number; + exitCode?: number | null; + killed?: boolean; +} + export interface ProcessInfo { - process: { - kill: (signal?: string) => void; - on: (event: string, callback: () => void) => void; - pid?: number; - }; + process: TrackedProcess; startedAt: Date; executableName?: string; packagePath?: string; releaseActivity?: () => void; } -// Global map to track active processes export const activeProcesses = new Map(); -// Helper functions for process management export const getProcess = (pid: number): ProcessInfo | undefined => { return activeProcesses.get(pid); }; @@ -42,3 +46,100 @@ export const clearAllProcesses = (): void => { } activeProcesses.clear(); }; + +function createTimeoutPromise(timeoutMs: number): Promise<'timed_out'> { + return new Promise((resolve) => { + const timer = setTimeout(() => resolve('timed_out'), timeoutMs); + timer.unref?.(); + }); +} + +async function terminateProcess( + info: ProcessInfo, + timeoutMs: number, +): Promise<{ usedForceKill?: boolean; error?: string }> { + try { + info.process.kill('SIGTERM'); + } catch (error) { + return { error: error instanceof Error ? error.message : String(error) }; + } + + const alreadyExited = info.process.exitCode != null || info.process.killed === true; + if (alreadyExited) { + return {}; + } + + let usedForceKill = false; + + const exitPromise = new Promise<'exited'>((resolve) => { + const onExit = (): void => resolve('exited'); + if (typeof info.process.once === 'function') { + info.process.once('exit', onExit); + return; + } + info.process.on('exit', onExit); + }).catch(() => 'exited' as const); + + const outcome = await Promise.race([exitPromise, createTimeoutPromise(timeoutMs)]); + if (outcome === 'timed_out') { + try { + info.process.kill('SIGKILL'); + usedForceKill = true; + } catch { + // ignore + } + } + + return { usedForceKill }; +} + +export async function terminateTrackedProcess( + pid: number, + timeoutMs = 5000, +): Promise<{ + status: 'not-found' | 'terminated'; + startedAt?: Date; + usedForceKill?: boolean; + error?: string; +}> { + const info = activeProcesses.get(pid); + if (!info) { + return { status: 'not-found' }; + } + + activeProcesses.delete(pid); + + try { + const result = await terminateProcess(info, timeoutMs); + return { + status: 'terminated', + startedAt: info.startedAt, + usedForceKill: result.usedForceKill, + error: result.error, + }; + } finally { + info.releaseActivity?.(); + } +} + +export async function stopAllTrackedProcesses(timeoutMs = 1000): Promise<{ + stoppedProcessCount: number; + errorCount: number; + errors: string[]; +}> { + const pids = Array.from(activeProcesses.keys()); + const errors: string[] = []; + + for (const pid of pids) { + const result = await terminateTrackedProcess(pid, timeoutMs); + if (result.error) { + errors.push(`${pid}: ${result.error}`); + } + } + + return { + stoppedProcessCount: pids.length - errors.length, + errorCount: errors.length, + errors, + }; +} diff --git a/src/mcp/tools/swift-package/swift_package_stop.ts b/src/mcp/tools/swift-package/swift_package_stop.ts index 916546d7..3366a485 100644 --- a/src/mcp/tools/swift-package/swift_package_stop.ts +++ b/src/mcp/tools/swift-package/swift_package_stop.ts @@ -1,53 +1,39 @@ import * as z from 'zod'; import { createTextResponse, createErrorResponse } from '../../../utils/responses/index.ts'; -import { getProcess, removeProcess, type ProcessInfo } from './active-processes.ts'; +import { getProcess, terminateTrackedProcess, type ProcessInfo } from './active-processes.ts'; import type { ToolResponse } from '../../../types/common.ts'; -// Define schema as ZodObject const swiftPackageStopSchema = z.object({ pid: z.number(), }); -// Use z.infer for type safety type SwiftPackageStopParams = z.infer; -/** - * Process manager interface for dependency injection - */ export interface ProcessManager { getProcess: (pid: number) => ProcessInfo | undefined; - removeProcess: (pid: number) => boolean; + terminateTrackedProcess: ( + pid: number, + timeoutMs: number, + ) => Promise<{ status: 'not-found' | 'terminated'; startedAt?: Date; error?: string }>; } -/** - * Default process manager implementation - */ const defaultProcessManager: ProcessManager = { getProcess, - removeProcess, + terminateTrackedProcess, }; -/** - * Get the default process manager instance - */ export function getDefaultProcessManager(): ProcessManager { return defaultProcessManager; } -/** - * Create a mock process manager for testing - */ export function createMockProcessManager(overrides?: Partial): ProcessManager { return { getProcess: () => undefined, - removeProcess: () => true, + terminateTrackedProcess: async () => ({ status: 'not-found' }), ...overrides, }; } -/** - * Business logic for stopping a Swift Package executable - */ export async function swift_package_stopLogic( params: SwiftPackageStopParams, processManager: ProcessManager = getDefaultProcessManager(), @@ -62,32 +48,25 @@ export async function swift_package_stopLogic( } try { - processInfo.process.kill('SIGTERM'); + const result = await processManager.terminateTrackedProcess(params.pid, timeout); + if (result.status === 'not-found') { + return createTextResponse( + `⚠️ No running process found with PID ${params.pid}. Use swift_package_run to check active processes.`, + true, + ); + } - // Give it time to terminate gracefully (configurable for testing) - await new Promise((resolve) => { - let terminated = false; + if (result.error) { + return createErrorResponse('Failed to stop process', result.error); + } - processInfo.process.on('exit', () => { - terminated = true; - resolve(true); - }); - - setTimeout(() => { - if (!terminated) { - processInfo.process.kill('SIGKILL'); - } - resolve(true); - }, timeout); - }); - - processManager.removeProcess(params.pid); + const startedAt = result.startedAt ?? processInfo.startedAt; return { content: [ { type: 'text', - text: `✅ Stopped executable (was running since ${processInfo.startedAt.toISOString()})`, + text: `✅ Stopped executable (was running since ${startedAt.toISOString()})`, }, { type: 'text', diff --git a/src/server/__tests__/mcp-lifecycle.test.ts b/src/server/__tests__/mcp-lifecycle.test.ts index fb46e33f..832b931e 100644 --- a/src/server/__tests__/mcp-lifecycle.test.ts +++ b/src/server/__tests__/mcp-lifecycle.test.ts @@ -5,7 +5,9 @@ import { buildMcpLifecycleSnapshot, classifyMcpLifecycleAnomalies, createMcpLifecycleCoordinator, + isTransportDisconnectReason, } from '../mcp-lifecycle.ts'; +import * as shutdownState from '../../utils/shutdown-state.ts'; class TestStdin extends EventEmitter { override once(event: string, listener: (...args: unknown[]) => void): this { @@ -20,6 +22,7 @@ class TestStdin extends EventEmitter { class TestProcess extends EventEmitter { readonly stdin = new TestStdin(); readonly stdout = new TestStdin(); + readonly stderr = new TestStdin(); override once(event: string, listener: (...args: unknown[]) => void): this { return super.once(event, listener); @@ -91,6 +94,9 @@ describe('mcp lifecycle coordinator', () => { }); it('maps broken stdout pipes to shutdowns', async () => { + const suppressSpy = vi + .spyOn(shutdownState, 'suppressProcessStdioWrites') + .mockImplementation(() => undefined); const processRef = new TestProcess(); const onShutdown = vi.fn().mockResolvedValue(undefined); const coordinator = createMcpLifecycleCoordinator({ @@ -106,6 +112,29 @@ describe('mcp lifecycle coordinator', () => { }); expect(onShutdown.mock.calls[0]?.[0]?.reason).toBe('stdout-error'); + expect(suppressSpy).toHaveBeenCalledTimes(1); + }); + + it('maps broken stderr pipes to shutdowns', async () => { + const processRef = new TestProcess(); + const onShutdown = vi.fn().mockResolvedValue(undefined); + const suppressSpy = vi + .spyOn(shutdownState, 'suppressProcessStdioWrites') + .mockImplementation(() => undefined); + const coordinator = createMcpLifecycleCoordinator({ + commandExecutor: createMockExecutor({ output: '' }), + processRef, + onShutdown, + }); + + coordinator.attachProcessHandlers(); + processRef.stderr.emit('error', Object.assign(new Error('broken pipe'), { code: 'EPIPE' })); + await vi.waitFor(() => { + expect(onShutdown).toHaveBeenCalledTimes(1); + }); + + expect(onShutdown.mock.calls[0]?.[0]?.reason).toBe('stderr-error'); + expect(suppressSpy).toHaveBeenCalledTimes(1); }); }); @@ -146,6 +175,16 @@ describe('mcp lifecycle snapshot', () => { expect(snapshot.matchingMcpProcessCount).toBe(2); expect(snapshot.matchingMcpPeerSummary).toEqual([{ pid: 999, ageSeconds: 180, rssKb: 1024 }]); + expect(snapshot.ppid).toBe(process.ppid); + expect(snapshot.orphaned).toBe(process.ppid === 1); expect(snapshot.anomalies).toEqual(['peer-age-high']); }); + + it('classifies transport disconnect reasons', () => { + expect(isTransportDisconnectReason('stdin-end')).toBe(true); + expect(isTransportDisconnectReason('stdin-close')).toBe(true); + expect(isTransportDisconnectReason('stdout-error')).toBe(true); + expect(isTransportDisconnectReason('stderr-error')).toBe(true); + expect(isTransportDisconnectReason('sigterm')).toBe(false); + }); }); diff --git a/src/server/__tests__/mcp-shutdown.test.ts b/src/server/__tests__/mcp-shutdown.test.ts new file mode 100644 index 00000000..c7617689 --- /dev/null +++ b/src/server/__tests__/mcp-shutdown.test.ts @@ -0,0 +1,104 @@ +import { beforeEach, describe, expect, it, vi } from 'vitest'; + +const mocks = vi.hoisted(() => ({ + stopXcodeStateWatcher: vi.fn(async () => undefined), + shutdownXcodeToolsBridge: vi.fn(async () => undefined), + disposeAll: vi.fn(async () => undefined), + stopAllLogCaptures: vi.fn(async () => ({ stoppedSessionCount: 0, errorCount: 0, errors: [] })), + stopAllDeviceLogCaptures: vi.fn(async () => ({ + stoppedSessionCount: 0, + errorCount: 0, + errors: [], + })), + stopAllVideoCaptureSessions: vi.fn(async () => ({ + stoppedSessionCount: 0, + errorCount: 0, + errors: [], + })), + stopAllTrackedProcesses: vi.fn(async () => ({ + stoppedProcessCount: 0, + errorCount: 0, + errors: [], + })), + captureMcpShutdownSummary: vi.fn(), + flushSentry: vi.fn(async () => 'flushed'), + sealSentryCapture: vi.fn(), +})); + +vi.mock('../../utils/xcode-state-watcher.ts', () => ({ + stopXcodeStateWatcher: mocks.stopXcodeStateWatcher, +})); +vi.mock('../../integrations/xcode-tools-bridge/index.ts', () => ({ + shutdownXcodeToolsBridge: mocks.shutdownXcodeToolsBridge, +})); +vi.mock('../../utils/debugger/index.ts', () => ({ + getDefaultDebuggerManager: () => ({ disposeAll: mocks.disposeAll }), +})); +vi.mock('../../utils/log_capture.ts', () => ({ + stopAllLogCaptures: mocks.stopAllLogCaptures, +})); +vi.mock('../../utils/log-capture/device-log-sessions.ts', () => ({ + stopAllDeviceLogCaptures: mocks.stopAllDeviceLogCaptures, +})); +vi.mock('../../utils/video_capture.ts', () => ({ + stopAllVideoCaptureSessions: mocks.stopAllVideoCaptureSessions, +})); +vi.mock('../../mcp/tools/swift-package/active-processes.ts', () => ({ + stopAllTrackedProcesses: mocks.stopAllTrackedProcesses, +})); +vi.mock('../../utils/sentry.ts', () => ({ + captureMcpShutdownSummary: mocks.captureMcpShutdownSummary, + flushSentry: mocks.flushSentry, +})); +vi.mock('../../utils/shutdown-state.ts', () => ({ + sealSentryCapture: mocks.sealSentryCapture, +})); + +import { runMcpShutdown } from '../mcp-shutdown.ts'; + +describe('runMcpShutdown', () => { + beforeEach(() => { + vi.clearAllMocks(); + }); + + it('runs cleanup, captures summary, seals capture, and flushes', async () => { + const result = await runMcpShutdown({ + reason: 'sigterm', + snapshot: { + pid: 1, + ppid: 1, + orphaned: true, + phase: 'running', + shutdownReason: 'sigterm', + uptimeMs: 100, + rssBytes: 1, + heapUsedBytes: 1, + watcherRunning: false, + watchedPath: null, + activeOperationCount: 0, + activeOperationByCategory: {}, + debuggerSessionCount: 0, + simulatorLogSessionCount: 0, + deviceLogSessionCount: 0, + videoCaptureSessionCount: 0, + swiftPackageProcessCount: 0, + matchingMcpProcessCount: 0, + matchingMcpPeerSummary: [], + anomalies: [], + }, + server: { close: async () => undefined }, + }); + + expect(result.exitCode).toBe(0); + expect(mocks.captureMcpShutdownSummary).toHaveBeenCalledTimes(1); + expect(mocks.sealSentryCapture).toHaveBeenCalledTimes(1); + expect(mocks.flushSentry).toHaveBeenCalledTimes(1); + expect(mocks.stopXcodeStateWatcher).toHaveBeenCalledTimes(1); + expect(mocks.shutdownXcodeToolsBridge).toHaveBeenCalledTimes(1); + expect(mocks.disposeAll).toHaveBeenCalledTimes(1); + expect(mocks.stopAllLogCaptures).toHaveBeenCalledTimes(1); + expect(mocks.stopAllDeviceLogCaptures).toHaveBeenCalledTimes(1); + expect(mocks.stopAllVideoCaptureSessions).toHaveBeenCalledTimes(1); + expect(mocks.stopAllTrackedProcesses).toHaveBeenCalledTimes(1); + }); +}); diff --git a/src/server/__tests__/start-mcp-server.test.ts b/src/server/__tests__/start-mcp-server.test.ts index 789a6a12..23b5ed80 100644 --- a/src/server/__tests__/start-mcp-server.test.ts +++ b/src/server/__tests__/start-mcp-server.test.ts @@ -1,5 +1,5 @@ import { afterEach, describe, expect, it, vi } from 'vitest'; -import { __closeServerForFastExitForTests } from '../start-mcp-server.ts'; +import { closeServerWithTimeout } from '../mcp-shutdown.ts'; describe('fast-exit server close', () => { afterEach(() => { @@ -8,12 +8,12 @@ describe('fast-exit server close', () => { }); it('returns skipped when server is not available', async () => { - await expect(__closeServerForFastExitForTests(undefined)).resolves.toBe('skipped'); + await expect(closeServerWithTimeout(undefined, 50)).resolves.toBe('skipped'); }); it('returns closed when server close resolves quickly', async () => { const close = vi.fn(async () => undefined); - await expect(__closeServerForFastExitForTests({ close }, 50)).resolves.toBe('closed'); + await expect(closeServerWithTimeout({ close }, 50)).resolves.toBe('closed'); expect(close).toHaveBeenCalledTimes(1); }); @@ -22,7 +22,7 @@ describe('fast-exit server close', () => { throw new Error('close failed'); }); - await expect(__closeServerForFastExitForTests({ close }, 50)).resolves.toBe('rejected'); + await expect(closeServerWithTimeout({ close }, 50)).resolves.toBe('rejected'); expect(close).toHaveBeenCalledTimes(1); }); @@ -30,7 +30,7 @@ describe('fast-exit server close', () => { vi.useFakeTimers(); const close = vi.fn(() => new Promise(() => undefined)); - const outcomePromise = __closeServerForFastExitForTests({ close }, 50); + const outcomePromise = closeServerWithTimeout({ close }, 50); await vi.advanceTimersByTimeAsync(50); await expect(outcomePromise).resolves.toBe('timed_out'); diff --git a/src/server/mcp-lifecycle.ts b/src/server/mcp-lifecycle.ts index 9c3f15cc..275d7b07 100644 --- a/src/server/mcp-lifecycle.ts +++ b/src/server/mcp-lifecycle.ts @@ -9,6 +9,7 @@ import { listActiveVideoCaptureSessionIds } from '../utils/video_capture.ts'; import { getDefaultCommandExecutor } from '../utils/execution/index.ts'; import type { CommandExecutor } from '../utils/execution/index.ts'; import { getWatchedPath, isWatcherRunning } from '../utils/xcode-state-watcher.ts'; +import { suppressProcessStdioWrites } from '../utils/shutdown-state.ts'; export type McpStartupPhase = | 'initializing' @@ -26,6 +27,7 @@ export type McpShutdownReason = | 'stdin-end' | 'stdin-close' | 'stdout-error' + | 'stderr-error' | 'sigint' | 'sigterm' | 'startup-failure' @@ -46,6 +48,8 @@ export interface McpPeerProcessSummary { export interface McpLifecycleSnapshot { pid: number; + ppid: number; + orphaned: boolean; phase: McpStartupPhase; shutdownReason: McpShutdownReason | null; uptimeMs: number; @@ -83,6 +87,7 @@ interface LifecycleStdoutLike { interface LifecycleProcessLike { stdin: LifecycleStdinLike; stdout?: LifecycleStdoutLike; + stderr?: LifecycleStdoutLike; once(event: string, listener: (...args: unknown[]) => void): this; removeListener(event: string, listener: (...args: unknown[]) => void): this; } @@ -267,6 +272,15 @@ async function sampleMcpPeerProcesses( } } +export function isTransportDisconnectReason(reason: McpShutdownReason): boolean { + return ( + reason === 'stdin-end' || + reason === 'stdin-close' || + reason === 'stdout-error' || + reason === 'stderr-error' + ); +} + export async function buildMcpLifecycleSnapshot(options: { phase: McpStartupPhase; shutdownReason: McpShutdownReason | null; @@ -282,6 +296,8 @@ export async function buildMcpLifecycleSnapshot(options: { const snapshotWithoutAnomalies = { pid: process.pid, + ppid: process.ppid, + orphaned: process.ppid === 1, phase: options.phase, shutdownReason: options.shutdownReason, uptimeMs: Math.max(0, Date.now() - options.startedAtMs), @@ -326,17 +342,27 @@ export function createMcpLifecycleCoordinator( void coordinator.shutdown('sigint'); }; const handleStdinEnd = (): void => { + suppressProcessStdioWrites(); void coordinator.shutdown('stdin-end'); }; const handleStdinClose = (): void => { + suppressProcessStdioWrites(); void coordinator.shutdown('stdin-close'); }; const handleStdoutError = (error: unknown): void => { if (!isBrokenPipeLikeError(error)) { return; } + suppressProcessStdioWrites(); void coordinator.shutdown('stdout-error', error); }; + const handleStderrError = (error: unknown): void => { + if (!isBrokenPipeLikeError(error)) { + return; + } + suppressProcessStdioWrites(); + void coordinator.shutdown('stderr-error', error); + }; const handleUncaughtException = (error: unknown): void => { void coordinator.shutdown('uncaught-exception', error); }; @@ -358,6 +384,7 @@ export function createMcpLifecycleCoordinator( processRef.stdin.once('end', handleStdinEnd); processRef.stdin.once('close', handleStdinClose); processRef.stdout?.once('error', handleStdoutError); + processRef.stderr?.once('error', handleStderrError); processRef.once('uncaughtException', handleUncaughtException); processRef.once('unhandledRejection', handleUnhandledRejection); }, @@ -373,6 +400,7 @@ export function createMcpLifecycleCoordinator( processRef.stdin.removeListener('end', handleStdinEnd); processRef.stdin.removeListener('close', handleStdinClose); processRef.stdout?.removeListener('error', handleStdoutError); + processRef.stderr?.removeListener('error', handleStderrError); processRef.removeListener('uncaughtException', handleUncaughtException); processRef.removeListener('unhandledRejection', handleUnhandledRejection); }, diff --git a/src/server/mcp-shutdown.ts b/src/server/mcp-shutdown.ts new file mode 100644 index 00000000..6f964fb8 --- /dev/null +++ b/src/server/mcp-shutdown.ts @@ -0,0 +1,200 @@ +import type { McpServer } from '@modelcontextprotocol/sdk/server/mcp.js'; +import { getDefaultDebuggerManager } from '../utils/debugger/index.ts'; +import { stopXcodeStateWatcher } from '../utils/xcode-state-watcher.ts'; +import { shutdownXcodeToolsBridge } from '../integrations/xcode-tools-bridge/index.ts'; +import { stopAllLogCaptures } from '../utils/log_capture.ts'; +import { stopAllDeviceLogCaptures } from '../utils/log-capture/device-log-sessions.ts'; +import { stopAllVideoCaptureSessions } from '../utils/video_capture.ts'; +import { stopAllTrackedProcesses } from '../mcp/tools/swift-package/active-processes.ts'; +import { + captureMcpShutdownSummary, + flushSentry, + type FlushSentryOutcome, +} from '../utils/sentry.ts'; +import { sealSentryCapture } from '../utils/shutdown-state.ts'; +import type { McpLifecycleSnapshot, McpShutdownReason } from './mcp-lifecycle.ts'; +import { isTransportDisconnectReason } from './mcp-lifecycle.ts'; + +const DISCONNECT_SERVER_CLOSE_TIMEOUT_MS = 150; +const DEFAULT_SERVER_CLOSE_TIMEOUT_MS = 1000; +const STEP_TIMEOUT_MS = 1000; +const DISCONNECT_FLUSH_TIMEOUT_MS = 250; +const DEFAULT_FLUSH_TIMEOUT_MS = 1500; + +export type ShutdownStepStatus = 'completed' | 'timed_out' | 'failed' | 'skipped'; + +export interface ShutdownStepResult { + name: string; + status: ShutdownStepStatus; + durationMs: number; + error?: string; +} + +interface ShutdownStepOutcome { + status: ShutdownStepStatus; + durationMs: number; + value?: T; + error?: string; +} + +export interface McpShutdownResult { + exitCode: number; + transportDisconnected: boolean; + sentryFlush: FlushSentryOutcome; + steps: ShutdownStepResult[]; +} + +function stringifyError(error: unknown): string { + return error instanceof Error ? error.message : String(error); +} + +function createTimer(timeoutMs: number, callback: () => void): NodeJS.Timeout { + const timer = setTimeout(callback, timeoutMs); + timer.unref?.(); + return timer; +} + +async function runStep( + name: string, + timeoutMs: number, + operation: () => Promise, +): Promise> { + const startedAt = Date.now(); + let timeoutHandle: NodeJS.Timeout | null = null; + + try { + const timeoutPromise = new Promise<'timed_out'>((resolve) => { + timeoutHandle = createTimer(timeoutMs, () => resolve('timed_out')); + }); + const operationPromise = operation(); + const outcome = await Promise.race([ + operationPromise.then((value) => ({ kind: 'value' as const, value })), + timeoutPromise.then(() => ({ kind: 'timed_out' as const })), + ]); + + if (outcome.kind === 'timed_out') { + return { + status: 'timed_out', + durationMs: Date.now() - startedAt, + }; + } + + return { + status: 'completed', + durationMs: Date.now() - startedAt, + value: outcome.value, + }; + } catch (error) { + return { + status: 'failed', + durationMs: Date.now() - startedAt, + error: stringifyError(error), + }; + } finally { + if (timeoutHandle) { + clearTimeout(timeoutHandle); + } + } +} + +function buildExitCode(reason: McpShutdownReason): number { + return reason === 'startup-failure' || + reason === 'uncaught-exception' || + reason === 'unhandled-rejection' + ? 1 + : 0; +} + +export async function closeServerWithTimeout( + server: Pick | null | undefined, + timeoutMs: number, +): Promise<'skipped' | 'closed' | 'timed_out' | 'rejected'> { + if (!server) { + return 'skipped'; + } + + const outcome = await runStep('server.close', timeoutMs, () => server.close()); + if (outcome.status === 'completed') { + return 'closed'; + } + if (outcome.status === 'timed_out') { + return 'timed_out'; + } + return 'rejected'; +} + +export async function runMcpShutdown(input: { + reason: McpShutdownReason; + error?: unknown; + snapshot: McpLifecycleSnapshot; + server: Pick | null; +}): Promise { + const shutdownStartedAt = Date.now(); + const exitCode = buildExitCode(input.reason); + const transportDisconnected = isTransportDisconnectReason(input.reason); + const steps: ShutdownStepResult[] = []; + + const pushStep = (name: string, outcome: ShutdownStepOutcome): void => { + steps.push({ + name, + status: outcome.status, + durationMs: outcome.durationMs, + ...(outcome.error ? { error: outcome.error } : {}), + }); + }; + + const serverCloseTimeout = transportDisconnected + ? DISCONNECT_SERVER_CLOSE_TIMEOUT_MS + : DEFAULT_SERVER_CLOSE_TIMEOUT_MS; + + const serverCloseOutcome = await runStep('server.close', serverCloseTimeout, async () => { + await input.server?.close(); + }); + pushStep('server.close', serverCloseOutcome); + + const cleanupSteps: Array<[string, () => Promise]> = [ + ['watcher.stop', () => stopXcodeStateWatcher()], + ['xcode-tools-bridge.shutdown', () => shutdownXcodeToolsBridge()], + ['debugger.dispose-all', () => getDefaultDebuggerManager().disposeAll()], + ['simulator-logs.stop-all', () => stopAllLogCaptures(STEP_TIMEOUT_MS)], + ['device-logs.stop-all', () => stopAllDeviceLogCaptures(STEP_TIMEOUT_MS)], + ['video-capture.stop-all', () => stopAllVideoCaptureSessions(STEP_TIMEOUT_MS)], + ['swift-processes.stop-all', () => stopAllTrackedProcesses(STEP_TIMEOUT_MS)], + ]; + + for (const [name, operation] of cleanupSteps) { + const outcome = await runStep(name, STEP_TIMEOUT_MS, operation); + pushStep(name, outcome); + } + + const triggerError = input.error === undefined ? undefined : stringifyError(input.error); + const cleanupFailureCount = steps.filter( + (step) => step.status === 'failed' || step.status === 'timed_out', + ).length; + + captureMcpShutdownSummary({ + reason: input.reason, + phase: input.snapshot.phase, + exitCode, + transportDisconnected, + triggerError, + cleanupFailureCount, + shutdownDurationMs: Date.now() - shutdownStartedAt, + snapshot: input.snapshot as unknown as Record, + steps: steps as unknown as Array>, + }); + + sealSentryCapture(); + + const flushTimeout = transportDisconnected + ? DISCONNECT_FLUSH_TIMEOUT_MS + : DEFAULT_FLUSH_TIMEOUT_MS; + const sentryFlush = await flushSentry(flushTimeout); + + return { + exitCode, + transportDisconnected, + sentryFlush, + steps, + }; +} diff --git a/src/server/start-mcp-server.ts b/src/server/start-mcp-server.ts index a17646b1..09156165 100644 --- a/src/server/start-mcp-server.ts +++ b/src/server/start-mcp-server.ts @@ -11,56 +11,21 @@ import { createServer, startServer } from './server.ts'; import { log, setLogLevel } from '../utils/logger.ts'; import { enrichSentryContext, - flushAndCloseSentry, initSentry, recordMcpLifecycleAnomalyMetric, recordMcpLifecycleMetric, setSentryRuntimeContext, } from '../utils/sentry.ts'; -import { getDefaultDebuggerManager } from '../utils/debugger/index.ts'; import { version } from '../version.ts'; import process from 'node:process'; import type { McpServer } from '@modelcontextprotocol/sdk/server/mcp.js'; import { bootstrapServer } from './bootstrap.ts'; -import { shutdownXcodeToolsBridge } from '../integrations/xcode-tools-bridge/index.ts'; import { createStartupProfiler, getStartupProfileNowMs } from './startup-profiler.ts'; import { getConfig } from '../utils/config-store.ts'; import { getRegisteredWorkflows } from '../utils/tool-registry.ts'; import { hydrateSentryDisabledEnvFromProjectConfig } from '../utils/sentry-config.ts'; -import { stopXcodeStateWatcher } from '../utils/xcode-state-watcher.ts'; -import { createMcpLifecycleCoordinator } from './mcp-lifecycle.ts'; - -const FAST_EXIT_SERVER_CLOSE_TIMEOUT_MS = 100; - -interface ClosableMcpServer { - close(): Promise; -} - -type FastExitCloseOutcome = 'skipped' | 'closed' | 'rejected' | 'timed_out'; - -function isTransportDisconnectReason(reason: string): boolean { - return reason === 'stdin-end' || reason === 'stdin-close' || reason === 'stdout-error'; -} - -export async function __closeServerForFastExitForTests( - server: ClosableMcpServer | null | undefined, - timeoutMs = FAST_EXIT_SERVER_CLOSE_TIMEOUT_MS, -): Promise { - if (!server) { - return 'skipped'; - } - - const closePromise = server - .close() - .then(() => 'closed') - .catch(() => 'rejected'); - - const timeoutPromise = new Promise((resolve) => { - setTimeout(() => resolve('timed_out'), timeoutMs); - }); - - return Promise.race([closePromise, timeoutPromise]); -} +import { createMcpLifecycleCoordinator, isTransportDisconnectReason } from './mcp-lifecycle.ts'; +import { runMcpShutdown } from './mcp-shutdown.ts'; /** * Start the MCP server. @@ -70,17 +35,8 @@ export async function __closeServerForFastExitForTests( export async function startMcpServer(): Promise { const lifecycle = createMcpLifecycleCoordinator({ onShutdown: async ({ reason, error, snapshot, server }) => { - const closeableServer: Pick | null = server; const isCrash = reason === 'uncaught-exception' || reason === 'unhandled-rejection'; const event = isCrash ? 'crash' : 'shutdown'; - const exitCode = - reason === 'stdin-end' || - reason === 'stdin-close' || - reason === 'stdout-error' || - reason === 'sigint' || - reason === 'sigterm' - ? 0 - : 1; if (reason === 'stdin-end') { log('info', 'MCP stdin ended; shutting down MCP server'); @@ -88,92 +44,42 @@ export async function startMcpServer(): Promise { log('info', 'MCP stdin closed; shutting down MCP server'); } else if (reason === 'stdout-error') { log('info', 'MCP stdout pipe broke; shutting down MCP server'); + } else if (reason === 'stderr-error') { + log('info', 'MCP stderr pipe broke; shutting down MCP server'); } else { log('info', `MCP shutdown requested: ${reason}`); } - log( - 'info', - `[mcp-lifecycle] ${event} ${JSON.stringify(snapshot)}`, - isCrash || snapshot.anomalies.length > 0 ? { sentry: true } : undefined, - ); - - if (isTransportDisconnectReason(reason)) { - lifecycle.detachProcessHandlers(); - await __closeServerForFastExitForTests(closeableServer); - process.exit(exitCode); - } - - recordMcpLifecycleMetric({ - event, - phase: snapshot.phase, - reason, - uptimeMs: snapshot.uptimeMs, - rssBytes: snapshot.rssBytes, - matchingMcpProcessCount: snapshot.matchingMcpProcessCount, - activeOperationCount: snapshot.activeOperationCount, - watcherRunning: snapshot.watcherRunning, - }); - - for (const anomaly of snapshot.anomalies) { - recordMcpLifecycleAnomalyMetric({ - kind: anomaly, + if (!isTransportDisconnectReason(reason)) { + recordMcpLifecycleMetric({ + event, phase: snapshot.phase, reason, + uptimeMs: snapshot.uptimeMs, + rssBytes: snapshot.rssBytes, + matchingMcpProcessCount: snapshot.matchingMcpProcessCount, + activeOperationCount: snapshot.activeOperationCount, + watcherRunning: snapshot.watcherRunning, }); - } - - if (snapshot.anomalies.length > 0) { - log('warn', `[mcp-lifecycle] observed anomalies: ${snapshot.anomalies.join(', ')}`, { - sentry: true, - }); - } - - if (error !== undefined) { - log('error', `MCP shutdown due to ${reason}: ${String(error)}`, { sentry: true }); - } - - if (reason === 'stdin-end' || reason === 'stdin-close') { - await new Promise((resolve) => setTimeout(resolve, 250)); - } - - let cleanupExitCode = exitCode; - - try { - await stopXcodeStateWatcher(); - } catch (shutdownError) { - cleanupExitCode = 1; - log('error', `Failed to stop Xcode watcher: ${String(shutdownError)}`, { sentry: true }); - } - - try { - await shutdownXcodeToolsBridge(); - } catch (shutdownError) { - cleanupExitCode = 1; - log('error', `Failed to shutdown Xcode tools bridge: ${String(shutdownError)}`, { - sentry: true, - }); - } - try { - await getDefaultDebuggerManager().disposeAll(); - } catch (shutdownError) { - cleanupExitCode = 1; - log('error', `Failed to dispose debugger sessions: ${String(shutdownError)}`, { - sentry: true, - }); + for (const anomaly of snapshot.anomalies) { + recordMcpLifecycleAnomalyMetric({ + kind: anomaly, + phase: snapshot.phase, + reason, + }); + } } - try { - await closeableServer?.close(); - } catch (shutdownError) { - cleanupExitCode = 1; - log('error', `Failed to close MCP server: ${String(shutdownError)}`, { sentry: true }); - } + const result = await runMcpShutdown({ + reason, + error, + snapshot, + server: server ? ({ close: () => server.close() } as Pick) : null, + }); lifecycle.detachProcessHandlers(); - await flushAndCloseSentry(2000); - process.exit(cleanupExitCode); + process.exit(result.exitCode); }, }); diff --git a/src/utils/__tests__/logger.test.ts b/src/utils/__tests__/logger.test.ts index 940c5d52..be87eed2 100644 --- a/src/utils/__tests__/logger.test.ts +++ b/src/utils/__tests__/logger.test.ts @@ -1,7 +1,11 @@ -import { describe, expect, it } from 'vitest'; +import { afterEach, describe, expect, it } from 'vitest'; import { __mapLogLevelToSentryForTests, __shouldCaptureToSentryForTests } from '../logger.ts'; +import { resetShutdownStateForTests, sealSentryCapture } from '../shutdown-state.ts'; describe('logger sentry capture policy', () => { + afterEach(() => { + resetShutdownStateForTests(); + }); it('does not capture by default', () => { expect(__shouldCaptureToSentryForTests()).toBe(false); }); @@ -14,6 +18,11 @@ describe('logger sentry capture policy', () => { expect(__shouldCaptureToSentryForTests({ sentry: true })).toBe(true); }); + it('does not capture after sentry sealing', () => { + sealSentryCapture(); + expect(__shouldCaptureToSentryForTests({ sentry: true })).toBe(false); + }); + it('maps internal levels to Sentry log levels', () => { expect(__mapLogLevelToSentryForTests('emergency')).toBe('fatal'); expect(__mapLogLevelToSentryForTests('warn')).toBe('warn'); diff --git a/src/utils/__tests__/shutdown-state.test.ts b/src/utils/__tests__/shutdown-state.test.ts new file mode 100644 index 00000000..d756255c --- /dev/null +++ b/src/utils/__tests__/shutdown-state.test.ts @@ -0,0 +1,27 @@ +import { afterEach, describe, expect, it } from 'vitest'; +import { + areProcessStdioWritesSuppressed, + isSentryCaptureSealed, + resetShutdownStateForTests, + sealSentryCapture, + suppressProcessStdioWrites, +} from '../shutdown-state.ts'; + +afterEach(() => { + resetShutdownStateForTests(); +}); + +describe('shutdown-state', () => { + it('suppresses stdio writes idempotently', () => { + expect(areProcessStdioWritesSuppressed()).toBe(false); + suppressProcessStdioWrites(); + suppressProcessStdioWrites(); + expect(areProcessStdioWritesSuppressed()).toBe(true); + }); + + it('seals sentry capture', () => { + expect(isSentryCaptureSealed()).toBe(false); + sealSentryCapture(); + expect(isSentryCaptureSealed()).toBe(true); + }); +}); diff --git a/src/utils/debugger/debugger-manager.ts b/src/utils/debugger/debugger-manager.ts index a93092e9..73c56543 100644 --- a/src/utils/debugger/debugger-manager.ts +++ b/src/utils/debugger/debugger-manager.ts @@ -121,20 +121,37 @@ export class DebuggerManager { } async disposeAll(): Promise { + const sessions = Array.from(this.sessions.values()); + this.sessions.clear(); + this.currentSessionId = null; + + const runWithTimeout = async ( + operation: () => Promise, + timeoutMs: number, + ): Promise => { + const timeoutPromise = new Promise<'timed_out'>((resolve) => { + const timer = setTimeout(() => resolve('timed_out'), timeoutMs); + timer.unref?.(); + }); + + await Promise.race([ + operation() + .then(() => 'completed' as const) + .catch(() => 'failed' as const), + timeoutPromise, + ]); + }; + await Promise.allSettled( - Array.from(this.sessions.values()).map(async (session) => { + sessions.map(async (session) => { try { - await session.backend.detach(); - } catch { - // Best-effort cleanup; detach can fail if the process exited. + await runWithTimeout(() => session.backend.detach(), 1000); } finally { - await session.backend.dispose(); + await runWithTimeout(() => session.backend.dispose(), 1000); session.releaseActivity(); } }), ); - this.sessions.clear(); - this.currentSessionId = null; } async addBreakpoint( diff --git a/src/utils/log-capture/device-log-sessions.ts b/src/utils/log-capture/device-log-sessions.ts index 938df930..a5457641 100644 --- a/src/utils/log-capture/device-log-sessions.ts +++ b/src/utils/log-capture/device-log-sessions.ts @@ -1,5 +1,8 @@ import type { ChildProcess } from 'child_process'; import type * as fs from 'fs'; +import { log } from '../logger.ts'; +import { getDefaultFileSystemExecutor } from '../command.ts'; +import type { FileSystemExecutor } from '../FileSystemExecutor.ts'; export interface DeviceLogSession { process: ChildProcess; @@ -12,3 +15,118 @@ export interface DeviceLogSession { } export const activeDeviceLogSessions = new Map(); + +type WriteStreamWithClosed = fs.WriteStream & { closed?: boolean }; + +function createTimeoutPromise(timeoutMs: number): Promise<'timed_out'> { + return new Promise((resolve) => { + const timer = setTimeout(() => resolve('timed_out'), timeoutMs); + timer.unref?.(); + }); +} + +async function ensureStreamClosed(stream: fs.WriteStream, timeoutMs: number): Promise { + const typedStream = stream as WriteStreamWithClosed; + if (typedStream.destroyed || typedStream.closed) { + return; + } + + const closePromise = new Promise<'closed'>((resolve) => { + const onClose = (): void => resolve('closed'); + typedStream.once('close', onClose); + typedStream.end(); + }).catch(() => 'closed' as const); + + const outcome = await Promise.race([closePromise, createTimeoutPromise(timeoutMs)]); + if (outcome === 'timed_out') { + typedStream.destroy(); + } +} + +async function waitForSessionToFinish(session: DeviceLogSession, timeoutMs: number): Promise { + if (session.hasEnded || session.process.exitCode != null) { + session.hasEnded = true; + return; + } + + const closePromise = new Promise<'closed'>((resolve) => { + const onClose = (): void => { + session.hasEnded = true; + resolve('closed'); + }; + session.process.once?.('close', onClose); + }).catch(() => 'closed' as const); + + const outcome = await Promise.race([closePromise, createTimeoutPromise(timeoutMs)]); + if (outcome === 'timed_out') { + session.hasEnded = true; + } +} + +export async function stopDeviceLogSessionById( + logSessionId: string, + fileSystemExecutor: FileSystemExecutor, + options: { timeoutMs?: number; readLogContent?: boolean } = {}, +): Promise<{ logContent: string; error?: string }> { + const session = activeDeviceLogSessions.get(logSessionId); + if (!session) { + return { logContent: '', error: `Device log capture session not found: ${logSessionId}` }; + } + + activeDeviceLogSessions.delete(logSessionId); + + const timeoutMs = options.timeoutMs ?? 1000; + + try { + if (!session.hasEnded && session.process.killed !== true && session.process.exitCode == null) { + session.process.kill?.('SIGTERM'); + } + + await waitForSessionToFinish(session, timeoutMs); + + if (session.logStream) { + await ensureStreamClosed(session.logStream, timeoutMs); + } + + if (options.readLogContent === true) { + if (!fileSystemExecutor.existsSync(session.logFilePath)) { + return { logContent: '', error: `Log file not found: ${session.logFilePath}` }; + } + const fileContent = await fileSystemExecutor.readFile(session.logFilePath, 'utf-8'); + return { logContent: fileContent }; + } + + return { logContent: '' }; + } catch (error) { + const message = error instanceof Error ? error.message : String(error); + return { logContent: '', error: message }; + } finally { + session.releaseActivity?.(); + } +} + +export async function stopAllDeviceLogCaptures(timeoutMs = 1000): Promise<{ + stoppedSessionCount: number; + errorCount: number; + errors: string[]; +}> { + const sessionIds = Array.from(activeDeviceLogSessions.keys()); + const errors: string[] = []; + + for (const sessionId of sessionIds) { + const result = await stopDeviceLogSessionById(sessionId, getDefaultFileSystemExecutor(), { + timeoutMs, + readLogContent: false, + }); + if (result.error) { + errors.push(`${sessionId}: ${result.error}`); + log('warn', `Failed to stop device log capture session ${sessionId}: ${result.error}`); + } + } + + return { + stoppedSessionCount: sessionIds.length - errors.length, + errorCount: errors.length, + errors, + }; +} diff --git a/src/utils/log-capture/index.ts b/src/utils/log-capture/index.ts index 2a25b5c3..544aeda2 100644 --- a/src/utils/log-capture/index.ts +++ b/src/utils/log-capture/index.ts @@ -1,4 +1,9 @@ -import { activeLogSessions, startLogCapture, stopLogCapture } from '../log_capture.ts'; +import { + activeLogSessions, + startLogCapture, + stopAllLogCaptures, + stopLogCapture, +} from '../log_capture.ts'; export type { SubsystemFilter } from '../log_capture.ts'; @@ -6,4 +11,4 @@ export function listActiveSimulatorLogSessionIds(): string[] { return Array.from(activeLogSessions.keys()).sort(); } -export { startLogCapture, stopLogCapture }; +export { startLogCapture, stopLogCapture, stopAllLogCaptures }; diff --git a/src/utils/log_capture.ts b/src/utils/log_capture.ts index 2074dfd8..d8e279d3 100644 --- a/src/utils/log_capture.ts +++ b/src/utils/log_capture.ts @@ -235,46 +235,128 @@ export async function startLogCapture( } } -/** - * Stop a log capture session and retrieve the log content. - */ -export async function stopLogCapture( +interface StopLogSessionOptions { + timeoutMs?: number; + readLogContent?: boolean; + fileSystem: FileSystemExecutor; +} + +interface StopLogSessionResult { + logContent: string; + error?: string; +} + +interface MinimalWritable { + end: () => void; + destroy?: (error?: Error) => void; +} + +function createTimeoutPromise(timeoutMs: number): Promise<'timed_out'> { + return new Promise((resolve) => { + const timer = setTimeout(() => resolve('timed_out'), timeoutMs); + timer.unref?.(); + }); +} + +async function closeLogStreamWithTimeout( + stream: MinimalWritable, + timeoutMs: number, +): Promise { + stream.end(); + const closePromise = finished(stream as Writable) + .then(() => 'closed' as const) + .catch(() => 'closed' as const); + const outcome = await Promise.race([closePromise, createTimeoutPromise(timeoutMs)]); + if (outcome === 'timed_out') { + stream.destroy?.(); + } +} + +async function stopLogSession( logSessionId: string, - fileSystem: FileSystemExecutor = getDefaultFileSystemExecutor(), -): Promise<{ logContent: string; error?: string }> { + options: StopLogSessionOptions, +): Promise { const session = activeLogSessions.get(logSessionId); if (!session) { - log('warn', `Log session not found: ${logSessionId}`); return { logContent: '', error: `Log capture session not found: ${logSessionId}` }; } + activeLogSessions.delete(logSessionId); + try { - log('info', `Attempting to stop log capture session: ${logSessionId}`); - const { logFilePath, logStream } = session; for (const process of session.processes) { if (!process.killed && process.exitCode === null) { process.kill('SIGTERM'); } } - logStream.end(); - await finished(logStream); - session.releaseActivity?.(); - activeLogSessions.delete(logSessionId); - log( - 'info', - `Log capture session ${logSessionId} stopped. Log file retained at: ${logFilePath}`, + + await closeLogStreamWithTimeout( + session.logStream as MinimalWritable, + options.timeoutMs ?? 1000, ); - if (!fileSystem.existsSync(logFilePath)) { - throw new Error(`Log file not found: ${logFilePath}`); + + if (options.readLogContent) { + if (!options.fileSystem.existsSync(session.logFilePath)) { + return { logContent: '', error: `Log file not found: ${session.logFilePath}` }; + } + const fileContent = await options.fileSystem.readFile(session.logFilePath, 'utf-8'); + return { logContent: fileContent }; } - const fileContent = await fileSystem.readFile(logFilePath, 'utf-8'); - log('info', `Successfully read log content from ${logFilePath}`); - return { logContent: fileContent }; + + return { logContent: '' }; } catch (error) { const message = error instanceof Error ? error.message : String(error); - log('error', `Failed to stop log capture session ${logSessionId}: ${message}`); return { logContent: '', error: message }; + } finally { + session.releaseActivity?.(); + } +} + +/** + * Stop a log capture session and retrieve the log content. + */ +export async function stopLogCapture( + logSessionId: string, + fileSystem: FileSystemExecutor = getDefaultFileSystemExecutor(), +): Promise<{ logContent: string; error?: string }> { + const result = await stopLogSession(logSessionId, { + fileSystem, + readLogContent: true, + timeoutMs: 1000, + }); + + if (result.error) { + log('error', `Failed to stop log capture session ${logSessionId}: ${result.error}`); + return { logContent: '', error: result.error }; } + + log('info', `Log capture session ${logSessionId} stopped.`); + return result; +} + +export async function stopAllLogCaptures(timeoutMs = 1000): Promise<{ + stoppedSessionCount: number; + errorCount: number; + errors: string[]; +}> { + const sessionIds = Array.from(activeLogSessions.keys()); + const errors: string[] = []; + for (const sessionId of sessionIds) { + const result = await stopLogSession(sessionId, { + fileSystem: getDefaultFileSystemExecutor(), + readLogContent: false, + timeoutMs, + }); + if (result.error) { + errors.push(`${sessionId}: ${result.error}`); + } + } + + return { + stoppedSessionCount: sessionIds.length - errors.length, + errorCount: errors.length, + errors, + }; } /** diff --git a/src/utils/logger.ts b/src/utils/logger.ts index 2a5ec9e2..0dc9ddf7 100644 --- a/src/utils/logger.ts +++ b/src/utils/logger.ts @@ -20,6 +20,7 @@ import { createWriteStream, type WriteStream } from 'node:fs'; import { createRequire } from 'node:module'; import { resolve } from 'node:path'; +import { areProcessStdioWritesSuppressed, isSentryCaptureSealed } from './shutdown-state.ts'; function isSentryDisabledFromEnv(): boolean { return ( @@ -54,7 +55,7 @@ export interface LogContext { } export function __shouldCaptureToSentryForTests(context?: LogContext): boolean { - return context?.sentry === true; + return context?.sentry === true && !isSentryCaptureSealed(); } // Client-requested log level ("none" means no output unless explicitly enabled) @@ -196,7 +197,9 @@ export function setLogFile(path: string | null): void { logFilePath = null; const message = error instanceof Error ? error.message : String(error); const timestamp = new Date().toISOString(); - console.error(`[${timestamp}] [ERROR] Log file disabled after error: ${message}`); + if (!areProcessStdioWritesSuppressed()) { + console.error(`[${timestamp}] [ERROR] Log file disabled after error: ${message}`); + } }); logFileStream = stream; logFilePath = path; @@ -276,5 +279,9 @@ export function log(level: string, message: string, context?: LogContext): void // Uses stderr to avoid interfering with MCP protocol on stdout // https://modelcontextprotocol.io/docs/tools/debugging#server-side-logging + if (areProcessStdioWritesSuppressed()) { + return; + } + console.error(logMessage); } diff --git a/src/utils/sentry.ts b/src/utils/sentry.ts index 77bf636e..de40502b 100644 --- a/src/utils/sentry.ts +++ b/src/utils/sentry.ts @@ -6,6 +6,7 @@ */ import * as Sentry from '@sentry/node'; import { version } from '../version.ts'; +import { isSentryCaptureSealed } from './shutdown-state.ts'; const USER_HOME_PATH_PATTERN = /\/Users\/[^/\s]+/g; const XCODE_VERSION_PATTERN = /^Xcode\s+(.+)$/m; const XCODE_BUILD_PATTERN = /^Build version\s+(.+)$/m; @@ -232,7 +233,7 @@ function applyRuntimeContext(context: SentryRuntimeContext): void { export function setSentryRuntimeContext(context: SentryRuntimeContext): void { pendingRuntimeContext = context; - if (!initialized || isSentryDisabled() || isTestEnv()) { + if (!initialized || isSentryDisabled() || isTestEnv() || isSentryCaptureSealed()) { return; } @@ -339,7 +340,7 @@ export function initSentry(context?: Pick): void { } export function enrichSentryContext(): void { - if (!initialized || enriched || isSentryDisabled() || isTestEnv()) { + if (!initialized || enriched || isSentryDisabled() || isTestEnv() || isSentryCaptureSealed()) { return; } @@ -366,6 +367,77 @@ export async function flushAndCloseSentry(timeoutMs = 2000): Promise { } } +export type FlushSentryOutcome = 'skipped' | 'flushed' | 'timed_out' | 'failed'; + +export interface McpShutdownSummaryEvent { + reason: string; + phase: string; + exitCode: number; + transportDisconnected: boolean; + triggerError?: string; + cleanupFailureCount: number; + shutdownDurationMs: number; + snapshot: Record; + steps: Array>; +} + +export async function flushSentry(timeoutMs = 2000): Promise { + if (!initialized || isSentryDisabled() || isTestEnv()) { + return 'skipped'; + } + + try { + const flushed = await Sentry.flush(timeoutMs); + return flushed ? 'flushed' : 'timed_out'; + } catch { + return 'failed'; + } +} + +export function captureMcpShutdownSummary(summary: McpShutdownSummaryEvent): void { + if (!initialized || isSentryDisabled() || isTestEnv() || isSentryCaptureSealed()) { + return; + } + + try { + const anomalies = + (summary.snapshot as { anomalies?: unknown }).anomalies && + Array.isArray((summary.snapshot as { anomalies?: unknown }).anomalies) + ? (summary.snapshot as { anomalies: unknown[] }).anomalies.length + : 0; + + const level = + summary.reason === 'startup-failure' || + summary.reason === 'uncaught-exception' || + summary.reason === 'unhandled-rejection' + ? 'error' + : summary.cleanupFailureCount > 0 || anomalies > 0 + ? 'warning' + : 'info'; + + Sentry.captureEvent({ + level, + message: 'mcp.shutdown.summary', + tags: { + runtime: 'mcp', + reason: sanitizeTagValue(summary.reason), + phase: sanitizeTagValue(summary.phase), + }, + extra: { + exitCode: summary.exitCode, + transportDisconnected: summary.transportDisconnected, + triggerError: summary.triggerError, + cleanupFailureCount: summary.cleanupFailureCount, + shutdownDurationMs: summary.shutdownDurationMs, + snapshot: summary.snapshot, + steps: summary.steps, + }, + }); + } catch { + // Shutdown summary is best effort. + } +} + interface ToolInvocationMetric { toolName: string; runtime: SentryToolRuntime; @@ -391,7 +463,7 @@ function sanitizeTagValue(value: string): string { } function shouldEmitMetrics(): boolean { - return initialized && !isSentryDisabled() && !isTestEnv(); + return initialized && !isSentryDisabled() && !isTestEnv() && !isSentryCaptureSealed(); } export function recordToolInvocationMetric(metric: ToolInvocationMetric): void { if (!shouldEmitMetrics()) { diff --git a/src/utils/shutdown-state.ts b/src/utils/shutdown-state.ts new file mode 100644 index 00000000..d6ffc105 --- /dev/null +++ b/src/utils/shutdown-state.ts @@ -0,0 +1,88 @@ +type WritableMethod = (chunk: unknown, encoding?: unknown, callback?: unknown) => boolean; + +interface StdioWriteTarget { + write?: WritableMethod; +} + +let stdioSuppressed = false; +let sentryCaptureSealed = false; +let originalStdoutWrite: WritableMethod | null = null; +let originalStderrWrite: WritableMethod | null = null; + +function createSuppressedWrite(): WritableMethod { + return (chunk: unknown, encoding?: unknown, callback?: unknown): boolean => { + const maybeEncoding = typeof encoding === 'function' ? undefined : encoding; + const maybeCallback = + typeof encoding === 'function' + ? encoding + : typeof callback === 'function' + ? callback + : undefined; + + void chunk; + void maybeEncoding; + + if (typeof maybeCallback === 'function') { + queueMicrotask(() => maybeCallback(null)); + } + + return true; + }; +} + +function setWrite(target: StdioWriteTarget | undefined, write: WritableMethod): void { + if (!target || typeof target.write !== 'function') { + return; + } + target.write = write; +} + +export function suppressProcessStdioWrites(): void { + if (stdioSuppressed) { + return; + } + + const stdout = process.stdout as StdioWriteTarget | undefined; + const stderr = process.stderr as StdioWriteTarget | undefined; + + originalStdoutWrite = typeof stdout?.write === 'function' ? stdout.write.bind(stdout) : null; + originalStderrWrite = typeof stderr?.write === 'function' ? stderr.write.bind(stderr) : null; + + const suppressedWrite = createSuppressedWrite(); + setWrite(stdout, suppressedWrite); + setWrite(stderr, suppressedWrite); + stdioSuppressed = true; +} + +export function restoreProcessStdioWritesForTests(): void { + const stdout = process.stdout as StdioWriteTarget | undefined; + const stderr = process.stderr as StdioWriteTarget | undefined; + + if (originalStdoutWrite) { + setWrite(stdout, originalStdoutWrite); + } + if (originalStderrWrite) { + setWrite(stderr, originalStderrWrite); + } + + originalStdoutWrite = null; + originalStderrWrite = null; + stdioSuppressed = false; +} + +export function areProcessStdioWritesSuppressed(): boolean { + return stdioSuppressed; +} + +export function sealSentryCapture(): void { + sentryCaptureSealed = true; +} + +export function isSentryCaptureSealed(): boolean { + return sentryCaptureSealed; +} + +export function resetShutdownStateForTests(): void { + restoreProcessStdioWritesForTests(); + sentryCaptureSealed = false; +} diff --git a/src/utils/video_capture.ts b/src/utils/video_capture.ts index b3c83771..1cd5c5a4 100644 --- a/src/utils/video_capture.ts +++ b/src/utils/video_capture.ts @@ -28,21 +28,93 @@ export interface AxeHelpers { getBundledAxeEnvironment: () => Record; } +function createTimeoutPromise(timeoutMs: number): Promise<'timed_out'> { + return new Promise((resolve) => { + const timer = setTimeout(() => resolve('timed_out'), timeoutMs); + timer.unref?.(); + }); +} + +async function waitForChildToStop(session: Session, timeoutMs: number): Promise { + const child = session.process as ChildProcess | undefined; + if (!child) { + return; + } + + const alreadyEnded = session.ended || child.exitCode !== null; + const hasSignal = (child as unknown as { signalCode?: string | null }).signalCode != null; + if (alreadyEnded || hasSignal) { + session.ended = true; + return; + } + + const closePromise = new Promise<'closed'>((resolve) => { + let resolved = false; + const finish = (): void => { + if (!resolved) { + resolved = true; + session.ended = true; + resolve('closed'); + } + }; + + child.once('close', finish); + child.once('exit', finish); + }).catch(() => 'closed' as const); + + const outcome = await Promise.race([closePromise, createTimeoutPromise(timeoutMs)]); + if (outcome === 'timed_out') { + try { + child.kill('SIGKILL'); + } catch { + // ignore + } + } +} + +async function stopSession( + simulatorUuid: string, + options: { timeoutMs?: number } = {}, +): Promise<{ sessionId?: string; stdout?: string; parsedPath?: string; error?: string }> { + const session = sessions.get(simulatorUuid); + if (!session) { + return { error: 'No active video recording session for this simulator' }; + } + + sessions.delete(simulatorUuid); + const child = session.process as ChildProcess | undefined; + + try { + child?.kill?.('SIGINT'); + } catch { + try { + child?.kill?.(); + } catch { + // ignore + } + } + + await waitForChildToStop(session, options.timeoutMs ?? 5000); + + const combinedOutput = session.buffer; + const parsedPath = parseLastAbsoluteMp4Path(combinedOutput) ?? undefined; + + session.releaseActivity?.(); + + return { + sessionId: session.sessionId, + stdout: combinedOutput, + parsedPath, + }; +} + function ensureSignalHandlersAttached(): void { if (signalHandlersAttached) return; signalHandlersAttached = true; const stopAll = (): void => { - for (const [simulatorUuid, sess] of sessions) { - try { - const child = sess.process as ChildProcess | undefined; - child?.kill?.('SIGINT'); - } catch { - // ignore - } finally { - sess.releaseActivity?.(); - sessions.delete(simulatorUuid); - } + for (const simulatorUuid of sessions.keys()) { + void stopSession(simulatorUuid, { timeoutMs: 250 }); } }; @@ -71,9 +143,6 @@ export function listActiveVideoCaptureSessionIds(): string[] { return Array.from(sessions.keys()).sort(); } -/** - * Start recording video for a simulator using AXe. - */ export async function startSimulatorVideoCapture( params: { simulatorUuid: string; fps?: number }, executor: CommandExecutor, @@ -128,24 +197,15 @@ export async function startSimulatorVideoCapture( try { child.stdout?.on('data', (d: unknown) => { - try { - session.buffer += String(d ?? ''); - } catch { - // ignore - } + session.buffer += String(d ?? ''); }); child.stderr?.on('data', (d: unknown) => { - try { - session.buffer += String(d ?? ''); - } catch { - // ignore - } + session.buffer += String(d ?? ''); }); } catch { // ignore stream listener setup failures } - // Track when the child process naturally ends, so stop can short-circuit try { child.once?.('exit', () => { session.ended = true; @@ -167,9 +227,6 @@ export async function startSimulatorVideoCapture( }; } -/** - * Stop recording video for a simulator. Returns aggregated output and parsed MP4 path if found. - */ export async function stopSimulatorVideoCapture( params: { simulatorUuid: string }, executor: CommandExecutor, @@ -180,7 +237,6 @@ export async function stopSimulatorVideoCapture( parsedPath?: string; error?: string; }> { - // Mark executor as used to satisfy lint rule void executor; const simulatorUuid = params.simulatorUuid; @@ -188,68 +244,42 @@ export async function stopSimulatorVideoCapture( return { stopped: false, error: 'simulatorUuid is required' }; } - const session = sessions.get(simulatorUuid); - if (!session) { - return { stopped: false, error: 'No active video recording session for this simulator' }; + const result = await stopSession(simulatorUuid, { timeoutMs: 5000 }); + if (result.error) { + return { stopped: false, error: result.error }; } - const child = session.process as ChildProcess | undefined; - - // Attempt graceful shutdown - try { - child?.kill?.('SIGINT'); - } catch { - try { - child?.kill?.(); - } catch { - // ignore - } - } - - // Wait for process to close (avoid hanging if it already exited) - await new Promise((resolve): void => { - if (!child) return resolve(); - - // If process has already ended, resolve immediately - const alreadyEnded = (session as Session).ended === true; - const hasExitCode = (child as ChildProcess).exitCode !== null; - const hasSignal = (child as unknown as { signalCode?: string | null }).signalCode != null; - if (alreadyEnded || hasExitCode || hasSignal) { - return resolve(); - } - - let resolved = false; - const finish = (): void => { - if (!resolved) { - resolved = true; - resolve(); - } - }; - try { - child.once('close', finish); - child.once('exit', finish); - } catch { - return finish(); - } - // Safety timeout to prevent indefinite hangs - setTimeout(finish, 5000); - }); - - const combinedOutput = session.buffer; - const parsedPath = parseLastAbsoluteMp4Path(combinedOutput) ?? undefined; - - session.releaseActivity?.(); - sessions.delete(simulatorUuid); - log( 'info', - `Stopped AXe video recording for simulator ${simulatorUuid}. ${parsedPath ? `Detected file: ${parsedPath}` : 'No file detected in output.'}`, + `Stopped AXe video recording for simulator ${simulatorUuid}. ${result.parsedPath ? `Detected file: ${result.parsedPath}` : 'No file detected in output.'}`, ); return { stopped: true, - sessionId: session.sessionId, - stdout: combinedOutput, - parsedPath, + sessionId: result.sessionId, + stdout: result.stdout, + parsedPath: result.parsedPath, + }; +} + +export async function stopAllVideoCaptureSessions(timeoutMs = 1000): Promise<{ + stoppedSessionCount: number; + errorCount: number; + errors: string[]; +}> { + const simulatorIds = Array.from(sessions.keys()); + const errors: string[] = []; + + for (const simulatorUuid of simulatorIds) { + const result = await stopSession(simulatorUuid, { timeoutMs }); + if (result.error) { + errors.push(`${simulatorUuid}: ${result.error}`); + } + } + + return { + stoppedSessionCount: simulatorIds.length - errors.length, + errorCount: errors.length, + errors, }; } From f2e1f70290c5fd93f7ec9eff1af4a49c475f9d68 Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Mon, 16 Mar 2026 14:42:50 +0000 Subject: [PATCH 6/8] fix(swift-package): Wait for real process exit after SIGTERM Do not treat ChildProcess.killed as an exit signal when deciding whether\nto skip termination waits. The killed flag means a signal was sent,\nnot that the process has exited.\n\nUse exitCode/signalCode to detect actual exit, and keep bounded\nwait+SIGKILL behavior intact for stuck processes.\n\nAdd regression coverage that sets killed=true without an exit event\nand verifies we still escalate from SIGTERM to SIGKILL. Co-Authored-By: OpenAI Codex --- .../__tests__/active-processes.test.ts | 29 +++++++++++++++++++ .../tools/swift-package/active-processes.ts | 3 +- 2 files changed, 31 insertions(+), 1 deletion(-) diff --git a/src/mcp/tools/swift-package/__tests__/active-processes.test.ts b/src/mcp/tools/swift-package/__tests__/active-processes.test.ts index 06eb57ba..86244a11 100644 --- a/src/mcp/tools/swift-package/__tests__/active-processes.test.ts +++ b/src/mcp/tools/swift-package/__tests__/active-processes.test.ts @@ -10,6 +10,7 @@ import { addProcess, removeProcess, clearAllProcesses, + terminateTrackedProcess, type ProcessInfo, } from '../active-processes.ts'; import { @@ -213,6 +214,34 @@ describe('active-processes module', () => { }); }); + describe('process termination helper', () => { + it('does not treat killed=true as exited after SIGTERM', async () => { + const signals: string[] = []; + + addProcess(4242, { + process: { + kill: (signal?: string) => { + signals.push(signal ?? 'SIGTERM'); + }, + on: () => { + // never emits exit; allow timeout path + }, + killed: true, + exitCode: null, + signalCode: null, + pid: 4242, + }, + startedAt: new Date('2023-01-01T00:00:00.000Z'), + }); + + const result = await terminateTrackedProcess(4242, 25); + + expect(result.status).toBe('terminated'); + expect(result.usedForceKill).toBe(true); + expect(signals).toEqual(['SIGTERM', 'SIGKILL']); + }); + }); + describe('ProcessInfo interface', () => { it('should work with complete process object', () => { const mockProcess = { diff --git a/src/mcp/tools/swift-package/active-processes.ts b/src/mcp/tools/swift-package/active-processes.ts index a5807b2b..7168a1de 100644 --- a/src/mcp/tools/swift-package/active-processes.ts +++ b/src/mcp/tools/swift-package/active-processes.ts @@ -11,6 +11,7 @@ interface TrackedProcess { removeListener?: (event: string, callback: () => void) => void; pid?: number; exitCode?: number | null; + signalCode?: string | null; killed?: boolean; } @@ -64,7 +65,7 @@ async function terminateProcess( return { error: error instanceof Error ? error.message : String(error) }; } - const alreadyExited = info.process.exitCode != null || info.process.killed === true; + const alreadyExited = info.process.exitCode != null || info.process.signalCode != null; if (alreadyExited) { return {}; } From 60ae62f5ba09d4f04d16388cfa65207300d88d75 Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Mon, 16 Mar 2026 15:09:36 +0000 Subject: [PATCH 7/8] fix(mcp): Bound shutdown cleanup budgets and race handling Scale bulk cleanup step timeouts to the tracked item counts so sequential\ncleanup work is not prematurely cut off by the outer step timer.\n\nHarden runStep timeout racing by consuming late operation rejections and\nreturning a structured failed outcome instead of risking unhandled\nrejections during shutdown.\n\nTrack the parent hard-exit helper script used by the lifecycle repro so\n--shutdown-mode parent-hard-exit works from a clean checkout.\n\nAdd shutdown regression coverage for expanded bulk timeout budgeting. Co-Authored-By: OpenAI Codex --- scripts/repro-mcp-parent-exit-helper.mjs | 21 +++++ src/server/__tests__/mcp-shutdown.test.ts | 41 ++++++++++ src/server/mcp-shutdown.ts | 93 +++++++++++++++++------ 3 files changed, 131 insertions(+), 24 deletions(-) create mode 100644 scripts/repro-mcp-parent-exit-helper.mjs diff --git a/scripts/repro-mcp-parent-exit-helper.mjs b/scripts/repro-mcp-parent-exit-helper.mjs new file mode 100644 index 00000000..9870311c --- /dev/null +++ b/scripts/repro-mcp-parent-exit-helper.mjs @@ -0,0 +1,21 @@ +import { spawn } from 'node:child_process'; +import process from 'node:process'; + +const [nodeExecPath, cliPath, cwd, exitDelayMsRaw] = process.argv.slice(2); +const exitDelayMs = Number(exitDelayMsRaw ?? 0); + +if (!nodeExecPath || !cliPath || !cwd || !Number.isFinite(exitDelayMs) || exitDelayMs < 0) { + console.error('Usage: node repro-mcp-parent-exit-helper.mjs '); + process.exit(2); +} + +const child = spawn(nodeExecPath, [cliPath, 'mcp'], { + cwd, + stdio: ['pipe', 'pipe', 'pipe'], +}); + +process.stdout.write(`${child.pid}\n`); + +setTimeout(() => { + process.exit(0); +}, exitDelayMs); diff --git a/src/server/__tests__/mcp-shutdown.test.ts b/src/server/__tests__/mcp-shutdown.test.ts index c7617689..7196d76f 100644 --- a/src/server/__tests__/mcp-shutdown.test.ts +++ b/src/server/__tests__/mcp-shutdown.test.ts @@ -56,6 +56,10 @@ vi.mock('../../utils/shutdown-state.ts', () => ({ import { runMcpShutdown } from '../mcp-shutdown.ts'; +function wait(ms: number): Promise { + return new Promise((resolve) => setTimeout(resolve, ms)); +} + describe('runMcpShutdown', () => { beforeEach(() => { vi.clearAllMocks(); @@ -101,4 +105,41 @@ describe('runMcpShutdown', () => { expect(mocks.stopAllVideoCaptureSessions).toHaveBeenCalledTimes(1); expect(mocks.stopAllTrackedProcesses).toHaveBeenCalledTimes(1); }); + + it('uses an expanded timeout budget for sequential bulk cleanup steps', async () => { + mocks.stopAllLogCaptures.mockImplementationOnce(async () => { + await wait(1100); + return { stoppedSessionCount: 2, errorCount: 0, errors: [] }; + }); + + const result = await runMcpShutdown({ + reason: 'sigterm', + snapshot: { + pid: 1, + ppid: 1, + orphaned: false, + phase: 'running', + shutdownReason: 'sigterm', + uptimeMs: 100, + rssBytes: 1, + heapUsedBytes: 1, + watcherRunning: false, + watchedPath: null, + activeOperationCount: 0, + activeOperationByCategory: {}, + debuggerSessionCount: 0, + simulatorLogSessionCount: 2, + deviceLogSessionCount: 0, + videoCaptureSessionCount: 0, + swiftPackageProcessCount: 0, + matchingMcpProcessCount: 0, + matchingMcpPeerSummary: [], + anomalies: [], + }, + server: { close: async () => undefined }, + }); + + const simulatorLogsStep = result.steps.find((step) => step.name === 'simulator-logs.stop-all'); + expect(simulatorLogsStep?.status).toBe('completed'); + }); }); diff --git a/src/server/mcp-shutdown.ts b/src/server/mcp-shutdown.ts index 6f964fb8..ab4e4dae 100644 --- a/src/server/mcp-shutdown.ts +++ b/src/server/mcp-shutdown.ts @@ -37,6 +37,11 @@ interface ShutdownStepOutcome { error?: string; } +type RunStepRaceOutcome = + | { kind: 'value'; value: T } + | { kind: 'error'; error: string } + | { kind: 'timed_out' }; + export interface McpShutdownResult { exitCode: number; transportDisconnected: boolean; @@ -63,14 +68,19 @@ async function runStep( let timeoutHandle: NodeJS.Timeout | null = null; try { - const timeoutPromise = new Promise<'timed_out'>((resolve) => { - timeoutHandle = createTimer(timeoutMs, () => resolve('timed_out')); + const timeoutPromise = new Promise>((resolve) => { + timeoutHandle = createTimer(timeoutMs, () => resolve({ kind: 'timed_out' })); }); - const operationPromise = operation(); - const outcome = await Promise.race([ - operationPromise.then((value) => ({ kind: 'value' as const, value })), - timeoutPromise.then(() => ({ kind: 'timed_out' as const })), - ]); + + const operationOutcome = operation() + .then((value): RunStepRaceOutcome => ({ kind: 'value', value })) + .catch( + (error): RunStepRaceOutcome => ({ + kind: 'error', + error: stringifyError(error), + }), + ); + const outcome = await Promise.race([operationOutcome, timeoutPromise]); if (outcome.kind === 'timed_out') { return { @@ -79,17 +89,19 @@ async function runStep( }; } + if (outcome.kind === 'error') { + return { + status: 'failed', + durationMs: Date.now() - startedAt, + error: outcome.error, + }; + } + return { status: 'completed', durationMs: Date.now() - startedAt, value: outcome.value, }; - } catch (error) { - return { - status: 'failed', - durationMs: Date.now() - startedAt, - error: stringifyError(error), - }; } finally { if (timeoutHandle) { clearTimeout(timeoutHandle); @@ -152,19 +164,52 @@ export async function runMcpShutdown(input: { }); pushStep('server.close', serverCloseOutcome); - const cleanupSteps: Array<[string, () => Promise]> = [ - ['watcher.stop', () => stopXcodeStateWatcher()], - ['xcode-tools-bridge.shutdown', () => shutdownXcodeToolsBridge()], - ['debugger.dispose-all', () => getDefaultDebuggerManager().disposeAll()], - ['simulator-logs.stop-all', () => stopAllLogCaptures(STEP_TIMEOUT_MS)], - ['device-logs.stop-all', () => stopAllDeviceLogCaptures(STEP_TIMEOUT_MS)], - ['video-capture.stop-all', () => stopAllVideoCaptureSessions(STEP_TIMEOUT_MS)], - ['swift-processes.stop-all', () => stopAllTrackedProcesses(STEP_TIMEOUT_MS)], + const perItemTimeoutMs = STEP_TIMEOUT_MS; + const bulkStepTimeoutMs = (itemCount: number): number => { + return Math.max(STEP_TIMEOUT_MS, itemCount * perItemTimeoutMs); + }; + + const cleanupSteps: Array<{ + name: string; + timeoutMs: number; + operation: () => Promise; + }> = [ + { name: 'watcher.stop', timeoutMs: STEP_TIMEOUT_MS, operation: () => stopXcodeStateWatcher() }, + { + name: 'xcode-tools-bridge.shutdown', + timeoutMs: STEP_TIMEOUT_MS, + operation: () => shutdownXcodeToolsBridge(), + }, + { + name: 'debugger.dispose-all', + timeoutMs: STEP_TIMEOUT_MS, + operation: () => getDefaultDebuggerManager().disposeAll(), + }, + { + name: 'simulator-logs.stop-all', + timeoutMs: bulkStepTimeoutMs(input.snapshot.simulatorLogSessionCount), + operation: () => stopAllLogCaptures(perItemTimeoutMs), + }, + { + name: 'device-logs.stop-all', + timeoutMs: bulkStepTimeoutMs(input.snapshot.deviceLogSessionCount), + operation: () => stopAllDeviceLogCaptures(perItemTimeoutMs), + }, + { + name: 'video-capture.stop-all', + timeoutMs: bulkStepTimeoutMs(input.snapshot.videoCaptureSessionCount), + operation: () => stopAllVideoCaptureSessions(perItemTimeoutMs), + }, + { + name: 'swift-processes.stop-all', + timeoutMs: bulkStepTimeoutMs(input.snapshot.swiftPackageProcessCount), + operation: () => stopAllTrackedProcesses(perItemTimeoutMs), + }, ]; - for (const [name, operation] of cleanupSteps) { - const outcome = await runStep(name, STEP_TIMEOUT_MS, operation); - pushStep(name, outcome); + for (const cleanupStep of cleanupSteps) { + const outcome = await runStep(cleanupStep.name, cleanupStep.timeoutMs, cleanupStep.operation); + pushStep(cleanupStep.name, outcome); } const triggerError = input.error === undefined ? undefined : stringifyError(input.error); From 0cf824ba854dd6f815cdc39f572f5b2608dcf598 Mon Sep 17 00:00:00 2001 From: Cameron Cooke Date: Mon, 16 Mar 2026 15:35:35 +0000 Subject: [PATCH 8/8] fix(mcp): Add shutdown timeout headroom Add explicit outer-step headroom for bulk cleanup so one-item and multi-item\nsteps are less likely to report false timeouts at the boundary.\n\nIncrease debugger dispose-all shutdown budget based on active session\ncount to align with debugger manager detach/dispose behavior.\n\nAdd regression coverage for one-item bulk headroom and debugger\ndispose-all timeout budgeting. Co-Authored-By: OpenAI Codex --- src/server/__tests__/mcp-shutdown.test.ts | 75 ++++++++++++++++++++++- src/server/mcp-shutdown.ts | 18 +++++- 2 files changed, 90 insertions(+), 3 deletions(-) diff --git a/src/server/__tests__/mcp-shutdown.test.ts b/src/server/__tests__/mcp-shutdown.test.ts index 7196d76f..24146acf 100644 --- a/src/server/__tests__/mcp-shutdown.test.ts +++ b/src/server/__tests__/mcp-shutdown.test.ts @@ -106,7 +106,44 @@ describe('runMcpShutdown', () => { expect(mocks.stopAllTrackedProcesses).toHaveBeenCalledTimes(1); }); - it('uses an expanded timeout budget for sequential bulk cleanup steps', async () => { + it('adds outer timeout headroom for one-item bulk cleanup', async () => { + mocks.stopAllLogCaptures.mockImplementationOnce(async () => { + await wait(1050); + return { stoppedSessionCount: 1, errorCount: 0, errors: [] }; + }); + + const result = await runMcpShutdown({ + reason: 'sigterm', + snapshot: { + pid: 1, + ppid: 1, + orphaned: false, + phase: 'running', + shutdownReason: 'sigterm', + uptimeMs: 100, + rssBytes: 1, + heapUsedBytes: 1, + watcherRunning: false, + watchedPath: null, + activeOperationCount: 0, + activeOperationByCategory: {}, + debuggerSessionCount: 0, + simulatorLogSessionCount: 1, + deviceLogSessionCount: 0, + videoCaptureSessionCount: 0, + swiftPackageProcessCount: 0, + matchingMcpProcessCount: 0, + matchingMcpPeerSummary: [], + anomalies: [], + }, + server: { close: async () => undefined }, + }); + + const simulatorLogsStep = result.steps.find((step) => step.name === 'simulator-logs.stop-all'); + expect(simulatorLogsStep?.status).toBe('completed'); + }); + + it('uses an expanded timeout budget for sequential multi-item bulk cleanup steps', async () => { mocks.stopAllLogCaptures.mockImplementationOnce(async () => { await wait(1100); return { stoppedSessionCount: 2, errorCount: 0, errors: [] }; @@ -142,4 +179,40 @@ describe('runMcpShutdown', () => { const simulatorLogsStep = result.steps.find((step) => step.name === 'simulator-logs.stop-all'); expect(simulatorLogsStep?.status).toBe('completed'); }); + + it('uses a larger timeout budget for debugger dispose-all', async () => { + mocks.disposeAll.mockImplementationOnce(async () => { + await wait(1500); + }); + + const result = await runMcpShutdown({ + reason: 'sigterm', + snapshot: { + pid: 1, + ppid: 1, + orphaned: false, + phase: 'running', + shutdownReason: 'sigterm', + uptimeMs: 100, + rssBytes: 1, + heapUsedBytes: 1, + watcherRunning: false, + watchedPath: null, + activeOperationCount: 0, + activeOperationByCategory: {}, + debuggerSessionCount: 1, + simulatorLogSessionCount: 0, + deviceLogSessionCount: 0, + videoCaptureSessionCount: 0, + swiftPackageProcessCount: 0, + matchingMcpProcessCount: 0, + matchingMcpPeerSummary: [], + anomalies: [], + }, + server: { close: async () => undefined }, + }); + + const debuggerStep = result.steps.find((step) => step.name === 'debugger.dispose-all'); + expect(debuggerStep?.status).toBe('completed'); + }); }); diff --git a/src/server/mcp-shutdown.ts b/src/server/mcp-shutdown.ts index ab4e4dae..d7183c51 100644 --- a/src/server/mcp-shutdown.ts +++ b/src/server/mcp-shutdown.ts @@ -18,6 +18,8 @@ import { isTransportDisconnectReason } from './mcp-lifecycle.ts'; const DISCONNECT_SERVER_CLOSE_TIMEOUT_MS = 150; const DEFAULT_SERVER_CLOSE_TIMEOUT_MS = 1000; const STEP_TIMEOUT_MS = 1000; +const STEP_TIMEOUT_HEADROOM_MS = 100; +const DEBUGGER_STEP_BASE_TIMEOUT_MS = 2200; const DISCONNECT_FLUSH_TIMEOUT_MS = 250; const DEFAULT_FLUSH_TIMEOUT_MS = 1500; @@ -166,7 +168,19 @@ export async function runMcpShutdown(input: { const perItemTimeoutMs = STEP_TIMEOUT_MS; const bulkStepTimeoutMs = (itemCount: number): number => { - return Math.max(STEP_TIMEOUT_MS, itemCount * perItemTimeoutMs); + const boundedCount = Math.max(1, itemCount); + return Math.max( + STEP_TIMEOUT_MS + STEP_TIMEOUT_HEADROOM_MS, + boundedCount * perItemTimeoutMs + STEP_TIMEOUT_HEADROOM_MS, + ); + }; + + const debuggerStepTimeoutMs = (debuggerSessionCount: number): number => { + const boundedCount = Math.max(1, debuggerSessionCount); + return Math.max( + DEBUGGER_STEP_BASE_TIMEOUT_MS, + boundedCount * STEP_TIMEOUT_MS + STEP_TIMEOUT_HEADROOM_MS, + ); }; const cleanupSteps: Array<{ @@ -182,7 +196,7 @@ export async function runMcpShutdown(input: { }, { name: 'debugger.dispose-all', - timeoutMs: STEP_TIMEOUT_MS, + timeoutMs: debuggerStepTimeoutMs(input.snapshot.debuggerSessionCount), operation: () => getDefaultDebuggerManager().disposeAll(), }, {