MCP Observability and Audit Logging

Interview answer (say this first). Observability is how you see and prove what an MCP server did. For every tool call, record six things: which server, which tool, which caller, the arguments (redacted), the result or error, and the decision plus duration. Correlate the host, the gateway, and the server with one trace or request id. Use structured logs to stderr or OpenTelemetry — MCP’s own logging notification is deprecated as of the 2026-07-28 revision (SEP-2577). Never log secrets or PII, keep an append-only tamper-evident audit trail, and alert on error rate, latency, and denied calls.

Note:

Verified. Every runnable pure-Python example on this page was executed on Python 3.14. The MCP round-trip was executed end to end on Python 3.12 with the official mcp SDK version 2.2.0, and the OpenTelemetry behavior was introspected from that same SDK. SDK shapes are reported for the versions named; MCP is still evolving, so check the version you ship.

Why this exists

An agent is a program that calls tools. When a call goes wrong, the chat transcript tells you almost nothing. It says “the refund failed”, not which server, which arguments, or which user caused it.

Here is the failure in plain terms. A support agent processes refunds. One day, sixty customers are refunded twice. You go to the logs. You find this:

INFO agent: tool call succeeded
INFO agent: tool call succeeded
INFO agent: tool call succeeded

No tool name. No order id. No caller. No duration. You cannot tell which calls were duplicates, whether a retry caused the second refund, or which user triggered the run. The bug is real, and the evidence is missing.

The same gap blocks four other things:

• Debugging. You cannot reconstruct a run without knowing the inputs and outputs.
• Security. After a prompt-injection attempt, you cannot prove which tool call the attacker influenced.
• Compliance. Auditors ask who did what, when, and under which approval. “It’s in the model’s context” is not an answer.
• Operations. You cannot page on error rate or latency if you never recorded them.

Observability exists to make every call reconstructable. Audit logging exists to make the record trustworthy.

Tip:

The one-sentence purpose. If you can answer “which caller ran which tool, with what inputs, producing what result, how fast, and was it allowed?” then you have observability. If you can also prove the record was not edited, you have an audit trail.

Start from zero

Two distinctions matter:

• Logs, metrics, and traces answer different questions. Logs say what happened. Metrics say how often and how fast. Traces say where the time went. You need all three.
• Observability is for operators; an audit log is for proof. Logs may be sampled or rotated away. Audit records are complete, ordered, and protected.

The core idea

Think of a bank.

• Every transaction produces a receipt: who, what, when, how much. That is a log line.
• The daily totals on the manager’s dashboard are metrics. They do not name every customer; they show trends.
• The ledger is the audit trail. It is ordered, append-only, and each entry locks in the previous one.
• The security camera is a trace. It shows the money moving through each station, with timestamps.

An MCP tool call is a transaction. The user request is one camera recording that starts at the host, passes through the gateway, and ends inside the server:

flowchart LR
    U["User request<br/>trace_id = abc123"] --> H["Host / agent<br/>span: agent.run"]
    H -->|"header: traceparent"| G["MCP gateway<br/>span: gateway.tools_call"]
    G -->|"_meta: traceparent"| S["MCP server<br/>span: tools/call process_refund"]
    S --> T["Tool executes<br/>duration, result"]
    T --> G
    G --> H
    H --> U
    H -.-> L["Logs + metrics + audit"]
    G -.-> L
    S -.-> L

The ids are what make the picture join up. The host generates trace_id. The gateway passes it on. The server attaches its span to the same trace. Without propagation, you have three unrelated log files.

MCP supports this directly. The official SDK ships an OpenTelemetry middleware and helpers that inject and extract W3C trace context through the request _meta field. The traceparent value rides along with the tool call, so the server’s span nests under the host’s.

The three pillars split the work like this:

Note:

What changed in the protocol. MCP once carried log messages from server to client (notifications/message with logging/setLevel). SEP-2577 deprecated that as of the 2026-07-28 revision. The reason is overlap: stderr already works for stdio servers, and OpenTelemetry already handles structured observability for HTTP servers. On 2026-07-28 delivery is a per-request opt-in: the server sends no log notification unless the request’s _meta carries the reserved key io.modelcontextprotocol/logLevel, and logging/setLevel is gone. The feature still works for requests that opt in, but new servers should not adopt it.

How it works

