Add verbose timing telemetry and improvements to terminal commands performance#257
Conversation
This commit adds comprehensive performance telemetry and fixes a critical bug where interact_with_process waited 8+ seconds despite output arriving in 2-6ms. Changes: - Add TimingInfo and OutputEvent types to track performance metrics - Add verbose_timing parameter to start_process, read_process_output, and interact_with_process - Implement detailed timing collection including exit reasons and output event timelines - Fix interact_with_process bug: removed broken duplicate stream listeners - Optimize polling: reduced interval from 200ms to 50ms (4x faster response) - Update tool documentation with performance debugging instructions Performance improvement: REPL interactions now complete in 50-100ms instead of 8s timeout (160x faster). Telemetry shows: - Exit reason (early_exit_quick_pattern, early_exit_periodic_check, process_exit, timeout) - Total duration and time to first output - Complete timeline of output events with timestamps and sources - Which detection mechanism triggered early exit 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude <noreply@anthropic.com>
WalkthroughAdds optional verbose timing telemetry across process tools: new TimingInfo/OutputEvent types and timingInfo on command results; TerminalManager collects and returns timing when requested; tools propagate and format verbose_timing; schemas gain verbose_timing flags; server docs expanded; new test ensures listener stability across consecutive reads. Changes
Sequence Diagram(s)sequenceDiagram
autonumber
participant C as Client
participant S as Server/tools
participant M as TerminalManager
participant P as OS Process
rect rgb(250,250,255)
note over C,S: startProcess / read / interact with verbose_timing=true
C->>S: startProcess(cmd, verbose_timing=true)
S->>M: executeCommand(cmd, ..., collectTiming=true)
activate M
M->>P: spawn process
M-->>M: record startTime
par output capture
P-->>M: stdout/stderr chunks
M-->>M: push OutputEvent (timestamp, source, snippet)
M-->>M: set firstOutputTime if unset
and periodic checks
M-->>M: periodic polling, may set exitReason (quick/periodic/timeout)
end
P-->>M: process exit
M-->>M: record endTime, totalDurationMs
M-->>S: CommandExecutionResult { output, timingInfo }
deactivate M
S-->>C: response + formatted timing block
end
Estimated code review effort🎯 4 (Complex) | ⏱️ ~60 minutes Possibly related PRs
Suggested reviewers
Poem
Pre-merge checks and finishing touches❌ Failed checks (1 warning)
✅ Passed checks (2 passed)
✨ Finishing touches
🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 1
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (5)
src/server.ts(3 hunks)src/terminal-manager.ts(8 hunks)src/tools/improved-process-tools.ts(13 hunks)src/tools/schemas.ts(2 hunks)src/types.ts(1 hunks)
🧰 Additional context used
🧬 Code graph analysis (2)
src/tools/improved-process-tools.ts (2)
src/terminal-manager.ts (1)
terminalManager(325-325)src/utils/process-detection.ts (1)
analyzeProcessState(54-130)
src/terminal-manager.ts (1)
src/types.ts (4)
CommandExecutionResult(24-29)TerminalSession(16-22)OutputEvent(42-49)TimingInfo(31-40)
wonderwhy-er
changed the title
Fixed critical bug where removeAllListeners('data') was removing
TerminalManager's persistent listeners, breaking all future calls.
Problem:
- read_process_output attached temporary listeners for immediate detection
- Used removeAllListeners('data') to clean up, which removed ALL listeners
- This broke TerminalManager's accumulator, causing future getNewOutput() to return empty
- Second call to read_process_output would always timeout
Solution:
- Store references to our specific detector functions
- Use .off('data', specificFunction) instead of .removeAllListeners('data')
- Only removes our temporary listeners, preserves TerminalManager's listeners
Testing:
- Added test-listener-bug.js that reproduces the issue
- Test verifies multiple sequential read_process_output calls work correctly
- All tests pass after fix
Credit: Fix suggested by code reviewer
🤖 Generated with [Claude Code](https://claude.com/claude-code)
Co-Authored-By: Claude <noreply@anthropic.com>
There was a problem hiding this comment.
Actionable comments posted: 3
🧹 Nitpick comments (7)
test-listener-bug.js (3)
22-41: Verify server process lifecycle.The test spawns a server but doesn't verify it started successfully before proceeding with tests. If the server fails to start or crashes during initialization, the test will hang waiting for responses.
Apply this diff to add startup verification:
const server = spawn('node', [serverPath, '--no-onboarding'], { stdio: ['pipe', 'pipe', 'pipe'] }); + + // Verify server started + let serverReady = false; + server.on('error', (error) => { + console.error('❌ Failed to start server:', error); + process.exit(1); + }); let responseBuffer = ''; let requestId = 1; server.stdout.on('data', (data) => { responseBuffer += data.toString(); + serverReady = true; });
136-137: Race condition: fixed delay may be insufficient.The 500ms sleep assumes output will arrive within that window, but under load or in slower environments, the command might not complete in time, causing a false failure.
Apply this diff to poll for output availability instead:
- // Wait a bit for output to arrive - await new Promise(resolve => setTimeout(resolve, 500)); + // Poll for output with timeout + const maxWait = 2000; + const pollInterval = 100; + let waited = 0; + while (waited < maxWait) { + const checkResult = await callTool('read_process_output', { + pid, + timeout_ms: 100 + }); + if (!checkResult.content[0].text.includes('No new output')) { + break; + } + await new Promise(resolve => setTimeout(resolve, pollInterval)); + waited += pollInterval; + }
169-171: Handle cleanup errors gracefully.
server.kill()can throw if the process already exited. This could mask the actual test failure with an unhandled exception.Apply this diff to handle cleanup errors:
} finally { - server.kill(); + try { + if (server && !server.killed) { + server.kill(); + } + } catch (error) { + // Process may have already exited + } }src/tools/improved-process-tools.ts (4)
181-193: Extract timing collection into a reusable helper.Timing collection logic (capturing timestamp, deltaMs, source, length, snippet) is duplicated across initial poll, stdout/stderr detectors, and periodic poll sites. This violates DRY and makes maintenance error-prone.
Apply this diff to create a shared helper:
+function recordOutputEvent( + outputEvents: any[], + startTime: number, + source: string, + text: string +): void { + const now = Date.now(); + outputEvents.push({ + timestamp: now, + deltaMs: now - startTime, + source, + length: text.length, + snippet: text.slice(0, 50).replace(/\n/g, '\\n') + }); +}Then replace each duplication site with:
- 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') - }); - } + if (verbose_timing) { + recordOutputEvent(outputEvents, startTime, 'initial_poll', initialOutput); + }Apply similar changes to the other three duplication sites at lines 237-245, 299-307, and 503-511.
Also applies to: 237-245, 299-307, 503-511
211-211: Deduplicate quick prompt pattern definitions.The regex
/>>>\s*$|>\s*$|\$\s*$|#\s*$/is defined identically at two locations (readProcessOutput and interactWithProcess). Consider extracting to a module-level constant for maintainability.Apply this diff to extract the pattern:
+// Quick prompt patterns for immediate detection across tools +const QUICK_PROMPT_PATTERNS = />>>\s*$|>\s*$|\$\s*$|#\s*$/; + /** * Start a new process (renamed from execute_command)Then replace both occurrences:
- const quickPromptPatterns = />>>\s*$|>\s*$|\$\s*$|#\s*$/;With:
+ const quickPromptPatterns = QUICK_PROMPT_PATTERNS;Also applies to: 476-476
116-124: Optimize output event rendering for large event lists.When
outputEventscontains hundreds of entries from long-running processes, rendering all events in the timing message could produce massive output that overwhelms the user. Consider limiting the number of events displayed or providing summary statistics.Apply this diff to cap and summarize events:
if (timing.outputEvents && timing.outputEvents.length > 0) { - msg += `\n Output Events (${timing.outputEvents.length} total):\n`; - timing.outputEvents.forEach((event, idx: number) => { + const maxEventsToShow = 10; + const eventsToShow = timing.outputEvents.slice(0, maxEventsToShow); + const remaining = timing.outputEvents.length - maxEventsToShow; + + msg += `\n Output Events (showing ${eventsToShow.length} of ${timing.outputEvents.length}):\n`; + eventsToShow.forEach((event, idx: number) => { msg += ` [${idx + 1}] +${event.deltaMs}ms | ${event.source} | ${event.length}b`; if (event.matchedPattern) { msg += ` | 🎯 ${event.matchedPattern}`; } msg += `\n "${event.snippet}"\n`; }); + + if (remaining > 0) { + msg += ` ... and ${remaining} more events\n`; + } }
338-338: Document rationale for 50ms polling interval.The comment states "Check every 50ms for faster response" but doesn't explain why 50ms was chosen over the previous 200ms, or the trade-offs (CPU usage vs. responsiveness). According to the PR objectives, this change produced ~160× improvement, which is a significant finding worth documenting.
Consider adding a more detailed comment:
- }, 50); // Check every 50ms for faster response + }, 50); // Poll every 50ms (optimized from 200ms) to detect prompts/completion quickly. + // This reduces typical response times from ~8s timeouts to ~50-100ms, + // while keeping CPU overhead acceptable (~2% per active process).
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (2)
src/tools/improved-process-tools.ts(13 hunks)test-listener-bug.js(1 hunks)
🧰 Additional context used
🧬 Code graph analysis (2)
test-listener-bug.js (2)
test/test-read-completed-process.js (3)
testReadCompletedProcessOutput(11-42)testImmediateCompletion(47-73)runTests(76-89)test/test-enhanced-repl.js (1)
testEnhancedREPL(29-136)
src/tools/improved-process-tools.ts (2)
src/terminal-manager.ts (1)
terminalManager(325-325)src/utils/process-detection.ts (1)
analyzeProcessState(54-130)
🔇 Additional comments (1)
src/tools/improved-process-tools.ts (1)
266-289: LGTM: Listener cleanup fix addresses critical bug.The code now correctly removes only the specific detectors it registered by keeping named references (
stdoutDetector,stderrDetector) and using.off()instead ofremoveAllListeners(). This preserves TerminalManager's persistent listeners and fixes the race condition that caused 8s timeouts.Based on past review comments, this implementation matches the recommended fix pattern and should resolve the listener cleanup bug validated by test-listener-bug.js.
| 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; | ||
| } |
There was a problem hiding this comment.
🛠️ Refactor suggestion | 🟠 Major
Use strict typing instead of any.
The timing parameter and event objects use any, which defeats TypeScript's type safety and makes refactoring error-prone. Based on the types introduced in src/types.ts (TimingInfo, OutputEvent), these should be strongly typed.
Apply this diff to add proper typing:
-function formatTimingInfo(timing: any): string {
+import type { TimingInfo } from '../types.js';
+
+function formatTimingInfo(timing: TimingInfo): 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) => {
+ timing.outputEvents.forEach((event, 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;
}📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| 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; | |
| } | |
| // at the top of src/tools/improved-process-tools.ts | |
| import type { TimingInfo } from '../types.js'; | |
| function formatTimingInfo(timing: TimingInfo): 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, 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; | |
| } |
🤖 Prompt for AI Agents
In src/tools/improved-process-tools.ts around lines 103 to 128, the
formatTimingInfo function and its loop use `any` for the timing parameter and
event objects; replace those with the proper exported types (TimingInfo for the
timing parameter and OutputEvent for each event) from src/types.ts, update the
function signature to `function formatTimingInfo(timing: TimingInfo): string`,
type the forEach callback as `(event: OutputEvent, idx: number)`, and adjust any
property checks to match the typed optional properties (e.g., use === undefined
or !== undefined for optional fields) so the code compiles under strict
TypeScript and leverages compile-time type safety.
| // 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'; | ||
|
|
There was a problem hiding this comment.
🛠️ Refactor suggestion | 🟠 Major
Type exitReason with a union type.
The exitReason variable is manually typed as a string union in two places, but it should reference a shared type definition from src/types.ts to ensure consistency and prevent drift.
If not already defined in src/types.ts, add:
export type ExitReason =
| 'early_exit_quick_pattern'
| 'early_exit_periodic_check'
| 'process_finished'
| 'timeout'
| 'no_wait';Then import and use it:
+import type { ExitReason } from '../types.js';
...
- let exitReason: 'early_exit_quick_pattern' | 'early_exit_periodic_check' | 'process_exit' | 'timeout' = 'timeout';
+ let exitReason: ExitReason = 'timeout';Apply the same change at line 427 in interactWithProcess.
Also applies to: 422-427
🤖 Prompt for AI Agents
In src/tools/improved-process-tools.ts around lines 170–176, exitReason is
currently declared inline as a string union; replace that inline type with a
shared ExitReason type imported from src/types.ts (add the ExitReason export to
src/types.ts if missing with the five variants 'early_exit_quick_pattern' |
'early_exit_periodic_check' | 'process_finished' | 'timeout' | 'no_wait'),
import ExitReason into improved-process-tools.ts, and type the exitReason
variable as ExitReason; also apply the same change where exitReason (or its
type) is used at lines ~422–427 in the interactWithProcess function so both
declarations reference the centralized ExitReason type.
Improved test-listener-bug.js to validate output content, not just presence: Changes: - Added validation that output contains expected result "4" from "2 + 2" - Added validation that output contains REPL prompt ">" - More detailed success messages showing what was validated - Better error messages if validation fails This prevents false positives where the test could pass even if: - Output is corrupt or incomplete - REPL prompt detection stops working - Listeners are partially broken All validations pass, confirming: ✓ Output contains correct computation result ✓ REPL prompt is properly detected ✓ Multiple sequential calls work correctly 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude <noreply@anthropic.com>
There was a problem hiding this comment.
Actionable comments posted: 2
🧹 Nitpick comments (2)
test-listener-bug.js (2)
103-105: Add defensive null check for regex match.Line 103 assumes the regex will always match, but if the output format changes,
pidMatch[1]will throw. Add a null check and specify radix in parseInt.Apply this diff:
- const pidMatch = startResult.content[0].text.match(/PID (\d+)/); - const pid = parseInt(pidMatch[1]); + const pidMatch = startResult.content[0].text.match(/PID (\d+)/); + if (!pidMatch) { + throw new Error('Failed to extract PID from start_process output'); + } + const pid = parseInt(pidMatch[1], 10);
136-137: Hardcoded wait may cause flakiness.The 500ms wait is arbitrary and assumes output arrives within that window. On slow systems or under load, this could cause intermittent failures.
Consider polling for output availability or making the delay configurable via environment variable:
- // Wait a bit for output to arrive - await new Promise(resolve => setTimeout(resolve, 500)); + // Wait for output to arrive (configurable for slow CI environments) + const outputDelay = parseInt(process.env.TEST_OUTPUT_DELAY || '500', 10); + await new Promise(resolve => setTimeout(resolve, outputDelay));
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (1)
test-listener-bug.js(1 hunks)
🔇 Additional comments (2)
test-listener-bug.js (2)
157-169: Output validation addresses previous review concern.The addition of content validation for "4" and ">" prompt directly addresses the previous review comment. The test now verifies not just presence of output, but correctness of content.
Optional enhancement: Consider using more precise pattern matching to avoid false positives:
// Validate output contains expected result from "2 + 2" - if (!outputText.includes('4')) { + if (!/[>\s]4\s/.test(outputText)) { 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); }
183-188: LGTM: Proper error handling and cleanup.The try-catch-finally structure ensures the server is always killed, preventing resource leaks. Error messages are clear and actionable.
| 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'] | ||
| }); |
There was a problem hiding this comment.
🛠️ Refactor suggestion | 🟠 Major
Add overall test timeout to prevent hangs.
The test has no maximum execution time. If any step hangs (e.g., server never responds), the test will run indefinitely. This is problematic for CI/CD pipelines.
Add a test timeout at the start of runTest:
async function runTest() {
console.log('🧪 Testing listener cleanup bug...\n');
+
+ // Set overall test timeout to prevent hanging
+ const testTimeout = setTimeout(() => {
+ console.error('❌ Test timeout: Exceeded maximum execution time');
+ process.exit(1);
+ }, 30000); // 30 seconds
+
+ // Clear timeout on completion
+ process.on('exit', () => clearTimeout(testTimeout));
// Start the MCP server📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| 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'] | |
| }); | |
| async function runTest() { | |
| console.log('🧪 Testing listener cleanup bug...\n'); | |
| // Set overall test timeout to prevent hanging | |
| const testTimeout = setTimeout(() => { | |
| console.error('❌ Test timeout: Exceeded maximum execution time'); | |
| process.exit(1); | |
| }, 30000); // 30 seconds | |
| // Clear timeout on completion | |
| process.on('exit', () => clearTimeout(testTimeout)); | |
| // Start the MCP server | |
| const serverPath = path.join(__dirname, 'dist', 'index.js'); | |
| const server = spawn('node', [serverPath, '--no-onboarding'], { | |
| stdio: ['pipe', 'pipe', 'pipe'] | |
| }); | |
| // …rest of runTest… | |
| } |
🤖 Prompt for AI Agents
In test-listener-bug.js around lines 22 to 29, the runTest function lacks a
global timeout so the test can hang forever; add an overall timeout at the start
of runTest that triggers after a reasonable duration (e.g., 2–5 minutes) to
cleanly fail the test: start a timer that on expiry kills the spawned server,
performs any necessary cleanup, logs a timeout error, and exits/throws with a
non-zero status; implement this either by wrapping the main run logic in a
Promise.race with a timeout promise or by creating a setTimeout handle that is
cleared on successful completion.
| 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); | ||
| }); | ||
| } |
There was a problem hiding this comment.
Fix buffer mutation to avoid removing wrong response.
Line 63 uses string.replace(line, '') which only removes the first occurrence. If duplicate JSON lines exist in the buffer, this could remove the wrong response or leave stale data.
Apply this diff to properly remove the matched line:
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) {
+ const lines = responseBuffer.split('\n');
+ for (let i = 0; i < lines.length; i++) {
+ const line = lines[i];
if (!line.trim()) continue;
try {
const response = JSON.parse(line);
if (response.id === expectedId) {
clearInterval(checkInterval);
- responseBuffer = responseBuffer.replace(line, '');
+ // Remove this specific line by reconstructing buffer without it
+ lines.splice(i, 1);
+ responseBuffer = lines.join('\n');
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);
});
}📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| 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); | |
| }); | |
| } | |
| function waitForResponse(expectedId, timeout = 5000) { | |
| return new Promise((resolve, reject) => { | |
| const startTime = Date.now(); | |
| const checkInterval = setInterval(() => { | |
| const lines = responseBuffer.split('\n'); | |
| for (let i = 0; i < lines.length; i++) { | |
| const line = lines[i]; | |
| if (!line.trim()) continue; | |
| try { | |
| const response = JSON.parse(line); | |
| if (response.id === expectedId) { | |
| clearInterval(checkInterval); | |
| // Remove this specific line by reconstructing buffer without it | |
| lines.splice(i, 1); | |
| responseBuffer = lines.join('\n'); | |
| 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); | |
| }); | |
| } |
🤖 Prompt for AI Agents
In test-listener-bug.js around lines 52–78, the code uses
responseBuffer.replace(line, '') to remove the matched JSON line which only
removes the first occurrence and can delete the wrong entry when duplicate lines
exist; replace that mutation by splitting responseBuffer into lines, remove the
exact matched line by index (e.g., find its index and splice it out or filter
out only the single matched element), then rejoin with '\n' to assign back to
responseBuffer so you remove the exact instance and preserve other identical
lines.
1 participant
Summary
This PR adds comprehensive performance telemetry and fixes a critical bug where
interact_with_processwaited 8+ seconds despite output arriving in 2-6ms.Problem Identified
Using the new telemetry, we discovered:
Root Causes & Fixes
1. Removed Broken Stream Listener
2. Optimized Polling Intervals
Features Added
Verbose Timing Telemetry
All three process tools now support
verbose_timing: trueparameter:start_processread_process_outputinteract_with_processTelemetry Output Includes:
Example Output:
Performance Impact
Files Changed
src/types.ts- Added TimingInfo and OutputEvent typessrc/tools/schemas.ts- Added verbose_timing parameter to schemassrc/terminal-manager.ts- Added timing collection to executeCommandsrc/tools/improved-process-tools.ts- Implemented telemetry and fixed pollingsrc/server.ts- Updated tool documentationTest Plan
🤖 Generated with Claude Code
Summary by CodeRabbit
New Features
Bug Fixes
Documentation
Tests