How to capture telemetry for MCP tool calls (your access log cannot)

If you want telemetry for MCP tool calls, the instrumentation point is inside the JSON-RPC handler, after the response body exists. Not the HTTP layer, not a proxy, not an access log. Write one row per request carrying the method, the tool name, the outcome read out of the response body, latency, byte counts, the caller's user agent and whatever identity you verified. Everything else in this post is why each of those fields is on the row, learned by shipping a gateway that was missing most of them.

An access log for an MCP server is a flat line

Our gateway serves every deployment from one route. A customer's agent calling eight different tools produces eight lines that differ only in the timestamp:

POST /api/public/mcp/d/acme  200  341ms
POST /api/public/mcp/d/acme  200  180ms
POST /api/public/mcp/d/acme  200  2104ms

Same method, same path, same status. The tool name lives in the request body, the outcome lives in the response body, and the HTTP layer reads neither. This is not a quirk of our design, it is what Streamable HTTP is: one endpoint, one verb, JSON-RPC inside.

The status code is worse than uninformative. A tool that fails returns a perfectly ordinary result with a flag set, so the outcome has to be dug out of the body we are about to send:

const result = truncateToolResult(rawResult);
response = jsonRpcResult(rpc.id, modern ? modernizeResult(result, serverInfo) : result, rpcHeaders);
if ((result as any)?.isError) {
  ok = false;
  errorCode = "tool_error";
}

The row we actually write

This is the shape, unedited. It is worth reading as a list of decisions rather than a schema:

export type RequestLogRow = {
  deploymentId: string;
  workspaceId: string;
  endUserId: string | null;
  method: string;
  toolName: string | null;
  ok: boolean;
  statusCode: number;
  latencyMs: number;
  requestBytes: number;
  responseBytes: number;
  errorCode: string | null;
  clientIp?: string | null;
  userAgent?: string | null;
  visitorSub?: string | null;
  visitorEmail?: string | null;
};

method and toolName are separate on purpose. A handshake, a tool listing and a tool call are all traffic, and only the last one is product usage. Keeping the JSON-RPC method next to the tool name is what lets one query answer "how many real tool calls" without a join.

responseBytes is the field people drop, and it is the one that caught our worst cost bug. We measure it by cloning the response we are already holding:

try {
  const cloned = response.clone();
  responseBytes = (await cloned.arrayBuffer()).byteLength;
} catch {
  /* ignore */
}

A tool returning 60 KB of JSON looks identical to a tool returning 600 bytes in every latency chart ever drawn. It is not identical to the model that has to read it, and it is not identical on the bill. Byte counts per tool are how a context-budget problem becomes visible before a customer reports a truncated answer.

Nobody tells you who called

A tools/call request has no caller field. You get a bearer token if you require one, and a user agent if the client bothers. So "our MCP handled 12,000 calls this month" is a sentence with no content. Claude retrying a failing tool six times is not six customers, and our own dashboard test button is not a customer at all.

We classify the caller from the user agent against a fixed table, and keep an explicit unknown bucket instead of inventing a default:

export const CLIENT_FAMILIES = [
  { key: "claude", label: "Claude", patterns: ["claude"] },
  { key: "chatgpt", label: "ChatGPT", patterns: ["chatgpt", "openai"] },
  { key: "cursor", label: "Cursor", patterns: ["cursor"] },
  { key: "windsurf", label: "Windsurf", patterns: ["windsurf", "codeium"] },
  { key: "vscode", label: "VS Code", patterns: ["vscode", "visual%studio%code", "copilot"] },
  { key: "mcp-inspector", label: "MCP Inspector", patterns: ["mcp-inspector", "inspector"] },
  // ... 13 families in total, plus curl, Postman and raw HTTP clients
];

Thirteen families sounds like over-engineering until the first support thread where the question is whether a customer's Cursor or a scraper produced the traffic. The patterns are deliberately loose and the fallthrough is a labelled other rather than a blank.

For end-user identity, we take the subject from the token we already verified, and try the email from the same payload without letting that attempt matter:

try {
  const json = JSON.parse(atob(b64 + "=".repeat((4 - (b64.length % 4)) % 4)));
  if (json && typeof json.email === "string" && json.email.includes("@"))
    email = json.email.slice(0, 320);
} catch {
  /* payload unreadable — sub alone is still worth recording */
}

