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()