MCP Deep Dive, Part 10: When the Agent Feels Off — Debugging and Observability for MCP in Production

A web API fails loudly: a 500, a stack trace, an alert. An agent fails softly. It doesn't crash — it quietly takes six turns instead of two, calls the wrong tool, spends triple the tokens, and returns an answer that's subtly wrong. None of that throws an exception, and none of it shows up in the logs of any single request. Debugging agents is a different discipline, and it starts with observing the run, not the request.

This is Part 10 of a 15-part deep dive on Model Context Protocol (MCP). Part 3 gave each tool call a span on the server; this part joins those into the whole picture — one agent run across the host, the model, and all three Mattrx servers, correlated so that when something feels off you have an answer instead of a shrug.

TL;DR

Question	Blind agent (before)	Observable MCP (after)
Where did the time go?	scattered logs	one trace per run (waterfall)
What did the agent do?	unknown	audit-log reconstruction
Which tool/tenant is slow?	generic HTTP metrics	per-tool, per-tenant latency/error
Is it thrashing?	invisible	turns-per-run + tokens-per-run
Server or agent?	guess	MCP Inspector — poke the server directly
Can I reproduce it?	no	replay the recorded session

The unit of observability for an agent is the RUN, not the request — one root trace propagated across host + every server.
Trace the loop: run → turn → model-call/tool-call spans, so the decision path is visible (not just leaf tool spans).
Structured, redacted logs correlated by trace id — method, tool, server, tenant, latency, outcome; never raw payloads.
The metrics that matter are MCP-specific: per-tool per-tenant latency/error, turns/run, tokens & cost/run.
The append-only audit log (Parts 7/8) is your debugging record — reconstruct what the agent saw and did.
MCP Inspector pokes a server directly; session replay reproduces a bug deterministically.
Dimension everything by tool and tenant — "the assistant is slow" becomes "tool X, tenant Y regressed."
OTel → Azure Monitor / App Insights; incident trace time hours → minutes.
Watch quality, not just latency — eval scores (faithfulness 0.96, gate 0.90) belong on the dashboard too.
You can't step through a non-deterministic agent — so record enough to reconstruct it.

The one mental shift: agents fail softly — slower, pricier, subtly wrong — and none of it is an exception. So stop debugging the request and start observing the run: the whole loop as one trace, an audit record you can reconstruct from, and metrics dimensioned by tool and tenant.

The running example: one Mattrx run, many hops

A single question to Mattrx Insights — "why did campaign 4821's CTR drop?" — fans out into several model calls and several tool calls across mattrx-analytics and mattrx-reports, over two or three turns. When that run is slow, or wrong, or expensive, the failure could be in any of a dozen places. Observability is what tells you which. Here's how we build it, with the blind version and the version you can actually debug.

One agent run, as a trace

  agent.run  (tenant, goal)                                       [==================] 1.8s
  |
  +- agent.turn 0                                                 [======]
  |    +- agent.model_call  (plan)                                [===]
  |    +- tool.get_campaign_kpis  -> mattrx-analytics             [==]   120ms
  |    +- tool.query_events       -> mattrx-analytics             [===]  180ms
  |
  +- agent.turn 1                                                 [=====]
  |    +- agent.model_call  (synthesize)                          [====]
  |    +- tool.create_report      -> mattrx-reports (enqueue)     [=]    90ms
  |
  +- eval gate 0.93 (pass) -> final answer

  One trace id ties the host loop and every server span together in App Insights.

1. Correlate the whole run with one trace id

Before

Logs scattered across the host and three servers, with no thread connecting them. "The assistant is slow" is unanswerable.

After

Start one root span per agent run and propagate its context across the MCP transport, so every server's spans nest under it.