1. The host assigns one correlation id per user request. This is the root of the trace. Every later event carries it.
2. The caller identity is captured at the boundary. Not the model’s claim of who it is — the authenticated principal from the OAuth token or session. MCP authorization belongs to the gateway and host, not the server’s good intentions.
3. The gateway logs the decision. Before the call reaches the server, record the caller, the tool, the arguments hash, the policy decision (allow or deny), and the reason. A denied call is often the most important line you have.
4. The server logs the invocation and its outcome. Start time, tool name, a redacted view of the arguments, the arguments hash, and the result summary. On error, log the error type, not the full stack in the audit record.
5. Duration is measured around the real work. Use a monotonic clock and record milliseconds. Duration turns “it felt slow” into a number.
6. Structured logs go to stderr, not stdout. For a stdio server, stdout is the JSON-RPC framing channel. Writing a log line there corrupts the protocol. stderr is safe and is captured by the host.
7. For HTTP servers, emit OpenTelemetry instead. OTel produces traces, metrics, and logs in one format. The MCP SDK’s OTel middleware wraps each inbound message in a span with standard attributes.
8. Traces propagate through _meta. The host injects traceparent; the server extracts it. The SDK exposes inject_trace_context(meta) and extract_trace_context(meta) for exactly this.
9. Metrics are recorded at the gateway. Count calls per tool, errors per tool, and a latency histogram. Add a token counter if the gateway sees model usage.
10. Redaction happens before the logger sees the value. A card_number, token, or authorization field is masked at the serialization boundary. Redacting “later” means the secret already reached disk.
11. Audit records are append-only and hash-chained. Each entry stores the hash of the previous entry, so an edit breaks the chain and verify() reports the first bad index.
12. Alerting watches the four signals that hurt. Error rate, p95 latency, denied-call spikes, and new tool names nobody approved.

The syntax you will use

A structured logger with a correlation id. contextvars carries the id across async calls without passing it as an argument everywhere.

import json, logging, contextvars

request_id = contextvars.ContextVar("request_id", default="-")

class JsonFormatter(logging.Formatter):
    def format(self, record):
        payload = {
            "ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S"),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
            "request_id": request_id.get(),
        }
        payload.update(getattr(record, "fields", {}))
        return json.dumps(payload, sort_keys=True)

Every line becomes one JSON object. A log query becomes a filter, not a regular expression.

The record you should keep for every call. Six fields plus a hash, exactly as the interview answer says.

from dataclasses import dataclass

@dataclass
class ToolCallRecord:
    correlation_id: str      # the shared request id
    caller: str              # authenticated principal
    server: str              # which MCP server
    tool: str                # which tool
    arguments: dict          # redacted arguments
    arguments_hash: str      # stable fingerprint of the real arguments
    decision: str            # allow / deny, from policy
    result: str              # short summary
    duration_ms: float
    ok: bool
    error: str | None = None

The hash lets you deduplicate and compare calls without storing the raw secret values.

Redaction at the boundary. Walk the structure and mask sensitive keys before serialization.

SENSITIVE = {"password", "token", "api_key", "card_number", "email", "authorization"}

def redact(value):
    if isinstance(value, dict):
        return {k: ("***" if k.lower() in SENSITIVE else redact(v))
                for k, v in value.items()}
    if isinstance(value, list):
        return [redact(v) for v in value]
    return value

Redaction is recursive, because secrets hide in nested objects.

A tamper-evident audit chain. Each entry commits to the previous entry’s hash.

import hashlib, json

GENESIS = "0" * 64

class AuditLog:
    def __init__(self):
        self.entries = []

    def append(self, event, **fields):
        prev = self.entries[-1]["hash"] if self.entries else GENESIS
        body = {"seq": len(self.entries), "event": event, "prev": prev, **fields}
        body["hash"] = hashlib.sha256(
            json.dumps(body, sort_keys=True, default=str).encode()).hexdigest()
        self.entries.append(body)
        return body["hash"]

    def verify(self):
        prev = GENESIS
        for i, entry in enumerate(self.entries):
            body = {k: v for k, v in entry.items() if k != "hash"}
            if body.get("prev") != prev:
                return (False, i)
            digest = hashlib.sha256(
                json.dumps(body, sort_keys=True, default=str).encode()).hexdigest()
            if digest != entry["hash"]:
                return (False, i)
            prev = entry["hash"]
        return (True, -1)

verify() walks the chain from the first entry and returns (False, index) at the first bad link, or (True, -1) when the whole chain is intact. Change any earlier field and the recomputed hash no longer matches.

Metrics that answer the operational questions. Counters for volume, a list for latency percentiles.

from collections import defaultdict