That comment is the whole rule for identity capture. A partially identified call is far more useful than an anonymous one, so no enrichment step is allowed to throw away the subject it was decorating.

Diagnostics belong in the log and nowhere near the counters

Auth probes, rejected requests and discovery traffic have to be logged. If a customer's agent is being turned away at the door, the absence of a row is the one thing that makes it undiagnosable. But those rows are not usage, and the first version of our rollup counted them.

A bot hammering an endpoint with bad credentials turned our error rate into something near 90% and quietly consumed quota. The fix is a naming convention and a one-line predicate:

export function isSystemLogMethod(method: string): boolean {
  return method.startsWith("(");
}

Synthetic events are written with a parenthesised method, for example (POST rejected). They appear in the request log where an operator needs them, and the daily rollup skips them without a second table or a nullable flag that someone forgets to set:

const rollupWrite = isSystemLogMethod(row.method)
  ? null
  : supabaseAdmin.rpc("bump_mcp_deployment_usage_daily", { /* ... */ });

Your own traffic needs the same treatment, and it is easy to forget because it is the traffic you generate while building the feature. Ours is excluded three ways: internal probes are skipped before the recorder is called, smoke tests announce themselves with a cmdk-smoke-test user-agent prefix, and end users created by the dashboard's own test console carry operator_test: true in their metadata. Without that last one, the top-customers table ranks the operator first on every new deployment.

One latency number starts arguments, six end them

A gateway's total latency is mostly somebody else's API. Reporting it as a single figure means every slow-tool conversation is a disagreement about whose fault it is. We split the request into phases and attach them to the response:

export type GatewayTiming = {
  session: number;
  gates: number;
  auth: number;
  upstream: number;
  record: number;
  total: number;
};

response.headers.set("x-cmdk-timing", timingHeaderValue(timing));

The header reads session=2;gates=14;auth=31;upstream=2810;record=48;total=2905. That request was not slow, the upstream API was, and the sentence is no longer an opinion. Anything over SLOW_REQUEST_MS = 1500 also lands in the platform log with the same breakdown plus the tool name, so a slow tool is searchable without reproducing it.

record is the phase that measures the recorder. Keeping it in the header is a standing reminder that telemetry is not free, and ours is currently awaited on the critical path, which is the first thing I would move to an after-response hook under real load.

The write path has to be boring

One rule is not negotiable: telemetry may never fail a request. The entire recorder sits in a try/catch whose worst outcome is a log line, because an agent mid-turn must not see an error caused by our analytics table being unhappy.

if (logErr) console.warn(`[mcp-gateway] request log insert failed: ${logErr.message}`);
if (rollup?.error) console.warn(`[mcp-gateway] usage rollup failed: ${rollup.error.message}`);

Two more that cost us time to learn:

• Decide retention before the first row. Ours grew unbounded because nothing ever deleted, and the fix arrived as a migration that installs a nightly job: delete from mcp_deployment_request_log where at < now() - interval '30 days'. Per-request rows last 30 days, daily aggregates are kept indefinitely. The aggregate is written by its own RPC in the same step as the insert, which is why dropping raw rows costs no history.
• Make it exportable on day one. Ours is ten columns of CSV over a window of up to 30 days, capped at 10,000 rows. The first enterprise security review will ask, and a dashboard with no export is a dashboard the buyer cannot hand to their auditor.

What to check on your own MCP server

• Pick a tool, break it upstream, and watch your success-rate chart. If it does not move, you are counting status codes.
• Query your top 10 callers. If an entry is your own test client or a blank user agent, your adoption numbers are inflated by an amount you cannot currently state.
• Take yesterday's p95 and try to say how much of it was your code. If you cannot, you need phase timings before you need any more charts.
• Find the row for a request that was rejected at auth. If there is no row, your most common customer-facing failure is the one event you have no record of.
• Check what deletes rows from your log table. If the answer is nothing, that is a bill arriving later rather than a retention policy.

All of this ships by default on a Command+K deployment, because we built it while getting an 84-tool GraphQL connector through real clients. If you want the metric layers rather than the capture mechanics, the MCP analytics post covers what to build on top of these rows, and the audit log post covers the compliance version of the same table.