Skip to content

feat(telemetry): send tool-call duration_ms with server_call_tool #492

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
wonderwhy-er merged 1 commit into from
Jun 5, 2026
Merged

feat(telemetry): send tool-call duration_ms with server_call_tool #492

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 18 additions & 6 deletions src/server.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1190,11 +1190,14 @@ import { ServerResult } from './types.js';
server.setRequestHandler(CallToolRequestSchema, async (request: CallToolRequest): Promise<ServerResult> => {
const { name, arguments: args } = request.params;
const startTime = Date.now();
// Hoisted above the try so the finally block can read them when emitting the
// server_call_tool completion event (duration + status), even on the crash path.
let telemetryData: any = { tool_name: name };
let result: ServerResult;
let isError = false;

try {
// Prepare telemetry data - add config key for set_config_value
const telemetryData: any = { tool_name: name };
// Extract metadata from _meta field if present
// telemetryData declared above; extract metadata from _meta field if present
const metadata = request.params._meta as any;
// Reset remote attribution for every call so a prior remote call never
// leaks its flag onto a subsequent local call. Set to true only when
Expand Down Expand Up @@ -1231,13 +1234,11 @@ server.setRequestHandler(CallToolRequestSchema, async (request: CallToolRequest)
}
}

capture_call_tool('server_call_tool', telemetryData);

// Track tool call
trackToolCall(name, args);

// Using a more structured approach with dedicated handlers
let result: ServerResult;
// (result is declared above so the finally block can read execution status)

switch (name) {
// Config tools
Expand Down Expand Up @@ -1453,6 +1454,7 @@ server.setRequestHandler(CallToolRequestSchema, async (request: CallToolRequest)

// Add tool call to history (exclude only get_recent_tool_calls to prevent recursion)
const duration = Date.now() - startTime;

@edgarsskore edgarsskore Jun 4, 2026

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this is the duration to use for the tool call duration without overhead calculations. Currently, on line 1581 duration is recalculated in finally, but there is a bit of an overhead between this point and that point, I think this duration is more precise for describing tool call duration. Should maybe recalculate sooner than finally.

@wonderwhy-er wonderwhy-er Jun 5, 2026

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In the end decided to leave as is.
Duration you point to is in try block.
Due to error it may never get calculated.

isError = !!result.isError;
const EXCLUDED_TOOLS = [
'get_recent_tool_calls',
'track_ui_event'
Expand Down Expand Up @@ -1557,6 +1559,7 @@ server.setRequestHandler(CallToolRequestSchema, async (request: CallToolRequest)

return result;
} catch (error) {
isError = true;
const errorMessage = error instanceof Error ? error.message : String(error);

// Track the failure
Expand All @@ -1569,6 +1572,15 @@ server.setRequestHandler(CallToolRequestSchema, async (request: CallToolRequest)
content: [{ type: "text", text: `Error: ${errorMessage}` }],
isError: true,
};
} finally {
// Single tool-call telemetry event, fired AFTER execution so it can carry
// timing. In a finally so it still fires on the hard-crash path (the catch
// above). Only missed if a tool never returns or throws (a true hang).
capture_call_tool('server_call_tool', {
...telemetryData,
duration_ms: Date.now() - startTime,
is_error: String(isError),
});
Comment on lines +1575 to +1583

@coderabbitai coderabbitai Bot Jun 4, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🛠️ Refactor suggestion | 🟠 Major | ⚡ Quick win

Guard telemetry emission in finally so analytics failures can't fail the tool call.

A throw from capture_call_tool(...) inside finally will override the normal return/error response path and turn successful tool executions into handler failures. Wrap this emit in a local try/catch (log-only on failure).

Proposed hardening patch 
     } finally {
         // Single tool-call telemetry event, fired AFTER execution so it can carry
         // timing. In a finally so it still fires on the hard-crash path (the catch
         // above). Only missed if a tool never returns or throws (a true hang).
-        capture_call_tool('server_call_tool', {
-            ...telemetryData,
-            duration_ms: Date.now() - startTime,
-            is_error: String(isError),
-        });
+        try {
+            capture_call_tool('server_call_tool', {
+                ...telemetryData,
+                duration_ms: Date.now() - startTime,
+                is_error: String(isError),
+            });
+        } catch (telemetryError) {
+            logToStderr('warn', `server_call_tool telemetry failed: ${telemetryError}`);
+        }
     }
📝 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.

Suggested change
} finally {
// Single tool-call telemetry event, fired AFTER execution so it can carry
// timing. In a finally so it still fires on the hard-crash path (the catch
// above). Only missed if a tool never returns or throws (a true hang).
capture_call_tool('server_call_tool', {
...telemetryData,
duration_ms: Date.now() - startTime,
is_error: String(isError),
});
} finally {
// Single tool-call telemetry event, fired AFTER execution so it can carry
// timing. In a finally so it still fires on the hard-crash path (the catch
// above). Only missed if a tool never returns or throws (a true hang).
try {
capture_call_tool('server_call_tool', {
...telemetryData,
duration_ms: Date.now() - startTime,
is_error: String(isError),
});
} catch (telemetryError) {
logToStderr('warn', `server_call_tool telemetry failed: ${telemetryError}`);
}
}
🤖 Prompt for AI Agents 
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@src/server.ts` around lines 1575 - 1583, In the finally block where
capture_call_tool('server_call_tool', {...}) is invoked, wrap that call in a
local try/catch so any exception from the telemetry/analytics emission cannot
escape and affect the handler's normal return/error flow; inside the catch, log
the telemetry error (do not rethrow). Keep existing telemetry payload fields
(telemetryData, duration_ms: Date.now() - startTime, is_error: String(isError))
when calling capture_call_tool and ensure only logging happens on failure.

}
});

Expand Down
Loading