// AFTER: one root activity per run; the trace context flows to every server call.
public async Task<AgentAnswer> RunAsync(AiPrincipal p, string goal, CancellationToken ct)
{
    using var run = ActivitySource.StartActivity("agent.run");   // the root span for the whole run
    run?.SetTag("mattrx.tenant", p.TenantId);
    run?.SetTag("agent.goal", Redact(goal));

    // OTel context propagates over the MCP transport (traceparent) -> every server span nests here.
    return await LoopAsync(p, goal, ct);
}

Diagnostic: the unit of observability for an agent is the run, not the request. Start one root span, propagate its context through the MCP transport headers, and every model call and tool call on every server joins the same trace — one waterfall that tells the whole story instead of six disconnected log streams.

Mattrx metric: a single correlated trace per run is why incident triage dropped from hours to minutes — one trace id, and the whole cross-server run is in front of you in App Insights.

2. Trace the loop, not just the tool

Before

Part 3 gave a span per tool call on the server, but the loop — model → tool → model → tool — was invisible. You could see the leaves, not the tree.

After

A span per turn, per model call, and per tool call, nested under the run.

// A span per TURN and per model/tool call — the agent's actual decision path.
for (var turn = 0; turn < MaxTurns; turn++)
{
    using var turnSpan = ActivitySource.StartActivity("agent.turn");
    turnSpan?.SetTag("agent.turn", turn);

    using (ActivitySource.StartActivity("agent.model_call"))
        reply = await model.ChatAsync(messages, tools, ct);           // one span per model call

    foreach (var call in reply.ToolCalls)
        using (var t = ActivitySource.StartActivity($"tool.{call.Name}"))
        {
            t?.SetTag("mcp.server", Route(call.Name));
            results.Add(await manager.InvokeAsync(call, ct));
        }
}

Diagnostic: the tool span answers "was the tool slow?"; the run→turn→call tree answers "why did the agent take six turns?" When an agent loops in circles, the trace shows exactly where — a model call that keeps re-requesting the same tool, a tool that keeps erroring and being retried.

Mattrx metric: tracing the loop is how we see that most runs finish in two or three turns — and how we catch the outliers that don't, before they become a cost or latency regression.

3. Structured, redacted protocol logging

Before

Print statements and raw payloads — which also quietly copies customer data into the log store.

After

Structured logs of the MCP interaction — method, tool, server, tenant, latency, outcome — correlated by the trace id and redacted.

// Structured, correlated, redacted. Logs answer "what happened"; traces answer "in what order."
logger.ToolCall(new
{
    TraceId    = Activity.Current?.TraceId.ToString(),
    Tool       = call.Name, Server = Route(call.Name),
    Tenant     = principal.TenantId,
    DurationMs = sw.ElapsedMilliseconds,
    Outcome    = result.IsError ? "error" : "ok",
    // arguments/results: a redacted projection or a hash — never the raw content (Security post)
});

Diagnostic: logs and traces are complementary — traces give order and latency, logs give detail. Correlate them by the trace id so you can pivot from a fat span straight to its log line, and redact the payloads exactly like the audit log so your observability stack doesn't become your largest unsecured copy of customer data.

Mattrx metric: every tool call logs a redacted, trace-correlated record — enough to debug, never enough to leak — which is why the logging pipeline passed the same privacy review as the rest of the system.

4. The metrics that matter for agents

Before

Generic HTTP metrics: requests per second, 2xx/5xx. None of it describes an agent.

After

MCP-specific metrics, dimensioned by tool and tenant: latency and error rate per tool, turns per run, tokens and cost per run.

// Metrics that actually describe an agent, tagged by tool + tenant (+ turns, tokens, cost).
meters.ToolLatency.Record(sw.ElapsedMilliseconds,
    [KeyValuePair.Create("tool", call.Name), KeyValuePair.Create("tenant", principal.TenantId)]);
meters.ToolErrors.Add(result.IsError ? 1 : 0, /* same tags */);
meters.TurnsPerRun.Record(turnCount);
meters.TokensPerRun.Record(usage.TotalTokens);

