fix(mcp-server): add diagnostic logging for 500 errors

packages/mcp-server/src/server.ts

@@ -56,6 +56,21 @@ const defaultLogger: Logger = (level, message) => {
   getDefaultLogFn(level)(message);
 };
 
+function logLevelForStatus(statusCode: number): LogLevel {
+  if (statusCode >= 500) return 'Error';
+  if (statusCode >= 400) return 'Warn';
+
+  return 'Info';
+}
+
+function logErrorWithStack(logger: Logger, message: string, err: Error): void {
+  logger('Error', message);
+
+  if (err.stack) {
+    logger('Error', `Stack: ${err.stack}`);
+  }
+}
+
 /** Fields that are safe to log for each tool (non-sensitive data) */
 const SAFE_ARGUMENTS_FOR_LOGGING: Record<string, string[]> = {
   list: ['collectionName'],
@@ -234,7 +249,8 @@ export default class ForestMCPServer {
    * Logs the request, intercepts the response for error logging, and delegates to the transport.
    */
   private async handleMcpRequest(req: express.Request, res: express.Response): Promise<void> {
-    this.logger('Info', `Incoming ${req.method} ${req.path}`);
+    const rpcMethod = req.body?.method || 'unknown';
+    this.logger('Info', `Incoming ${req.method} ${req.path} [${rpcMethod}]`);
 
     if (!this.mcpTransport) {
       throw new Error('MCP transport not initialized');
@@ -328,17 +344,14 @@ export default class ForestMCPServer {
     app.use((req, res, next) => {
       const startTime = Date.now();
 
-      // Capture the original end method to log after response is sent
-      const originalEnd = res.end.bind(res);
-      res.end = ((chunk?: unknown, encoding?: BufferEncoding | (() => void)) => {
+      res.on('finish', () => {
         const duration = Date.now() - startTime;
+        const level = logLevelForStatus(res.statusCode);
         this.logger(
-          'Info',
+          level,
           `[${res.statusCode}] ${req.method} ${req.baseUrl || req.path} - ${duration}ms`,
         );
-
-        return originalEnd(chunk, encoding as BufferEncoding);
-      }) as typeof res.end;
+      });
 
       next();
     });
@@ -373,30 +386,45 @@ export default class ForestMCPServer {
       }),
       (req, res) => {
         this.handleMcpRequest(req, res).catch(error => {
-          this.logger('Error', `MCP Error: ${error}`);
+          const mcpMethod = req.body?.method || 'unknown';
+          const err = error instanceof Error ? error : new Error(String(error));
+          logErrorWithStack(
+            this.logger,
+            `MCP Error on method '${mcpMethod}': ${err.message || error}`,
+            err,
+          );
 
           if (!res.headersSent) {
             res.status(500).json({
               jsonrpc: '2.0',
               error: {
                 code: -32603,
-                message: (error as Error)?.message || 'Internal server error',
+                message: err.message || 'Internal server error',
               },
               id: null,
             });
+          } else {
+            this.logger(
+              'Warn',
+              `Cannot send error response (headers already sent) for method '${mcpMethod}'`,
+            );
           }
         });
       },
     );
 
     // Global error handler to catch any unhandled errors
     // Express requires all 4 parameters to recognize this as an error handler
-    // Capture logger for use in error handler (arrow function would lose context)
+    // Capture logger reference so the error handler closure does not depend on 'this'
     const { logger } = this;
     app.use(
       // eslint-disable-next-line @typescript-eslint/no-unused-vars
-      (err: Error, _req: express.Request, res: express.Response, _next: express.NextFunction) => {
-        logger('Error', `Unhandled error: ${err.message}`);
+      (err: Error, req: express.Request, res: express.Response, _next: express.NextFunction) => {
+        logErrorWithStack(
+          logger,
+          `Unhandled error on ${req.method} ${req.path}: ${err.message}`,
+          err,
+        );
 
         if (!res.headersSent) {
           res.status(500).json({

packages/mcp-server/test/server.test.ts

@@ -2056,7 +2056,7 @@ describe('ForestMCPServer Instance', () => {
         .set('Accept', 'application/json, text/event-stream')
         .send({ jsonrpc: '2.0', method: 'tools/list', id: 1 });
 
-      expect(mockLogger).toHaveBeenCalledWith('Info', 'Incoming POST /mcp');
+      expect(mockLogger).toHaveBeenCalledWith('Info', 'Incoming POST /mcp [tools/list]');
     });
 
     it('should log tool calls with safe parameters', async () => {
@@ -2145,6 +2145,100 @@ describe('ForestMCPServer Instance', () => {
       );
     });
 
+    it('should log with Warn level for 4xx responses', async () => {
+      // Send unauthenticated request to trigger 401
+      await request(loggingHttpServer)
+        .post('/mcp')
+        .set('Content-Type', 'application/json')
+        .send({ jsonrpc: '2.0', method: 'tools/list', id: 1 });
+
+      expect(mockLogger).toHaveBeenCalledWith(
+        'Warn',
+        expect.stringMatching(/\[401\] POST \/mcp - \d+ms/),
+      );
+    });
+
+    it('should log MCP error with method name and stack trace when handleMcpRequest fails', async () => {
+      const authSecret = process.env.FOREST_AUTH_SECRET || 'test-auth-secret';
+      const validToken = jsonwebtoken.sign(
+        { id: 123, email: 'user@example.com', renderingId: 456 },
+        authSecret,
+        { expiresIn: '1h' },
+      );
+
+      // Break the transport to force an error in handleMcpRequest
+      const originalTransport = loggingServer.mcpTransport;
+      loggingServer.mcpTransport = undefined;
+
+      await request(loggingHttpServer)
+        .post('/mcp')
+        .set('Authorization', `Bearer ${validToken}`)
+        .set('Content-Type', 'application/json')
+        .set('Accept', 'application/json, text/event-stream')
+        .send({ jsonrpc: '2.0', method: 'tools/list', id: 1 });
+
+      // Restore transport
+      loggingServer.mcpTransport = originalTransport;
+
+      expect(mockLogger).toHaveBeenCalledWith(
+        'Error',
+        expect.stringContaining("MCP Error on method 'tools/list'"),
+      );
+      expect(mockLogger).toHaveBeenCalledWith('Error', expect.stringContaining('Stack:'));
+    });
+
+    it('should log warning when headersSent prevents MCP error response', async () => {
+      const authSecret = process.env.FOREST_AUTH_SECRET || 'test-auth-secret';
+      const validToken = jsonwebtoken.sign(
+        { id: 123, email: 'user@example.com', renderingId: 456 },
+        authSecret,
+        { expiresIn: '1h' },
+      );
+
+      // Mock handleMcpRequest to send headers, end response, then throw
+      const serverRecord = loggingServer as unknown as Record<string, unknown>;
+      const originalHandle = serverRecord.handleMcpRequest;
+
+      serverRecord.handleMcpRequest = async (
+        _req: unknown,
+        res: { writeHead: (s: number) => void; end: () => void },
+      ) => {
+        res.writeHead(200);
+        res.end();
+        throw new Error('Error after headers sent');
+      };
+
+      await request(loggingHttpServer)
+        .post('/mcp')
+        .set('Authorization', `Bearer ${validToken}`)
+        .set('Content-Type', 'application/json')
+        .set('Accept', 'application/json, text/event-stream')
+        .send({ jsonrpc: '2.0', method: 'tools/list', id: 1 });
+
+      // Restore
+      serverRecord.handleMcpRequest = originalHandle;
+
+      expect(mockLogger).toHaveBeenCalledWith(
+        'Warn',
+        expect.stringContaining('Cannot send error response (headers already sent)'),
+      );
+    });
+
+    it('should log unhandled Express error with stack trace', async () => {
+      // Send malformed JSON to trigger express.json() parse error,
+      // which calls next(err) and reaches the global error handler
+      await request(loggingHttpServer)
+        .post('/mcp')
+        .set('Content-Type', 'application/json')
+        .send('invalid json');
+
+      expect(mockLogger).toHaveBeenCalledWith(
+        'Error',
+        expect.stringContaining('Unhandled error on POST /mcp'),
+      );
+      expect(mockLogger).toHaveBeenCalledWith('Error', expect.stringContaining('Stack:'));
+    });
+
     it('should log in correct order: incoming, tool call, response', async () => {
       const authSecret = process.env.FOREST_AUTH_SECRET || 'test-auth-secret';
       const validToken = jsonwebtoken.sign(
@@ -2172,7 +2266,9 @@ describe('ForestMCPServer Instance', () => {
         });
 
       const { calls } = mockLogger.mock;
-      const incomingIndex = calls.findIndex((c: [string, string]) => c[1] === 'Incoming POST /mcp');
+      const incomingIndex = calls.findIndex((c: [string, string]) =>
+        c[1].startsWith('Incoming POST /mcp'),
+      );
       const toolCallIndex = calls.findIndex((c: [string, string]) =>
         c[1].includes('Tool call: list'),
       );