-
Notifications
You must be signed in to change notification settings - Fork 3.7k
diag(mcp): comprehensive HTTP logging for OAuth + streamable-HTTP transport #5782
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Merged
+188
−2
Merged
Changes from all commits
Commits
Show all changes
5 commits
Select commit
Hold shift + click to select a range
d110c2e
diag(mcp): comprehensive HTTP logging for OAuth + streamable-HTTP tra…
waleedlatif1 ed55598
diag(mcp): scope body logging to initialize + redact URLs + wrap unpi…
waleedlatif1 b5edb9e
diag(mcp): sanitize initialize preview + log at warn for visibility
waleedlatif1 d8467f4
diag(mcp): reuse sanitizeUrlForLog + cancel log reader on abort
waleedlatif1 443e023
diag(mcp): length-gate initialize check to skip parsing large tool pa…
waleedlatif1 File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Some comments aren't visible on the classic Files Changed page.
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,176 @@ | ||
| import type { FetchLike } from '@modelcontextprotocol/sdk/shared/transport.js' | ||
| import { createLogger } from '@sim/logger' | ||
| import { sanitizeForLogging } from '@/lib/core/security/redaction' | ||
| import { sanitizeUrlForLog } from '@/lib/core/utils/logging' | ||
| import { getMcpSafeErrorDiagnostics } from '@/lib/mcp/error-diagnostics' | ||
|
|
||
| const logger = createLogger('McpHttpDiag') | ||
|
|
||
| const MAX_LOGGED_CHUNKS = 40 | ||
| const PREVIEW_CHARS = 500 | ||
|
|
||
| /** | ||
| * TEMPORARY diagnostic for the MCP OAuth + streamable-HTTP transport HTTP layer. | ||
| * Enabled by default; set `MCP_HTTP_DIAGNOSTICS=false` to silence. Remove once the | ||
| * Gauge `initialize` hang is root-caused. | ||
| * | ||
| * Secret-safety (the wrapped transport fetch also carries in-transport OAuth | ||
| * refresh/registration, and every tool result): | ||
| * - Request and OAuth response bodies are NEVER logged. | ||
| * - The only response body streamed is the one whose REQUEST is an MCP `initialize` | ||
| * JSON-RPC call — which excludes token/refresh responses AND `tools/call` results | ||
| * (tool output can be PII/file contents/credentials). The `initialize` result is | ||
| * protocol metadata only (serverInfo, capabilities), no credentials. | ||
| * - URLs are logged origin+path only; query strings (`?code=`, `?token=`, …) are | ||
| * redacted. Sensitive headers (authorization/cookie/www-authenticate) are omitted. | ||
| */ | ||
| function diagnosticsEnabled(): boolean { | ||
| if (process.env.NODE_ENV === 'test' || process.env.VITEST) return false | ||
| return process.env.MCP_HTTP_DIAGNOSTICS !== 'false' | ||
| } | ||
|
|
||
| function rawUrl(input: string | URL | Request): string { | ||
| return typeof input === 'string' ? input : input instanceof URL ? input.href : input.url | ||
| } | ||
|
|
||
| /** | ||
| * The `initialize` request is a small fixed structure (protocolVersion, capabilities, | ||
| * clientInfo). This length gate lets us skip parsing large `tools/call` payloads — | ||
| * which can be multi-MB — entirely, keeping the check off the hot path. | ||
| */ | ||
| const MAX_INIT_BODY_CHARS = 4096 | ||
|
|
||
| /** | ||
| * True only when the request body is an MCP `initialize` JSON-RPC message. Used to | ||
| * scope response-body logging to the initialize handshake and nothing else — token | ||
| * requests (form-encoded) and tool calls (`method: 'tools/call'`) both fail this. | ||
| * Large bodies are rejected by length before any parse (see {@link MAX_INIT_BODY_CHARS}). | ||
| */ | ||
| function isInitializeRequest(body: unknown): boolean { | ||
| if (typeof body !== 'string' || body.length > MAX_INIT_BODY_CHARS) return false | ||
| try { | ||
| return (JSON.parse(body) as { method?: unknown })?.method === 'initialize' | ||
| } catch { | ||
| return false | ||
| } | ||
| } | ||
|
|
||
| /** | ||
| * Wraps a `FetchLike` so every request/response in the MCP OAuth or transport flow is | ||
| * logged with timing. Only the `initialize` response body is streamed (see secret-safety | ||
| * note above) — that's the suspected hang. | ||
| */ | ||
| export function withMcpHttpDiagnostics( | ||
| fetchFn: FetchLike, | ||
| phase: 'oauth' | 'transport' | ||
| ): FetchLike { | ||
| if (!diagnosticsEnabled()) return fetchFn | ||
|
|
||
| return async (input, init) => { | ||
| const url = sanitizeUrlForLog(rawUrl(input as string | URL | Request)) | ||
| const method = init?.method ?? 'GET' | ||
| const reqHeaders = new Headers((init?.headers as HeadersInit | undefined) ?? undefined) | ||
| const startedAt = Date.now() | ||
|
|
||
| logger.warn('request', { | ||
| phase, | ||
| method, | ||
| url, | ||
|
waleedlatif1 marked this conversation as resolved.
|
||
| hasAuth: reqHeaders.has('authorization'), | ||
| accept: reqHeaders.get('accept') ?? undefined, | ||
| }) | ||
|
|
||
| let res: Response | ||
| try { | ||
| res = (await fetchFn(input, init)) as Response | ||
| } catch (error) { | ||
| logger.warn('fetch rejected', { | ||
| phase, | ||
| method, | ||
| url, | ||
| ms: Date.now() - startedAt, | ||
| error: getMcpSafeErrorDiagnostics(error), | ||
| }) | ||
| throw error | ||
| } | ||
|
|
||
| logger.warn('response', { | ||
| phase, | ||
| method, | ||
| url, | ||
| status: res.status, | ||
| contentType: res.headers.get('content-type') ?? '', | ||
| mcpSessionId: res.headers.get('mcp-session-id') ? 'present' : 'absent', | ||
| headerMs: Date.now() - startedAt, | ||
| }) | ||
|
waleedlatif1 marked this conversation as resolved.
|
||
|
|
||
| // Stream-log ONLY the initialize handshake response — never OAuth bodies or tool results. | ||
| if (phase !== 'transport' || !isInitializeRequest(init?.body) || !res.body) return res | ||
|
waleedlatif1 marked this conversation as resolved.
|
||
|
|
||
| let logBranch: ReadableStream<Uint8Array> | ||
| let passBranch: ReadableStream<Uint8Array> | ||
| try { | ||
| ;[logBranch, passBranch] = res.body.tee() | ||
| } catch { | ||
| return res | ||
| } | ||
|
|
||
| // Cancel the detached log reader when the caller aborts (e.g. the SDK's 30s | ||
| // initialize timeout — exactly the hang we're tracing) so this tee branch can't | ||
| // keep the response stream / connection alive after the SDK has given up. | ||
| const signal = init?.signal | ||
| void (async () => { | ||
| const reader = logBranch.getReader() | ||
| const cancelReader = () => void reader.cancel().catch(() => {}) | ||
| if (signal?.aborted) { | ||
| cancelReader() | ||
| return | ||
| } | ||
| signal?.addEventListener('abort', cancelReader, { once: true }) | ||
| const decoder = new TextDecoder() | ||
| let chunks = 0 | ||
| let bytes = 0 | ||
| try { | ||
| for (;;) { | ||
| const { done, value } = await reader.read() | ||
| if (done) { | ||
| logger.warn('initialize body complete', { | ||
| url, | ||
| chunks, | ||
| bytes, | ||
| ms: Date.now() - startedAt, | ||
| }) | ||
| break | ||
| } | ||
| chunks += 1 | ||
| bytes += value.byteLength | ||
| if (chunks <= MAX_LOGGED_CHUNKS) { | ||
| logger.warn('initialize body chunk', { | ||
| url, | ||
| chunk: chunks, | ||
| size: value.byteLength, | ||
| ms: Date.now() - startedAt, | ||
| preview: sanitizeForLogging(decoder.decode(value, { stream: true }), PREVIEW_CHARS), | ||
| }) | ||
|
waleedlatif1 marked this conversation as resolved.
|
||
| } | ||
| } | ||
| } catch (error) { | ||
| logger.warn('initialize body read error', { | ||
| url, | ||
| chunks, | ||
| bytes, | ||
| ms: Date.now() - startedAt, | ||
| error: getMcpSafeErrorDiagnostics(error), | ||
| }) | ||
| } finally { | ||
| signal?.removeEventListener('abort', cancelReader) | ||
| } | ||
| })() | ||
|
waleedlatif1 marked this conversation as resolved.
|
||
|
|
||
| return new Response(passBranch, { | ||
| status: res.status, | ||
| statusText: res.statusText, | ||
| headers: res.headers, | ||
| }) | ||
|
waleedlatif1 marked this conversation as resolved.
waleedlatif1 marked this conversation as resolved.
|
||
| } | ||
| } | ||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Uh oh!
There was an error while loading. Please reload this page.