Diagnostic: "requests per second" tells you nothing about whether your agent is healthy. Per-tool per-tenant latency and error rate turn "the assistant is slow" into "query_events on tenant Y regressed at 14:00." Turns-per-run catches thrashing; tokens-and-cost-per-run catches the agent that quietly got expensive.

Mattrx metric: dimensioned metrics are how read-tool p95 stays pinned at 120 ms and the tool-call error rate at 0.8% — a regression shows up as one tool on one tenant, not a vague fleet-wide dip.

5. The audit log is your debugging record

Before

"The agent did something weird once" — unreproducible, unexplained, and now a mystery ticket.

After

The append-only audit log you already built for security (Parts 7/8) reconstructs exactly what the agent saw and did.

// The audit log IS the debugging record. It answers the question that matters when an agent
// misbehaves: "what did it actually see, retrieve, and call — in what order?"
var reconstruction = await audit.ReconstructAsync(traceId, ct);
// -> every tool call, result hash, guardrail decision, and outcome, in sequence

Diagnostic: agents are non-deterministic, so "just reproduce it" usually fails. The audit trail is your reconstruction: the exact tool calls, retrieved chunk ids, authorization decisions, and outcomes, in order. It turns "it did something weird" from a shrug into an investigation — the same append-only log that gives you security also gives you post-hoc debuggability.

Mattrx metric: because every decision is recorded, an agent-behavior investigation is a query, not an archaeology dig — which, again, is why incident trace time is measured in minutes.

6. Local debugging: the MCP Inspector and session replay

Before

Debug a misbehaving agent by adding print statements to production and waiting for it to happen again.

After

Poke the server directly with the MCP Inspector, and replay a recorded session to reproduce a bug deterministically.

# Poke a server directly — list tools, call one, see the raw JSON-RPC request/response.
npx @modelcontextprotocol/inspector node ./mattrx-analytics-server
#   connect -> tools/list -> call get_campaign_kpis -> inspect the exact messages

// Replay a recorded session against a server to reproduce a bug without the model in the loop.
await replayer.RunAsync("session-4821.jsonl", targetServer: "mattrx-analytics", ct);

Diagnostic: the Inspector is the fastest way to answer "is it the server or the agent?" — you call the tool by hand and see the raw messages, no model involved. And replaying a recorded session drives the exact call sequence against the server deterministically, so a bug that only showed up once becomes a repeatable test.

Mattrx metric: most "the agent got a weird result" tickets resolve at the Inspector in minutes — call the tool directly, see it's the server (or see it isn't), and skip the guesswork entirely.

What to check when the agent "feels off"

  Symptom                         Look at...
  --------                        ---------
  slow                     ->  the RUN trace: which turn/tool span is fat?
  wrong answer             ->  the AUDIT log: what did it retrieve + call?
  too many turns / cost    ->  turns-per-run + tokens-per-run metrics
  intermittent failures    ->  per-tool per-tenant error rate + retries
  "did the server change?" ->  the MCP Inspector: call the tool by hand
  can't reproduce          ->  REPLAY the recorded session against the server

The numbers, in one place

Metric	Blind agent (before)	Observable MCP (after)
Incident trace time	hours	minutes
Cross-server correlation	none	one trace per run
Regression localization	fleet-wide guess	per-tool, per-tenant
Turns per run	invisible	measured (~2–3)
Tokens / cost per run	invisible	measured + alertable
Reproducing a bug	rarely	Inspector + session replay

Observability checklist

One root span per agent run, with context propagated across every server.
Span the loop — run → turn → model-call/tool-call — not just leaf tool calls.
Structured, trace-correlated, redacted logs of every MCP interaction.
Metrics dimensioned by tool and tenant: latency, errors, turns/run, tokens & cost/run.
Treat the audit log as a first-class debugging record; be able to reconstruct a run.
Keep the MCP Inspector in the toolkit for direct, model-free server debugging.
Record sessions so you can replay and reproduce non-deterministic bugs.
Dashboard quality (eval scores), not just latency and errors.

