diff --git a/api/server/services/MCP.js b/api/server/services/MCP.js index 1e8820b487..444a353951 100644 --- a/api/server/services/MCP.js +++ b/api/server/services/MCP.js @@ -1308,10 +1308,19 @@ function createToolInstance({ } return result; } catch (error) { - logger.error( - `[MCP][${serverName}][${toolName}][User: ${userId}] Error calling MCP tool:`, - error, - ); + /** A user Stop aborts every in-flight call at once. The rejection that + * follows is the cancellation working, so it must not reach error-level + * operational alerts; the wrapping below still reports it to the turn. */ + if (config?.signal?.aborted === true) { + logger.debug( + `[MCP][${serverName}][${toolName}][User: ${userId}] Tool call cancelled by user abort`, + ); + } else { + logger.error( + `[MCP][${serverName}][${toolName}][User: ${userId}] Error calling MCP tool:`, + error, + ); + } /** Carries the actionable re-auth message; the substring heuristic below would misreport it as an OAuth configuration problem */ if (error instanceof OpenIDReauthRequiredError) { diff --git a/api/server/services/MCP.spec.js b/api/server/services/MCP.spec.js index 86a0681c28..090088b39b 100644 --- a/api/server/services/MCP.spec.js +++ b/api/server/services/MCP.spec.js @@ -1610,6 +1610,76 @@ describe('User parameter passing tests', () => { expect(callTool).toHaveBeenCalledTimes(2); }); + it('logs a user-aborted tool call as debug, not as an MCP error', async () => { + const mockUser = { id: 'cancel-user', role: 'USER' }; + const mockRes = { write: jest.fn(), flush: jest.fn() }; + const abortController = new AbortController(); + const { getRoleByName } = require('~/models'); + getRoleByName.mockResolvedValue({ + permissions: { + [PermissionTypes.MCP_SERVERS]: { + [Permissions.USE]: true, + }, + }, + }); + mockGetMCPManager.mockReturnValue({ + callTool: jest.fn( + ({ options }) => + new Promise((_resolve, reject) => { + const signal = options?.signal; + signal?.addEventListener( + 'abort', + () => reject(new Error('This operation was aborted')), + { + once: true, + }, + ); + }), + ), + }); + + const mcpTool = await createMCPTool({ + res: mockRes, + user: mockUser, + config: { url: 'https://cancel.example.com/mcp' }, + toolKey: `test-tool${D}test-server`, + provider: 'openai', + userMCPAuthMap: {}, + availableTools: { + [`test-tool${D}test-server`]: { + function: { + description: 'Cached tool', + parameters: { type: 'object', properties: {} }, + }, + }, + }, + }); + + const call = mcpTool.invoke( + {}, + { + signal: abortController.signal, + configurable: { user: mockUser }, + metadata: { provider: 'openai', thread_id: 'thread-1', run_id: 'run-1' }, + toolCall: {}, + }, + ); + await new Promise((resolve) => setImmediate(resolve)); + abortController.abort(); + await expect(call).rejects.toThrow(); + /** The wrapper rejects on abort while `_call` is still unwinding; let its + * catch run before asserting on what it logged. */ + await new Promise((resolve) => setImmediate(resolve)); + + expect(logger.error).not.toHaveBeenCalledWith( + expect.stringContaining('Error calling MCP tool'), + expect.anything(), + ); + expect(logger.debug).toHaveBeenCalledWith( + expect.stringContaining('Tool call cancelled by user abort'), + ); + }); + it.each(['OAuth flow initiated - return early', 'Pending OAuth flow reused - return early'])( 'preserves runtime-detected OAuth for the internal signal: %s', async (oauthSignal) => { diff --git a/packages/api/src/agents/handlers.spec.ts b/packages/api/src/agents/handlers.spec.ts index fbdcf02fcd..306dfacf7c 100644 --- a/packages/api/src/agents/handlers.spec.ts +++ b/packages/api/src/agents/handlers.spec.ts @@ -384,6 +384,48 @@ describe('createToolExecuteHandler', () => { ), ).toHaveLength(0); }); + + /** + * An aborted run means the turn is over, not that this particular rejection + * was the cancellation — an unrelated failure can always race the Stop. The + * quiet-log branch must therefore never become a way around output filtering. + */ + it('still filters a tool failure that rejects after the run was aborted', async () => { + const protectedValue = 'PROTECTED-CANCELLED-TOOL-OUTPUT'; + const controller = new AbortController(); + const tool = { + name: 'slow_tool', + invoke: jest.fn( + (_args: unknown, config: Record) => + new Promise((_resolve, reject) => { + const signal = config.signal as AbortSignal; + signal.addEventListener('abort', () => reject(new Error(protectedValue)), { + once: true, + }); + }), + ), + }; + const loadTools: ToolExecuteOptions['loadTools'] = jest.fn(async () => ({ + loadedTools: [tool] as never[], + })); + const handler = createToolExecuteHandler({ loadTools }); + + const [result] = await new Promise((resolve, reject) => { + const request: ToolExecuteBatchRequest = { + toolCalls: [{ id: 'call-1', name: 'slow_tool', args: {} }] as ToolCallRequest[], + configurable: { req: protectedToolOutputRequest() }, + signal: controller.signal, + resolve, + reject, + }; + handler.handle('on_tool_execute', request); + setTimeout(() => controller.abort(new Error('Operation aborted by user')), 10); + }); + + expect(result.status).toBe('error'); + expect(result.errorMessage).toContain('content_filter_block'); + expect(result.errorMessage).not.toContain(protectedValue); + }); }); describe('tool argument normalization', () => { diff --git a/packages/api/src/agents/handlers.ts b/packages/api/src/agents/handlers.ts index 958f887a90..e4be216182 100644 --- a/packages/api/src/agents/handlers.ts +++ b/packages/api/src/agents/handlers.ts @@ -5997,26 +5997,33 @@ export function createToolExecuteHandler(options: ToolExecuteOptions): EventHand } const { message, logContext } = getSafeToolError(toolError); /** A user Stop rejects every in-flight call at once. That is - * the abort working, not a fault, so it stays out of the - * error log; the message still reaches the model turn. */ - if (runSignal?.aborted === true) { - logger.debug(`[ON_TOOL_EXECUTE] Tool ${tc.name} cancelled by run abort`, { - name: logContext.name, - }); - return errorResult(tc, message); - } + * the abort working, not a fault, so it is logged at debug. + * It only ever changes the log level: an aborted run says + * the turn is over, not that this particular rejection was + * the cancellation, so an unrelated failure racing the Stop + * must still take the same filtering and result path. */ + const logToolFailure = (context: Record): void => { + if (runSignal?.aborted === true) { + logger.debug( + `[ON_TOOL_EXECUTE] Tool ${tc.name} cancelled by run abort`, + context, + ); + return; + } + logger.error(`[ON_TOOL_EXECUTE] Tool ${tc.name} error`, context); + }; const req = mergedConfigurable?.req as ServerRequest | undefined; const filteredError = filteredToolOutputResult(tc, req, { errorMessage: message, }); if (filteredError != null) { - logger.error(`[ON_TOOL_EXECUTE] Tool ${tc.name} error`, { + logToolFailure({ name: logContext.name, contentFiltered: true, }); return filteredError; } - logger.error(`[ON_TOOL_EXECUTE] Tool ${tc.name} error`, { + logToolFailure({ ...logContext, toolCallArgsShape: getValueShape(tc.args), toolInputSchemaKind: getToolInputSchemaKind(tool),