Observability and operations

Why you need this

Once a server runs for other people, "the assistant is slow" or "the tool keeps failing" arrives as a complaint with no stack trace attached. Observability means the server records enough, as it runs, to answer those questions afterwards: which request, which tool, how long, and where the time went. This is stage 6 of a server's life, "Maintain it".

The idea

An MCP server offers tools; a host (the app a person uses) runs a client per server on behalf of the model (the language model inside the host). A single question to the assistant can pass through all of them and then on to some downstream API the tool calls. Three kinds of record let you follow it: logs, traces, and metrics.

Logs: one line per request

Write one structured line (a JSON object) per request, after it finishes.

Log	Never log
Method (tools/call, tools/list, ...)	Access tokens, API keys, passwords
Tool, resource, or prompt name	Tool arguments or results that may hold personal data
Duration in milliseconds	Full request bodies "just in case"
resultType (complete or input_required)	Anything the client sends that you have not checked
isError for tool results, or the JSON-RPC error code
Client name from io.modelcontextprotocol/clientInfo
Trace id (below)

Client info is self-reported and unverified; the specification says it is for "display, logging, and debugging", so log it but never trust it for a decision.

Where the line goes. On stdio, stdout is the protocol channel, so logs go to stderr; the host usually captures stderr into its own log file. On HTTP, write to stderr or stdout and let the platform collect it.

The Logging feature is deprecated

MCP once had a way for servers to send log lines to the client as notifications/message. The 2026-07-28 revision deprecates that Logging feature, along with Roots and Sampling. The Logging section names the replacement: migrate to "logging to stderr for stdio transports, or to OpenTelemetry for structured observability". It stays in the specification for at least twelve months.

While it remains, it works per request. A client that wants log lines for one request puts io.modelcontextprotocol/logLevel in that request's _meta (still a reserved key, but marked deprecated in the schema along with the feature), and the server "MUST NOT emit notifications/message for a request that does not include this field". Lines at or above the requested level travel on that request's own response stream, never on a subscriptions/listen stream. We checked this with the official Python SDK: a tool that logged one debug line and one info line delivered nothing with no level set, only the info line at "info", and both at "debug". New servers should not adopt it.

Traces: following one request across programs

A trace is the record of one piece of work across every program it touches. Each program's part is a span. They are tied together by a trace id that every hop passes on. MCP uses the W3C Trace Context format, the same one OpenTelemetry uses, carried in _meta under three keys:

Key	Holds
traceparent	Version, trace id, the sender's span id, flags
tracestate	Vendor-specific extra trace data
baggage	Key-value pairs to pass along, such as a tenant name

Like progressToken, these reserved _meta keys have no io.modelcontextprotocol/ prefix; the specification makes the exception so existing OpenTelemetry tooling works unchanged.

A traceparent is four fields joined by hyphens. In 00-4bf92f3577b34da6a3ce929d0e0e4736-b7ad6b7169203331-01, 00 is the format version, the next 32 hex digits are the trace id, the next 16 are the span id of whoever sent it, and 01 means "sampled", that is, record this trace. Each hop keeps the trace id, replaces the span id with its own, and passes the result on.

The official Python SDK wraps every request in an OpenTelemetry span (named like tools/call quote_shipping), reading the parent from _meta. It does nothing until you install an OpenTelemetry exporter.

Progress and cancellation

A client that wants progress puts a progressToken in the request's _meta. The server may then send notifications/progress with that token, a progress number that must increase each time, an optional total, and an optional message. Progress is also a liveness signal: the Cancellation section allows a client to reset its timeout on each progress notification, while still enforcing a maximum.

To cancel, a client on HTTP closes the request's response stream; the Streamable HTTP section says that "MUST be treated by the server as cancellation of that request". On stdio there is no per-request stream, so the client sends notifications/cancelled with the requestId and an optional reason. A cancelled request should stop its downstream calls too, or it keeps spending money for nobody.

Metrics that matter

Metric	Why
Calls per minute, per tool	Shows which tools the model actually uses, and sudden loops
Error rate, split into tool errors (isError) and protocol errors	Tool errors mean the model is calling badly; protocol errors mean a client or the server is broken
Latency percentiles per tool	The slow calls are the ones people notice
input_required rate	How often a tool has to stop and ask the person something
Downstream API latency and errors	Most slow tool calls are a slow dependency

