Open
Description
Describe the bug
After a successful initialize request using StreamableHTTPServerTransport with session management (via Express.js), subsequent tool/call requests on the established session consistently result in a JSON-RPC error {"code": -32601, "message": "Method not found"}. This occurs even for extremely simple, synchronous tools. The initialize request itself is handled correctly, a session ID is generated and returned in the mcp-session-id header, and server logs confirm this session ID is correctly identified and the associated transport is reused for the tool/call request.
Environment:
@modelcontextprotocol/sdk version: 1.12.0
Node.js version: v20.2.0 (Please confirm if this is still accurate for the user, it was seen in earlier logs)
Express.js version: (Please provide your Express version, e.g., 4.17.1 or similar)
OS: Windows (win32 10.0.26100)
To Reproduce
Steps to reproduce the behavior:
- Set up an Express.js server with an MCP request handler using McpServer and StreamableHTTPServerTransport for stateful sessions, as shown in the relevant code snippets below.
- Client sends an initialize request to the MCP endpoint.
- Request Body:
"jsonrpc": "2.0",
"method": "initialize",
"params": {
"protocolVersion": "2024-11-05",
"capabilities": {
"interactive": true
},
"clientInfo": {
"name": "TestClient",
"version": "1.0.0"
}
},
"id": 1
}
- Required Headers: Content-Type: application/json, Accept: application/json, text/event-stream (plus any custom auth headers your setup uses).
- Server responds successfully to the initialize request (e.g., HTTP 200 OK) and includes an mcp-session-id in the response headers. The response body is the standard MCP initialize success response.
- Client sends a tool/call request to the same MCP endpoint for a registered tool (e.g., the simple echo_tool shown below).
- Request Body:
"jsonrpc": "2.0",
"method": "tool/call",
"params": {
"name": "echo_tool",
"arguments": {
"message": "Hello MCP world!"
}
},
"id": 2
}
- Required Headers: Content-Type: application/json, Accept: application/json, text/event-stream, and importantly, the mcp-session-id header with the value received from the initialize response (plus any custom auth headers).
- Server responds with the error:
"jsonrpc": "2.0",
"id": 2,
"error": {
"code": -32601,
"message": "Method not found"
}
}
Expected behavior
The tool/call request in step 4 should successfully invoke the registered echo_tool (or any other registered tool), and the server should return the tool's result as per MCP specification. For echo_tool, it would be something like:
"jsonrpc": "2.0",
"id": 2,
"result": {
"content": [
{
"type": "text",
"text": "Echo: Hello MCP world!"
}
]
}
}
Relevant Code Snippets:
import { McpServer } from '@modelcontextprotocol/sdk/server/mcp';
import { StreamableHTTPServerTransport } from '@modelcontextprotocol/sdk/server/streamableHttp';
import { isInitializeRequest } from '@modelcontextprotocol/sdk/types'; // Ensure this is the correct import path
import { z } from 'zod';
import { Request, Response } from 'express';
import { randomUUID } from 'node:crypto';
import { createLogger, /* ... other winston imports ... */ } from 'winston';
// Logger setup (as per user's code)
const mcpServerLogger = createLogger({ /* ... */ });
interface McpUserContext { userId: string; }
const transports: Record<string, StreamableHTTPServerTransport> = {};
export function createMcpRequestHandler(supabase: any /* SupabaseClient */) {
async function handleMcpRequest(req: Request, res: Response) {
// Auth middleware sets (req as any).user
const user = (req as any).user;
if (!user || !user.id) { /* ... error ... */ return; }
const mcpContext: McpUserContext = { userId: user.id };
const sessionId = req.headers['mcp-session-id'] as string | undefined;
let transport: StreamableHTTPServerTransport | undefined = undefined;
const parsedBody = req.body;
mcpServerLogger.info({ message: 'MCP handleMcpRequest ...', parsedBody });
const sdkCheckIsInit = isInitializeRequest(parsedBody);
mcpServerLogger.info({ message: 'MCP isInitializeRequest result', sdkCheckIsInit });
if (req.method === 'POST' && !sessionId && sdkCheckIsInit) {
mcpServerLogger.info({ message: 'Processing as new initialization request...', mcpContext });
const newTransport = new StreamableHTTPServerTransport({
sessionIdGenerator: () => {
const newId = randomUUID();
mcpServerLogger.info({ message: 'sessionIdGenerator called', generatedId: newId });
return newId;
},
onsessioninitialized: (newSessionId: string) => {
mcpServerLogger.info({ message: 'onsessioninitialized CALLED', newSessionId });
transports[newSessionId] = newTransport;
mcpServerLogger.info(`MCP Session TRULY initialized. Transport session ID: ${newTransport.sessionId}`);
}
});
newTransport.onerror = (error: Error) => { /* ... logging ... */ };
newTransport.onclose = () => { /* ... logging & cleanup ... */ };
const server = new McpServer({
name: "ArgentumMcpServer", // Or your server name
version: "1.0.0",
context: mcpContext,
});
server.tool( // Simple echo tool for testing
"echo_tool",
{ message: z.string() },
async (params) => {
mcpServerLogger.info({ message: `MCP: echo_tool called`, params });
return { content: [{ type: "text", text: `Echo: ${params.message}` }] };
}
);
// ... (other tool registrations like create_agent can also be mentioned if relevant)
await server.connect(newTransport);
mcpServerLogger.info("MCP Server connected to new transport.", { transportSessionId: newTransport.sessionId });
transport = newTransport;
} else if (sessionId && transports[sessionId]) {
mcpServerLogger.info({ message: "Reusing existing transport for session.", sessionId });
transport = transports[sessionId];
mcpServerLogger.info({
message: "Retrieved transport for subsequent request.",
retrievedTransportSessionId: transport.sessionId,
isTransportDefined: !!transport
});
} else if (sessionId && !transports[sessionId]) {
mcpServerLogger.warn({ message: "Invalid or expired session ID.", sessionId });
return res.status(400).json({ /* ... error ... */ });
} else if (!sdkCheckIsInit) {
mcpServerLogger.warn({ message: "MCP: Invalid request state - not an init request and no valid session ID provided.", sessionId });
return res.status(400).json({ /* ... error ... */ });
} else {
mcpServerLogger.error('MCP: Unhandled request state.', { sessionId });
return res.status(500).json({/* ... error ... */});
}
if (!transport) {
mcpServerLogger.error('MCP: Transport could not be determined or initialized.');
return res.status(500).json({ /* ... error ... */ });
}
mcpServerLogger.info({ message: 'MCP: About to call transport.handleRequest', transportSessionId: transport.sessionId });
try {
await transport.handleRequest(req, res, parsedBody);
mcpServerLogger.info({ message: 'MCP: transport.handleRequest completed.', transportSessionId: transport.sessionId });
} catch (handleRequestError: any) {
mcpServerLogger.error({ message: 'MCP: Error in transport.handleRequest', /* ... details ... */ });
if (!res.headersSent) { /* ... error ... */ }
}
}
return handleMcpRequest;
}
Logs:
1. Successful initialize Request logs:
Incoming request: {
method: 'POST',
path: '/mcpapi/v1',
origin: undefined,
mcpSessionId: undefined,
mcpUserAssertion: 'Present',
mcpClaimedUserId: 'c78aa5ec-f1e0-42ef-8fc3-12d4852596e8',
headers: {
'content-type': 'application/json',
'x-argentum-user-id': 'c78aa5ec-f1e0-42ef-8fc3-12d4852596e8',
'x-user-assertion-token': 'eyJ1c2VySWQiOiJjNzhhYTVlYy1mMWUwLTQyZWYtOGZjMy0xMmQ0ODUyNTk2ZTgiLCJleHAiOjE3NDgzMDg1MzUzNjN9.72171804150cc9fde2595c0502c5dd33c1559183a43eec070c0c4fa01203d156',
accept: 'application/json, text/event-stream',
'user-agent': 'PostmanRuntime/7.44.0',
'postman-token': '3ca17b66-baad-4d97-9906-232f25282208',
host: 'localhost:3001',
'accept-encoding': 'gzip, deflate, br',
connection: 'keep-alive',
'content-length': '270'
}
}
[MCP Route Debug] Request to /mcpapi/v1. Content-Type: application/json
[MCP Route Debug] req.body BEFORE mcpAuthMiddleware: {
"jsonrpc": "2.0",
"method": "initialize",
"params": {
"protocolVersion": "2024-11-05",
"capabilities": {
"interactive": true
},
"clientInfo": {
"name": "PostmanTestClient",
"version": "1.0.0"
}
},
"id": 1
}
{"body_id":1,"body_jsonrpc":"2.0","body_method":"initialize","level":"info","message":"MCP handleMcpRequest using req.body. Checking its properties.","parsedBody":{"id":1,"jsonrpc":"2.0","method":"initialize","params":{"capabilities":{"interactive":true},"clientInfo":{"name":"PostmanTestClient","version":"1.0.0"},"protocolVersion":"2024-11-05"}},"timestamp":"2025-05-27T00:35:40.948Z","type_body":"object","type_id":"number","type_jsonrpc":"string","type_method":"string"}
{"level":"info","message":"MCP isInitializeRequest (imported) official check result","sdkCheckIsInit":true,"timestamp":"2025-05-27T00:35:40.949Z"}
{"level":"info","mcpContext":{"userId":"c78aa5ec-f1e0-42ef-8fc3-12d4852596e8"},"message":"Processing as new initialization request (based on SDK check).","timestamp":"2025-05-27T00:35:40.949Z"}
{"level":"info","message":"MCP Server connected to new transport. Transport's session ID AFTER connect:","timestamp":"2025-05-27T00:35:40.950Z"}
{"acceptHeaderForTransport":"application/json, text/event-stream","level":"info","message":"MCP: About to call transport.handleRequest","parsedBodyForHandleRequest":{"id":1,"jsonrpc":"2.0","method":"initialize","params":{"capabilities":{"interactive":true},"clientInfo":{"name":"PostmanTestClient","version":"1.0.0"},"protocolVersion":"2024-11-05"}},"timestamp":"2025-05-27T00:35:40.951Z"}
{"generatedId":"27f70b07-b5b2-4b8b-aded-b9a27921cb36","level":"info","message":"StreamableHTTPServerTransport: sessionIdGenerator called","timestamp":"2025-05-27T00:35:40.952Z"}
{"level":"info","message":"StreamableHTTPServerTransport: onsessioninitialized CALLED","newSessionId":"27f70b07-b5b2-4b8b-aded-b9a27921cb36","timestamp":"2025-05-27T00:35:40.952Z"}
{"level":"info","message":"MCP Session TRULY initialized in callback: 27f70b07-b5b2-4b8b-aded-b9a27921cb36. Transport current session ID: 27f70b07-b5b2-4b8b-aded-b9a27921cb36","timestamp":"2025-05-27T00:35:40.952Z"}
{"level":"info","message":"MCP: transport.handleRequest completed.","timestamp":"2025-05-27T00:35:40.954Z","transportSessionId":"27f70b07-b5b2-4b8b-aded-b9a27921cb36"}
2. Failing tool/call Request Logs (for echo_tool):
Incoming request: {
method: 'POST',
path: '/mcpapi/v1',
origin: undefined,
mcpSessionId: '<session_id_1>',
mcpUserAssertion: 'Present',
mcpClaimedUserId: '<user_identifier>',
headers: {
'content-type': 'application/json',
'x-argentum-user-id': '<user_identifier>',
'x-user-assertion-token': '<assertion_token_placeholder>',
accept: 'application/json, text/event-stream',
'mcp-session-id': '<session_id_1>',
'user-agent': 'PostmanRuntime/7.44.0',
'postman-token': '<postman_token_placeholder>',
host: 'localhost:3001',
'accept-encoding': 'gzip, deflate, br',
connection: 'keep-alive',
'content-length': '201'
}
}
[MCP Route Debug] Request to /mcpapi/v1. Content-Type: application/json
[MCP Route Debug] req.body BEFORE mcpAuthMiddleware: {
"jsonrpc": "2.0",
"method": "tool/call",
"params": {
"name": "echo_tool",
"arguments": {
"message": "Hello MCP world!"
}
},
"id": 3
}
{"body_id":3,"body_jsonrpc":"2.0","body_method":"tool/call","level":"info","message":"MCP handleMcpRequest using req.body. Checking its properties.","parsedBody":{"id":3,"jsonrpc":"2.0","method":"tool/call","params":{"arguments":{"message":"Hello MCP world!"},"name":"echo_tool"}},"timestamp":"2025-05-27T00:44:05.854Z","type_body":"object","type_id":"number","type_jsonrpc":"string","type_method":"string"}
{"level":"info","message":"MCP isInitializeRequest (imported) official check result","sdkCheckIsInit":false,"timestamp":"2025-05-27T00:44:05.854Z"}
{"level":"info","message":"Reusing existing transport for session.","sessionId":"<session_id_1>","timestamp":"2025-05-27T00:44:05.854Z"}
{"isTransportDefined":true,"level":"info","message":"Retrieved transport for subsequent request.","retrievedTransportSessionId":"<session_id_1>","timestamp":"2025-05-27T00:44:05.854Z"}
{"acceptHeaderForTransport":"application/json, text/event-stream","level":"info","message":"MCP: About to call transport.handleRequest","parsedBodyForHandleRequest":{"id":3,"jsonrpc":"2.0","method":"tool/call","params":{"arguments":{"message":"Hello MCP world!"},"name":"echo_tool"}},"timestamp":"2025-05-27T00:44:05.854Z","transportSessionId":"<session_id_1>"}
{"level":"info","message":"MCP: transport.handleRequest completed.","timestamp":"2025-05-27T00:44:05.855Z","transportSessionId":"<session_id_1>"}
Additional context:
The issue seems to be specific to how tool/call (or perhaps any method other than initialize) is handled by the McpServer / StreamableHTTPServerTransport combination on a pre-existing, stateful session.
The session ID is correctly passed and identified by the server for the tool/call request.
The correct StreamableHTTPServerTransport instance is retrieved from the server's internal map for handling the tool/call request.
The problem persists even with the simplest possible tool definition and synchronous handler.
Custom authentication is in use (forwarding JWT assertion), but this seems to pass correctly, and the MCP request handler is entered with user context. The "Method not found" error occurs after auth and after identifying the correct MCP session/transport
Metadata
Metadata
Assignees
Labels
Type
Projects
Status
To triage