feat(mcp): add tool-call middleware seam#378
Conversation
Add CallerIdentity (client id + scopes) and caller_identity(request), reading the validated caller off the request scope without re-decoding the bearer. Extract a shared _authenticated_user so caller_identity and require_request_bearer locate the validated user the same way; caller_identity is non-raising so it runs on every profile (anonymous under stdio/local). Subject is deferred until its consumer (per-user quotas) exists.
Turn FastMCP's single CallToolRequest handler slot into an ordered, documented middleware chain so cross-cutting concerns (logging, quotas, rate limiting) layer without overwriting the private slot. Middleware register on McpRuntime and run outer-to-inner, may short-circuit with a canonical error result, and see the caller identity, tool name, bounded argument keys, and a request id. The chain wraps the handler once at build time (in server.py, the wiring root), is a no-op when nothing is registered, and is idempotent per app. A structured tool-log middleware ships as the first consumer, seeded only under the remote profile and emitting JSON to stderr so it never corrupts the stdio stream.
gbrlcustodio
changed the title
The local static token is a JWT carrying the user subject, so subject is feasible on both profiles; it is deferred for want of a consumer, not because it cannot be sourced.
The middleware chain is profile-agnostic; only per-user concerns (quotas, cost attribution) are hosted-specific, while observability and downstream protection apply to any deployment. Reframe the module docstring, the logger-seeding comment, and AGENTS.md so the remote-only logger default reads as a default, not a capability boundary.
Drop editorial framing and restated rationale from the seam's docstrings, fix a number-agreement slip, and correct require_request_bearer to say the read goes through request.scope rather than the request.user property the refactor stopped using.
Behavioral fixes: - log-middleware outcome is now ok/error/cancelled/elicitation, so client disconnects and URL-elicitation control flow no longer inflate error metrics. - a repeat install with a different middleware set raises instead of silently dropping the newcomers; the marker now snapshots the installed set. - harden the request_id read so a present non-dict scope["state"] cannot crash the chain entry. - require_request_bearer's error names both causes (no valid bearer, or auth middleware not wired), recovering the signal the old request.user assertion gave. Accompanying tidy-ups in the same files: - ToolCallContext.tool_name/arguments are read-only views over req.params, so the context cannot drift from the request it wraps. - guard the log emit at the call site so the event dict is not built when INFO is off; drop an over-defensive getattr in _outcome; drop a redundant list() in compose. - reword an as-is doc line in AGENTS.md that described the seam as a delta.
The runtime seeded a profile-specific logger into a registration list that server.py then read back out and installed, which coupled core to a concrete observability middleware and made the list a pointless round-trip. Move the seeding decision to default_tool_middlewares(settings) in server.py and pass the list straight to install_tool_call_middleware. Drop the runtime's _tool_middlewares list, register_tool_middleware, and tool_middlewares property: the composition root builds the list and installs it, so the runtime owns only the engine, identity, and inbound auth again. The core -> observability import is gone; the dependency now runs one way.
The install marker snapshotted the middleware tuple and compared it on re-install, buying a same-set-is-a-no-op tolerance no caller reaches (install runs once per app at the composition root) at the cost of object-identity equality semantics on callables. Replace it with a boolean marker that raises on any second install: simpler, and still fail-loud against silently stacking or dropping middleware. Also drop CallerIdentity from the module __all__; its home is auth.request_identity and nothing imports it through this module.
Follow-up: make the seam publicly registerable, and use it to make FastMCP an implementation detailContext: I consumed this branch end to end in a real remote deployment (a thin Kubernetes serving layer over Gap 1: the seam is installed but not externally registerableThe PR body says " Concrete motivating case: the deployment needed per-tool Prometheus metrics (a second consumer of the same seam). With no registration point, the only options were to re-wrap the private handler (defeats the PR) or drop the metrics (what I did). The seam solved the collision problem internally but did not expose the solution. Gap 2:
|
Add an optional extra_tool_middlewares to build_pipefy_mcp_server so a consumer of the builder (a hosted serving layer wanting per-tool metrics, say) folds its own middleware into the single install rather than reaching into the private request_handlers slot. The built-in defaults run outer to the consumer's, so the default observability layer records every call, including those a consumer's middleware short-circuits.
…lope Correct the short_circuit_error docstring: it does not replicate FastMCP's dict normalization byte-for-byte. A dict-returning tool with no output schema runs through FastMCP's own encoder (non-ASCII left raw, structuredContent unset), while short_circuit_error uses json.dumps and fills structuredContent. The match is on the decoded envelope, not the bytes. Add a contract test that drives a real dict-returning tool through the terminal and asserts the decoded envelope equals short_circuit_error's, with the intended isError divergence, so an SDK encoder change fails loud rather than drifting the two apart silently.
adriannoes
left a comment
adriannoes
left a comment
There was a problem hiding this comment.
Summary
This lands the tool-call middleware seam the hosted stack needs: an ordered chain around FastMCP’s single CallToolRequest slot, with short-circuit, request-scoped identity, and tool_log_middleware as the first consumer. The public registration path via build_pipefy_mcp_server(..., extra_tool_middlewares=...) is the right shape for a second consumer without re-wrapping private handlers. Tests and CI look solid on this head.
What worked well
- Builder fold-in with built-ins outer and a real session test that proves consumer middleware runs.
- Composition root owns the list;
corestays free ofobservability. - Short-circuit envelope parity with in-tool
tool_error(decoded JSON, intentionalisErrordivergence). - Clear outcome taxonomy on the logger (
ok/error/cancelled/elicitation) and stderr-safe emission.
Also noted
ToolCallContextandmcp.types:reqis still public (your Gap 2). Not blocking if the pipefy-owned context lands with thePlugin/build_appfollow-up — worth confirming that plan so consumers don’t treatreqas stable API.- JSON line integrity (inline): under the default FastMCP/
RichHandlerconfig, a realistictool_callevent wraps in non-TTY logs. Sequencing question for #373’s emitter vs a dedicated handler on this middleware — details on the thread.
Keep the stdlib-only JSON emitter package surface from this stack and the tool-call middleware composition root from #378; wire both into server.py.
Reuse build_tool_call_event/emit_structured_event so #378 tool lines share the pinned stderr JSON channel and allowlisted shape (including cancelled and elicitation outcomes) instead of a parallel logger.info path.
…ack 2/3) (#376) * feat(mcp): add stdout JSON structured logging emitter Introduce allowlisted JSON event builders and a dedicated stdout logger with propagate=False so hosted observability coexists with FastMCP's RichHandler. Add PIPEFY_MCP_LOG_LEVEL to McpSettings and wire it through run_server and FastMCP construction. * feat(mcp): preserve JWT sub claim in PipefyAccessToken Extend the resource-server token mapping with an optional sub field so hosted HTTP request logs can emit caller subject alongside client_id without re-decoding the bearer. * fix(mcp): map log levels explicitly and re-export the emitter surface normalize_log_level resolved names via getattr(logging, ...), which returns non-level module attributes (BASIC_FORMAT) and accepts aliases the settings Literal rejects (WARN, FATAL); an explicit map fails loudly on both. The observability package now re-exports its stdlib-only emitter surface per the package convention, and a suite-wide autouse fixture drops leftover stdout handlers so a test that configures the process-global logger cannot leak a closed-stream handler into later tests. * fix(mcp): degrade a non-string JWT sub to None instead of rejecting the token PipefyAccessToken.sub is str | None, so a validly-signed token carrying a numeric sub raised ValidationError inside _to_access_token and verify_token turned it into a 401, a token dev accepted before the field existed. sub feeds request logging only; a malformed value must not gate authentication. RFC 7519 requires StringOrURI, so only non-compliant IdPs ever hit this. * feat(mcp): add pure-ASGI HTTP request log middleware Emit one structured JSON line per HTTP request from middleware that only inspects response.start, stores request_id in scope state, and reads caller identity from the auth context at emit time. * feat(mcp): serve HTTP with request logging via manual uvicorn Wire RequestLogMiddleware through streamable_http_app once and replace FastMCP.run(streamable-http) with explicit uvicorn serve and access_log disabled so structured request lines replace text access logs. * fix(mcp): configure the stdout emitter only on the HTTP serve path configure_observability_logging ran before the transport branch, arming a stdout handler in the stdio process too, where stdout is the JSON-RPC wire. Nothing emits under stdio today, but the D10 guarantee was conventional rather than structural: one future emit call in shared code would corrupt the protocol. The call now lives in _serve_streamable_http, and the stdio test asserts configuration never happens there. Also imports AuthenticatedUser from its defining module (bearer_auth) and extends the middleware tests: bearer absent from output with an Authorization header planted, UnauthenticatedUser yields null identity, the ordering test fails fast instead of hanging, and a send that raises mid-stream still emits exactly one line. * fix(mcp): emit structured JSON logs on stderr Route the hosted observability handler to stderr so structured lines never share the stdio JSON-RPC stdout channel. Collectors already capture both streams; HTTP-only configure remains the gate that keeps local installs clean. * feat(mcp): honor inbound x-request-id and x-correlation-id Prefer an upstream request or correlation id when present so hosted request logs stay correlated across service boundaries; mint a UUID only when both headers are absent or blank. * fix(mcp): pin structured logger at INFO independent of text level PIPEFY_MCP_LOG_LEVEL now governs only the FastMCP root logger. The hosted structured emitter stays at INFO so quieting noisy text logs cannot silently drop request/tool debugging lines. Docs frame these events as debugging with a privacy allowlist, not an audit trail. * refactor(mcp): route tool_log_middleware through the structured emitter Reuse build_tool_call_event/emit_structured_event so #378 tool lines share the pinned stderr JSON channel and allowlisted shape (including cancelled and elicitation outcomes) instead of a parallel logger.info path.
2 participants
Closes #374.
What
Adds a public, ordered middleware chain around MCP tool invocation so cross-cutting concerns (logging, quotas, rate limiting, cost weighting, downstream 429/circuit-breaking) layer as composed middleware instead of each overwriting FastMCP's single private
request_handlers[CallToolRequest]slot.How
core/tool_middleware.pydefines the contract (ToolCallContext,ToolCallMiddleware/CallNext,short_circuit_error),compose(outer-to-inner), andinstall_tool_call_middleware, which wraps the handler once at build time (once per app: a second install raises; a no-op when the list is empty).server.py'sdefault_tool_middlewares(settings)builds the per-profile list and hands it toinstall_tool_call_middleware(app, ...). The runtime stays out of middleware entirely and owns only the engine, identity, and inbound auth, socoreno longer depends onobservability.auth/request_identity.pygainscaller_identity(request)returning the validated caller's client id and scopes (the typectx.identitycarries), sharing one_authenticated_userreader withrequire_request_bearer.observability/tool_log_middleware.pyships the first consumer: one structured JSON line per call (tool, outcome, duration, argument keys, client id, request id), emitted to stderr so it never corrupts the stdio JSON-RPC stream. It is seeded by default only under the remote profile; that is a default, not a capability boundary, since the chain installs on every profile.Design notes
tool_errorenvelope (isError=True, signalling the tool never ran), and reads identity from the per-message request context, neverauth_context_var.validate_input=False);argument_keysis bounded and values-free, and the bearer and argument values are never logged.cancelledon client disconnect,elicitationon a URL-elicitation signal) fromerror, so neither inflates error metrics.CallToolRequestslot is no longer the extension surface; the wrap is pinned tomcp==1.25.0and fails loud if that contract changes.Deferred / follow-up
subclaim, local by decoding the configured JWT credential once at startup), so the AC's subject field arrives with that consumer, across both profiles.sub-preserving token subtype is what the remote half of subject would reuse. Structured request and tool logging #373's "logs on stdout" acceptance criterion should reconcile to stderr, since this chain also runs under the stdio transport where stdout carries the JSON-RPC stream.outcome=error; a distinctdeniedoutcome (so quota and rate-limit rejections do not read as failures) lands with the quota consumer.Testing
caller_identity(including the local-over-HTTP no-user-scope case),default_tool_middlewaresper profile, and the tool-log middleware (fields, privacy, stdout silence).packages/mcpsuite: 1434 passed, 9 skipped (the no-creds live tests). Verified the real build path wraps the handler under remote and is a no-op under local.