A percentile says how long the slowest calls take. Sort the latencies; the $p$-th percentile is the value at rank $\lceil p n / 100 \rceil$ out of $n$. Take ten calls in milliseconds: 120, 130, 135, 140, 150, 160, 170, 180, 900, 1213. The median (p50) is rank 5, 150 ms. The p90 is rank 9, 900 ms. The mean is $3298 / 10 = 329.8$ ms, a duration no call actually took. Alert on p95 or p99, not the mean.

Worked example

A shipping-quote server whose one tool waits 1.2 seconds on a carrier's rate API. The script plays all four parts in one process: the host starts a trace, the client sends tools/call with a traceparent and a progress callback, a server middleware writes one log line per request, and the tool forwards the trace to the downstream API.

"""One slow tools/call, traced from host to downstream API, with one log line per hop."""
import asyncio
import json
import logging
import sys
import time

from mcp import Client
from mcp.server import MCPServer
from mcp.server.mcpserver import Context
from mcp.shared.exceptions import MCPError
from mcp_types import Implementation

logging.basicConfig(stream=sys.stderr, level=logging.INFO, format="%(message)s")
logging.getLogger("mcp").setLevel(logging.WARNING)  # keep the SDK's own lines out of this demo


def log(side: str, **fields) -> None:
    """One JSON object per line on stderr: easy to grep, easy to ship to a log store."""
    logging.getLogger(side).info(json.dumps({"side": side, **fields}))


server = MCPServer("shipping")


async def carrier_rates_api(weight_kg: float, headers: dict) -> float:
    """Stands in for a slow third-party HTTP API."""
    started = time.perf_counter()
    await asyncio.sleep(1.2)
    log("carrier-api", traceparent=headers["traceparent"], ms=round((time.perf_counter() - started) * 1000))
    return round(4.5 + 2.1 * weight_kg, 2)


@server.tool()
async def quote_shipping(weight_kg: float, ctx: Context) -> float:
    """Price in dollars to ship a parcel of the given weight."""
    # Keep the trace id, swap in this server's own span id (an OpenTelemetry SDK would mint it).
    version, trace_id, _parent, flags = ctx.request_context.meta["traceparent"].split("-")
    outgoing = f"{version}-{trace_id}-e457b5a2e4d86bd1-{flags}"
    await ctx.report_progress(0, 2, "asking carrier")
    price = await carrier_rates_api(weight_kg, {"traceparent": outgoing})
    await ctx.report_progress(2, 2, "done")
    return price


async def access_log(ctx, call_next):
    """Server middleware: one line per request, written after the handler finishes."""
    meta = ctx.meta or {}
    started = time.perf_counter()
    result, error_code = None, None
    try:
        result = await call_next(ctx)  # a dict in wire form (camelCase keys)
        return result
    except MCPError as e:
        error_code = e.error.code
        raise
    finally:
        log("server",
            method=ctx.method,
            tool=(ctx.params or {}).get("name"),
            ms=round((time.perf_counter() - started) * 1000),
            result_type=(result or {}).get("resultType"),
            is_error=(result or {}).get("isError"),
            error_code=error_code,
            client=(meta.get("io.modelcontextprotocol/clientInfo") or {}).get("name"),
            traceparent=meta.get("traceparent"))


server.middleware.append(access_log)


async def main():
    # The host starts a trace for the user's turn and passes it down.
    trace_id = "4bf92f3577b34da6a3ce929d0e0e4736"
    host_span, client_span = "00f067aa0ba902b7", "b7ad6b7169203331"
    log("host", event="model asked for quote_shipping", traceparent=f"00-{trace_id}-{host_span}-01")

    async def on_progress(progress, total, message):
        log("client", event="progress", progress=progress, total=total, message=message)

    async with Client(server, client_info=Implementation(name="demo-host", version="1.0")) as client:
        started = time.perf_counter()
        result = await client.call_tool(
            "quote_shipping",
            {"weight_kg": 3},
            progress_callback=on_progress,
            meta={"traceparent": f"00-{trace_id}-{client_span}-01"},
        )
        log("client", method="tools/call", tool="quote_shipping",
            ms=round((time.perf_counter() - started) * 1000), result=result.structured_content)


asyncio.run(main())

