From 37f5fe3d8d3095e94500c18b991ead5670b6ec6a Mon Sep 17 00:00:00 2001 From: alban bertolini Date: Wed, 11 Feb 2026 09:34:29 +0100 Subject: [PATCH] fix(mcp-server): log response body on HTTP 500 errors When the MCP SDK writes a 500 response directly (plain JSON, not SSE), the error details were lost because the existing interceptor only parsed SSE-format data. This adds chunk collection and HTTP 500+ body logging so error messages are visible in the logs. Co-Authored-By: Claude Opus 4.6 --- .../mcp-server/src/utils/sse-error-logger.ts | 42 ++++- .../test/utils/sse-error-logger.test.ts | 167 ++++++++++++++++++ 2 files changed, 208 insertions(+), 1 deletion(-) create mode 100644 packages/mcp-server/test/utils/sse-error-logger.test.ts diff --git a/packages/mcp-server/src/utils/sse-error-logger.ts b/packages/mcp-server/src/utils/sse-error-logger.ts index 34649d6b2..185460286 100644 --- a/packages/mcp-server/src/utils/sse-error-logger.ts +++ b/packages/mcp-server/src/utils/sse-error-logger.ts @@ -126,9 +126,29 @@ function logChunkErrors( * This function modifies res.write() and res.end() to add logging without * affecting the actual response sent to the client. */ +/** + * Logs the collected response body when the HTTP status code indicates a server error. + * This catches cases where the MCP SDK writes a 500 response directly (e.g. plain JSON) + * without going through the SSE error format. + */ +function logHttpErrorBody(chunks: string[], res: Response, logger: Logger): void { + if (res.statusCode < 500) { + return; + } + + const body = chunks.join(''); + + if (!body) { + return; + } + + logger('Error', `HTTP ${res.statusCode} response body: ${body}`); +} + export default function interceptResponseForErrorLogging(res: Response, logger: Logger): void { const originalWrite = res.write.bind(res); const originalEnd = res.end.bind(res); + const chunks: string[] = []; // Intercept streaming chunks (res.write) res.write = function interceptedWrite( @@ -138,6 +158,12 @@ export default function interceptResponseForErrorLogging(res: Response, logger: ): boolean { logChunkErrors(chunk, logger); + try { + chunks.push(chunkToString(chunk)); + } catch { + // Never affect the response + } + return originalWrite(chunk, encodingOrCallback as BufferEncoding, callback); } as typeof res.write; @@ -149,8 +175,22 @@ export default function interceptResponseForErrorLogging(res: Response, logger: ): typeof res { if (chunk && typeof chunk !== 'function') { logChunkErrors(chunk as Buffer | string | Uint8Array, logger); + + try { + chunks.push(chunkToString(chunk as Buffer | string | Uint8Array)); + } catch { + // Never affect the response + } + } + + const result = originalEnd(chunk, encodingOrCallback as BufferEncoding, callback); + + try { + logHttpErrorBody(chunks, res, logger); + } catch { + // Never affect the response } - return originalEnd(chunk, encodingOrCallback as BufferEncoding, callback); + return result; } as typeof res.end; } diff --git a/packages/mcp-server/test/utils/sse-error-logger.test.ts b/packages/mcp-server/test/utils/sse-error-logger.test.ts new file mode 100644 index 000000000..59d2aa4b9 --- /dev/null +++ b/packages/mcp-server/test/utils/sse-error-logger.test.ts @@ -0,0 +1,167 @@ +import type { Response } from 'express'; + +import interceptResponseForErrorLogging from '../../src/utils/sse-error-logger'; + +function createMockResponse(): Response { + const res = { + statusCode: 200, + write: jest.fn().mockReturnValue(true), + end: jest.fn().mockReturnThis(), + } as unknown as Response; + + return res; +} + +describe('interceptResponseForErrorLogging', () => { + let logger: jest.Mock; + let res: Response; + + beforeEach(() => { + logger = jest.fn(); + res = createMockResponse(); + }); + + describe('SSE error logging (existing behavior)', () => { + it('should log JSON-RPC errors from SSE data in write chunks', () => { + interceptResponseForErrorLogging(res, logger); + + res.write('event: message\ndata: {"error":{"message":"Method not found"}}\n\n'); + + expect(logger).toHaveBeenCalledWith('Error', 'Method not found'); + }); + + it('should log tool errors from SSE data in write chunks', () => { + interceptResponseForErrorLogging(res, logger); + + res.write( + 'event: message\ndata: {"result":{"isError":true,"content":[{"text":"tool failed"}]}}\n\n', + ); + + expect(logger).toHaveBeenCalledWith('Error', 'Tool error: tool failed'); + }); + + it('should log JSON-RPC errors from the final chunk in end', () => { + interceptResponseForErrorLogging(res, logger); + + res.end('event: message\ndata: {"error":{"message":"Internal error"}}\n\n'); + + expect(logger).toHaveBeenCalledWith('Error', 'Internal error'); + }); + + it('should not log for non-error SSE messages', () => { + interceptResponseForErrorLogging(res, logger); + + res.write('event: message\ndata: {"result":{"content":[{"text":"ok"}]}}\n\n'); + + expect(logger).not.toHaveBeenCalled(); + }); + + it('should handle Buffer chunks', () => { + interceptResponseForErrorLogging(res, logger); + + res.write(Buffer.from('event: message\ndata: {"error":{"message":"buf error"}}\n\n')); + + expect(logger).toHaveBeenCalledWith('Error', 'buf error'); + }); + }); + + describe('HTTP 500 body logging', () => { + it('should log the response body when status is 500', () => { + interceptResponseForErrorLogging(res, logger); + + res.statusCode = 500; + res.end('{"error":"Internal Server Error"}'); + + expect(logger).toHaveBeenCalledWith( + 'Error', + 'HTTP 500 response body: {"error":"Internal Server Error"}', + ); + }); + + it('should log the response body when status is 502', () => { + interceptResponseForErrorLogging(res, logger); + + res.statusCode = 502; + res.end('Bad Gateway'); + + expect(logger).toHaveBeenCalledWith('Error', 'HTTP 502 response body: Bad Gateway'); + }); + + it('should collect chunks from write and end into the full body', () => { + interceptResponseForErrorLogging(res, logger); + + res.write('{"error":'); + res.statusCode = 500; + res.end('"server error"}'); + + expect(logger).toHaveBeenCalledWith( + 'Error', + 'HTTP 500 response body: {"error":"server error"}', + ); + }); + + it('should not log body for 200 responses', () => { + interceptResponseForErrorLogging(res, logger); + + res.end('{"result":"ok"}'); + + expect(logger).not.toHaveBeenCalled(); + }); + + it('should not log body for 404 responses', () => { + interceptResponseForErrorLogging(res, logger); + + res.statusCode = 404; + res.end('Not Found'); + + expect(logger).not.toHaveBeenCalled(); + }); + + it('should not log when 500 response has no body', () => { + interceptResponseForErrorLogging(res, logger); + + res.statusCode = 500; + res.end(); + + expect(logger).not.toHaveBeenCalled(); + }); + + it('should handle end called with a callback function only', () => { + interceptResponseForErrorLogging(res, logger); + + res.statusCode = 500; + const callback = jest.fn(); + res.end(callback); + + expect(logger).not.toHaveBeenCalled(); + }); + }); + + describe('passthrough behavior', () => { + it('should call original write with the same arguments', () => { + const originalWrite = res.write; + interceptResponseForErrorLogging(res, logger); + + res.write('chunk', 'utf8'); + + expect(originalWrite).toHaveBeenCalledWith('chunk', 'utf8', undefined); + }); + + it('should call original end with the same arguments', () => { + const originalEnd = res.end; + interceptResponseForErrorLogging(res, logger); + + res.end('final', 'utf8'); + + expect(originalEnd).toHaveBeenCalledWith('final', 'utf8', undefined); + }); + + it('should return the original write result', () => { + interceptResponseForErrorLogging(res, logger); + + const result = res.write('data'); + + expect(result).toBe(true); + }); + }); +});