← Back to Kontasks

MCP Tool Timing Bug Identified

Found root cause - parallel tool calls overwrite timing state

✓ Completed
on 3 Jan 2026, 9:17 pm

Output

Bug Found: Parallel Tool Timing Lost

MCP tools (like konui_create_task) aren't missing - they're being tracked but their timing is lost due to a race condition in parallel tool calls.

Root Cause

The KontextBuilder uses a single active state to track tool timing:

activeToolStart?: number
activeToolName?: string
activeToolSummary?: string

When Claude makes parallel tool calls, each addToolUse() overwrites the previous tool's state. Only the last tool in the batch gets its timing recorded.

Example: 3 Parallel Tools

1. addToolUse("Bash")      → activeToolName = "Bash"
2. addToolUse("Read")      → activeToolName = "Read" ← overwrites!
3. addToolUse("mcp__konui") → activeToolName = "mcp__konui" ← overwrites!
4. addToolResult()         → records "mcp__konui" ✓
5. addToolResult()         → activeToolName=undefined ✗ lost
6. addToolResult()         → activeToolName=undefined ✗ lost

The Fix

Use a Map keyed by tool_use_id instead of a single active state. Claude's stream-json includes a unique id for each tool_use, which matches the tool_use_id in the corresponding tool_result.

// Before (broken)
activeToolStart?: number

// After (correct)
pendingTools: Map<string, { start: number, name: string, summary: string }>

Impact

  • Thinking time inflated - ~98% shown vs ~70% actual
  • Tool time underreported - Missing 2-3 tools per turn
  • MCP tools invisible - Always lost (called in batch with others)

What's Next?

Choose an action:

Quick Actions

Original Request

No layout configured

Details

Type General
Status Completed
Scope vibetools
Tags telemetryperformancebug
Created 3 Jan 2026, 9:17 pm
Updated 3 Jan 2026, 9:17 pm
Created By claude

Raw Data

{
  "id": "7dab01b2-5034-46b1-b745-b02224b9f9bb",
  "type": "general",
  "status": "completed",
  "title": "MCP Tool Timing Bug Identified",
  "description": "Found root cause - parallel tool calls overwrite timing state",
  "context": {
    "output": "<div style=\"background:#1e1e1e;color:#e0e0e0;padding:20px;border-radius:8px;font-family:system-ui,sans-serif;\"><h2 style=\"color:#f97316;margin:0 0 16px 0;\">Bug Found: Parallel Tool Timing Lost</h2><p style=\"color:#9ca3af;margin-bottom:16px;\">MCP tools (like konui_create_task) aren't missing - they're being tracked but their <strong>timing is lost</strong> due to a race condition in parallel tool calls.</p><div style=\"background:#2d2d2d;padding:16px;border-radius:6px;margin-bottom:16px;\"><h4 style=\"color:#ef4444;margin:0 0 12px 0;\">Root Cause</h4><p style=\"color:#9ca3af;margin:0;line-height:1.6;\">The <code style=\"background:#444;padding:2px 6px;border-radius:3px;\">KontextBuilder</code> uses a <strong>single active state</strong> to track tool timing:</p><pre style=\"background:#1a1a1a;padding:12px;border-radius:4px;margin:12px 0;overflow-x:auto;color:#e5c07b;font-size:0.85rem;\">activeToolStart?: number\nactiveToolName?: string\nactiveToolSummary?: string</pre><p style=\"color:#9ca3af;margin:8px 0 0 0;\">When Claude makes <strong>parallel tool calls</strong>, each <code>addToolUse()</code> overwrites the previous tool's state. Only the <strong>last tool</strong> in the batch gets its timing recorded.</p></div><div style=\"background:#2d2d2d;padding:16px;border-radius:6px;margin-bottom:16px;\"><h4 style=\"color:#e5c07b;margin:0 0 12px 0;\">Example: 3 Parallel Tools</h4><pre style=\"background:#1a1a1a;padding:12px;border-radius:4px;overflow-x:auto;color:#9ca3af;font-size:0.85rem;line-height:1.6;\">1. addToolUse(\"Bash\")      → activeToolName = \"Bash\"\n2. addToolUse(\"Read\")      → activeToolName = \"Read\" <span style=\"color:#ef4444;\">← overwrites!</span>\n3. addToolUse(\"mcp__konui\") → activeToolName = \"mcp__konui\" <span style=\"color:#ef4444;\">← overwrites!</span>\n4. addToolResult()         → records \"mcp__konui\" <span style=\"color:#22c55e;\">✓</span>\n5. addToolResult()         → activeToolName=undefined <span style=\"color:#ef4444;\">✗ lost</span>\n6. addToolResult()         → activeToolName=undefined <span style=\"color:#ef4444;\">✗ lost</span></pre></div><div style=\"background:#2d2d2d;padding:16px;border-radius:6px;margin-bottom:16px;\"><h4 style=\"color:#22c55e;margin:0 0 12px 0;\">The Fix</h4><p style=\"color:#9ca3af;margin:0;line-height:1.6;\">Use a <strong>Map keyed by tool_use_id</strong> instead of a single active state. Claude's stream-json includes a unique <code>id</code> for each tool_use, which matches the <code>tool_use_id</code> in the corresponding tool_result.</p><pre style=\"background:#1a1a1a;padding:12px;border-radius:4px;margin:12px 0;overflow-x:auto;color:#98c379;font-size:0.85rem;\">// Before (broken)\nactiveToolStart?: number\n\n// After (correct)\npendingTools: Map&lt;string, { start: number, name: string, summary: string }&gt;</pre></div><div style=\"background:#2d2d2d;padding:16px;border-radius:6px;\"><h4 style=\"color:#61afef;margin:0 0 12px 0;\">Impact</h4><ul style=\"margin:0;padding-left:20px;color:#9ca3af;line-height:1.8;\"><li><strong>Thinking time inflated</strong> - ~98% shown vs ~70% actual</li><li><strong>Tool time underreported</strong> - Missing 2-3 tools per turn</li><li><strong>MCP tools invisible</strong> - Always lost (called in batch with others)</li></ul></div><div style=\"background:#2d2d2d;padding:16px;border-radius:6px;margin-top:16px;\"><h4 style=\"margin:0 0 8px 0;color:#fff;\">What's Next?</h4><p style=\"color:#9ca3af;margin:0;\">Choose an action:</p></div></div>",
    "choices": [
      {
        "label": "Fix the bug",
        "value": "Fix the parallel tool timing bug in konsole/src/kontext.ts - use tool_use_id keyed Map instead of single active state",
        "primary": true
      },
      {
        "label": "Show me the code",
        "value": "Show me the relevant code sections in kontext.ts and stream.ts that need to change"
      },
      {
        "label": "Defer to backlog",
        "value": "Add this fix to the backlog for later implementation"
      }
    ],
    "requestedAt": "2026-01-03T11:30:00Z",
    "requestId": "05ca6451-f2dd-41d0-9a4c-500fc304276d"
  },
  "createdBy": "claude",
  "createdAt": "2026-01-03T11:17:47.946Z",
  "updatedAt": "2026-01-03T11:17:48.096Z",
  "requestId": "05ca6451-f2dd-41d0-9a4c-500fc304276d",
  "scope": "vibetools",
  "tags": [
    "telemetry",
    "performance",
    "bug"
  ],
  "targetUser": "claude"
}
DashboardReportsKontasksSessionsTelemetryLogs + Go