The honest stuff: proportion and pitfalls

A single local stdio tool. The Inspector plus a log line is enough — don't stand up distributed tracing for a helper.
Logging raw prompts and results. Your traces and logs become a second unsecured copy of customer data. Redact, always.
Tracing only tool calls. The model calls and loop turns are where agents actually go wrong. Span the whole run.
Metrics without dimensions. Aggregate p95 hides the one bad tenant. Always tag by tool and tenant.
"No errors" ≠ "working." An agent at 0% errors can still give bad answers. Watch eval/quality, not just exceptions.
Over-sampling traces. Agent runs are low-volume and high-value — sample far less than you would a web API.
Reproduce, don't reconstruct. Stop trying to re-run a non-deterministic agent. Invest in the audit and replay record instead.

The model to carry forward

Agents fail softly, so you have to watch softly too. The exception-and-alert model built for web APIs misses everything that actually goes wrong with an agent — the slow drift, the extra turns, the subtly worse answer. Observe the whole run as one trace, keep an audit record you can reconstruct from, dimension your metrics by tool and tenant, and watch quality alongside latency. Then "the agent feels off" has an answer.

Three habits that make MCP debuggable:

Trace the run, not the request. One root span, propagated across every server, spanning every turn and call.
Keep a reconstructable record. The audit log is how you debug a non-deterministic system after the fact.
Dimension by tool and tenant, and watch quality. Latency, errors, turns, cost — and eval scores.

In Part 11 we zoom all the way out: rolling MCP across an enterprise — the governance, provisioning, and identity model that decides whether agents ship company-wide at all.

Continue the series — MCP Deep Dive

TL;DR

Question	Blind agent (before)	Observable MCP (after)
Where did the time go?	scattered logs	one trace per run (waterfall)
What did the agent do?	unknown	audit-log reconstruction
Which tool/tenant is slow?	generic HTTP metrics	per-tool, per-tenant latency/error
Is it thrashing?	invisible	turns-per-run + tokens-per-run
Server or agent?	guess	MCP Inspector — poke the server directly
Can I reproduce it?	no	replay the recorded session

The unit of observability for an agent is the RUN, not the request — one root trace propagated across host + every server.
Trace the loop: run → turn → model-call/tool-call spans, so the decision path is visible (not just leaf tool spans).
Structured, redacted logs correlated by trace id — method, tool, server, tenant, latency, outcome; never raw payloads.
The metrics that matter are MCP-specific: per-tool per-tenant latency/error, turns/run, tokens & cost/run.
The append-only audit log (Parts 7/8) is your debugging record — reconstruct what the agent saw and did.
MCP Inspector pokes a server directly; session replay reproduces a bug deterministically.
Dimension everything by tool and tenant — "the assistant is slow" becomes "tool X, tenant Y regressed."
OTel → Azure Monitor / App Insights; incident trace time hours → minutes.
Watch quality, not just latency — eval scores (faithfulness 0.96, gate 0.90) belong on the dashboard too.
You can't step through a non-deterministic agent — so record enough to reconstruct it.

The one mental shift: agents fail softly — slower, pricier, subtly wrong — and none of it is an exception. So stop debugging the request and start observing the run: the whole loop as one trace, an audit record you can reconstruct from, and metrics dimensioned by tool and tenant.

The running example: one Mattrx run, many hops

One agent run, as a trace

  agent.run  (tenant, goal)                                       [==================] 1.8s
  |
  +- agent.turn 0                                                 [======]
  |    +- agent.model_call  (plan)                                [===]
  |    +- tool.get_campaign_kpis  -> mattrx-analytics             [==]   120ms
  |    +- tool.query_events       -> mattrx-analytics             [===]  180ms
  |
  +- agent.turn 1                                                 [=====]
  |    +- agent.model_call  (synthesize)                          [====]
  |    +- tool.create_report      -> mattrx-reports (enqueue)     [=]    90ms
  |
  +- eval gate 0.93 (pass) -> final answer

  One trace id ties the host loop and every server span together in App Insights.

