MCP Observability: Logging, Tracing, and Metrics
MCP observability means giving yourself visibility into what a Model Context Protocol server and its clients are actually doing: which tools got called, with what arguments, how long each call took, and where a request failed. Without it, a broken MCP integration looks like a black box: the model just stops using a tool, or an agent silently retries the same failing call in a loop, and you have no record of why.
MCP servers are unusual instrumentation targets. Many run over stdio, which means anything written to stdout corrupts the protocol stream. Many are short-lived child processes spawned per session, so you cannot rely on a long-running process to batch and flush telemetry. And a single user-facing "ask the agent to do X" request can fan out into a dozen tool calls across multiple servers, so a flat log line per call tells you almost nothing about the causal chain. This article covers the three pillars, logging, tracing, and metrics, specifically as they apply to MCP, with working code for both a Python server (using the official mcp SDK) and a TypeScript server.
Why standard APM tooling falls short for MCP
A typical APM agent instruments HTTP frameworks: it sees a request come in, wraps it in a span, and reports it. That works fine if your MCP server runs over the Streamable HTTP transport, because HTTP requests are what your APM vendor already understands. It falls apart in three MCP-specific situations.
First, the stdio transport. A large share of local MCP servers (the ones Claude Desktop, Claude Code, and similar clients launch as subprocesses) communicate over stdin/stdout using JSON-RPC. If your logging library defaults to console.log or print(), every log line lands on stdout and gets interpreted as a malformed JSON-RPC message by the client. The server appears to "hang" or the client disconnects with a parse error. Any MCP observability setup has to route logs somewhere other than stdout: stderr, a file, or an OTLP exporter over the network.
Second, session and process lifecycle. Stdio servers are usually spawned fresh per client session and torn down when the session ends. There's no warm process sitting around exporting metrics on a steady interval unless you flush eagerly and handle shutdown signals correctly. A metrics pipeline that batches for 60 seconds before exporting will lose everything from a server that lives for 20 seconds.
Third, causality across the tool-call boundary. When an LLM decides to call three tools to answer one question, you want to see those three calls as children of one logical request, not three unrelated log lines. That requires propagating a trace context (or at minimum a correlation ID) from the client into each tool call, which the MCP spec does not do automatically for you: you have to design it in.
Structured logging for MCP servers
The first rule of MCP observability is: never let anything but protocol messages hit stdout on a stdio server. The second rule is: log in a structured format (JSON lines) from day one so you are not writing regexes against prose log messages six months from now.
Python: routing logs to stderr. The mcp Python SDK's Server and FastMCP classes communicate over stdio when you run with mcp.server.stdio. Configure the root logger to write JSON to stderr, never stdout:
import logging
import sys
import json
from datetime import datetime, timezone
class JsonFormatter(logging.Formatter):
def format(self, record):
payload = {
"timestamp": datetime.now(timezone.utc).isoformat(),
"level": record.levelname,
"logger": record.name,
"message": record.getMessage(),
}
if record.exc_info:
payload["exception"] = self.formatException(record.exc_info)
if hasattr(record, "tool_name"):
payload["tool_name"] = record.tool_name
if hasattr(record, "session_id"):
payload["session_id"] = record.session_id
return json.dumps(payload)
handler = logging.StreamHandler(stream=sys.stderr)
handler.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])
logger = logging.getLogger("mcp-server")Every subsequent logger.info(...) call lands on stderr as a JSON object, which any log shipper (Vector, Fluent Bit, or just journald if you run the server under systemd) can pick up without touching the protocol stream on stdout.
Wrapping tool handlers to log every call. Rather than sprinkling log calls inside every tool function, wrap the dispatch layer so every tool invocation is logged consistently: arguments, duration, outcome.
import time
import functools
def logged_tool(name):
def decorator(fn):
@functools.wraps(fn)
async def wrapper(*args, **kwargs):
start = time.monotonic()
logger.info(
"tool_call_started",
extra={"tool_name": name},
)
try:
result = await fn(*args, **kwargs)
duration_ms = (time.monotonic() - start) * 1000
logger.info(
"tool_call_succeeded: %s (%.1fms)" % (name, duration_ms),
extra={"tool_name": name},
)
return result
except Exception:
duration_ms = (time.monotonic() - start) * 1000
logger.exception(
"tool_call_failed: %s (%.1fms)" % (name, duration_ms),
extra={"tool_name": name},
)
raise
return wrapper
return decorator
@logged_tool("search_docs")
async def search_docs(query: str) -> str:
# tool implementation
return f"results for {query}"This gives you a start/success/failure triplet for every call, with the timing baked in, without touching business logic inside each tool.
TypeScript: same rule, different runtime. If you are on the TypeScript SDK (@modelcontextprotocol/sdk), the equivalent trap is console.log. Use console.error for anything you want on stderr, or better, a structured logger like pino configured to write to a file descriptor other than stdout:
import pino from "pino";
const logger = pino(
{ level: "info" },
pino.destination({ dest: 2, sync: false }) // fd 2 = stderr
);
export function withLogging<T extends (...args: any[]) => Promise<any>>(
toolName: string,
fn: T
): T {
return (async (...args: Parameters<T>) => {
const start = performance.now();
logger.info({ toolName, event: "tool_call_started" });
try {
const result = await fn(...args);
logger.info({
toolName,
event: "tool_call_succeeded",
durationMs: performance.now() - start,
});
return result;
} catch (err) {
logger.error({
toolName,
event: "tool_call_failed",
durationMs: performance.now() - start,
error: err instanceof Error ? err.message : String(err),
});
throw err;
}
}) as T;
}If your server runs over the Streamable HTTP transport instead of stdio, stdout is safe to use, but keep the JSON-lines discipline anyway: you want the same log shape whether the server runs locally or behind an HTTP gateway, so your parsing pipeline doesn't fork into two formats.
Distributed tracing across the MCP boundary
Logging tells you what happened inside one process. Tracing tells you how a request flowed across processes: client, MCP server, and anything the server itself calls out to (a database, another API, another MCP server it proxies). For MCP specifically, the useful unit of a trace is one client-initiated request (a single tools/call JSON-RPC message), and the span tree under it should include every downstream call that request triggered.
Instrumenting with OpenTelemetry. OpenTelemetry works over stdio MCP servers because the exporter talks to a collector over the network (OTLP/gRPC or OTLP/HTTP), not over stdout. Set it up once at server startup:
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
from opentelemetry.sdk.resources import Resource
resource = Resource.create({"service.name": "mcp-search-server"})
provider = TracerProvider(resource=resource)
exporter = OTLPSpanExporter(endpoint="http://localhost:4317", insecure=True)
provider.add_span_processor(BatchSpanProcessor(exporter))
trace.set_tracer_provider(provider)
tracer = trace.get_tracer("mcp-search-server")Wrap each tool call in a span, and record the tool name and a truncated version of the arguments as span attributes. Do not log full arguments if they might contain secrets or large payloads: truncate or hash them.
async def call_tool(name: str, arguments: dict):
with tracer.start_as_current_span(f"mcp.tool/{name}") as span:
span.set_attribute("mcp.tool.name", name)
span.set_attribute("mcp.tool.arg_count", len(arguments))
try:
result = await dispatch(name, arguments)
span.set_attribute("mcp.tool.status", "ok")
return result
except Exception as e:
span.set_attribute("mcp.tool.status", "error")
span.record_exception(e)
raiseBecause the server-side span is created fresh for each tool call, any HTTP calls or database queries your tool function makes will automatically nest under it as child spans, as long as you've also instrumented those clients (opentelemetry-instrumentation-requests, opentelemetry-instrumentation-httpx, and similar auto-instrumentation packages handle this without extra code).
Propagating context from the client. The harder problem is connecting the client-side "the agent decided to call this tool" event to the server-side span. MCP's JSON-RPC envelope doesn't include a standard trace-context field, so if you control both the client and server (for example, you're building an internal agent framework that talks to your own MCP servers), pass the trace context explicitly as part of the tool call metadata.
A pragmatic approach: generate a correlation ID on the client for the whole agent turn, and pass it as an extra field on every tool call the client makes during that turn.
// client side, before calling the tool
const correlationId = crypto.randomUUID();
const result = await client.callTool({
name: "search_docs",
arguments: { query: userQuery, _correlation_id: correlationId },
});On the server, read _correlation_id out of the arguments before dispatching to the actual tool function, attach it as a span attribute, and strip it so it doesn't leak into the tool's real argument schema:
async def call_tool(name: str, arguments: dict):
correlation_id = arguments.pop("_correlation_id", None)
with tracer.start_as_current_span(f"mcp.tool/{name}") as span:
if correlation_id:
span.set_attribute("mcp.correlation_id", correlation_id)
return await dispatch(name, arguments)Now every span across every tool call in one agent turn shares a mcp.correlation_id attribute, and you can pivot on that in your tracing backend (Jaeger, Honeycomb, Grafana Tempo) to see the whole turn as a group even though there is no formal parent-child span link across the process boundary. If you control the client framework end to end, it's cleaner to inject a real W3C traceparent header into the tool call metadata instead of a bare UUID, so the server can start its span as a proper child of the client's span using opentelemetry.propagate.extract.
What to name your spans. Keep span names low-cardinality: use the tool name, not the tool name plus arguments, or your tracing backend's UI becomes unusable. Put high-cardinality data (the actual query string, the actual file path) in span attributes, where it's searchable but doesn't fragment your span-name-based aggregations.
Metrics: the three that actually matter
You do not need a large metrics catalog to get value out of MCP metrics. Three counters and one histogram cover almost every operational question you'll ask.
- Tool call count, labeled by tool name and outcome (success/error). Answers "which tools are actually being used" and "which tool is failing."
- Tool call duration, a histogram labeled by tool name. Answers "which tool is slow" and lets you set p95/p99 alerts.
- Tool call error rate, derived from the two above, or tracked directly as a ratio. Answers "is this server healthy right now."
- Active sessions / connections, a gauge, if your server is long-running (HTTP transport) rather than spawned per call (stdio).
Using the OpenTelemetry metrics API alongside the tracing setup:
from opentelemetry import metrics
meter = metrics.get_meter("mcp-search-server")
tool_call_counter = meter.create_counter(
"mcp.tool.calls",
description="Number of MCP tool calls",
)
tool_call_duration = meter.create_histogram(
"mcp.tool.duration",
unit="ms",
description="Duration of MCP tool calls",
)
async def call_tool(name: str, arguments: dict):
start = time.monotonic()
status = "ok"
try:
return await dispatch(name, arguments)
except Exception:
status = "error"
raise
finally:
duration_ms = (time.monotonic() - start) * 1000
attrs = {"tool_name": name, "status": status}
tool_call_counter.add(1, attrs)
tool_call_duration.record(duration_ms, attrs)For a stdio server that lives for a single short session, export eagerly rather than relying on the default batch interval. A PeriodicExportingMetricReader with a short interval (a few seconds) or an explicit force_flush() call on shutdown ensures a 20-second-lived process still reports its numbers before the process exits. Register a shutdown handler so SIGTERM triggers a flush:
import signal
import atexit
def flush_telemetry():
provider.force_flush()
meter_provider.force_flush()
atexit.register(flush_telemetry)
signal.signal(signal.SIGTERM, lambda *_: (flush_telemetry(), sys.exit(0)))Putting it together: one call, three signals
For a single tool call, you want all three signals to be joinable after the fact. The cleanest way is to make the trace ID the join key: log lines include the current trace ID, and metrics carry the tool name label that matches the span name. A combined wrapper looks like this in Python:
async def observed_call_tool(name: str, arguments: dict):
correlation_id = arguments.pop("_correlation_id", None)
start = time.monotonic()
status = "ok"
with tracer.start_as_current_span(f"mcp.tool/{name}") as span:
trace_id = format(span.get_span_context().trace_id, "032x")
if correlation_id:
span.set_attribute("mcp.correlation_id", correlation_id)
logger.info(
"tool_call_started",
extra={"tool_name": name, "trace_id": trace_id, "correlation_id": correlation_id},
)
try:
result = await dispatch(name, arguments)
return result
except Exception as e:
status = "error"
span.record_exception(e)
logger.exception(
"tool_call_failed",
extra={"tool_name": name, "trace_id": trace_id},
)
raise
finally:
duration_ms = (time.monotonic() - start) * 1000
attrs = {"tool_name": name, "status": status}
tool_call_counter.add(1, attrs)
tool_call_duration.record(duration_ms, attrs)
logger.info(
"tool_call_finished: %s (%.1fms, %s)" % (name, duration_ms, status),
extra={"tool_name": name, "trace_id": trace_id},
)With this in place, an on-call engineer can start from a metrics dashboard showing a spike in mcp.tool.calls{tool_name="search_docs",status="error"}, jump to the tracing backend filtered by that tool and time window, open a specific slow or failed span, copy its trace ID, and grep the log aggregator for that trace ID to see the exact exception and arguments involved. That loop, metric to trace to log, is the entire point of instrumenting all three signals instead of just one.
Debugging common MCP failure modes with this setup
A few failure patterns show up repeatedly in MCP integrations, and each maps cleanly to one of the three signals above.
The model stops calling a tool it used to call. Check the tool call counter. If calls dropped to zero rather than erroring, the problem is usually upstream of your server: the tool description changed, the client's tool list didn't refresh, or the model decided the tool wasn't relevant. If calls continue but errors spike, it's a server-side regression, and the trace will show where.
A tool call hangs and the client times out. The duration histogram will show a long tail before you even get a user complaint, since a full timeout has to elapse before the client gives up. Set an alert on p99 duration per tool, not just error rate, since a hang doesn't count as an error until the client's timeout fires.
Intermittent failures that don't reproduce locally. This is what correlation IDs are for. Ask the user (or your own logging) for the trace ID or correlation ID from the failing turn, and pull the exact span and log lines for that one request instead of trying to reproduce a transient issue blind.
stdout corruption breaking the protocol entirely. If you see JSON-RPC parse errors on the client side that weren't there before, audit for a stray print() or console.log() that snuck into a dependency or a debug line someone forgot to remove. This is common enough with MCP servers that it's worth adding a startup self-check: write a canary string to stdout in a test harness and assert the client never receives it outside of valid JSON-RPC frames.
Practical rollout checklist
- Route all logs to stderr (stdio transport) or a file/OTLP exporter, never stdout, and verify with a quick manual test that a debug
print()left in code would actually break the client. - Emit structured JSON logs, one object per line, with at minimum a timestamp, level, tool name, and correlation or trace ID field.
- Wrap tool dispatch once, centrally, rather than instrumenting each tool function by hand, so new tools get observability for free.
- Export traces via OTLP to a collector you already run or a hosted backend, and propagate a correlation ID or full
traceparentfrom client to server on every tool call. - Track three metrics minimum: call count by tool and status, call duration histogram by tool, and (for HTTP-transport servers) active session gauge.
- Force-flush metrics and traces on shutdown for short-lived stdio processes; don't rely on a background batch interval outliving the process.
- Set alerts on error rate per tool and p95/p99 duration per tool, not just aggregate server health, since a single misbehaving tool can hide inside a healthy-looking average.
FAQ
Does the MCP spec define a standard way to do observability? No. The Model Context Protocol specification covers the JSON-RPC message format, capabilities negotiation, and transports (stdio, Streamable HTTP), but it does not mandate a logging, tracing, or metrics format. Everything in this article is a convention you apply on top of the protocol, not something MCP enforces for you.
Can I just use console.log or print for quick debugging? Only if your server runs over the HTTP transport, and even then it's worth avoiding out of habit. On the stdio transport, anything written to stdout is interpreted as a JSON-RPC message by the client, so a stray debug print will corrupt the session. Always route debug output to stderr.
Do I need a full OpenTelemetry collector to get value from tracing? No. You can start by exporting spans to a local file or console exporter during development, then point the OTLP exporter at a hosted backend (Honeycomb, Grafana Cloud, Datadog, or similar) once you're ready to run in production. The instrumentation code in your server doesn't change: only the exporter endpoint does.
How do I trace across multiple MCP servers if one server calls another? If your server itself acts as an MCP client to a downstream server (a proxy or aggregator pattern), extract the incoming trace context and inject it into the outgoing call the same way you would with any other client library: extract on receipt, start a child span, inject before making the downstream call. Since MCP doesn't standardize a trace-context field, you have to carry it yourself, either as an extra argument field or, if you control the transport layer, as a custom header on the Streamable HTTP request.
What's the performance cost of instrumenting every tool call? Negligible for logging and metrics; a span creation and a couple of attribute sets add microseconds, well under the latency of any real tool call (a network request, a database query, an LLM call). The main cost to watch is span and log volume at high request rates: use sampling on the tracing side if you're running thousands of tool calls per second, and keep log lines to one per call rather than one per internal step inside a tool.
Should I log the full arguments and results of every tool call? Log enough to debug, not everything by default. Full arguments and results can contain user data or secrets, and large payloads bloat your log storage. A reasonable default is to log argument keys and truncated values, with a debug-level flag that enables full payload logging only when actively investigating an issue.
BootcampA 30-day guided bootcamp: build, harden and ship a production autonomous agent from scratch.
AI AgentsUnderstand how AI agents really work: the loop, the tools, the memory, and why most agent projects fail.