class Metrics:
    def __init__(self):
        self.calls = defaultdict(int)
        self.errors = defaultdict(int)
        self.latencies = defaultdict(list)

    def record(self, tool, ms, ok=True):
        self.calls[tool] += 1
        if not ok:
            self.errors[tool] += 1
        self.latencies[tool].append(ms)

    def percentile(self, tool, pct):
        xs = sorted(self.latencies[tool])
        if not xs:
            return 0.0
        return xs[round((pct / 100) * (len(xs) - 1))]

    def summary(self, tool):
        n = self.calls[tool]
        return {
            "calls": n,
            "errors": self.errors[tool],
            "error_rate": round(self.errors[tool] / n, 3) if n else 0.0,
            "p50_ms": self.percentile(tool, 50),
            "p95_ms": self.percentile(tool, 95),
        }

In production you would emit these to Prometheus or OTel instead of keeping them in memory.

The MCP logging and progress API. A server can push a log message or progress update to the client. logger_name names the logger; report_progress carries a fraction and an optional message.

from mcp.server.mcpserver.context import Context

async def process_refund(order_id: str, ctx: Context) -> str:
    await ctx.log("info", f"refund requested for {order_id}", logger_name="billing.audit")
    await ctx.report_progress(0.5, 1.0, "validating order")
    return f"refund queued for {order_id}"

This still works, but it raises an MCPDeprecationWarning on mcp 2.2.0 because of SEP-2577. On the 2026-07-28 revision the client must opt in per request by putting io.modelcontextprotocol/logLevel in the request _meta; without that key the server must send nothing. Prefer stderr or OTel for new servers. (The worked round-trip in Example 7 runs on the 2025-11-25 handshake, where the level is set once for the session rather than per request.)

OpenTelemetry in the MCP SDK. The SDK ships a middleware that wraps each inbound message in a span and propagates trace context.

from mcp.server.mcpserver import MCPServer
from mcp.server._otel import OpenTelemetryMiddleware
from mcp.shared._otel import inject_trace_context, extract_trace_context

# On the server: wrap every inbound message in a span.
server = MCPServer("billing", middleware=[OpenTelemetryMiddleware()])

# On the host: put trace context into the request `_meta`.
meta: dict = {}
inject_trace_context(meta)          # adds "traceparent"

# On the server: pull it back out and nest the span.
parent = extract_trace_context(meta)

The middleware sets mcp.method.name, mcp.protocol.version, jsonrpc.request.id, and, for tool calls, gen_ai.operation.name = "execute_tool" and gen_ai.tool.name. Those are the attribute names to expect in your trace backend.

Examples: simple to real

Example 1 — one JSON line beats one prose line.

{"level": "INFO", "logger": "mcp.gateway", "message": "tool_call", "request_id": "req-7f3a", "server": "billing", "tool": "process_refund", "ts": "2026-09-13T19:36:09"}
{"level": "WARNING", "logger": "mcp.gateway", "message": "policy_denied", "request_id": "req-9c21", "server": "billing", "tool": "delete_account", "ts": "2026-09-13T19:36:09"}

Both lines carry the request id, the server, and the tool. The second is a security event. This exact output was produced and captured while writing the page.

Example 2 — the full call record, with the secret masked.

{"arguments": {"card_number": "***", "order_id": "A-100"}, "arguments_hash": "fd7da19d4fd0", "caller": "user:ada", "correlation_id": "req-7f3a", "decision": "allow", "duration_ms": 0.02, "error": null, "ok": true, "result": "refund queued for A-100", "server": "billing", "tool": "process_refund"}
raw card number present in logged arguments: False

The card number was passed to the tool, but the log contains ***. The hash still lets you match repeated calls. This is the pattern to copy: execute with the real value, log the redacted value plus a hash.

Example 3 — a denied call is recorded, not dropped.

{"arguments": {"account_id": "B-9"}, "arguments_hash": "054cc518c584", "caller": "user:bob", "correlation_id": "req-9c21", "decision": "deny", "duration_ms": 0.0, "error": "policy_denied", "ok": false, "result": "blocked", "server": "billing", "tool": "delete_account"}

The tool never ran, yet the attempt is on record. Denied calls are how you detect probing, misconfiguration, and prompt injection.

Example 4 — an edited audit entry breaks the chain.

chain intact after 3 appends: (True, -1)
chain intact after tamper: (False, 1)

verify() scans from the first entry and returns the index where the chain breaks. Entry 1 was edited from deny to allow, and the check caught it. In production, anchor the newest hash somewhere independent, or an attacker can recompute the whole chain.