1. Correlate the whole run with one trace id

Before

Logs scattered across the host and three servers, with no thread connecting them. "The assistant is slow" is unanswerable.

After

Start one root span per agent run and propagate its context across the MCP transport, so every server's spans nest under it.

// AFTER: one root activity per run; the trace context flows to every server call.
public async Task<AgentAnswer> RunAsync(AiPrincipal p, string goal, CancellationToken ct)
{
    using var run = ActivitySource.StartActivity("agent.run");   // the root span for the whole run
    run?.SetTag("mattrx.tenant", p.TenantId);
    run?.SetTag("agent.goal", Redact(goal));

    // OTel context propagates over the MCP transport (traceparent) -> every server span nests here.
    return await LoopAsync(p, goal, ct);
}

Mattrx metric: a single correlated trace per run is why incident triage dropped from hours to minutes — one trace id, and the whole cross-server run is in front of you in App Insights.

2. Trace the loop, not just the tool

Before

Part 3 gave a span per tool call on the server, but the loop — model → tool → model → tool — was invisible. You could see the leaves, not the tree.

After

A span per turn, per model call, and per tool call, nested under the run.

// A span per TURN and per model/tool call — the agent's actual decision path.
for (var turn = 0; turn < MaxTurns; turn++)
{
    using var turnSpan = ActivitySource.StartActivity("agent.turn");
    turnSpan?.SetTag("agent.turn", turn);

    using (ActivitySource.StartActivity("agent.model_call"))
        reply = await model.ChatAsync(messages, tools, ct);           // one span per model call

    foreach (var call in reply.ToolCalls)
        using (var t = ActivitySource.StartActivity($"tool.{call.Name}"))
        {
            t?.SetTag("mcp.server", Route(call.Name));
            results.Add(await manager.InvokeAsync(call, ct));
        }
}

Mattrx metric: tracing the loop is how we see that most runs finish in two or three turns — and how we catch the outliers that don't, before they become a cost or latency regression.

3. Structured, redacted protocol logging

Before

Print statements and raw payloads — which also quietly copies customer data into the log store.

After

Structured logs of the MCP interaction — method, tool, server, tenant, latency, outcome — correlated by the trace id and redacted.

// Structured, correlated, redacted. Logs answer "what happened"; traces answer "in what order."
logger.ToolCall(new
{
    TraceId    = Activity.Current?.TraceId.ToString(),
    Tool       = call.Name, Server = Route(call.Name),
    Tenant     = principal.TenantId,
    DurationMs = sw.ElapsedMilliseconds,
    Outcome    = result.IsError ? "error" : "ok",
    // arguments/results: a redacted projection or a hash — never the raw content (Security post)
});

4. The metrics that matter for agents

Before

Generic HTTP metrics: requests per second, 2xx/5xx. None of it describes an agent.

After

MCP-specific metrics, dimensioned by tool and tenant: latency and error rate per tool, turns per run, tokens and cost per run.

// Metrics that actually describe an agent, tagged by tool + tenant (+ turns, tokens, cost).
meters.ToolLatency.Record(sw.ElapsedMilliseconds,
    [KeyValuePair.Create("tool", call.Name), KeyValuePair.Create("tenant", principal.TenantId)]);
meters.ToolErrors.Add(result.IsError ? 1 : 0, /* same tags */);
meters.TurnsPerRun.Record(turnCount);
meters.TokensPerRun.Record(usage.TotalTokens);

5. The audit log is your debugging record

Before

"The agent did something weird once" — unreproducible, unexplained, and now a mystery ticket.

After

The append-only audit log you already built for security (Parts 7/8) reconstructs exactly what the agent saw and did.