server.middleware is the SDK's hook for code that wraps every request; the SDK marks its signature as provisional in version 2. Passing progress_callback makes the client add a progressToken to the request for you. python traced_call.py printed these lines on stderr:

{"side": "host", "event": "model asked for quote_shipping", "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}
{"side": "server", "method": "server/discover", "tool": null, "ms": 0, "result_type": "complete", "is_error": null, "error_code": null, "client": "demo-host", "traceparent": null}
{"side": "client", "event": "progress", "progress": 0, "total": 2, "message": "asking carrier"}
{"side": "carrier-api", "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-e457b5a2e4d86bd1-01", "ms": 1211}
{"side": "client", "event": "progress", "progress": 2, "total": 2, "message": "done"}
{"side": "server", "method": "tools/call", "tool": "quote_shipping", "ms": 1213, "result_type": "complete", "is_error": false, "error_code": null, "client": "demo-host", "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-b7ad6b7169203331-01"}
{"side": "server", "method": "tools/list", "tool": null, "ms": 0, "result_type": "complete", "is_error": null, "error_code": null, "client": "demo-host", "traceparent": null}
{"side": "client", "method": "tools/call", "tool": "quote_shipping", "ms": 1283, "result": {"result": 10.8}}

Read the trace by its id, 4bf92f35..., which appears on the host, server, and carrier lines:

Hop	Span id in its traceparent	Time	What it tells you
Host	00f067aa0ba902b7		The user's turn started here
Client to server	b7ad6b7169203331	1283 ms at the client	Total time the host waited
Server, tools/call	(received b7ad...)	1213 ms	Time inside the server
Server to carrier API	e457b5a2e4d86bd1	1211 ms	Time inside the dependency

So 1211 of 1213 server milliseconds were the carrier, and only 70 ms of the client's 1283 went to the SDK and the extra requests. The fix, if there is one, is a cache or a faster carrier, not the server code. The two untraced lines are the SDK client's own requests: server/discover when it connected, and a tools/list after the call, which it uses to check the result against the tool's outputSchema. Two progress notifications arrived during the wait; a host can show "asking carrier" instead of a frozen spinner. The price checks out: $4.5 + 2.1 \times 3 = 10.8$.

In a server's life

• Maintain it (stage 6) is this page: the logs and metrics here are how you notice that a change from Evolving a server broke someone.
• Test and ship (stage 5): once deployed as several copies, the trace id is the only thing tying one request's lines together.
• Secure it (stage 4): logs are a place secrets leak. The Logging section's rule, that log messages "MUST NOT contain" credentials or personal identifying information, is good practice for every log, deprecated feature or not.

Common mistakes

• Logging to stdout from a stdio server. Symptom: the client logs a parse error for every log line, and a stricter client than the Python SDK's may drop the connection. Log to stderr.
• Logging arguments and results wholesale. Symptom: a user's address or an access token turns up in the log store. Log names, sizes, and codes, not values.
• Starting a new trace in the server. Symptom: the host's trace and the server's trace never join, so a slow turn shows no server time. Read traceparent from _meta and continue it.
• Ignoring cancellation. Symptom: downstream calls keep running, and keep being billed, after the user gave up. Stop work when the stream closes or notifications/cancelled arrives.
• Alerting on the mean. Symptom: one tool is unusable for a tenth of calls but the dashboard looks fine. Alert on p95 or p99 per tool.
• Counting tool errors as outages. Symptom: pages at night because a model sent bad units. Track isError results separately from protocol errors and crashes.

Cost

One log line per request is a few hundred bytes; at $r$ requests per second that is roughly $r \times 300$ bytes per second, about 26 MB per day at $r = 1$, which matters only when the log store charges by volume. A trace adds one span per hop and one dictionary lookup per request. Progress notifications cost one small message each; send them every second or so, not on every loop iteration. The real cost is engineering time: deciding which fields to log, building the dashboard, and choosing alert thresholds that wake someone only for real problems.

Going further

• OpenTelemetry's semantic conventions for MCP, which name the span attributes the SDK sets.
• The Progress and Cancellation sections of the 2026-07-28 specification.
• The W3C Trace Context format, for the exact rules on traceparent and tracestate.
• Trace sampling in OpenTelemetry: recording only a fraction of requests once traffic is high.
• Service level objectives: turning "p95 under 2 seconds" into an alert budget.