Distributed Tracing for MCP Tool Calls with OpenTelemetry

A single agent task, “look up this customer’s account health”, can fan out into several tool calls across multiple MCP servers. Without distributed tracing, each server’s logs sit in isolation, making it nearly impossible to reconstruct where time went or which call actually caused a failure. OpenTelemetry, already the standard for tracing in most enterprise stacks, applies directly to MCP tool calls, and the full picture requires reaching beyond the MCP server itself into the agent’s own reasoning time.

Instrumenting Tool Calls as Spans

from opentelemetry import trace
from opentelemetry.trace import Status, StatusCode

tracer = trace.get_tracer("enterprise-mcp-server")

@mcp.middleware()
async def tracing_middleware(request, call_next):
    with tracer.start_as_current_span(
        f"mcp.tool_call.{request.tool_name}",
        attributes={
            "mcp.tool_name": request.tool_name,
            "mcp.caller_subject": getattr(request.state, "subject", "unknown"),
            "mcp.session_id": request.session_id,
            "mcp.arguments_summary": _summarize_args(request.arguments),
        },
    ) as span:
        try:
            result = await call_next(request)
            span.set_status(Status(StatusCode.OK))
            return result
        except Exception as e:
            span.set_status(Status(StatusCode.ERROR, str(e)))
            span.record_exception(e)
            raise

def _summarize_args(args: dict) -> str:
    """Avoid putting large or sensitive payloads directly in span attributes."""
    return ", ".join(f"{k}={str(v)[:50]}" for k, v in args.items())

Propagating Trace Context Across Servers

For a trace to connect calls across a federation gateway (Lesson 17) or a multi-server agent session (Lesson 24) into one coherent view, the trace context must travel with the request, standard W3C Trace Context propagation over HTTP headers handles this automatically once both client and server are instrumented.

from opentelemetry.propagate import inject

async def call_tool_with_trace_propagation(session, tool_name: str, arguments: dict):
    headers = {}
    inject(headers)  # Injects traceparent header from the current span context
    return await session.call_tool(tool_name, arguments, extra_headers=headers)

sequenceDiagram
    participant Agent
    participant Gateway as Federation Gateway
    participant CRM as CRM MCP Server
    participant KB as Knowledge-Base MCP Server

    Agent->>Gateway: tools/call crm.search_accounts\n(traceparent: trace-id-A)
    Gateway->>CRM: tools/call search_accounts\n(traceparent: trace-id-A, propagated)
    CRM-->>Gateway: result (span: crm.search_accounts, 340ms)
    Gateway-->>Agent: result
    Agent->>Gateway: tools/call kb.query\n(traceparent: trace-id-A)
    Gateway->>KB: tools/call query\n(traceparent: trace-id-A, propagated)
    KB-->>Gateway: result (span: kb.query, 2100ms)
    Gateway-->>Agent: result

    Note over Agent,KB: One trace (trace-id-A) links every span,\nrevealing kb.query as the slow step

Closing the Gap: Correlating with the Agent’s Own Reasoning Time

Tracing only the MCP server side answers “how long did each tool call take,” but a real agent task’s total wall-clock time also includes model inference latency and reasoning time between tool calls, deciding what to call next, interpreting a result, formulating the next query, none of which is visible from MCP-side spans alone. If a trace shows tool calls accounting for only a fraction of the total task time, the remainder is almost always sitting in this client-side reasoning gap, and finding out for certain requires the agent framework itself to also emit spans into the same trace, not just the server.

# Client/agent side: wrap each model inference call and each reasoning
# step in its own span, propagated into the SAME trace as the MCP spans,
# so the full task timeline, not just the tool-call portion, is visible.
async def run_agent_turn_with_tracing(model_client, messages, tools, tracer):
    with tracer.start_as_current_span("agent.model_inference") as span:
        response = await model_client.chat.completions.create(model=MODEL, messages=messages, tools=tools)
        span.set_attribute("agent.tokens_used", response.usage.total_tokens)

    msg = response.choices[0].message
    if msg.tool_calls:
        with tracer.start_as_current_span("agent.tool_call_dispatch"):
            # Each dispatched call's traceparent is injected here (as in the
            # earlier snippet), linking the MCP-side spans into this same trace.
            results = await asyncio.gather(*(execute_single_call(mcp_session, c) for c in msg.tool_calls))
        messages.extend(results)
        return await run_agent_turn_with_tracing(model_client, messages, tools, tracer)
    return msg.content

flowchart LR
    subgraph fullTrace["One trace, full picture"]
        Infer1["agent.model_inference\n1.2s"] --> Dispatch1["agent.tool_call_dispatch"]
        Dispatch1 --> CRMSpan["mcp.tool_call.crm.search_accounts\n0.34s"]
        Dispatch1 --> KBSpan["mcp.tool_call.kb.query\n2.1s"]
        CRMSpan --> Infer2["agent.model_inference\n0.9s"]
        KBSpan --> Infer2
        Infer2 --> Final["Final response"]
    end

    style Infer1 fill:#EEF0F7,stroke:#6366F1,color:#0F172A
    style Infer2 fill:#EEF0F7,stroke:#6366F1,color:#0F172A
    style Dispatch1 fill:#fff7ed,stroke:#f59e0b,color:#0F172A
    style CRMSpan fill:#f0fdf9,stroke:#0D9488,color:#0F172A
    style KBSpan fill:#f0fdf9,stroke:#0D9488,color:#0F172A
    style Final fill:#fff7ed,stroke:#f59e0b,color:#0F172A

With both sides instrumented into the same trace, the earlier 8-second task now fully accounts for itself: roughly 2.1 seconds of tool execution, and the remaining time split across two model inference calls, a genuinely actionable breakdown rather than a mystery gap.

Using Traces to Debug Agent Task Performance, and Alerting on Them

Once traces flow into a backend (Jaeger, Tempo, or a hosted APM), a slow or failed agent task can be inspected end to end. Beyond ad hoc investigation, the same span attributes support standing alerts: a p95 latency threshold on mcp.tool_call.* spans grouped by tool name catches a specific tool degrading before users notice broadly, and an error-rate threshold on the same grouping feeds directly into the canary rollback analysis built in Lesson 29, the tracing infrastructure built here is not only for reactive debugging, it is the data source several of this course’s other production controls depend on.

The next lesson complements tracing (which observes production behavior) with contract testing, which catches tool regressions before they ever reach production traffic.