A server in production has to answer three questions: is it up, what is it doing,
and when something breaks, why. This tutorial adds the three observability
pillars to a FastMCP server — structured logs, a
health check, and metrics — using only the standard library plus two
FastMCP primitives (middleware and custom routes). The stack is Mac-native: uv,
make, and pytest.
The design keeps instrumentation out of the tools:
- Logging is a JSON formatter on the root logger, written to stderr.
- Metrics are a small in-process registry fed by one piece of middleware, so every tool is measured without touching its code.
- Health and metrics are exposed twice: as MCP resources (readable over any
transport, including stdio) and as HTTP routes (
/health,/metrics) for load balancers and Prometheus.
The stdio trap. The stdio transport uses stdout for the MCP protocol itself. Anything else written to stdout — a stray
What you will build
logging_config.py: JSON logs on stderr, with FastMCP’s own colorized logging folded into the same format.metrics.py: a dependency-free registry (calls, errors, durations) exposed as a JSON snapshot and as Prometheus text.middleware.py: oneon_call_toolhook that times every call, counts errors, and emits a structured log line.server.py: two demo tools,health://statusandmetrics://summaryresources, and/healthand/metricsHTTP routes.- A
pytestsuite and amakewrapper with a live demo.
Prerequisites
- macOS 13+ with Homebrew (brew.sh).
- uv 0.5+ —
brew install uv; verifyuv --version. - Xcode Command Line Tools (
xcode-select --install) formake. - Familiarity with FastMCP tools and transports (see Build an MCP Server with FastMCP).
Step 1: Scaffold and add project hygiene
Create the files
mkdir -p observability-fastmcp-server-macos
cd observability-fastmcp-server-macos
touch .gitignore
Add the code: .gitignore
# Python
__pycache__/
*.py[cod]
.venv/
.uv/
.pytest_cache/
.ruff_cache/
.mypy_cache/
logs/
*.log
*.pid
# OS / editor noise
.DS_Store
Detailed breakdown
- Standard Python ignores.
logs/and*.logare listed because a real deployment usually redirects the stderr stream to a log file.
Step 2: Initialize the project with uv
Create the files
uv init --name macmcp --no-workspace
rm -f main.py hello.py
uv add fastmcp
uv add --dev pytest pytest-asyncio
Add the code: pyproject.toml
[project]
name = "macmcp"
version = "0.1.0"
description = "An observable FastMCP server: structured logs, health, metrics"
readme = "README.md"
requires-python = ">=3.12"
dependencies = [
"fastmcp>=3.4.4",
]
[dependency-groups]
dev = [
"pytest>=9.1.1",
"pytest-asyncio>=1.4.0",
]
Detailed breakdown
- No metrics or logging library is needed. The registry and JSON formatter are built from the standard library, which keeps the dependency surface — and the attack surface — small.
Step 3: Structured JSON logging
One JSON object per line is what log processors (Datadog, Loki, CloudWatch, or a
local jq) parse without regex. FastMCP installs its own colorized handler, so
this module also disables that and routes FastMCP’s records through the same JSON
formatter.
Create the file
touch logging_config.py
Add the code: logging_config.py
"""Structured JSON logging for the server.
Every log line is a single JSON object, which log processors (Datadog, Loki,
CloudWatch, `jq`) can parse without regex. The handler writes to **stderr** on
purpose: the stdio transport uses stdout for the MCP protocol itself, so any
byte written to stdout that is not a protocol message corrupts the stream. HTTP
has no such constraint, but logging to stderr keeps one code path for both.
"""
import json
import logging
import os
import sys
from datetime import datetime, timezone
import fastmcp
class JsonFormatter(logging.Formatter):
"""Render a LogRecord as a compact JSON object."""
def format(self, record: logging.LogRecord) -> str:
payload = {
"ts": datetime.now(timezone.utc).isoformat(),
"level": record.levelname,
"logger": record.name,
"msg": record.getMessage(),
}
# Merge any structured fields passed via logger.info(..., extra={"extra": {...}}).
extra = getattr(record, "extra", None)
if isinstance(extra, dict):
payload.update(extra)
if record.exc_info:
payload["exc"] = self.formatException(record.exc_info)
return json.dumps(payload)
def configure_logging() -> None:
"""Install the JSON handler on the root logger, at LOG_LEVEL (default INFO)."""
level = os.environ.get("LOG_LEVEL", "INFO").upper()
handler = logging.StreamHandler(sys.stderr)
handler.setFormatter(JsonFormatter())
root = logging.getLogger()
root.handlers.clear() # replace FastMCP/uvicorn defaults with ours
root.addHandler(handler)
root.setLevel(level)
# FastMCP installs its own RichHandler on the "fastmcp" logger with
# propagate=False, which would print colorized, non-JSON tracebacks. Turn
# that off and let its records flow into our JSON handler on the root logger.
fastmcp.settings.log_enabled = False
fastmcp_logger = logging.getLogger("fastmcp")
fastmcp_logger.handlers.clear()
fastmcp_logger.propagate = True
Detailed breakdown
JsonFormatterbuilds a dict per record and serializes it. Theextramerge is what turnslogger.info("tool_call", extra={"extra": {...}})into fields on the JSON object instead of an opaque message string.record.exc_infois serialized into anexcfield, so a tool that raises produces one JSON log line containing the full traceback — greppable, not a multi-line color block.- The FastMCP block is the non-obvious part. FastMCP configures a
RichHandleron thefastmcplogger withpropagate=False. Settingfastmcp.settings.log_enabled = Falsestops it from reinstalling that handler, and clearing the handler pluspropagate = Truelets FastMCP’s own records (including tool-error tracebacks) reach the root JSON handler. Without this you get two log formats interleaved. LOG_LEVELlets you raise verbosity (LOG_LEVEL=DEBUG) without a code change.
Step 4: The metrics registry
A metrics client is overkill for a single server. A couple of dictionaries behind a lock answer “how many calls, how many errors, how slow”, and render either as JSON or Prometheus text.
Create the file
touch metrics.py
Add the code: metrics.py
"""An in-process metrics registry for tool calls.
Deliberately dependency-free: a couple of dictionaries behind a lock, enough to
answer "how many calls, how many errors, how slow" without pulling in a metrics
client. Exposed two ways — a JSON snapshot (works over any transport, including
stdio) and Prometheus text (for an HTTP scrape endpoint).
"""
import threading
import time
_lock = threading.Lock()
_calls: dict[str, int] = {}
_errors: dict[str, int] = {}
_duration_sum: dict[str, float] = {}
_START = time.monotonic()
def record(tool: str, duration_seconds: float, ok: bool) -> None:
"""Record one tool call: bump counts and accumulate duration."""
with _lock:
_calls[tool] = _calls.get(tool, 0) + 1
_duration_sum[tool] = _duration_sum.get(tool, 0.0) + duration_seconds
if not ok:
_errors[tool] = _errors.get(tool, 0) + 1
def uptime_seconds() -> float:
"""Monotonic seconds since the process started serving."""
return time.monotonic() - _START
def snapshot() -> dict:
"""A JSON-serializable view of every counter, plus totals and uptime."""
with _lock:
tools = sorted(set(_calls) | set(_errors))
return {
"uptime_seconds": round(uptime_seconds(), 3),
"calls_total": sum(_calls.values()),
"errors_total": sum(_errors.values()),
"tools": {
name: {
"calls": _calls.get(name, 0),
"errors": _errors.get(name, 0),
"duration_seconds_sum": round(_duration_sum.get(name, 0.0), 6),
}
for name in tools
},
}
def prometheus() -> str:
"""Render the registry in Prometheus text exposition format."""
snap = snapshot()
lines = [
"# HELP mcp_tool_calls_total Total tool calls.",
"# TYPE mcp_tool_calls_total counter",
]
for name, s in snap["tools"].items():
lines.append(f'mcp_tool_calls_total{{tool="{name}"}} {s["calls"]}')
lines += [
"# HELP mcp_tool_errors_total Total tool call errors.",
"# TYPE mcp_tool_errors_total counter",
]
for name, s in snap["tools"].items():
lines.append(f'mcp_tool_errors_total{{tool="{name}"}} {s["errors"]}')
lines += [
"# HELP mcp_tool_duration_seconds_sum Cumulative tool duration.",
"# TYPE mcp_tool_duration_seconds_sum counter",
]
for name, s in snap["tools"].items():
lines.append(
f'mcp_tool_duration_seconds_sum{{tool="{name}"}} {s["duration_seconds_sum"]}'
)
return "\n".join(lines) + "\n"
def reset() -> None:
"""Clear all counters. Used by tests for isolation."""
with _lock:
_calls.clear()
_errors.clear()
_duration_sum.clear()
Detailed breakdown
recordis the only writer, so all mutation is inside onewith _lockblock. FastMCP serves requests on an event loop, but HTTP worker threads and the sync-tool threadpool make the lock worth keeping.snapshotreturns totals plus a per-tool breakdown, rounded for readability.uptime_secondsusestime.monotonic, which never goes backward when the system clock changes.prometheusemits the standard# HELP/# TYPEheader plus one line per tool per counter, with the tool name as a label. A Prometheus scrape parses this directly.resetexists for test isolation; the registry is module-global, so tests clear it between cases.- Caveat: counters live in this process. Behind multiple workers, each has its own registry — see the closing notes for the multi-process fix.
Step 5: The metrics middleware
Middleware wraps the whole request pipeline, so one on_call_tool hook
instruments every tool. Add a tool later and it is measured automatically.
Create the file
touch middleware.py
Add the code: middleware.py
"""Middleware that times every tool call, counts errors, and logs one line.
FastMCP middleware wraps the whole request pipeline, so a single `on_call_tool`
hook instruments every tool without touching the tools themselves. This is the
right layer for cross-cutting observability: add a tool later and it is measured
automatically.
"""
import logging
import time
from fastmcp.server.middleware import Middleware, MiddlewareContext
import metrics
logger = logging.getLogger("mcp.tools")
class MetricsMiddleware(Middleware):
"""Record duration + success for each tool call and emit a structured log."""
async def on_call_tool(self, context: MiddlewareContext, call_next):
tool = getattr(context.message, "name", "unknown")
start = time.perf_counter()
ok = True
try:
return await call_next(context)
except Exception:
ok = False
raise
finally:
duration = time.perf_counter() - start
metrics.record(tool, duration, ok)
logger.info(
"tool_call",
extra={
"extra": {
"tool": tool,
"ok": ok,
"duration_ms": round(duration * 1000, 2),
}
},
)
Detailed breakdown
context.message.nameis the tool being called;on_call_toolfires for every tool invocation regardless of transport.call_next(context)runs the rest of the pipeline (other middleware, then the tool). Wrapping it intry/except/finallymeans the metric and log record even when the tool raises — theexceptflipsokand re-raises so the client still sees the error.time.perf_counteris a monotonic high-resolution clock, the right choice for measuring durations.- The structured log rides the
extra={"extra": {...}}convention from Step 3, sotool,ok, andduration_msland as top-level JSON fields.
Step 6: The server
The server wires the three pillars together and exposes health and metrics two ways: as MCP resources (any transport) and as HTTP routes (for infrastructure).
Create the file
touch server.py
Add the code: server.py
"""A FastMCP server instrumented for observability.
Three pillars, all built from the standard library plus FastMCP primitives:
- structured JSON logging (logging_config), safe for the stdio transport;
- a metrics registry (metrics) fed by middleware on every tool call;
- health and metrics surfaces exposed both as MCP resources (any transport) and
as HTTP routes (for load balancers and Prometheus).
"""
import os
from starlette.requests import Request
from starlette.responses import JSONResponse, PlainTextResponse
import metrics
from fastmcp import FastMCP
from logging_config import configure_logging
from middleware import MetricsMiddleware
VERSION = "0.1.0"
configure_logging()
mcp = FastMCP("macmcp-observability")
mcp.add_middleware(MetricsMiddleware())
@mcp.tool
def add(a: int, b: int) -> int:
"""Add two integers."""
return a + b
@mcp.tool
def flaky(fail: bool = False) -> str:
"""Succeed, or raise when fail=True — useful for exercising error metrics."""
if fail:
raise ValueError("flaky was asked to fail")
return "ok"
def _health() -> dict:
return {
"status": "ok",
"version": VERSION,
"uptime_seconds": round(metrics.uptime_seconds(), 3),
}
@mcp.resource("health://status")
def health_resource() -> dict:
"""Liveness/version info as an MCP resource (works over stdio and HTTP)."""
return _health()
@mcp.resource("metrics://summary")
def metrics_resource() -> dict:
"""Current metrics as a JSON snapshot (works over stdio and HTTP)."""
return metrics.snapshot()
@mcp.custom_route("/health", methods=["GET"])
async def health_route(_request: Request) -> JSONResponse:
"""HTTP health check for load balancers and uptime monitors."""
return JSONResponse(_health())
@mcp.custom_route("/metrics", methods=["GET"])
async def metrics_route(_request: Request) -> PlainTextResponse:
"""Prometheus scrape endpoint."""
return PlainTextResponse(metrics.prometheus())
def main() -> None:
if os.environ.get("MCP_TRANSPORT", "stdio").lower() == "http":
mcp.run(
transport="http",
host=os.environ.get("MCP_HOST", "127.0.0.1"),
port=int(os.environ.get("MCP_PORT", "8000")),
)
else:
mcp.run() # stdio: logs go to stderr so stdout stays protocol-only
if __name__ == "__main__":
main()
Detailed breakdown
configure_logging()runs beforeFastMCP(...)so the JSON handler is in place and FastMCP’s own logging is disabled before the server constructs.mcp.add_middleware(MetricsMiddleware())registers the instrumentation once; every tool call flows through it.health_resource/metrics_resourceare the transport-agnostic surfaces. A stdio client (Claude Desktop, Claude Code) cannot call an HTTP endpoint, but it can readhealth://status, so observability is available there too.@mcp.custom_routemounts plain Starlette routes on the HTTP app, separate from the/mcp/protocol endpoint./healthreturns JSON;/metricsreturns Prometheus text. A load balancer polls/health; Prometheus scrapes/metrics.flakyexists to generate error metrics on demand.
Step 7: Tests
Test the registry as pure logic, then drive the server in-memory (tool calls feed metrics, resources report them), then hit the HTTP routes.
Create the files
mkdir -p tests
touch tests/__init__.py tests/test_metrics.py tests/test_server.py tests/test_http_routes.py pytest.ini
Add the code: pytest.ini
[pytest]
asyncio_mode = auto
filterwarnings =
ignore::DeprecationWarning
Add the code: tests/test_metrics.py
"""Unit-test the metrics registry as pure logic."""
import metrics
def setup_function():
metrics.reset()
def test_record_counts_calls_and_errors():
metrics.record("add", 0.01, ok=True)
metrics.record("add", 0.02, ok=True)
metrics.record("flaky", 0.03, ok=False)
snap = metrics.snapshot()
assert snap["calls_total"] == 3
assert snap["errors_total"] == 1
assert snap["tools"]["add"]["calls"] == 2
assert snap["tools"]["add"]["errors"] == 0
assert snap["tools"]["flaky"]["errors"] == 1
def test_duration_accumulates():
metrics.record("add", 0.10, ok=True)
metrics.record("add", 0.05, ok=True)
assert metrics.snapshot()["tools"]["add"]["duration_seconds_sum"] == 0.15
def test_prometheus_text_format():
metrics.record("add", 0.01, ok=True)
metrics.record("flaky", 0.02, ok=False)
text = metrics.prometheus()
assert "# TYPE mcp_tool_calls_total counter" in text
assert 'mcp_tool_calls_total{tool="add"} 1' in text
assert 'mcp_tool_errors_total{tool="flaky"} 1' in text
assert text.endswith("\n")
def test_uptime_is_nonnegative():
assert metrics.uptime_seconds() >= 0
Add the code: tests/test_server.py
"""Drive the server in-memory: tool calls feed metrics, resources report them."""
import json
import pytest
from fastmcp import Client
import metrics
import server
@pytest.fixture(autouse=True)
def _reset_metrics():
metrics.reset()
async def test_tool_calls_are_counted():
async with Client(server.mcp) as client:
assert (await client.call_tool("add", {"a": 2, "b": 3})).data == 5
await client.call_tool("add", {"a": 1, "b": 1})
snap = json.loads((await client.read_resource("metrics://summary"))[0].text)
assert snap["tools"]["add"]["calls"] == 2
assert snap["tools"]["add"]["errors"] == 0
assert snap["calls_total"] == 2
async def test_tool_errors_are_counted():
async with Client(server.mcp) as client:
with pytest.raises(Exception):
await client.call_tool("flaky", {"fail": True})
await client.call_tool("flaky", {"fail": False})
snap = json.loads((await client.read_resource("metrics://summary"))[0].text)
assert snap["tools"]["flaky"]["calls"] == 2
assert snap["tools"]["flaky"]["errors"] == 1
assert snap["errors_total"] == 1
async def test_health_resource_reports_ok():
async with Client(server.mcp) as client:
health = json.loads((await client.read_resource("health://status"))[0].text)
assert health["status"] == "ok"
assert health["version"] == server.VERSION
assert health["uptime_seconds"] >= 0
Add the code: tests/test_http_routes.py
"""The HTTP health and metrics routes, via Starlette's TestClient."""
import metrics
from starlette.testclient import TestClient
import server
def test_health_route_returns_ok():
metrics.reset()
with TestClient(server.mcp.http_app()) as client:
resp = client.get("/health")
assert resp.status_code == 200
body = resp.json()
assert body["status"] == "ok"
assert body["version"] == server.VERSION
def test_metrics_route_is_prometheus_text():
metrics.reset()
metrics.record("add", 0.01, ok=True)
with TestClient(server.mcp.http_app()) as client:
resp = client.get("/metrics")
assert resp.status_code == 200
assert "text/plain" in resp.headers["content-type"]
assert 'mcp_tool_calls_total{tool="add"} 1' in resp.text
Detailed breakdown
test_metrics.pycovers the registry directly — counting, duration accumulation, and the exact Prometheus text — withreset()between cases.test_server.pyuses an in-memoryClient(server.mcp)(no subprocess, no network) to prove the middleware path: callingaddtwice increments its counter, a raisedflakyincrements the error counter, and the resources read the values back. Theautousefixture resets the registry per test.test_http_routes.pyboots the HTTP app withTestClientand asserts the/healthJSON and the/metricsPrometheus body and content type.
Run them:
uv run pytest -q
......... [100%]
9 passed
Step 8: The Makefile
Wrap it so plain make prints help, with a live demo and curl helpers.
Create the file
touch Makefile
Add the code: Makefile
.DEFAULT_GOAL := help
HOST ?= 127.0.0.1
PORT ?= 8000
.PHONY: help install test demo serve-http health metrics clean
help: ## Show this help screen
@grep -E '^[a-zA-Z_-]+:.*?## .*$$' $(MAKEFILE_LIST) \
| awk 'BEGIN {FS = ":.*?## "}; {printf " \033[36m%-12s\033[0m %s\n", $$1, $$2}'
install: ## Sync runtime and dev dependencies
uv sync
test: ## Run the test suite
uv run pytest -q
demo: ## Call tools in-memory and print the metrics snapshot (logs to stderr)
uv run python demo.py
serve-http: ## Run the HTTP server (exposes /health and /metrics)
MCP_TRANSPORT=http MCP_HOST=$(HOST) MCP_PORT=$(PORT) uv run python server.py
health: ## Curl the HTTP health check (server must be running)
@curl -s http://$(HOST):$(PORT)/health && echo
metrics: ## Curl the Prometheus metrics endpoint (server must be running)
@curl -s http://$(HOST):$(PORT)/metrics
clean: ## Remove caches and logs
rm -rf .pytest_cache logs __pycache__ tests/__pycache__
Detailed breakdown
- Plain
makeprints the help screen listing every target. demoruns a small in-memory script (next listing) that exercises the tools and prints the snapshot — the fastest way to see the pillars working.serve-httpruns the HTTP server sohealthandmetricscan curl the endpoints from another terminal.
Create the file
touch demo.py
Add the code: demo.py
"""Exercise the tools in-memory, then print the metrics snapshot.
A quick way to see the middleware and registry working without a client or a
network: it calls a few tools (including one failure) and reads the
`metrics://summary` resource back. Structured JSON logs stream to stderr.
"""
import asyncio
import json
from fastmcp import Client
import server
async def main() -> None:
async with Client(server.mcp) as client:
await client.call_tool("add", {"a": 2, "b": 3})
await client.call_tool("add", {"a": 10, "b": 20})
try:
await client.call_tool("flaky", {"fail": True})
except Exception:
pass # counted as an error by the middleware
summary = (await client.read_resource("metrics://summary"))[0].text
print(json.dumps(json.loads(summary), indent=2))
if __name__ == "__main__":
asyncio.run(main())
Detailed breakdown
demo.pysits at the project root soimport serverresolves when run aspython demo.py. It callsaddtwice andflakyonce (forced to fail), then reads the snapshot.- The JSON snapshot prints to stdout; the structured logs go to stderr, so
make demo 2>/dev/nullshows just the metrics.
Run the demo:
make demo 2>/dev/null
{
"uptime_seconds": 0.057,
"calls_total": 3,
"errors_total": 1,
"tools": {
"add": {
"calls": 2,
"errors": 0,
"duration_seconds_sum": 0.000869
},
"flaky": {
"calls": 1,
"errors": 1,
"duration_seconds_sum": 0.001085
}
}
}
The uptime_seconds and duration_seconds_sum values vary per run; the counts
do not.
Each tool call also logs one JSON line to stderr:
{"ts": "2026-07-17T16:30:53.785941+00:00", "level": "INFO", "logger": "mcp.tools", "msg": "tool_call", "tool": "add", "ok": true, "duration_ms": 0.74}
The HTTP endpoints
In one terminal, start the HTTP server:
make serve-http
In another, call the health check and (after some tool calls) scrape metrics:
make health
# {"status":"ok","version":"0.1.0","uptime_seconds":0.91}
make metrics
# HELP mcp_tool_calls_total Total tool calls.
# TYPE mcp_tool_calls_total counter
mcp_tool_calls_total{tool="add"} 2
mcp_tool_calls_total{tool="flaky"} 1
# HELP mcp_tool_errors_total Total tool call errors.
# TYPE mcp_tool_errors_total counter
mcp_tool_errors_total{tool="add"} 0
mcp_tool_errors_total{tool="flaky"} 1
# HELP mcp_tool_duration_seconds_sum Cumulative tool duration.
# TYPE mcp_tool_duration_seconds_sum counter
mcp_tool_duration_seconds_sum{tool="add"} 0.001086
mcp_tool_duration_seconds_sum{tool="flaky"} 0.001293
/metrics reflects tool calls made against this server process over the MCP
protocol (POST /mcp/); a freshly started server reports only the # HELP/# TYPE headers until the first tool runs.
Troubleshooting
- The client hangs or errors immediately over stdio. Something wrote to
stdout. Check for a
printin a tool or a logging handler pointed at stdout; everything must go to stderr. - Logs come out in two formats. FastMCP’s colorized handler is still active.
Confirm
configure_logging()runs beforeFastMCP(...)and that it setsfastmcp.settings.log_enabled = False. /metricsis always empty. No tool has been called on that process yet, or you are scraping a different worker. The headers with no data lines are the correct empty state.- Metrics look too low behind a proxy. Counters are per-process. With multiple workers, each keeps its own registry; see the notes below.
/healthreturns 404. The custom routes live on the HTTP app; confirm you started withMCP_TRANSPORT=httpand are hitting the right host/port.
Recap
- Structured logs are a JSON formatter on the root logger, written to stderr so the stdio protocol on stdout stays clean — with FastMCP’s own logging folded into the same format.
- Metrics are a dependency-free registry fed by one
on_call_toolmiddleware, so every tool is measured without per-tool code. - Health and metrics are exposed as MCP resources (any transport) and as
/health//metricsHTTP routes (load balancers, Prometheus). - Tests cover the registry, the middleware path in-memory, and the HTTP
routes;
9 passed.
Next improvements
- Multi-process metrics. Behind several workers, swap the in-process registry
for
prometheus_clientwith the multiprocess collector, or push to a StatsD/OTLP endpoint, so counts aggregate across workers. - Distributed tracing. Add OpenTelemetry spans in the middleware to trace a tool call across the services it touches, correlating with the logs by trace id.
- Richer health. Extend
/healthinto a readiness probe that checks downstream dependencies (a database, an upstream API) and returns503when one is down. - Log correlation. Add a request id in the middleware and include it in every log line for a call, so a single tool invocation’s logs group together.