// The audit log IS the debugging record. It answers the question that matters when an agent
// misbehaves: "what did it actually see, retrieve, and call — in what order?"
var reconstruction = await audit.ReconstructAsync(traceId, ct);
// -> every tool call, result hash, guardrail decision, and outcome, in sequence

Mattrx metric: because every decision is recorded, an agent-behavior investigation is a query, not an archaeology dig — which, again, is why incident trace time is measured in minutes.

6. Local debugging: the MCP Inspector and session replay

Before

Debug a misbehaving agent by adding print statements to production and waiting for it to happen again.

After

Poke the server directly with the MCP Inspector, and replay a recorded session to reproduce a bug deterministically.

# Poke a server directly — list tools, call one, see the raw JSON-RPC request/response.
npx @modelcontextprotocol/inspector node ./mattrx-analytics-server
#   connect -> tools/list -> call get_campaign_kpis -> inspect the exact messages

// Replay a recorded session against a server to reproduce a bug without the model in the loop.
await replayer.RunAsync("session-4821.jsonl", targetServer: "mattrx-analytics", ct);

Mattrx metric: most "the agent got a weird result" tickets resolve at the Inspector in minutes — call the tool directly, see it's the server (or see it isn't), and skip the guesswork entirely.

What to check when the agent "feels off"

  Symptom                         Look at...
  --------                        ---------
  slow                     ->  the RUN trace: which turn/tool span is fat?
  wrong answer             ->  the AUDIT log: what did it retrieve + call?
  too many turns / cost    ->  turns-per-run + tokens-per-run metrics
  intermittent failures    ->  per-tool per-tenant error rate + retries
  "did the server change?" ->  the MCP Inspector: call the tool by hand
  can't reproduce          ->  REPLAY the recorded session against the server

The numbers, in one place

Metric	Blind agent (before)	Observable MCP (after)
Incident trace time	hours	minutes
Cross-server correlation	none	one trace per run
Regression localization	fleet-wide guess	per-tool, per-tenant
Turns per run	invisible	measured (~2–3)
Tokens / cost per run	invisible	measured + alertable
Reproducing a bug	rarely	Inspector + session replay

Observability checklist

One root span per agent run, with context propagated across every server.
Span the loop — run → turn → model-call/tool-call — not just leaf tool calls.
Structured, trace-correlated, redacted logs of every MCP interaction.
Metrics dimensioned by tool and tenant: latency, errors, turns/run, tokens & cost/run.
Treat the audit log as a first-class debugging record; be able to reconstruct a run.
Keep the MCP Inspector in the toolkit for direct, model-free server debugging.
Record sessions so you can replay and reproduce non-deterministic bugs.
Dashboard quality (eval scores), not just latency and errors.

The honest stuff: proportion and pitfalls

A single local stdio tool. The Inspector plus a log line is enough — don't stand up distributed tracing for a helper.
Logging raw prompts and results. Your traces and logs become a second unsecured copy of customer data. Redact, always.
Tracing only tool calls. The model calls and loop turns are where agents actually go wrong. Span the whole run.
Metrics without dimensions. Aggregate p95 hides the one bad tenant. Always tag by tool and tenant.
"No errors" ≠ "working." An agent at 0% errors can still give bad answers. Watch eval/quality, not just exceptions.
Over-sampling traces. Agent runs are low-volume and high-value — sample far less than you would a web API.
Reproduce, don't reconstruct. Stop trying to re-run a non-deterministic agent. Invest in the audit and replay record instead.

The model to carry forward

Three habits that make MCP debuggable:

Trace the run, not the request. One root span, propagated across every server, spanning every turn and call.
Keep a reconstructable record. The audit log is how you debug a non-deterministic system after the fact.
Dimension by tool and tenant, and watch quality. Latency, errors, turns, cost — and eval scores.

In Part 11 we zoom all the way out: rolling MCP across an enterprise — the governance, provisioning, and identity model that decides whether agents ship company-wide at all.

Get the next issue

Keep reading

Get the next issue

Keep reading