Example 5 — metrics turn the run into trends.

{"run_sql": {"calls": 3, "error_rate": 0.333, "errors": 1, "p50_ms": 45, "p95_ms": 800}, "search_docs": {"calls": 6, "error_rate": 0.0, "errors": 0, "p50_ms": 18, "p95_ms": 900}}

search_docs has no errors but a p95 of 900 ms — a latency problem, not an error problem. run_sql fails one call in three. Different alerts for different tools, from the same small record.

Example 6 — trace context flows host to server through _meta.

injected meta keys: ['traceparent']
parent == host trace: True

The host wrapped work in a span, injected traceparent into a metadata dict, and the “server” extracted it and started a child span. The child shares the host’s trace_id. This is the mechanism that makes the diagram at the top real.

Example 7 — MCP round-trip, verified end to end. A server logs and reports progress; a client receives both while the call runs.

CLIENT LOG: info billing.audit -> refund requested for A-100
CLIENT PROGRESS: 0.5/1.0 validating order
CLIENT LOG: info billing.audit -> order validated
CLIENT PROGRESS: 1.0/1.0 refund queued
RESULT: refund queued for A-100 is_error= False

This was executed against a real MCPServer over stdio with a real ClientSession, on the 2025-11-25 handshake (the last revision where the server may push logs for the session without a per-request _meta opt-in). Note the deprecation warning in the server output: the protocol channel works, but the ecosystem is moving to stderr and OTel.

In production

• Never write logs to stdout on a stdio server. stdout carries JSON-RPC frames. One stray print() corrupts the session and the client disconnects. Log to stderr.
• Redact before logging, not after. The safest secret is the one that never reaches the log buffer. Put redaction in the formatter or the serializer, so no call site can forget.
• Hash arguments instead of truncating them. A hash lets you group duplicate calls and detect argument drift without storing sensitive data. Store the full payload only in a controlled store with its own access policy.
• Do not log the full tool result by default. Results can contain PII, tokens, or large documents. Log a summary and a size, and fetch the body from the tool’s own store when needed.
• Watch cardinality. Labeling a metric with the user id or the full argument makes a new time series per value. Metrics explode and cost more than the feature is worth. Keep high-cardinality data in logs or traces.
• Treat the audit chain as detective, not preventive. Hash chaining proves an edit happened; it does not stop one. Ship the newest hash to separate storage or sign it.
• Cap and sample the noisy logs. Debug logs at full volume can cost more than the workload. Sample routine calls, but always keep the audit record complete.
• Correlate through _meta, not a global variable. The only reliable way to connect host, gateway, and server is to put the trace context in the request itself.
• Log the policy decision and the reason. “Denied” without “why” sends you back to the code every time. Record the rule that fired.
• Alert on the absence of data too. A tool that suddenly stops receiving calls is often worse than one throwing errors. A dead server is silent.
• Beware deprecated protocol logging. If your server only logs through MCP notifications, you have no logs when the client disconnects. Write to stderr or OTel as the primary path.
• Test your redaction with a real payload. A nested token inside a list inside a dict is the case people miss. Assert that the serialized line does not contain the secret.

Interview questions

1. What should you log for every MCP tool call?

Answer. Six things: the server, the tool, the authenticated caller, the arguments (redacted), the result or error, and the decision plus duration. Add one correlation id shared by host, gateway, and server. That set answers who did what, with what, how it turned out, whether it was allowed, and how long it took.

Follow-up: “Why the caller separately from the arguments?” Because the model can put a username inside the arguments, and that claim is untrusted. The caller must come from the authenticated session or token. Conflating the two lets a prompt injection impersonate another user.

Trap. Logging only the tool name and “success”. That is the state that made the double-refund incident undebuggable.

2. Why is MCP protocol logging deprecated, and what replaces it?

Answer. SEP-2577 deprecated the logging capability and logging/setLevel as of the 2026-07-28 revision, because it overlaps with standard infrastructure. On 2026-07-28 log delivery is a per-request opt-in: the client puts io.modelcontextprotocol/logLevel in a request’s _meta, the server must send no notifications/message for a request that omits it, and logging/setLevel is removed. For stdio servers, log to stderr. For HTTP servers, use OpenTelemetry for structured observability. The feature still works for opted-in requests in current spec versions, but new servers should not adopt it.

