diff --git a/src/server.ts b/src/server.ts index 62848df0..a497ca7b 100644 --- a/src/server.ts +++ b/src/server.ts @@ -651,12 +651,20 @@ server.setRequestHandler(ListToolsRequestSchema, async () => { STATES DETECTED: Process waiting for input (shows prompt) - Process finished execution + Process finished execution Process running (use read_process_output) - + + PERFORMANCE DEBUGGING (verbose_timing parameter): + Set verbose_timing: true to get detailed timing information including: + - Exit reason (early_exit_quick_pattern, early_exit_periodic_check, process_exit, timeout) + - Total duration and time to first output + - Complete timeline of all output events with timestamps + - Which detection mechanism triggered early exit + Use this to identify missed optimization opportunities and improve detection patterns. + ALWAYS USE FOR: Local file analysis, CSV processing, data exploration, system commands NEVER USE ANALYSIS TOOL FOR: Local file access (analysis tool is browser-only and WILL FAIL) - + ${PATH_GUIDANCE} ${CMD_PREFIX_DESCRIPTION}`, inputSchema: zodToJsonSchema(StartProcessArgsSchema), @@ -690,7 +698,15 @@ server.setRequestHandler(ListToolsRequestSchema, async () => { Process waiting for input (ready for interact_with_process) Process finished execution Timeout reached (may still be running) - + + PERFORMANCE DEBUGGING (verbose_timing parameter): + Set verbose_timing: true to get detailed timing information including: + - Exit reason (early_exit_quick_pattern, early_exit_periodic_check, process_finished, timeout) + - Total duration and time to first output + - Complete timeline of all output events with timestamps + - Which detection mechanism triggered early exit + Use this to identify when timeouts could be reduced or detection patterns improved. + ${CMD_PREFIX_DESCRIPTION}`, inputSchema: zodToJsonSchema(ReadProcessOutputArgsSchema), annotations: { @@ -741,12 +757,21 @@ server.setRequestHandler(ListToolsRequestSchema, async () => { - input: Code/command to execute - timeout_ms: Max wait (default: 8000ms) - wait_for_prompt: Auto-wait for response (default: true) - + - verbose_timing: Enable detailed performance telemetry (default: false) + Returns execution result with status indicators. - + + PERFORMANCE DEBUGGING (verbose_timing parameter): + Set verbose_timing: true to get detailed timing information including: + - Exit reason (early_exit_quick_pattern, early_exit_periodic_check, process_finished, timeout, no_wait) + - Total duration and time to first output + - Complete timeline of all output events with timestamps + - Which detection mechanism triggered early exit + Use this to identify slow interactions and optimize detection patterns. + ALWAYS USE FOR: CSV analysis, JSON processing, file statistics, data visualization prep, ANY local file work NEVER USE ANALYSIS TOOL FOR: Local file access (it cannot read files from disk and WILL FAIL) - + ${CMD_PREFIX_DESCRIPTION}`, inputSchema: zodToJsonSchema(InteractWithProcessArgsSchema), annotations: { diff --git a/src/terminal-manager.ts b/src/terminal-manager.ts index 00486b58..d5ce2e1c 100644 --- a/src/terminal-manager.ts +++ b/src/terminal-manager.ts @@ -1,5 +1,5 @@ import { spawn } from 'child_process'; -import { TerminalSession, CommandExecutionResult, ActiveSession } from './types.js'; +import { TerminalSession, CommandExecutionResult, ActiveSession, TimingInfo, OutputEvent } from './types.js'; import { DEFAULT_COMMAND_TIMEOUT } from './config.js'; import { configManager } from './config-manager.js'; import {capture} from "./utils/capture.js"; @@ -43,7 +43,7 @@ export class TerminalManager { } } - async executeCommand(command: string, timeoutMs: number = DEFAULT_COMMAND_TIMEOUT, shell?: string): Promise { + async executeCommand(command: string, timeoutMs: number = DEFAULT_COMMAND_TIMEOUT, shell?: string, collectTiming: boolean = false): Promise { // Get the shell from config if not specified let shellToUse: string | boolean | undefined = shell; if (!shellToUse) { @@ -55,29 +55,29 @@ export class TerminalManager { shellToUse = true; } } - + // For REPL interactions, we need to ensure stdin, stdout, and stderr are properly configured // Note: No special stdio options needed here, Node.js handles pipes by default - + // Enhance SSH commands automatically let enhancedCommand = command; if (command.trim().startsWith('ssh ') && !command.includes(' -t')) { enhancedCommand = command.replace(/^ssh /, 'ssh -t '); console.log(`Enhanced SSH command: ${enhancedCommand}`); } - - const spawnOptions: any = { + + const spawnOptions: any = { shell: shellToUse, env: { ...process.env, TERM: 'xterm-256color' // Better terminal compatibility } }; - + // Spawn the process with an empty array of arguments and our options const childProcess = spawn(enhancedCommand, [], spawnOptions); let output = ''; - + // Ensure childProcess.pid is defined before proceeding if (!childProcess.pid) { // Return a consistent error object instead of throwing @@ -87,7 +87,7 @@ export class TerminalManager { isBlocked: false }; } - + const session: TerminalSession = { pid: childProcess.pid, process: childProcess, @@ -95,31 +95,76 @@ export class TerminalManager { isBlocked: false, startTime: new Date() }; - + this.sessions.set(childProcess.pid, session); + // Timing telemetry + const startTime = Date.now(); + let firstOutputTime: number | undefined; + let lastOutputTime: number | undefined; + const outputEvents: OutputEvent[] = []; + let exitReason: TimingInfo['exitReason'] = 'timeout'; + return new Promise((resolve) => { let resolved = false; let periodicCheck: NodeJS.Timeout | null = null; - + // Quick prompt patterns for immediate detection const quickPromptPatterns = />>>\s*$|>\s*$|\$\s*$|#\s*$/; - + const resolveOnce = (result: CommandExecutionResult) => { if (resolved) return; resolved = true; if (periodicCheck) clearInterval(periodicCheck); + + // Add timing info if requested + if (collectTiming) { + const endTime = Date.now(); + result.timingInfo = { + startTime, + endTime, + totalDurationMs: endTime - startTime, + exitReason, + firstOutputTime, + lastOutputTime, + timeToFirstOutputMs: firstOutputTime ? firstOutputTime - startTime : undefined, + outputEvents: outputEvents.length > 0 ? outputEvents : undefined + }; + } + resolve(result); }; childProcess.stdout.on('data', (data: any) => { const text = data.toString(); + const now = Date.now(); + + if (!firstOutputTime) firstOutputTime = now; + lastOutputTime = now; + output += text; session.lastOutput += text; - + + // Record output event if collecting timing + if (collectTiming) { + outputEvents.push({ + timestamp: now, + deltaMs: now - startTime, + source: 'stdout', + length: text.length, + snippet: text.slice(0, 50).replace(/\n/g, '\\n') + }); + } + // Immediate check for obvious prompts if (quickPromptPatterns.test(text)) { session.isBlocked = true; + exitReason = 'early_exit_quick_pattern'; + + if (collectTiming && outputEvents.length > 0) { + outputEvents[outputEvents.length - 1].matchedPattern = 'quick_pattern'; + } + resolveOnce({ pid: childProcess.pid!, output, @@ -130,8 +175,24 @@ export class TerminalManager { childProcess.stderr.on('data', (data: any) => { const text = data.toString(); + const now = Date.now(); + + if (!firstOutputTime) firstOutputTime = now; + lastOutputTime = now; + output += text; session.lastOutput += text; + + // Record output event if collecting timing + if (collectTiming) { + outputEvents.push({ + timestamp: now, + deltaMs: now - startTime, + source: 'stderr', + length: text.length, + snippet: text.slice(0, 50).replace(/\n/g, '\\n') + }); + } }); // Periodic comprehensive check every 100ms @@ -140,6 +201,7 @@ export class TerminalManager { const processState = analyzeProcessState(output, childProcess.pid); if (processState.isWaitingForInput) { session.isBlocked = true; + exitReason = 'early_exit_periodic_check'; resolveOnce({ pid: childProcess.pid!, output, @@ -152,6 +214,7 @@ export class TerminalManager { // Timeout fallback setTimeout(() => { session.isBlocked = true; + exitReason = 'timeout'; resolveOnce({ pid: childProcess.pid!, output, @@ -169,15 +232,16 @@ export class TerminalManager { startTime: session.startTime, endTime: new Date() }); - + // Keep only last 100 completed sessions if (this.completedSessions.size > 100) { const oldestKey = Array.from(this.completedSessions.keys())[0]; this.completedSessions.delete(oldestKey); } - + this.sessions.delete(childProcess.pid); } + exitReason = 'process_exit'; resolveOnce({ pid: childProcess.pid!, output, diff --git a/src/tools/improved-process-tools.ts b/src/tools/improved-process-tools.ts index 984e1bf5..3764c489 100644 --- a/src/tools/improved-process-tools.ts +++ b/src/tools/improved-process-tools.ts @@ -63,7 +63,8 @@ export async function startProcess(args: unknown): Promise { const result = await terminalManager.executeCommand( parsed.data.command, parsed.data.timeout_ms, - shellUsed + shellUsed, + parsed.data.verbose_timing || false ); if (result.pid === -1) { @@ -75,7 +76,7 @@ export async function startProcess(args: unknown): Promise { // Analyze the process state to detect if it's waiting for input const processState = analyzeProcessState(result.output, result.pid); - + let statusMessage = ''; if (processState.isWaitingForInput) { statusMessage = `\n๐Ÿ”„ ${formatProcessStateMessage(processState, result.pid)}`; @@ -85,14 +86,47 @@ export async function startProcess(args: unknown): Promise { statusMessage = '\nโณ Process is running. Use read_process_output to get more output.'; } + // Add timing information if requested + let timingMessage = ''; + if (result.timingInfo) { + timingMessage = formatTimingInfo(result.timingInfo); + } + return { content: [{ type: "text", - text: `Process started with PID ${result.pid} (shell: ${shellUsed})\nInitial output:\n${result.output}${statusMessage}` + text: `Process started with PID ${result.pid} (shell: ${shellUsed})\nInitial output:\n${result.output}${statusMessage}${timingMessage}` }], }; } +function formatTimingInfo(timing: any): string { + let msg = '\n\n๐Ÿ“Š Timing Information:\n'; + msg += ` Exit Reason: ${timing.exitReason}\n`; + msg += ` Total Duration: ${timing.totalDurationMs}ms\n`; + + if (timing.timeToFirstOutputMs !== undefined) { + msg += ` Time to First Output: ${timing.timeToFirstOutputMs}ms\n`; + } + + if (timing.firstOutputTime && timing.lastOutputTime) { + msg += ` Output Window: ${timing.lastOutputTime - timing.firstOutputTime}ms\n`; + } + + if (timing.outputEvents && timing.outputEvents.length > 0) { + msg += `\n Output Events (${timing.outputEvents.length} total):\n`; + timing.outputEvents.forEach((event: any, idx: number) => { + msg += ` [${idx + 1}] +${event.deltaMs}ms | ${event.source} | ${event.length}b`; + if (event.matchedPattern) { + msg += ` | ๐ŸŽฏ ${event.matchedPattern}`; + } + msg += `\n "${event.snippet}"\n`; + }); + } + + return msg; +} + /** * Read output from a running process (renamed from read_output) * Includes early detection of process waiting for input @@ -106,7 +140,7 @@ export async function readProcessOutput(args: unknown): Promise { }; } - const { pid, timeout_ms = 5000 } = parsed.data; + const { pid, timeout_ms = 5000, verbose_timing = false } = parsed.data; const session = terminalManager.getSession(pid); if (!session) { @@ -120,7 +154,7 @@ export async function readProcessOutput(args: unknown): Promise { }], }; } - + // Neither active nor completed session found return { content: [{ type: "text", text: `No session found for PID ${pid}` }], @@ -133,15 +167,37 @@ export async function readProcessOutput(args: unknown): Promise { let earlyExit = false; let processState: ProcessState | undefined; + // Timing telemetry + const startTime = Date.now(); + let firstOutputTime: number | undefined; + let lastOutputTime: number | undefined; + const outputEvents: any[] = []; + let exitReason: 'early_exit_quick_pattern' | 'early_exit_periodic_check' | 'process_finished' | 'timeout' = 'timeout'; + try { const outputPromise: Promise = new Promise((resolve) => { const initialOutput = terminalManager.getNewOutput(pid); if (initialOutput && initialOutput.length > 0) { + const now = Date.now(); + if (!firstOutputTime) firstOutputTime = now; + lastOutputTime = now; + + if (verbose_timing) { + outputEvents.push({ + timestamp: now, + deltaMs: now - startTime, + source: 'initial_poll', + length: initialOutput.length, + snippet: initialOutput.slice(0, 50).replace(/\n/g, '\\n') + }); + } + // Immediate check on existing output const state = analyzeProcessState(initialOutput, pid); if (state.isWaitingForInput) { earlyExit = true; processState = state; + exitReason = 'early_exit_periodic_check'; } resolve(initialOutput); return; @@ -150,7 +206,7 @@ export async function readProcessOutput(args: unknown): Promise { let resolved = false; let interval: NodeJS.Timeout | null = null; let timeout: NodeJS.Timeout | null = null; - + // Quick prompt patterns for immediate detection const quickPromptPatterns = />>>\s*$|>\s*$|\$\s*$|#\s*$/; @@ -164,14 +220,30 @@ export async function readProcessOutput(args: unknown): Promise { resolved = true; cleanup(); timeoutReached = isTimeout; + if (isTimeout) exitReason = 'timeout'; resolve(value); }; // Monitor for new output with immediate detection const session = terminalManager.getSession(pid); if (session && session.process && session.process.stdout && session.process.stderr) { - const immediateDetector = (data: Buffer) => { + const immediateDetector = (data: Buffer, source: 'stdout' | 'stderr') => { const text = data.toString(); + const now = Date.now(); + + if (!firstOutputTime) firstOutputTime = now; + lastOutputTime = now; + + if (verbose_timing) { + outputEvents.push({ + timestamp: now, + deltaMs: now - startTime, + source, + length: text.length, + snippet: text.slice(0, 50).replace(/\n/g, '\\n') + }); + } + // Immediate check for obvious prompts if (quickPromptPatterns.test(text)) { const newOutput = terminalManager.getNewOutput(pid) || text; @@ -179,32 +251,40 @@ export async function readProcessOutput(args: unknown): Promise { if (state.isWaitingForInput) { earlyExit = true; processState = state; + exitReason = 'early_exit_quick_pattern'; + + if (verbose_timing && outputEvents.length > 0) { + outputEvents[outputEvents.length - 1].matchedPattern = 'quick_pattern'; + } + resolveOnce(newOutput); return; } } }; - - session.process.stdout.on('data', immediateDetector); - session.process.stderr.on('data', immediateDetector); - + + const stdoutDetector = (data: Buffer) => immediateDetector(data, 'stdout'); + const stderrDetector = (data: Buffer) => immediateDetector(data, 'stderr'); + session.process.stdout.on('data', stdoutDetector); + session.process.stderr.on('data', stderrDetector); + // Cleanup immediate detectors when done const originalResolveOnce = resolveOnce; const cleanupDetectors = () => { if (session.process.stdout) { - session.process.stdout.removeListener('data', immediateDetector); + session.process.stdout.off('data', stdoutDetector); } if (session.process.stderr) { - session.process.stderr.removeListener('data', immediateDetector); + session.process.stderr.off('data', stderrDetector); } }; - + // Override resolveOnce to include cleanup const resolveOnceWithCleanup = (value: string, isTimeout = false) => { cleanupDetectors(); originalResolveOnce(value, isTimeout); }; - + // Replace the local resolveOnce reference resolveOnce = resolveOnceWithCleanup; } @@ -212,29 +292,50 @@ export async function readProcessOutput(args: unknown): Promise { interval = setInterval(() => { const newOutput = terminalManager.getNewOutput(pid); if (newOutput && newOutput.length > 0) { + const now = Date.now(); + if (!firstOutputTime) firstOutputTime = now; + lastOutputTime = now; + + if (verbose_timing) { + outputEvents.push({ + timestamp: now, + deltaMs: now - startTime, + source: 'periodic_poll', + length: newOutput.length, + snippet: newOutput.slice(0, 50).replace(/\n/g, '\\n') + }); + } + const currentOutput = output + newOutput; const state = analyzeProcessState(currentOutput, pid); - + // Early exit if process is clearly waiting for input if (state.isWaitingForInput) { earlyExit = true; processState = state; + exitReason = 'early_exit_periodic_check'; + + if (verbose_timing && outputEvents.length > 0) { + outputEvents[outputEvents.length - 1].matchedPattern = 'periodic_check'; + } + resolveOnce(newOutput); return; } - + output = currentOutput; - + // Continue collecting if still running if (!state.isFinished) { return; } - + // Process finished processState = state; + exitReason = 'process_finished'; resolveOnce(newOutput); } - }, 200); // Check every 200ms + }, 50); // Check every 50ms for faster response timeout = setTimeout(() => { const finalOutput = terminalManager.getNewOutput(pid) || ""; @@ -267,12 +368,29 @@ export async function readProcessOutput(args: unknown): Promise { statusMessage = '\nโฑ๏ธ Timeout reached - process may still be running'; } + // Add timing information if requested + let timingMessage = ''; + if (verbose_timing) { + const endTime = Date.now(); + const timingInfo = { + startTime, + endTime, + totalDurationMs: endTime - startTime, + exitReason, + firstOutputTime, + lastOutputTime, + timeToFirstOutputMs: firstOutputTime ? firstOutputTime - startTime : undefined, + outputEvents: outputEvents.length > 0 ? outputEvents : undefined + }; + timingMessage = formatTimingInfo(timingInfo); + } + const responseText = output || 'No new output available'; - + return { content: [{ type: "text", - text: `${responseText}${statusMessage}` + text: `${responseText}${statusMessage}${timingMessage}` }], }; } @@ -293,13 +411,21 @@ export async function interactWithProcess(args: unknown): Promise }; } - const { - pid, - input, + const { + pid, + input, timeout_ms = 8000, - wait_for_prompt = true + wait_for_prompt = true, + verbose_timing = false } = parsed.data; - + + // Timing telemetry + const startTime = Date.now(); + let firstOutputTime: number | undefined; + let lastOutputTime: number | undefined; + const outputEvents: any[] = []; + let exitReason: 'early_exit_quick_pattern' | 'early_exit_periodic_check' | 'process_finished' | 'timeout' | 'no_wait' = 'timeout'; + try { capture('server_interact_with_process', { pid: pid, @@ -307,7 +433,7 @@ export async function interactWithProcess(args: unknown): Promise }); const success = terminalManager.sendInputToProcess(pid, input); - + if (!success) { return { content: [{ type: "text", text: `Error: Failed to send input to process ${pid}. The process may have exited or doesn't accept input.` }], @@ -317,10 +443,26 @@ export async function interactWithProcess(args: unknown): Promise // If not waiting for response, return immediately if (!wait_for_prompt) { + exitReason = 'no_wait'; + let timingMessage = ''; + if (verbose_timing) { + const endTime = Date.now(); + const timingInfo = { + startTime, + endTime, + totalDurationMs: endTime - startTime, + exitReason, + firstOutputTime, + lastOutputTime, + timeToFirstOutputMs: undefined, + outputEvents: undefined + }; + timingMessage = formatTimingInfo(timingInfo); + } return { content: [{ type: "text", - text: `โœ… Input sent to process ${pid}. Use read_process_output to get the response.` + text: `โœ… Input sent to process ${pid}. Use read_process_output to get the response.${timingMessage}` }], }; } @@ -329,7 +471,7 @@ export async function interactWithProcess(args: unknown): Promise let output = ""; let processState: ProcessState | undefined; let earlyExit = false; - + // Quick prompt patterns for immediate detection const quickPromptPatterns = />>>\s*$|>\s*$|\$\s*$|#\s*$/; @@ -337,93 +479,69 @@ export async function interactWithProcess(args: unknown): Promise return new Promise((resolve) => { let resolved = false; let attempts = 0; - const maxAttempts = Math.ceil(timeout_ms / 200); + const pollIntervalMs = 50; // Poll every 50ms for faster response + const maxAttempts = Math.ceil(timeout_ms / pollIntervalMs); let interval: NodeJS.Timeout | null = null; - + let resolveOnce = () => { if (resolved) return; resolved = true; if (interval) clearInterval(interval); resolve(); }; - - // Set up immediate detection on the process streams - const session = terminalManager.getSession(pid); - if (session && session.process && session.process.stdout && session.process.stderr) { - const immediateDetector = (data: Buffer) => { - const text = data.toString(); - // Immediate check for obvious prompts - if (quickPromptPatterns.test(text)) { - // Get the latest output and analyze - setTimeout(() => { - const newOutput = terminalManager.getNewOutput(pid); - if (newOutput) { - output += newOutput; - const state = analyzeProcessState(output, pid); - if (state.isWaitingForInput) { - processState = state; - earlyExit = true; - resolveOnce(); - } - } - }, 50); // Small delay to ensure output is captured - } - }; - - session.process.stdout.on('data', immediateDetector); - session.process.stderr.on('data', immediateDetector); - - // Cleanup when done - const cleanupDetectors = () => { - if (session.process.stdout) { - session.process.stdout.removeListener('data', immediateDetector); - } - if (session.process.stderr) { - session.process.stderr.removeListener('data', immediateDetector); - } - }; - - // Override resolveOnce to include cleanup - const originalResolveOnce = resolveOnce; - const resolveOnceWithCleanup = () => { - cleanupDetectors(); - originalResolveOnce(); - }; - - // Replace the local resolveOnce reference - resolveOnce = resolveOnceWithCleanup; - } - - // Periodic check as fallback + + // Fast-polling check - check every 50ms for quick responses interval = setInterval(() => { if (resolved) return; - + const newOutput = terminalManager.getNewOutput(pid); if (newOutput && newOutput.length > 0) { + const now = Date.now(); + if (!firstOutputTime) firstOutputTime = now; + lastOutputTime = now; + + if (verbose_timing) { + outputEvents.push({ + timestamp: now, + deltaMs: now - startTime, + source: 'periodic_poll', + length: newOutput.length, + snippet: newOutput.slice(0, 50).replace(/\n/g, '\\n') + }); + } + output += newOutput; - + // Analyze current state processState = analyzeProcessState(output, pid); - + // Exit early if we detect the process is waiting for input if (processState.isWaitingForInput) { earlyExit = true; + exitReason = 'early_exit_periodic_check'; + + if (verbose_timing && outputEvents.length > 0) { + outputEvents[outputEvents.length - 1].matchedPattern = 'periodic_check'; + } + resolveOnce(); return; } - + // Also exit if process finished if (processState.isFinished) { + exitReason = 'process_finished'; resolveOnce(); return; } } - + attempts++; if (attempts >= maxAttempts) { + exitReason = 'timeout'; resolveOnce(); } - }, 200); + }, pollIntervalMs); }); }; @@ -446,32 +564,53 @@ export async function interactWithProcess(args: unknown): Promise } else if (timeoutReached) { statusMessage = '\nโฑ๏ธ Response may be incomplete (timeout reached)'; } - + + // Add timing information if requested + let timingMessage = ''; + if (verbose_timing) { + const endTime = Date.now(); + const timingInfo = { + startTime, + endTime, + totalDurationMs: endTime - startTime, + exitReason, + firstOutputTime, + lastOutputTime, + timeToFirstOutputMs: firstOutputTime ? firstOutputTime - startTime : undefined, + outputEvents: outputEvents.length > 0 ? outputEvents : undefined + }; + timingMessage = formatTimingInfo(timingInfo); + } + if (cleanOutput.trim().length === 0 && !timeoutReached) { return { content: [{ type: "text", - text: `โœ… Input executed in process ${pid}.\n๐Ÿ“ญ (No output produced)${statusMessage}` + text: `โœ… Input executed in process ${pid}.\n๐Ÿ“ญ (No output produced)${statusMessage}${timingMessage}` }], }; } - + // Format response with better structure and consistent emojis let responseText = `โœ… Input executed in process ${pid}`; - + if (cleanOutput && cleanOutput.trim().length > 0) { responseText += `:\n\n๐Ÿ“ค Output:\n${cleanOutput}`; } else { responseText += `.\n๐Ÿ“ญ (No output produced)`; } - + if (statusMessage) { responseText += `\n\n${statusMessage}`; } + if (timingMessage) { + responseText += timingMessage; + } + return { content: [{ - type: "text", + type: "text", text: responseText }], }; diff --git a/src/tools/schemas.ts b/src/tools/schemas.ts index 35dd7edf..56902df3 100644 --- a/src/tools/schemas.ts +++ b/src/tools/schemas.ts @@ -22,11 +22,13 @@ export const StartProcessArgsSchema = z.object({ command: z.string(), timeout_ms: z.number(), shell: z.string().optional(), + verbose_timing: z.boolean().optional(), }); export const ReadProcessOutputArgsSchema = z.object({ pid: z.number(), timeout_ms: z.number().optional(), + verbose_timing: z.boolean().optional(), }); export const ForceTerminateArgsSchema = z.object({ @@ -89,6 +91,7 @@ export const InteractWithProcessArgsSchema = z.object({ input: z.string(), timeout_ms: z.number().optional(), wait_for_prompt: z.boolean().optional(), + verbose_timing: z.boolean().optional(), }); // Usage stats schema diff --git a/src/types.ts b/src/types.ts index d023f464..fb2f7d94 100644 --- a/src/types.ts +++ b/src/types.ts @@ -25,6 +25,27 @@ export interface CommandExecutionResult { pid: number; output: string; isBlocked: boolean; + timingInfo?: TimingInfo; +} + +export interface TimingInfo { + startTime: number; + endTime: number; + totalDurationMs: number; + exitReason: 'early_exit_quick_pattern' | 'early_exit_periodic_check' | 'process_exit' | 'timeout'; + firstOutputTime?: number; + lastOutputTime?: number; + timeToFirstOutputMs?: number; + outputEvents?: OutputEvent[]; +} + +export interface OutputEvent { + timestamp: number; + deltaMs: number; + source: 'stdout' | 'stderr'; + length: number; + snippet: string; + matchedPattern?: string; } export interface ActiveSession { diff --git a/test-listener-bug.js b/test-listener-bug.js new file mode 100755 index 00000000..28390881 --- /dev/null +++ b/test-listener-bug.js @@ -0,0 +1,191 @@ +#!/usr/bin/env node + +/** + * Test to verify that read_process_output doesn't break future calls + * by removing TerminalManager's listeners with removeAllListeners + * + * Expected behavior: + * 1. Start Node.js REPL + * 2. Send command with interact_with_process + * 3. Call read_process_output - should work + * 4. Send another command with interact_with_process + * 5. Call read_process_output again - should STILL work (this would fail with removeAllListeners bug) + */ + +import { spawn } from 'child_process'; +import path from 'path'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); +const __dirname = path.dirname(__filename); + +async function runTest() { + console.log('๐Ÿงช Testing listener cleanup bug...\n'); + + // Start the MCP server + const serverPath = path.join(__dirname, 'dist', 'index.js'); + const server = spawn('node', [serverPath, '--no-onboarding'], { + stdio: ['pipe', 'pipe', 'pipe'] + }); + + let responseBuffer = ''; + let requestId = 1; + + server.stdout.on('data', (data) => { + responseBuffer += data.toString(); + }); + + server.stderr.on('data', (data) => { + console.error('Server stderr:', data.toString()); + }); + + function sendRequest(method, params) { + const request = { + jsonrpc: '2.0', + id: requestId++, + method, + params + }; + server.stdin.write(JSON.stringify(request) + '\n'); + } + + function waitForResponse(expectedId, timeout = 5000) { + return new Promise((resolve, reject) => { + const startTime = Date.now(); + const checkInterval = setInterval(() => { + const lines = responseBuffer.split('\n'); + for (const line of lines) { + if (!line.trim()) continue; + try { + const response = JSON.parse(line); + if (response.id === expectedId) { + clearInterval(checkInterval); + responseBuffer = responseBuffer.replace(line, ''); + resolve(response); + return; + } + } catch (e) { + // Not valid JSON yet, keep waiting + } + } + + if (Date.now() - startTime > timeout) { + clearInterval(checkInterval); + reject(new Error(`Timeout waiting for response ${expectedId}`)); + } + }, 50); + }); + } + + async function callTool(name, args) { + const id = requestId; + sendRequest('tools/call', { name, arguments: args }); + const response = await waitForResponse(id); + if (response.error) { + throw new Error(`Tool error: ${JSON.stringify(response.error)}`); + } + return response.result; + } + + try { + // Initialize + sendRequest('initialize', { protocolVersion: '2024-11-05', capabilities: {} }); + await waitForResponse(requestId - 1); + + console.log('โœ… Server initialized\n'); + + // Step 1: Start Node.js REPL + console.log('๐Ÿ“ Step 1: Starting Node.js REPL...'); + const startResult = await callTool('start_process', { + command: 'node -i', + timeout_ms: 5000 + }); + const pidMatch = startResult.content[0].text.match(/PID (\d+)/); + const pid = parseInt(pidMatch[1]); + console.log(`โœ… Started process with PID: ${pid}\n`); + + // Step 2: Send first command + console.log('๐Ÿ“ Step 2: Sending first command (1 + 1)...'); + const interact1 = await callTool('interact_with_process', { + pid, + input: '1 + 1', + timeout_ms: 3000 + }); + console.log('โœ… First interact succeeded'); + console.log(` Output snippet: ${interact1.content[0].text.substring(0, 50)}...\n`); + + // Step 3: First read_process_output (this might break listeners with removeAllListeners) + console.log('๐Ÿ“ Step 3: First read_process_output...'); + const read1 = await callTool('read_process_output', { + pid, + timeout_ms: 1000 + }); + console.log('โœ… First read_process_output succeeded'); + console.log(` Output: ${read1.content[0].text.substring(0, 50)}...\n`); + + // Step 4: Send second command WITHOUT waiting (so output stays in buffer) + console.log('๐Ÿ“ Step 4: Sending second command (2 + 2) WITHOUT waiting...'); + const interact2 = await callTool('interact_with_process', { + pid, + input: '2 + 2', + timeout_ms: 3000, + wait_for_prompt: false // Don't wait, let read_process_output get it + }); + console.log('โœ… Second interact sent (not waiting for output)\n'); + + // Wait a bit for output to arrive + await new Promise(resolve => setTimeout(resolve, 500)); + + // Step 5: Second read_process_output (THIS WILL FAIL if listeners were removed) + console.log('๐Ÿ“ Step 5: Second read_process_output (critical test)...'); + const read2 = await callTool('read_process_output', { + pid, + timeout_ms: 2000 + }); + + const outputText = read2.content[0].text; + const hasOutput = !outputText.includes('No new output') && + !outputText.includes('Timeout reached'); + + if (!hasOutput) { + console.error('โŒ BUG DETECTED: Second read_process_output returned no output!'); + console.error(' This means TerminalManager listeners were removed by removeAllListeners'); + console.error(` Full output: ${outputText}`); + process.exit(1); + } + + // Validate output contains expected result from "2 + 2" + if (!outputText.includes('4')) { + console.error('โŒ BUG DETECTED: Second read_process_output has corrupt output!'); + console.error(` Expected result "4" from "2 + 2" but got: ${outputText}`); + process.exit(1); + } + + // Validate output contains REPL prompt (proves detection is working) + if (!outputText.includes('>')) { + console.error('โŒ BUG DETECTED: Second read_process_output missing REPL prompt!'); + console.error(` Expected ">" prompt but got: ${outputText}`); + process.exit(1); + } + + console.log('โœ… Second read_process_output succeeded!'); + console.log(` โœ“ Contains expected result: "4"`); + console.log(` โœ“ Contains REPL prompt: ">"`); + console.log(` Full output: ${outputText.substring(0, 100)}...\n`); + + // Cleanup + await callTool('force_terminate', { pid }); + console.log('โœ… Process terminated\n'); + + console.log('๐ŸŽ‰ All tests passed! Listener cleanup is working correctly.'); + process.exit(0); + + } catch (error) { + console.error('โŒ Test failed:', error.message); + process.exit(1); + } finally { + server.kill(); + } +} + +runTest();