|
| 1 | +import type { FetchLike } from '@modelcontextprotocol/sdk/shared/transport.js' |
| 2 | +import { createLogger } from '@sim/logger' |
| 3 | +import { sanitizeForLogging } from '@/lib/core/security/redaction' |
| 4 | +import { getMcpSafeErrorDiagnostics } from '@/lib/mcp/error-diagnostics' |
| 5 | + |
| 6 | +const logger = createLogger('McpHttpDiag') |
| 7 | + |
| 8 | +const MAX_LOGGED_CHUNKS = 40 |
| 9 | +const PREVIEW_CHARS = 500 |
| 10 | + |
| 11 | +/** |
| 12 | + * TEMPORARY diagnostic for the MCP OAuth + streamable-HTTP transport HTTP layer. |
| 13 | + * Enabled by default; set `MCP_HTTP_DIAGNOSTICS=false` to silence. Remove once the |
| 14 | + * Gauge `initialize` hang is root-caused. |
| 15 | + * |
| 16 | + * Safety: request bodies and the OAuth token-response body carry the authorization |
| 17 | + * code / access / refresh tokens, so they are NEVER logged. Only the *transport* |
| 18 | + * response body — MCP JSON-RPC protocol messages, which contain no credentials — is |
| 19 | + * streamed and logged, and every logged value passes through `sanitizeForLogging`. |
| 20 | + */ |
| 21 | +function diagnosticsEnabled(): boolean { |
| 22 | + if (process.env.NODE_ENV === 'test' || process.env.VITEST) return false |
| 23 | + return process.env.MCP_HTTP_DIAGNOSTICS !== 'false' |
| 24 | +} |
| 25 | + |
| 26 | +function requestUrl(input: string | URL | Request): string { |
| 27 | + if (typeof input === 'string') return input |
| 28 | + if (input instanceof URL) return input.href |
| 29 | + return input.url |
| 30 | +} |
| 31 | + |
| 32 | +/** |
| 33 | + * Wraps a `FetchLike` so every request/response in the MCP OAuth or transport flow is |
| 34 | + * logged with timing. `phase` distinguishes the two so the transport `initialize` — the |
| 35 | + * suspected hang — can be traced chunk-by-chunk while OAuth bodies stay unlogged. |
| 36 | + */ |
| 37 | +export function withMcpHttpDiagnostics( |
| 38 | + fetchFn: FetchLike, |
| 39 | + phase: 'oauth' | 'transport' |
| 40 | +): FetchLike { |
| 41 | + if (!diagnosticsEnabled()) return fetchFn |
| 42 | + |
| 43 | + return async (input, init) => { |
| 44 | + const url = requestUrl(input as string | URL | Request) |
| 45 | + const method = init?.method ?? 'GET' |
| 46 | + const reqHeaders = new Headers((init?.headers as HeadersInit | undefined) ?? undefined) |
| 47 | + const startedAt = Date.now() |
| 48 | + |
| 49 | + logger.info('request', { |
| 50 | + phase, |
| 51 | + method, |
| 52 | + url, |
| 53 | + hasAuth: reqHeaders.has('authorization'), |
| 54 | + accept: reqHeaders.get('accept') ?? undefined, |
| 55 | + }) |
| 56 | + |
| 57 | + let res: Response |
| 58 | + try { |
| 59 | + res = (await fetchFn(input, init)) as Response |
| 60 | + } catch (error) { |
| 61 | + logger.warn('fetch rejected', { |
| 62 | + phase, |
| 63 | + method, |
| 64 | + url, |
| 65 | + ms: Date.now() - startedAt, |
| 66 | + error: getMcpSafeErrorDiagnostics(error), |
| 67 | + }) |
| 68 | + throw error |
| 69 | + } |
| 70 | + |
| 71 | + const contentType = res.headers.get('content-type') ?? '' |
| 72 | + const safeHeaders: Record<string, string> = {} |
| 73 | + for (const [name, value] of res.headers.entries()) { |
| 74 | + const lower = name.toLowerCase() |
| 75 | + safeHeaders[name] = |
| 76 | + lower === 'set-cookie' || lower === 'authorization' || lower === 'www-authenticate' |
| 77 | + ? '<omitted>' |
| 78 | + : sanitizeForLogging(value, 200) |
| 79 | + } |
| 80 | + |
| 81 | + logger.info('response', { |
| 82 | + phase, |
| 83 | + method, |
| 84 | + url, |
| 85 | + status: res.status, |
| 86 | + contentType, |
| 87 | + mcpSessionId: res.headers.get('mcp-session-id') ? 'present' : 'absent', |
| 88 | + headerMs: Date.now() - startedAt, |
| 89 | + headers: safeHeaders, |
| 90 | + }) |
| 91 | + |
| 92 | + // Only the transport body is safe to log (MCP protocol JSON, no credentials). |
| 93 | + if (phase !== 'transport' || !res.body) return res |
| 94 | + |
| 95 | + let logBranch: ReadableStream<Uint8Array> |
| 96 | + let passBranch: ReadableStream<Uint8Array> |
| 97 | + try { |
| 98 | + ;[logBranch, passBranch] = res.body.tee() |
| 99 | + } catch { |
| 100 | + return res |
| 101 | + } |
| 102 | + |
| 103 | + void (async () => { |
| 104 | + const reader = logBranch.getReader() |
| 105 | + const decoder = new TextDecoder() |
| 106 | + let chunks = 0 |
| 107 | + let bytes = 0 |
| 108 | + try { |
| 109 | + for (;;) { |
| 110 | + const { done, value } = await reader.read() |
| 111 | + if (done) { |
| 112 | + logger.info('transport body complete', { |
| 113 | + phase, |
| 114 | + url, |
| 115 | + chunks, |
| 116 | + bytes, |
| 117 | + ms: Date.now() - startedAt, |
| 118 | + }) |
| 119 | + break |
| 120 | + } |
| 121 | + chunks += 1 |
| 122 | + bytes += value.byteLength |
| 123 | + if (chunks <= MAX_LOGGED_CHUNKS) { |
| 124 | + logger.info('transport body chunk', { |
| 125 | + phase, |
| 126 | + url, |
| 127 | + chunk: chunks, |
| 128 | + size: value.byteLength, |
| 129 | + ms: Date.now() - startedAt, |
| 130 | + preview: sanitizeForLogging(decoder.decode(value, { stream: true }), PREVIEW_CHARS), |
| 131 | + }) |
| 132 | + } |
| 133 | + } |
| 134 | + } catch (error) { |
| 135 | + logger.warn('transport body read error', { |
| 136 | + phase, |
| 137 | + url, |
| 138 | + chunks, |
| 139 | + bytes, |
| 140 | + ms: Date.now() - startedAt, |
| 141 | + error: getMcpSafeErrorDiagnostics(error), |
| 142 | + }) |
| 143 | + } |
| 144 | + })() |
| 145 | + |
| 146 | + return new Response(passBranch, { |
| 147 | + status: res.status, |
| 148 | + statusText: res.statusText, |
| 149 | + headers: res.headers, |
| 150 | + }) |
| 151 | + } |
| 152 | +} |
0 commit comments