Follow-up: “So monitoring breaks?” No. It moves out of the protocol channel. You gain OTel traces, metrics, and logs that feed the same dashboards as the rest of your stack, and the client no longer has to render log lines.

Trap. Saying logging was removed. It was deprecated, with a per-version support window; it remains functional for a period after the deprecating revision, though on 2026-07-28 delivery also requires the per-request _meta opt-in.

3. Explain correlation ids and trace context for MCP.

Answer. A correlation id is one id for a whole request. Trace context is the standard way to carry it across process boundaries: a traceparent value holding the trace id and parent span id. The host injects it into the request _meta; the server extracts it and starts a child span. The MCP SDK provides inject_trace_context and extract_trace_context for this.

Follow-up: “Why not use a thread-local or a global?” Because the server is often a different process or machine. In-memory state does not cross the boundary. The id must travel with the request.

Trap. Generating a fresh id at each hop. Then host, gateway, and server logs cannot be joined, and the trace is three disconnected fragments.

4. What is the difference between logs, metrics, and traces?

Answer. Logs are timestamped events with detail. Metrics are numbers over time: counters, gauges, histograms. Traces are timed spans showing one request’s path across components. Logs tell you what happened, metrics tell you how often and how fast, and traces tell you where the time went. Use all three.

Follow-up: “Which one do you alert on?” Metrics, because they are cheap to query continuously and support thresholds. Logs are for the investigation after an alert fires.

Trap. Trying to answer “how many calls failed last hour?” by grepping logs. That is a metrics question, and log volume makes it slow and expensive.

5. What must never be logged, and how do you enforce it?

Answer. Secrets (API keys, passwords, tokens) and PII (card numbers, emails, phone numbers). Enforce it in code: a recursive redaction function at the serialization boundary, an allowlist of fields rather than a blocklist where possible, and a test that asserts the secret string never appears in the serialized line. Log a hash if you still need to compare values.

Follow-up: “What about tool results?” Treat them as untrusted and potentially sensitive. Log a summary, a size, and maybe a hash; store the body in a controlled system with its own access control.

Trap. Redacting at the call site and not in the shared formatter. One forgotten call site leaks the secret, and it will be the one you forgot.

6. How do you make an audit trail tamper-evident?

Answer. Make it append-only and hash-chain the entries: each entry includes the hash of the previous entry, and hashing the entry yields its own hash. Any edit to an earlier entry breaks every later hash, and verification reports the first broken index. Optionally sign the chain or ship the latest hash to independent storage.

Follow-up: “Is hash chaining enough?” It is detective, not preventive. Someone with write access can recompute the entire chain. Independent anchoring, append-only storage with restricted permissions, and signatures raise the cost of forgery.

Trap. Calling a mutable database table an audit log. If rows can be updated or deleted, it is not an audit log, whatever the table is named.

7. Which metrics would you put on an MCP dashboard?

Answer. Calls per tool, error rate per tool, latency percentiles (p50 and p95) per tool, and denied calls per caller. If the gateway sees model usage, add token counts and cost. Add new-tool and new-caller counts, because an unexpected tool name is a safety signal.

Follow-up: “What is the cardinality danger?” Labeling by user id, session id, or argument value creates a new series per value. Keep those in logs or traces, and label metrics by tool, server, and outcome only.

Trap. Tracking only averages. A mean latency of 200 ms can hide a p95 of 4 seconds, and the tail is what users remember.

8. An alert fires: p95 latency on one tool jumped from 50 ms to 2 s. How do you investigate?

Answer. Start from the trace. Filter spans by that tool and the time window, then compare the slow spans to the fast ones. Look for a specific caller, a changed argument size, a slow downstream call, or a server deploy. Use the log records for those correlation ids to see the exact inputs and outcomes. Metrics told you that it changed; traces and logs tell you why.

Follow-up: “What if the traces are sampled and you have no slow trace?” Increase sampling for that tool temporarily, or reproduce with a synthetic call. Sampling is a cost trade-off; make it adjustable per tool so you can raise it during an incident.

Trap. Raising the timeout before understanding the cause. That hides the symptom and often doubles the load, because slow calls hold connections longer.

Remember this

• Six fields per call: server, tool, caller, redacted arguments, result, decision and duration.
• One correlation id, propagated through request _meta as traceparent, joins host, gateway, and server.
• Logs to stderr, structure with OTel. MCP’s own logging capability is deprecated (SEP-2577).
• Redact secrets and PII before serialization, and hash arguments when you need to compare them.
• Audit records are append-only and hash-chained; logs can be sampled, audit records cannot.