From 9736750624c05d2bf3f9ad65e6908c1092358701 Mon Sep 17 00:00:00 2001 From: Juan Antonio Osorio Date: Wed, 29 Jul 2026 14:52:47 +0300 Subject: [PATCH] Opt Modern backends into log notifications via logLevel _meta MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The 2026-07-28 (Modern) MCP revision removed the logging/setLevel RPC; the per-request io.modelcontextprotocol/logLevel _meta key replaces it. modelcontextprotocol/go-sdk#1116 confirmed go-sdk's SetLoggingLevel is wont-fix-by-design on Modern sessions, so a Modern backend never emits notifications/message through vMCP. When server->client forwarding is bound, modernCallTool now overlays logLevel: debug onto the request _meta (the Modern analogue of the Legacy enableBackendLogging) and relays interleaved notifications/message and notifications/progress from the backend's SSE stream to the downstream client. The logLevel key and listener are omitted when forwarding is unbound, and every other Modern call site is unchanged. Also export mcp.MetaKeyLogLevel for the overlay, and reframe the two pin comments that attributed the -32020 rejection to a transient upstream bug — it is the standing contract for a removed RPC. Closes #6130 --- docs/arch/10-virtual-mcp-architecture.md | 2 +- pkg/mcp/revision.go | 7 +- pkg/mcp/revision_test.go | 4 +- pkg/vmcp/client/client.go | 27 +++- pkg/vmcp/client/forwarding.go | 56 +++++++++ pkg/vmcp/client/modern.go | 63 ++++++++-- pkg/vmcp/client/modern_calls_test.go | 45 +++++++ pkg/vmcp/client/modern_integration_test.go | 2 +- pkg/vmcp/client/modern_test.go | 118 ++++++++++++++++-- ...forwarding_realbackend_integration_test.go | 22 ++-- .../modern_realbackend_integration_test.go | 20 +-- 11 files changed, 312 insertions(+), 54 deletions(-) diff --git a/docs/arch/10-virtual-mcp-architecture.md b/docs/arch/10-virtual-mcp-architecture.md index 4bcb07d17b..70525f3c4d 100644 --- a/docs/arch/10-virtual-mcp-architecture.md +++ b/docs/arch/10-virtual-mcp-architecture.md @@ -804,7 +804,7 @@ forwarding applies — see [Limitation: elicitation and sampling are unavailable to Modern clients](#limitation-elicitation-and-sampling-are-unavailable-to-modern-clients) for what a Modern caller gets instead. -**Known limitation (logging level)**: forwarded backend logging is not yet filtered to the downstream client's requested `logging/setLevel`. vMCP requests debug-level logging from the backend so it emits `notifications/message`, and every such notification is forwarded — the downstream client's own level preference is not applied to the relayed stream. +**Known limitation (logging level)**: forwarded backend logging is not yet filtered to the downstream client's requested level. On Legacy, vMCP requests debug-level logging from the backend (`logging/setLevel`) so it emits `notifications/message`, and every such notification is forwarded — the downstream client's own `logging/setLevel` preference is not applied to the relayed stream. The same is true on Modern (2026-07-28), where the RPC is removed and the level rides per-request in `_meta["io.modelcontextprotocol/logLevel"]`: vMCP strips that reserved per-hop key from the downstream request and overlays its own (`debug`, when forwarding is bound) on the backend hop, so a Modern client's per-request level preference is likewise not honored — the relay runs at debug either way. **Known limitation (resource-template authorization)**: a resource template is advertised on the template-string entity (e.g. `file:///logs/{date}.txt`), but a concrete read is admission-checked on the **expanded** URI (e.g. `file:///logs/2025-01-01.txt`). Operators should therefore author resource authorization policies against concrete URI patterns, not the template string. diff --git a/pkg/mcp/revision.go b/pkg/mcp/revision.go index 9d65bdbee3..2f2e7e58f9 100644 --- a/pkg/mcp/revision.go +++ b/pkg/mcp/revision.go @@ -56,7 +56,7 @@ const metaKeyClientInfo = "io.modelcontextprotocol/clientInfo" // schema's RequestMetaObject. const metaKeyClientCapabilities = "io.modelcontextprotocol/clientCapabilities" -// metaKeyLogLevel carries the per-request minimum log level on Modern +// MetaKeyLogLevel carries the per-request minimum log level on Modern // (2026-07-28) requests (draft schema RequestMetaObject; go-sdk protocol.go). // It is a reserved per-hop key that must be stripped before a Legacy backend // hop, but — unlike the other reserved keys — its mere presence is NOT a claim @@ -64,7 +64,10 @@ const metaKeyClientCapabilities = "io.modelcontextprotocol/clientCapabilities" // on protocolVersion, and SEP-2577 already deprecates logLevel. It therefore // belongs in the strip set (ReservedMetaPrefix, minus passthroughMetaKeys) but // not the ingress signal set (modernSignalMetaKeys). -const metaKeyLogLevel = "io.modelcontextprotocol/logLevel" +// +// Exported so the vMCP Modern client can overlay it onto the request _meta it +// mints (the Modern replacement for the removed logging/setLevel RPC). +const MetaKeyLogLevel = "io.modelcontextprotocol/logLevel" // ReservedMetaPrefix is the _meta key namespace the MCP spec reserves for the // protocol's own use. StripReservedMeta removes every key carrying it except diff --git a/pkg/mcp/revision_test.go b/pkg/mcp/revision_test.go index eafc1e10ac..a70c50839b 100644 --- a/pkg/mcp/revision_test.go +++ b/pkg/mcp/revision_test.go @@ -222,7 +222,7 @@ func TestClassifyRevision(t *testing.T) { // Legacy. name: "legacy: logLevel reserved key alone is not a Modern signal", method: "tools/call", - meta: map[string]any{metaKeyLogLevel: "debug"}, + meta: map[string]any{MetaKeyLogLevel: "debug"}, protoHeader: "", expectedRev: RevisionLegacy, checkErr: func(t *testing.T, err error) { @@ -697,7 +697,7 @@ func TestStripReservedMeta(t *testing.T) { metaKeyProtocolVersion: MCPVersionModern, metaKeyClientInfo: map[string]any{"name": "x"}, metaKeyClientCapabilities: map[string]any{}, - metaKeyLogLevel: "debug", + MetaKeyLogLevel: "debug", // Response/notification-side reserved keys: a backend must not be able // to speak for vMCP on the way back to the client (#5986). "io.modelcontextprotocol/serverInfo": map[string]any{"name": "attacker"}, diff --git a/pkg/vmcp/client/client.go b/pkg/vmcp/client/client.go index d0115cddf9..a1df7468f9 100644 --- a/pkg/vmcp/client/client.go +++ b/pkg/vmcp/client/client.go @@ -1067,7 +1067,7 @@ func discoverModernCapabilities(ctx context.Context, hc *http.Client, endpoint s Capabilities mcp.ServerCapabilities `json:"capabilities"` SupportedVersions []string `json:"supportedVersions"` } - if err := modernCall(ctx, hc, endpoint, "server/discover", nil, "", nil, &discover); err != nil { + if err := modernCall(ctx, hc, endpoint, "server/discover", nil, "", nil, &discover, "", nil); err != nil { return nil, err } // Exact-match on MCPVersionModern (2026-07-28): vMCP's shim only speaks that @@ -1249,7 +1249,7 @@ func modernListAll[T any]( ) ([]T, error) { return pagination.ListAll(ctx, func(ctx context.Context, cursor mcp.Cursor) ([]T, mcp.Cursor, error) { var page map[string]json.RawMessage - if err := modernCall(ctx, hc, endpoint, method, cursorParams(cursor), "", nil, &page); err != nil { + if err := modernCall(ctx, hc, endpoint, method, cursorParams(cursor), "", nil, &page, "", nil); err != nil { return nil, "", err } var items []T @@ -1662,9 +1662,24 @@ func (h *httpBackendClient) modernCallTool( if len(meta) > 0 { params["_meta"] = meta } + + // Modern logging parity with the Legacy path (enableBackendLogging): when + // server->client forwarding is bound, opt the call in to the backend's + // notifications/message at debug level via the per-request logLevel _meta key + // (the Modern replacement for the removed logging/setLevel RPC), and relay any + // interleaved notifications to the downstream client. Both are no-ops when + // forwarding is unbound — no logLevel key is sent and no listener is attached. + fwd := h.forwarders.Load() + var logLevel string + var onNotification func(string, json.RawMessage) + if fwd != nil && fwd.notifier != nil { + logLevel = string(mcp.LoggingLevelDebug) + onNotification = newModernNotificationForwarder(ctx, fwd.notifier) + } + var result mcp.CallToolResult if err := modernCall( - ctx, hc, target.BaseURL, "tools/call", params, backendToolName, paramHeaders, &result, + ctx, hc, target.BaseURL, "tools/call", params, backendToolName, paramHeaders, &result, logLevel, onNotification, ); err != nil { return nil, fmt.Errorf("%w: tool call failed on backend %s: %w", vmcp.ErrBackendUnavailable, target.WorkloadID, err) } @@ -1854,7 +1869,7 @@ func (h *httpBackendClient) modernReadResource( Meta map[string]any `json:"_meta"` } params := map[string]any{"uri": backendURI} - if err := modernCall(ctx, hc, target.BaseURL, "resources/read", params, backendURI, nil, &res); err != nil { + if err := modernCall(ctx, hc, target.BaseURL, "resources/read", params, backendURI, nil, &res, "", nil); err != nil { return nil, fmt.Errorf("resource read failed on backend %s: %w", target.WorkloadID, err) } mcpContents := make([]mcp.ResourceContents, len(res.Contents)) @@ -1972,7 +1987,7 @@ func (h *httpBackendClient) modernGetPrompt( } `json:"messages"` Meta map[string]any `json:"_meta"` } - if err := modernCall(ctx, hc, target.BaseURL, "prompts/get", params, backendPromptName, nil, &res); err != nil { + if err := modernCall(ctx, hc, target.BaseURL, "prompts/get", params, backendPromptName, nil, &res, "", nil); err != nil { return nil, fmt.Errorf("prompt get failed on backend %s: %w", target.WorkloadID, err) } messages := make([]vmcp.PromptMessage, 0, len(res.Messages)) @@ -2094,7 +2109,7 @@ func (h *httpBackendClient) modernComplete( HasMore bool `json:"hasMore"` } `json:"completion"` } - err = modernCall(ctx, hc, target.BaseURL, "completion/complete", params, "", nil, &res) + err = modernCall(ctx, hc, target.BaseURL, "completion/complete", params, "", nil, &res, "", nil) if errors.Is(err, mcp.ErrMethodNotFound) { return &vmcp.CompletionResult{Values: []string{}}, nil } diff --git a/pkg/vmcp/client/forwarding.go b/pkg/vmcp/client/forwarding.go index b6e94427d5..5406332433 100644 --- a/pkg/vmcp/client/forwarding.go +++ b/pkg/vmcp/client/forwarding.go @@ -5,6 +5,7 @@ package client import ( "context" + "encoding/json" "log/slog" "github.com/stacklok/toolhive-core/mcpcompat/client" @@ -48,6 +49,12 @@ func (h *httpBackendClient) BindForwarders( // relays to the downstream client. It is a no-op when no forwarders are bound or // the backend does not advertise the logging capability. Best-effort: a failure // is logged at debug and does not fail the caller. +// +// This RPC (logging/setLevel) exists only on the LEGACY revision: the 2026-07-28 +// (Modern) revision removed it — go-sdk#1116 was closed wont-fix-by-design — so +// this is only ever called from legacyCallTool. The Modern equivalent is the +// per-request io.modelcontextprotocol/logLevel _meta key, which modernCallTool +// overlays onto the request it mints (see TestModernCallTool_LogLevelGating). func (h *httpBackendClient) enableBackendLogging( ctx context.Context, c *client.Client, caps *mcp.ServerCapabilities, backendID string, ) { @@ -248,6 +255,55 @@ func newNotificationForwarder(callCtx context.Context, notifier vmcp.ClientNotif } } +// newModernNotificationForwarder builds the onNotification callback modernCall +// invokes for each server->client notification a Modern (2026-07-28) backend +// interleaves on the SSE stream ahead of the tool-call response. It is the +// Modern analogue of newNotificationForwarder: the wire shape differs (raw +// method + params instead of a typed mcp.JSONRPCNotification), but the relay is +// the same best-effort NotifyLog/NotifyProgress to the downstream client via the +// bound notifier, using the captured per-call downstream context. Only the two +// mid-call methods vMCP opts into (log via the logLevel _meta key, progress via +// a progressToken) are relayed; anything else is ignored. +func newModernNotificationForwarder( + callCtx context.Context, notifier vmcp.ClientNotifier, +) func(method string, params json.RawMessage) { + // Same WithoutCancel rationale as newNotificationForwarder: notifications can + // arrive just after the tool call context is cancelled, but forwarding should + // still run best-effort. + forwardCtx := context.WithoutCancel(callCtx) + + return func(method string, params json.RawMessage) { + switch method { + case vmcp.MethodProgressNotification, vmcp.MethodLogNotification: + default: + return // not a mid-call method this forwarder relays + } + var fields map[string]any + if err := json.Unmarshal(params, &fields); err != nil { + slog.Debug("failed to decode modern notification params", "method", method, "error", err) + return + } + if method == vmcp.MethodProgressNotification { + if err := notifier.NotifyProgress(forwardCtx, vmcp.ProgressNotification{ + ProgressToken: fields["progressToken"], + Progress: toFloat(fields["progress"]), + Total: toFloat(fields["total"]), + Message: toString(fields["message"]), + }); err != nil { + slog.Debug("failed to forward progress notification", "error", err) + } + return + } + if err := notifier.NotifyLog(forwardCtx, vmcp.LogMessage{ + Level: toString(fields["level"]), + Logger: toString(fields["logger"]), + Data: fields["data"], + }); err != nil { + slog.Debug("failed to forward log notification", "error", err) + } + } +} + // fromMCPSamplingMessages maps SDK sampling messages to the domain type. func fromMCPSamplingMessages(msgs []mcp.SamplingMessage) []vmcp.SamplingMessage { if msgs == nil { diff --git a/pkg/vmcp/client/modern.go b/pkg/vmcp/client/modern.go index f5c703f7c6..d397e4cf5f 100644 --- a/pkg/vmcp/client/modern.go +++ b/pkg/vmcp/client/modern.go @@ -175,6 +175,18 @@ var modernRequestID atomic.Int64 // - errModernInputRequired: a non-"complete" envelope. // - errModernProtocolError: a Modern-specific -3202x error body. // - a wrapped call error: any other JSON-RPC error. +// +// logLevel, when non-empty, is overlaid onto the request _meta as +// io.modelcontextprotocol/logLevel (the Modern replacement for the removed +// logging/setLevel RPC): it opts the request in to the backend's +// notifications/message at that minimum level. Empty leaves the key unset so the +// backend MUST NOT emit log notifications for the request. +// +// onNotification, when non-nil, is invoked with each server->client notification +// the SSE stream interleaves ahead of the response (a nil-Method envelope is the +// response, not a notification). It is how a caller relays the log/progress +// notifications logLevel elicited; nil preserves the historical drop. It only +// ever fires on the SSE path — a single JSON 200 body carries no notifications. func modernCall( ctx context.Context, hc *http.Client, @@ -183,6 +195,8 @@ func modernCall( name string, paramHeaders map[string]string, out any, + logLevel string, + onNotification func(method string, params json.RawMessage), ) error { id := modernRequestID.Add(1) @@ -190,7 +204,7 @@ func modernCall( if reqParams == nil { reqParams = map[string]any{} } - reqParams["_meta"] = mergeModernMeta(params["_meta"]) + reqParams["_meta"] = mergeModernMeta(params["_meta"], logLevel) body, err := json.Marshal(map[string]any{ "jsonrpc": "2.0", @@ -237,7 +251,7 @@ func modernCall( _ = resp.Body.Close() }() - result, rpcErr, err := readModernEnvelope(resp, id) + result, rpcErr, err := readModernEnvelope(resp, id, onNotification) if err != nil { return err } @@ -296,7 +310,12 @@ func interpretModernResult(result json.RawMessage, rpcErr *modernRPCError, metho // mergeModernMeta strips the reserved io.modelcontextprotocol/* keys from a // caller-supplied _meta (if any) and overlays vMCP's authoritative values last. // The caller's _meta is never mutated (StripReservedMeta clones it). -func mergeModernMeta(callerMeta any) map[string]any { +// +// logLevel, when non-empty, is overlaid as io.modelcontextprotocol/logLevel — +// vMCP, not the caller, decides whether the backend is asked to emit log +// notifications for this request (the caller's own key was already stripped as +// reserved). Empty leaves the key unset. +func mergeModernMeta(callerMeta any, logLevel string) map[string]any { m, _ := callerMeta.(map[string]any) meta := mcpparser.StripReservedMeta(m) if meta == nil { @@ -307,6 +326,9 @@ func mergeModernMeta(callerMeta any) map[string]any { for k, v := range mcpparser.ModernRequestMeta(modernClientName, versions.Version) { meta[k] = v } + if logLevel != "" { + meta[mcpparser.MetaKeyLogLevel] = logLevel + } return meta } @@ -320,14 +342,16 @@ type modernRPCError struct { Data json.RawMessage `json:"data,omitempty"` } -// modernRPCEnvelope is the outer JSON-RPC response envelope. Method is set only -// on server->client requests/notifications interleaved on an SSE stream, which a -// single-shot client ignores. +// modernRPCEnvelope is the outer JSON-RPC response envelope. Method and Params +// are set only on server->client requests/notifications interleaved on an SSE +// stream; a single-shot client matches the response (Method == "") and, when an +// onNotification listener is bound, relays Method/Params for the notifications. type modernRPCEnvelope struct { ID json.RawMessage `json:"id"` Result json.RawMessage `json:"result"` Error *modernRPCError `json:"error"` Method string `json:"method"` + Params json.RawMessage `json:"params"` } // readModernEnvelope reads the JSON-RPC response matching wantID, handling both @@ -343,7 +367,9 @@ type modernRPCEnvelope struct { // the revision cache). A genuine Modern -32601/-32602 rides HTTP 404/400 WITH a // JSON-RPC body and is handled by the body logic below, so those statuses are // deliberately NOT short-circuited here. -func readModernEnvelope(resp *http.Response, wantID int64) (json.RawMessage, *modernRPCError, error) { +func readModernEnvelope( + resp *http.Response, wantID int64, onNotification func(method string, params json.RawMessage), +) (json.RawMessage, *modernRPCError, error) { switch { case resp.StatusCode == http.StatusUnauthorized, resp.StatusCode == http.StatusForbidden, resp.StatusCode == http.StatusProxyAuthRequired: @@ -356,7 +382,7 @@ func readModernEnvelope(resp *http.Response, wantID int64) (json.RawMessage, *mo body := io.LimitReader(resp.Body, maxResponseSize) if strings.HasPrefix(resp.Header.Get("Content-Type"), "text/event-stream") { - return readModernSSE(body, wantID) + return readModernSSE(body, wantID, onNotification) } data, err := io.ReadAll(body) @@ -376,10 +402,16 @@ func readModernEnvelope(resp *http.Response, wantID int64) (json.RawMessage, *mo return env.Result, env.Error, nil } -// readModernSSE scans an SSE body for the response whose id matches wantID, -// consuming (ignoring) any server->client requests/notifications interleaved on -// the stream. A stream that ends without a matching response yields errWrongEra. -func readModernSSE(body io.Reader, wantID int64) (json.RawMessage, *modernRPCError, error) { +// readModernSSE scans an SSE body for the response whose id matches wantID. +// Server->client requests/notifications interleaved on the stream (envelopes +// with a Method) are not the response: when onNotification is non-nil their +// method and params are handed to it (so a caller can relay the +// notifications/message and notifications/progress the request's logLevel / +// progressToken elicited); when nil they are dropped as before. A stream that +// ends without a matching response yields errWrongEra. +func readModernSSE( + body io.Reader, wantID int64, onNotification func(method string, params json.RawMessage), +) (json.RawMessage, *modernRPCError, error) { sc := bufio.NewScanner(body) // Cap the token at maxResponseSize (the doc-promised bound) so a valid single // data: event up to that size decodes; the outer io.LimitReader already bounds @@ -395,7 +427,12 @@ func readModernSSE(body io.Reader, wantID int64) (json.RawMessage, *modernRPCErr continue } if env.Method != "" { - continue // server->client request/notification; not our response + // server->client request/notification; not our response. Relay it when a + // listener is bound, otherwise drop it (historical behavior). + if onNotification != nil { + onNotification(env.Method, env.Params) + } + continue } if !modernIDMatches(env.ID, wantID) { continue diff --git a/pkg/vmcp/client/modern_calls_test.go b/pkg/vmcp/client/modern_calls_test.go index 838df7d85a..5b53500ab8 100644 --- a/pkg/vmcp/client/modern_calls_test.go +++ b/pkg/vmcp/client/modern_calls_test.go @@ -80,6 +80,51 @@ func TestModernCallTool(t *testing.T) { assert.Equal(t, "x", res.Meta["trace"], "result _meta must be forwarded to core") } +// TestModernCallTool_LogLevelGating pins when the Modern tools/call opts into +// backend log notifications: the io.modelcontextprotocol/logLevel _meta key is +// injected at debug level ONLY when server->client forwarding is bound (the +// Modern analogue of enableBackendLogging on the Legacy path). Unbound, the key +// must be absent so a conformant backend does not emit notifications/message. +func TestModernCallTool_LogLevelGating(t *testing.T) { + t.Parallel() + + logLevelOf := func(body *map[string]any) (any, bool) { + meta, _ := (*body)["_meta"].(map[string]any) + v, ok := meta["io.modelcontextprotocol/logLevel"] + return v, ok + } + + t.Run("bound forwarders inject debug logLevel", func(t *testing.T) { + t.Parallel() + srv, _, body := bodyRecordingServer(t, map[string]any{ + "content": []any{map[string]any{"type": "text", "text": "ok"}}, + }) + h, target := modernClient(t, srv.URL) + h.BindForwarders(&stubElicitationRequester{}, &stubSamplingRequester{}, stubClientNotifier{}) + + _, err := h.CallTool(context.Background(), target, "echo", map[string]any{"input": "hi"}, nil, nil) + require.NoError(t, err) + + v, ok := logLevelOf(body) + require.True(t, ok, "bound forwarders must opt the call into log notifications") + assert.Equal(t, "debug", v) + }) + + t.Run("unbound forwarders send no logLevel", func(t *testing.T) { + t.Parallel() + srv, _, body := bodyRecordingServer(t, map[string]any{ + "content": []any{map[string]any{"type": "text", "text": "ok"}}, + }) + h, target := modernClient(t, srv.URL) + + _, err := h.CallTool(context.Background(), target, "echo", map[string]any{"input": "hi"}, nil, nil) + require.NoError(t, err) + + _, ok := logLevelOf(body) + assert.False(t, ok, "without forwarding the backend must not be asked to emit logs") + }) +} + // TestModernReadResource verifies resources/read shaping (Mcp-Name mirrors the // translated uri) and text/blob content decode. func TestModernReadResource(t *testing.T) { diff --git a/pkg/vmcp/client/modern_integration_test.go b/pkg/vmcp/client/modern_integration_test.go index f24aa4b21c..a58d4ab238 100644 --- a/pkg/vmcp/client/modern_integration_test.go +++ b/pkg/vmcp/client/modern_integration_test.go @@ -140,7 +140,7 @@ func TestIntegration_ModernCall_Discover(t *testing.T) { } `json:"capabilities"` SupportedVersions []string `json:"supportedVersions"` } - err := modernCall(context.Background(), hc, vmcpSrv.URL+"/mcp", "server/discover", nil, "", nil, &out) + err := modernCall(context.Background(), hc, vmcpSrv.URL+"/mcp", "server/discover", nil, "", nil, &out, "", nil) require.NoError(t, err) // Request shaping reached the real server intact. diff --git a/pkg/vmcp/client/modern_test.go b/pkg/vmcp/client/modern_test.go index b851ac9b55..5aef8b7d24 100644 --- a/pkg/vmcp/client/modern_test.go +++ b/pkg/vmcp/client/modern_test.go @@ -19,14 +19,15 @@ import ( ) // completeEnvelope is a minimal valid Modern success body for a given method's -// result payload merged with the resultType envelope key. -func completeEnvelope(t *testing.T, id any, payload map[string]any) []byte { +// result payload merged with the resultType envelope key. The id is always 1: +// these fakes serve the JSON (not SSE) path, which does not match by id. +func completeEnvelope(t *testing.T, payload map[string]any) []byte { t.Helper() result := map[string]any{"resultType": "complete"} for k, v := range payload { result[k] = v } - body, err := json.Marshal(map[string]any{"jsonrpc": "2.0", "id": id, "result": result}) + body, err := json.Marshal(map[string]any{"jsonrpc": "2.0", "id": 1, "result": result}) require.NoError(t, err) return body } @@ -86,7 +87,7 @@ func TestModernCall_RequestShaping(t *testing.T) { gotReq = r gotBody, _ = readAll(t, r) w.Header().Set("Content-Type", "application/json") - _, _ = w.Write(completeEnvelope(t, 1, map[string]any{})) + _, _ = w.Write(completeEnvelope(t, map[string]any{})) })) t.Cleanup(srv.Close) @@ -94,7 +95,7 @@ func TestModernCall_RequestShaping(t *testing.T) { if tt.callerMeta != nil { params["_meta"] = tt.callerMeta } - err := modernCall(context.Background(), srv.Client(), srv.URL, tt.method, params, tt.mcpName, nil, nil) + err := modernCall(context.Background(), srv.Client(), srv.URL, tt.method, params, tt.mcpName, nil, nil, "", nil) require.NoError(t, err) assert.Equal(t, "application/json", gotReq.Header.Get("Content-Type")) @@ -129,13 +130,13 @@ func TestModernCall_CallerMetaNotMutated(t *testing.T) { srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { w.Header().Set("Content-Type", "application/json") - _, _ = w.Write(completeEnvelope(t, 1, map[string]any{})) + _, _ = w.Write(completeEnvelope(t, map[string]any{})) })) t.Cleanup(srv.Close) callerMeta := map[string]any{"userKey": "v"} params := map[string]any{"_meta": callerMeta, "name": "x"} - require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "tools/list", params, "", nil, nil)) + require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "tools/list", params, "", nil, nil, "", nil)) assert.Equal(t, map[string]any{"userKey": "v"}, callerMeta, "caller _meta must be untouched") assert.NotContains(t, params, "does-not-add-keys") @@ -150,7 +151,7 @@ func TestModernCall_Decode(t *testing.T) { srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { w.Header().Set("Content-Type", "application/json") - _, _ = w.Write(completeEnvelope(t, 1, map[string]any{ + _, _ = w.Write(completeEnvelope(t, map[string]any{ "supportedVersions": []string{"2026-07-28"}, })) })) @@ -160,7 +161,7 @@ func TestModernCall_Decode(t *testing.T) { ResultType string `json:"resultType"` SupportedVersions []string `json:"supportedVersions"` } - require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, &out)) + require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, &out, "", nil)) assert.Equal(t, "complete", out.ResultType) assert.Equal(t, []string{"2026-07-28"}, out.SupportedVersions) } @@ -190,11 +191,104 @@ func TestModernCall_SSEResponse(t *testing.T) { t.Cleanup(srv.Close) var out map[string]any - require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, &out)) + require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, &out, "", nil)) assert.Equal(t, "complete", out["resultType"]) assert.Equal(t, true, out["ok"]) } +// TestModernCall_LogLevelMeta verifies the logLevel argument is overlaid onto +// the minted request _meta as io.modelcontextprotocol/logLevel — the Modern +// (2026-07-28) replacement for the removed logging/setLevel RPC — and that an +// empty logLevel leaves the key unset (so a conformant backend MUST NOT emit +// notifications/message for the request). +func TestModernCall_LogLevelMeta(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + logLevel string + wantKey bool + wantLogLevel any + }{ + {name: "non-empty logLevel is injected", logLevel: "debug", wantKey: true, wantLogLevel: "debug"}, + {name: "empty logLevel omits the key", logLevel: "", wantKey: false}, + } + + for _, tt := range tests { + tt := tt + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + var gotBody []byte + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + gotBody, _ = readAll(t, r) + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write(completeEnvelope(t, map[string]any{})) + })) + t.Cleanup(srv.Close) + + require.NoError(t, modernCall( + context.Background(), srv.Client(), srv.URL, "tools/call", + map[string]any{"name": "x"}, "x", nil, nil, tt.logLevel, nil, + )) + + var decoded struct { + Params struct { + Meta map[string]any `json:"_meta"` + } `json:"params"` + } + require.NoError(t, json.Unmarshal(gotBody, &decoded)) + if tt.wantKey { + assert.Equal(t, tt.wantLogLevel, decoded.Params.Meta["io.modelcontextprotocol/logLevel"]) + } else { + assert.NotContains(t, decoded.Params.Meta, "io.modelcontextprotocol/logLevel") + } + }) + } +} + +// TestModernCall_SSENotificationRelay verifies that when an onNotification +// listener is bound, an interleaved server->client notification is handed to it +// (method + params) AND the matching response is still returned — the listener +// must not swallow the response the caller is waiting on. +func TestModernCall_SSENotificationRelay(t *testing.T) { + t.Parallel() + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + var req struct { + ID json.RawMessage `json:"id"` + } + body, _ := io.ReadAll(r.Body) + require.NoError(t, json.Unmarshal(body, &req)) + + w.Header().Set("Content-Type", "text/event-stream") + // A log notification (method, no id) then the matching response. + _, _ = w.Write([]byte("data: {\"jsonrpc\":\"2.0\",\"method\":\"notifications/message\"," + + "\"params\":{\"level\":\"info\",\"data\":\"hello\"}}\n\n")) + _, _ = w.Write([]byte("data: {\"jsonrpc\":\"2.0\",\"id\":" + string(req.ID) + + ",\"result\":{\"resultType\":\"complete\",\"ok\":true}}\n\n")) + })) + t.Cleanup(srv.Close) + + var gotMethod string + var gotParams map[string]any + onNotification := func(method string, params json.RawMessage) { + gotMethod = method + _ = json.Unmarshal(params, &gotParams) + } + + var out map[string]any + require.NoError(t, modernCall( + context.Background(), srv.Client(), srv.URL, "tools/call", + map[string]any{"name": "x"}, "x", nil, &out, "debug", onNotification, + )) + + assert.Equal(t, "notifications/message", gotMethod) + assert.Equal(t, "info", gotParams["level"]) + assert.Equal(t, "hello", gotParams["data"]) + assert.Equal(t, "complete", out["resultType"], "the response must still be delivered to the caller") +} + // TestModernCall_ErrorMapping verifies the era/error classification: a valid // -32601 body is method-not-found (backend IS Modern), a non-"complete" envelope // is input-required, and non-Modern responses are wrong-era. @@ -307,7 +401,7 @@ func TestModernCall_ErrorMapping(t *testing.T) { })) t.Cleanup(srv.Close) - err := modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, nil) + err := modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, nil, "", nil) require.Error(t, err) if tt.wantErr != nil { assert.ErrorIs(t, err, tt.wantErr) @@ -347,7 +441,7 @@ func TestModernCall_LargeSSEEvent(t *testing.T) { var got struct { Blob string `json:"blob"` } - require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, &got)) + require.NoError(t, modernCall(context.Background(), srv.Client(), srv.URL, "server/discover", nil, "", nil, &got, "", nil)) assert.Len(t, got.Blob, len(big)) } diff --git a/pkg/vmcp/server/forwarding_realbackend_integration_test.go b/pkg/vmcp/server/forwarding_realbackend_integration_test.go index d6898fd94f..3d7b2ec435 100644 --- a/pkg/vmcp/server/forwarding_realbackend_integration_test.go +++ b/pkg/vmcp/server/forwarding_realbackend_integration_test.go @@ -474,15 +474,19 @@ func TestForwarding_Progress_RealBackend(t *testing.T) { // to the downstream client, which has itself set a logging level. // // Legacy-pinned. The one fact worth keeping AT this test so nobody "fixes" -// vMCP to make it pass on Modern: go-sdk's SetLoggingLevel (v1.7.0-pre.3) -// omits the per-request _meta injection every other Modern-aware method -// performs, so the Modern request it sends is MALFORMED (header without -// _meta.protocolVersion) and vMCP's -32020 rejection is CORRECT — accepting -// it would be worse than the failing call. Upstream bug, filed separately. -// The rest of the disposition (the RPC is removed on Modern, logLevel _meta -// replaces it, SEP-2577 deprecates logging) lives in the client-edge -// limitation in docs/arch/10-virtual-mcp-architecture.md; today's Modern -// contract is pinned by TestIntegration_Modern_RealBackend_LoggingContract. +// vMCP to make it pass on Modern: go-sdk's SetLoggingLevel omits the per-request +// _meta injection every other Modern-aware method performs, so the Modern +// request it sends is MALFORMED (header without _meta.protocolVersion) and +// vMCP's -32020 rejection is CORRECT — accepting it would be worse than the +// failing call. This is a PERMANENT fixture of go-sdk v1.7.x, not a bug to wait +// out: modelcontextprotocol/go-sdk#1116 was closed wont-fix-by-design because +// the 2026-07-28 revision REMOVED the logging/setLevel RPC (the maintainer's +// answer: use the per-request logLevel _meta key instead). The rest of the +// disposition (the RPC removal, the logLevel _meta replacement, SEP-2577's +// deprecation of logging) lives in the client-edge limitation in +// docs/arch/10-virtual-mcp-architecture.md; today's Modern contract is pinned +// by TestIntegration_Modern_RealBackend_LoggingContract, and the Modern log +// opt-in + relay is exercised by TestModernCallTool_LogLevelGating. func TestForwarding_Logging_RealBackend(t *testing.T) { t.Parallel() ctx, cancel := context.WithTimeout(t.Context(), forwardingRealBackendTimeout) diff --git a/pkg/vmcp/server/modern_realbackend_integration_test.go b/pkg/vmcp/server/modern_realbackend_integration_test.go index 5b60103a68..6c6ef2e5ae 100644 --- a/pkg/vmcp/server/modern_realbackend_integration_test.go +++ b/pkg/vmcp/server/modern_realbackend_integration_test.go @@ -402,16 +402,20 @@ func TestIntegration_Modern_RealBackend_ProgressDropped(t *testing.T) { // - A WELL-FORMED Modern logging/setLevel is an unknown method to // dispatchModern: 404 + -32601, matching go-sdk's own server ("method // removed in the new protocol"). -// - The request go-sdk v1.7.0-pre.3 ACTUALLY sends is malformed — its -// SetLoggingLevel omits the per-request _meta injection (upstream bug), -// producing a Modern header with no _meta protocolVersion — and vMCP's -// classifier CORRECTLY rejects that shape with 400 + -32020 -// (HeaderMismatch). Loosening this to accept the malformed request would -// be worse than the failing upstream call. +// - The request go-sdk v1.7.x ACTUALLY sends is malformed — its +// SetLoggingLevel omits the per-request _meta injection, producing a Modern +// header with no _meta protocolVersion — and vMCP's classifier CORRECTLY +// rejects that shape with 400 + -32020 (HeaderMismatch). Loosening this to +// accept the malformed request would be worse than the failing upstream +// call. This malformed shape is a permanent go-sdk v1.7.x fixture: +// modelcontextprotocol/go-sdk#1116 was closed wont-fix-by-design (the RPC +// is removed on Modern), so -32020 is the standing contract for any caller +// still using the removed RPC on a Modern session, not a temporary bug +// guard. // // See TestForwarding_Logging_RealBackend's pin comment for the full -// three-cause disposition (upstream bug, method removal/streaming gap, -// SEP-2577 deprecation). +// three-cause disposition (go-sdk's wont-fix SetLoggingLevel, method +// removal/streaming gap, SEP-2577 deprecation). func TestIntegration_Modern_RealBackend_LoggingContract(t *testing.T) { t.Parallel()