mirror of
https://github.com/danny-avila/LibreChat.git
synced 2026-10-22 18:13:27 +00:00
🔇 fix: Keep Cancelled Tool Calls on the Filtered Path and Out of Error Logs
Addresses both findings from the Codex review of 48fded564a.
P1 — the cancellation branch returned before `filteredToolOutputResult`,
so with tool-output filtering configured an aborted call's error text
reached the turn uninspected. Worse, `runSignal.aborted` says the run is
over, not that this rejection was the cancellation: an unrelated failure
racing the Stop took the same unfiltered exit. Cancellation now only
selects the log level; filtering and the result shape are unchanged.
P2 — `createMCPTool` logs its own error before wrapping and rethrowing,
so every Stop during an MCP call still emitted an error-level MCP entry
and could pollute operational alerts. That catch now recognizes the abort
and logs at debug; the wrapped message still reaches the turn.
Both are covered by tests that fail against the previous commit.
This commit is contained in:
parent
48fded564a
commit
b3c67082cd
4 changed files with 142 additions and 14 deletions
|
|
@ -1308,10 +1308,19 @@ function createToolInstance({
|
||||||
}
|
}
|
||||||
return result;
|
return result;
|
||||||
} catch (error) {
|
} catch (error) {
|
||||||
logger.error(
|
/** A user Stop aborts every in-flight call at once. The rejection that
|
||||||
`[MCP][${serverName}][${toolName}][User: ${userId}] Error calling MCP tool:`,
|
* follows is the cancellation working, so it must not reach error-level
|
||||||
error,
|
* 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 */
|
/** Carries the actionable re-auth message; the substring heuristic below would misreport it as an OAuth configuration problem */
|
||||||
if (error instanceof OpenIDReauthRequiredError) {
|
if (error instanceof OpenIDReauthRequiredError) {
|
||||||
|
|
|
||||||
|
|
@ -1610,6 +1610,76 @@ describe('User parameter passing tests', () => {
|
||||||
expect(callTool).toHaveBeenCalledTimes(2);
|
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'])(
|
it.each(['OAuth flow initiated - return early', 'Pending OAuth flow reused - return early'])(
|
||||||
'preserves runtime-detected OAuth for the internal signal: %s',
|
'preserves runtime-detected OAuth for the internal signal: %s',
|
||||||
async (oauthSignal) => {
|
async (oauthSignal) => {
|
||||||
|
|
|
||||||
|
|
@ -384,6 +384,48 @@ describe('createToolExecuteHandler', () => {
|
||||||
),
|
),
|
||||||
).toHaveLength(0);
|
).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<string, unknown>) =>
|
||||||
|
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<ToolExecuteResult[]>((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', () => {
|
describe('tool argument normalization', () => {
|
||||||
|
|
|
||||||
|
|
@ -5997,26 +5997,33 @@ export function createToolExecuteHandler(options: ToolExecuteOptions): EventHand
|
||||||
}
|
}
|
||||||
const { message, logContext } = getSafeToolError(toolError);
|
const { message, logContext } = getSafeToolError(toolError);
|
||||||
/** A user Stop rejects every in-flight call at once. That is
|
/** A user Stop rejects every in-flight call at once. That is
|
||||||
* the abort working, not a fault, so it stays out of the
|
* the abort working, not a fault, so it is logged at debug.
|
||||||
* error log; the message still reaches the model turn. */
|
* It only ever changes the log level: an aborted run says
|
||||||
if (runSignal?.aborted === true) {
|
* the turn is over, not that this particular rejection was
|
||||||
logger.debug(`[ON_TOOL_EXECUTE] Tool ${tc.name} cancelled by run abort`, {
|
* the cancellation, so an unrelated failure racing the Stop
|
||||||
name: logContext.name,
|
* must still take the same filtering and result path. */
|
||||||
});
|
const logToolFailure = (context: Record<string, unknown>): void => {
|
||||||
return errorResult(tc, message);
|
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 req = mergedConfigurable?.req as ServerRequest | undefined;
|
||||||
const filteredError = filteredToolOutputResult(tc, req, {
|
const filteredError = filteredToolOutputResult(tc, req, {
|
||||||
errorMessage: message,
|
errorMessage: message,
|
||||||
});
|
});
|
||||||
if (filteredError != null) {
|
if (filteredError != null) {
|
||||||
logger.error(`[ON_TOOL_EXECUTE] Tool ${tc.name} error`, {
|
logToolFailure({
|
||||||
name: logContext.name,
|
name: logContext.name,
|
||||||
contentFiltered: true,
|
contentFiltered: true,
|
||||||
});
|
});
|
||||||
return filteredError;
|
return filteredError;
|
||||||
}
|
}
|
||||||
logger.error(`[ON_TOOL_EXECUTE] Tool ${tc.name} error`, {
|
logToolFailure({
|
||||||
...logContext,
|
...logContext,
|
||||||
toolCallArgsShape: getValueShape(tc.args),
|
toolCallArgsShape: getValueShape(tc.args),
|
||||||
toolInputSchemaKind: getToolInputSchemaKind(tool),
|
toolInputSchemaKind: getToolInputSchemaKind(tool),
|
||||||
|
|
|
||||||
Loading…
Add table
Add a link
Reference in a new issue