From 30cd1c2f2e6ce6bdd55d0b1f3ee7d5be532f5c10 Mon Sep 17 00:00:00 2001 From: Danny Avila Date: Fri, 4 Sep 2026 09:21:24 -0400 Subject: [PATCH] =?UTF-8?q?=F0=9F=94=87=20fix:=20Stop=20logging=20an=20abs?= =?UTF-8?q?ent=20`create=5Ffile`=20target=20as=20an=20error=20(#15591)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `create_file` reads its target before writing so it can tell a create from an overwrite, so `readSandboxFile` missing the path is the ordinary case for a create — yet it was reported at error level, through `logAxiosError`, which rendered the sandbox's own `cat: …: No such file or directory` as "An error occurred while setting up the request" plus a stack. Every ordinary file creation emitted an error-level entry claiming a transport fault about a file that was written half a second later, and an operator reading it concluded the file had been lost. Split the two failures `readSandboxFile` was conflating. A request that never completed still goes to `logAxiosError`; a request the sandbox answered with stderr is now classified on that stderr — an absent path logs at debug, and anything else (permission, a broken interpreter) keeps error level with the sandbox's own wording. The thrown error is unchanged, so the authoring flow's create/overwrite decision still reads it the same way. The classifier moves to `packages/api/src/files/code/errors.ts` and is now shared: `handlers.ts` had two near-duplicate copies of it, the narrower of which documented itself as narrower than the broader one without either deriving from the other. Also carry the cause on `[preflightCodeOutputBatch] … could not be inspected`. That warning follows each `create_file` in the same request, and the batch discarded the error entirely — so a Code API that refused the download, one routed to the wrong execution profile, and a file too large to inspect all arrived as the same sentence, and neither this warning nor the one above could be told apart from the failures around them. It goes through `getSafeErrorMetadata`, which is what keeps the upstream message and the artifact's name — both of which can echo submitted content — out of the log. --- .../tools.callTool.contentFilter.spec.js | 4 ++ api/server/services/Files/Code/preflight.js | 15 ++++++- .../services/Files/Code/preflight.spec.js | 30 +++++++++++++ api/server/services/Files/Code/process.js | 31 +++++++++---- .../services/Files/Code/process.spec.js | 43 +++++++++++++++++++ packages/api/src/agents/handlers.ts | 33 ++++---------- packages/api/src/files/code/errors.spec.ts | 27 ++++++++++++ packages/api/src/files/code/errors.ts | 20 +++++++++ packages/api/src/files/code/index.ts | 1 + packages/api/src/files/code/preflight.ts | 12 ++++-- 10 files changed, 178 insertions(+), 38 deletions(-) create mode 100644 packages/api/src/files/code/errors.spec.ts create mode 100644 packages/api/src/files/code/errors.ts diff --git a/api/server/controllers/__tests__/tools.callTool.contentFilter.spec.js b/api/server/controllers/__tests__/tools.callTool.contentFilter.spec.js index 0565c26595..6eb4cac8f5 100644 --- a/api/server/controllers/__tests__/tools.callTool.contentFilter.spec.js +++ b/api/server/controllers/__tests__/tools.callTool.contentFilter.spec.js @@ -523,8 +523,12 @@ describe('callTool generated-content protection', () => { expect(mockProcessCodeOutput).toHaveBeenCalledWith( expect.objectContaining({ downloadFallback: true, preparedBuffer: undefined }), ); + /* The cause rides the warning so the failure is diagnosable at all, but + * only through `getSafeErrorMetadata` — the upstream message here is + * `PRIVATE-DOWNLOAD-ERROR`, and that is precisely what must not appear. */ expect(mockLogger.warn).toHaveBeenCalledWith( '[preflightCodeOutputBatch] Generated artifact 1 could not be inspected', + { type: 'Error' }, ); expect(JSON.stringify(mockLogger.warn.mock.calls)).not.toContain('PRIVATE-'); expect(res.status).toHaveBeenCalledWith(200); diff --git a/api/server/services/Files/Code/preflight.js b/api/server/services/Files/Code/preflight.js index 156e364bab..31bdc31f94 100644 --- a/api/server/services/Files/Code/preflight.js +++ b/api/server/services/Files/Code/preflight.js @@ -1,5 +1,8 @@ const { logger } = require('@librechat/data-schemas'); -const { preflightCodeOutputBatch: runCodeOutputBatchPreflight } = require('@librechat/api'); +const { + getSafeErrorMetadata, + preflightCodeOutputBatch: runCodeOutputBatchPreflight, +} = require('@librechat/api'); const { EModelEndpoint, mergeFileConfig, @@ -37,9 +40,17 @@ const preflightCodeOutputBatch = async ({ req, artifact, codeExecutionContext }) bridgeWorkerId: codeExecutionContext?.bridgeWorkerId, executionRouteKey: codeExecutionContext?.executionRouteKey, }), - onInspectionUnavailable: (index) => { + /** The batch degrades this artifact to the download fallback and the turn + * still succeeds, so this warning is the only trace the failure leaves. + * Carry the cause: without it a Code API that refused the download, one + * routed to the wrong execution profile, and a file too large to inspect + * all read as the same sentence. `getSafeErrorMetadata` is what keeps + * that from reaching for the artifact's name or the upstream body — + * both can echo submitted content into the log. */ + onInspectionUnavailable: (index, cause) => { logger.warn( `[preflightCodeOutputBatch] Generated artifact ${index + 1} could not be inspected`, + getSafeErrorMetadata(cause), ); }, }); diff --git a/api/server/services/Files/Code/preflight.spec.js b/api/server/services/Files/Code/preflight.spec.js index 317618a579..f9baa15b9e 100644 --- a/api/server/services/Files/Code/preflight.spec.js +++ b/api/server/services/Files/Code/preflight.spec.js @@ -1,5 +1,6 @@ const mockRunCodeOutputBatchPreflight = jest.fn(); const mockPrepareCodeOutputForInspection = jest.fn(); +const mockGetSafeErrorMetadata = jest.fn(() => ({ type: 'Error', status: 404 })); jest.mock('@librechat/data-schemas', () => ({ logger: { warn: jest.fn() }, @@ -7,6 +8,7 @@ jest.mock('@librechat/data-schemas', () => ({ jest.mock('@librechat/api', () => ({ preflightCodeOutputBatch: (...args) => mockRunCodeOutputBatchPreflight(...args), + getSafeErrorMetadata: (...args) => mockGetSafeErrorMetadata(...args), })); jest.mock('librechat-data-provider', () => ({ @@ -23,6 +25,7 @@ jest.mock('./process', () => ({ prepareCodeOutputForInspection: (...args) => mockPrepareCodeOutputForInspection(...args), })); +const { logger } = require('@librechat/data-schemas'); const { preflightCodeOutputBatch } = require('./preflight'); describe('preflightCodeOutputBatch Code API routing', () => { @@ -68,4 +71,31 @@ describe('preflightCodeOutputBatch Code API routing', () => { executionRouteKey: 'stateful:route', }); }); + + /* The batch degrades an uninspectable artifact to the download fallback and + * the turn still succeeds, so this warning is the only trace it leaves. + * Without the cause, a refused download, a misrouted execution profile and + * an oversized file are one indistinguishable sentence. */ + it('reports why an artifact could not be inspected, through the safe-metadata filter', async () => { + const cause = Object.assign(new Error('Request failed with status code 404'), { + response: { status: 404 }, + }); + mockRunCodeOutputBatchPreflight.mockImplementation(async ({ onInspectionUnavailable }) => { + onInspectionUnavailable(0, cause); + return []; + }); + + await preflightCodeOutputBatch({ + req: { config: {}, user: { id: 'user-1' } }, + artifact: { files: [{ id: 'file-1', name: 'PRIVATE-name.txt' }] }, + }); + + expect(mockGetSafeErrorMetadata).toHaveBeenCalledWith(cause); + expect(logger.warn).toHaveBeenCalledWith( + '[preflightCodeOutputBatch] Generated artifact 1 could not be inspected', + { type: 'Error', status: 404 }, + ); + /* The artifact's name is submitted content and must never ride the log. */ + expect(JSON.stringify(logger.warn.mock.calls)).not.toContain('PRIVATE-'); + }); }); diff --git a/api/server/services/Files/Code/process.js b/api/server/services/Files/Code/process.js index 479386d459..1b90948e88 100644 --- a/api/server/services/Files/Code/process.js +++ b/api/server/services/Files/Code/process.js @@ -13,6 +13,7 @@ const { getCodeApiAuthHeaders, withCodeApiRateLimit, classifyCodeArtifact, + isMissingSandboxPathError, parseSandboxImageChunk, readWindowedSandboxImage, createCodeApiRateLimitBudget, @@ -1617,9 +1618,10 @@ async function readSandboxFile({ postData.files = files; } + let response; try { const authHeaders = await getCodeApiAuthHeaders(req, bridgeWorkerId); - const response = await axios({ + response = await axios({ method: 'post', url: `${baseURL}/exec`, data: postData, @@ -1633,14 +1635,6 @@ async function readSandboxFile({ httpsAgent: codeServerHttpsAgent, timeout: 15000, }); - const result = response?.data ?? {}; - if (result.stderr && (result.stdout == null || result.stdout === '')) { - throw new Error(String(result.stderr).trim()); - } - if (result.stdout == null) { - return null; - } - return { content: String(result.stdout) }; } catch (error) { logAxiosError({ message: `Error reading sandbox file "${file_path}"`, @@ -1648,6 +1642,25 @@ async function readSandboxFile({ }); throw error; } + + const result = response?.data ?? {}; + if (result.stderr && (result.stdout == null || result.stdout === '')) { + const reason = String(result.stderr).trim(); + /** An absent path is the ordinary outcome, not a fault: `create_file` + * reads its target before writing so it can tell a create from an + * overwrite. Logging that at error level with a stack made every + * file creation look like a file that had gone missing. */ + if (isMissingSandboxPathError(reason)) { + logger.debug(`[readSandboxFile] "${file_path}" is not present in the sandbox: ${reason}`); + } else { + logger.error(`[readSandboxFile] Error reading sandbox file "${file_path}": ${reason}`); + } + throw new Error(reason); + } + if (result.stdout == null) { + return null; + } + return { content: String(result.stdout) }; } /** diff --git a/api/server/services/Files/Code/process.spec.js b/api/server/services/Files/Code/process.spec.js index 15b7fa9d3b..7865a6eac2 100644 --- a/api/server/services/Files/Code/process.spec.js +++ b/api/server/services/Files/Code/process.spec.js @@ -66,6 +66,12 @@ jest.mock('@librechat/api', () => { const https = require('https'); return { logAxiosError: jest.fn(), + /* Behaviourally identical to the real predicate in + * `packages/api/src/files/code/errors.ts`, which owns the contract and + * its own spec. Inlined because this factory replaces the whole module + * and `requireActual` here would load the entire package. */ + isMissingSandboxPathError: (reason) => + /no such file or directory|cannot access|cannot find the path|enoent/i.test(reason), getBasePath: jest.fn(() => ''), sanitizeArtifactPath: jest.fn((name) => name), flattenArtifactPath: jest.fn((name) => name.replace(/\//g, '__')), @@ -2071,6 +2077,43 @@ describe('Code Process', () => { }), ); }); + + /* `create_file` reads its target before writing so it can tell a create + * from an overwrite, so an absent path is the ordinary case. Reported at + * error level it made every file creation look like a lost file — and + * `logAxiosError` rendered the sandbox's own stderr as "An error occurred + * while setting up the request", which reads as a transport fault. */ + it('logs an absent path at debug, not through the error-level axios logger', async () => { + const { logAxiosError } = require('@librechat/api'); + mockAxios.mockResolvedValueOnce({ + data: { stdout: '', stderr: 'cat: /mnt/data/SKILL.md: No such file or directory\n' }, + }); + + await expect(readSandboxFile({ file_path: '/mnt/data/SKILL.md' })).rejects.toThrow( + 'No such file or directory', + ); + + expect(logAxiosError).not.toHaveBeenCalled(); + expect(logger.error).not.toHaveBeenCalled(); + expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('/mnt/data/SKILL.md')); + }); + + it('still reports a non-missing sandbox read failure at error level', async () => { + const { logAxiosError } = require('@librechat/api'); + mockAxios.mockResolvedValueOnce({ + data: { stdout: '', stderr: 'cat: /mnt/data/x.txt: Permission denied\n' }, + }); + + await expect(readSandboxFile({ file_path: '/mnt/data/x.txt' })).rejects.toThrow( + 'Permission denied', + ); + + expect(logger.debug).not.toHaveBeenCalled(); + expect(logger.error).toHaveBeenCalledWith(expect.stringContaining('Permission denied')); + /* The sandbox answered; nothing about the request failed, so the + * axios-shaped logger would misattribute this to the transport. */ + expect(logAxiosError).not.toHaveBeenCalled(); + }); }); describe('timeout', () => { diff --git a/packages/api/src/agents/handlers.ts b/packages/api/src/agents/handlers.ts index 2287d15d28..fc0c5a68a8 100644 --- a/packages/api/src/agents/handlers.ts +++ b/packages/api/src/agents/handlers.ts @@ -88,6 +88,7 @@ import { import { buildSkillPrimeMessage, isSkillFilePath, SKILL_FILE_PREFIX } from './skills'; import { resolveCallerCapabilityProjectionSnapshot } from './callerCapabilities'; import { createSkillContentDigest } from './compatibility'; +import { isMissingSandboxPathError } from '~/files/code'; import { parseFrontmatter } from '../skills/import'; import { cleanCodeToolOutput } from './cleanup'; import { primeSkillFiles } from './skillFiles'; @@ -1878,24 +1879,6 @@ function looksBinary(content: string): boolean { return false; } -/** - * True for the errors a sandbox raises about the requested PATH, and only - * those. Deliberately narrower than {@link isSandboxMissingFileError}: that - * predicate also accepts a bare "not found", which the sandbox reader emits - * for a missing interpreter (`python3: not found`). Reporting that as a - * missing image would send the model to `ls /mnt/data` while hiding a - * runner dependency the operator needs to see. - */ -function isMissingSandboxPathError(reason: string): boolean { - const message = reason.toLowerCase(); - return ( - message.includes('no such file or directory') || - message.includes('cannot access') || - message.includes('cannot find the path') || - message.includes('enoent') - ); -} - /** * Model-visible error for an image the sandbox could not hand back. The * read is a supported operation that FAILED, so the message must not reuse @@ -2209,13 +2192,15 @@ function mergeSandboxSessionArtifact( } } +/** + * Broader than {@link isMissingSandboxPathError}: the authoring flow also + * treats a bare "not found" as an absent file, because a `cat` that cannot + * start is indistinguishable from a `cat` that found nothing as far as + * "should this create or overwrite?" is concerned. + */ function isSandboxMissingFileError(error: unknown): boolean { - const message = getThrownValueMessage(error).toLowerCase(); - return ( - message.includes('no such file or directory') || - message.includes('cannot access') || - message.includes('not found') - ); + const message = getThrownValueMessage(error); + return isMissingSandboxPathError(message) || message.toLowerCase().includes('not found'); } function invalidSandboxAuthoringPath(filePath: string): string | null { diff --git a/packages/api/src/files/code/errors.spec.ts b/packages/api/src/files/code/errors.spec.ts new file mode 100644 index 0000000000..7f0112053e --- /dev/null +++ b/packages/api/src/files/code/errors.spec.ts @@ -0,0 +1,27 @@ +import { isMissingSandboxPathError } from './errors'; + +describe('isMissingSandboxPathError', () => { + it('recognizes the shell and runtime spellings of an absent path', () => { + expect(isMissingSandboxPathError('cat: /mnt/data/SKILL.md: No such file or directory')).toBe( + true, + ); + expect(isMissingSandboxPathError("ls: cannot access '/mnt/data/x': No such file")).toBe(true); + expect(isMissingSandboxPathError('The system cannot find the path specified')).toBe(true); + expect(isMissingSandboxPathError("ENOENT: no such file, open '/mnt/data/x'")).toBe(true); + expect(isMissingSandboxPathError('CAT: /MNT/DATA/X: NO SUCH FILE OR DIRECTORY')).toBe(true); + }); + + /* A missing interpreter is a runner dependency the operator must see, not + * an absent file — demoting it to an expected miss would hide it. */ + it('does not treat a bare "not found" as an absent path', () => { + expect(isMissingSandboxPathError('python3: not found')).toBe(false); + expect(isMissingSandboxPathError('/bin/sh: 1: cat: not found')).toBe(false); + }); + + it('rejects transport and permission failures', () => { + expect(isMissingSandboxPathError('connect ECONNREFUSED 127.0.0.1:3112')).toBe(false); + expect(isMissingSandboxPathError('Request failed with status code 403')).toBe(false); + expect(isMissingSandboxPathError('cat: /mnt/data/x: Permission denied')).toBe(false); + expect(isMissingSandboxPathError('')).toBe(false); + }); +}); diff --git a/packages/api/src/files/code/errors.ts b/packages/api/src/files/code/errors.ts new file mode 100644 index 0000000000..0729d33f93 --- /dev/null +++ b/packages/api/src/files/code/errors.ts @@ -0,0 +1,20 @@ +/** + * True for the failures a code-execution sandbox reports about the requested + * PATH, and only those. Deliberately narrow: a bare "not found" is also what + * the sandbox emits for a missing interpreter (`python3: not found`), and + * treating that as an absent file would hide a runner dependency the operator + * needs to see. + * + * Reads that miss are an ordinary outcome — `create_file` reads the target + * before writing so it can detect an overwrite — so callers use this to keep + * an expected miss out of error-level logging and off the model's error path. + */ +export function isMissingSandboxPathError(reason: string): boolean { + const message = reason.toLowerCase(); + return ( + message.includes('no such file or directory') || + message.includes('cannot access') || + message.includes('cannot find the path') || + message.includes('enoent') + ); +} diff --git a/packages/api/src/files/code/index.ts b/packages/api/src/files/code/index.ts index 6414ff2564..6573508a3f 100644 --- a/packages/api/src/files/code/index.ts +++ b/packages/api/src/files/code/index.ts @@ -1,5 +1,6 @@ export * from './classify'; export * from './destinations'; +export * from './errors'; export * from './extract'; export * from './form'; export * from './identity'; diff --git a/packages/api/src/files/code/preflight.ts b/packages/api/src/files/code/preflight.ts index ca4407e826..05c9caf1a5 100644 --- a/packages/api/src/files/code/preflight.ts +++ b/packages/api/src/files/code/preflight.ts @@ -63,7 +63,13 @@ export interface PreflightCodeOutputBatchInput { readonly artifact?: CodeOutputArtifact | null; readonly limits: CodeOutputPreflightLimits; readonly prepare: (input: PrepareCodeOutputInput) => Promise; - readonly onInspectionUnavailable?: (index: number) => void; + /** Reports an artifact whose bytes could not be fetched for inspection. + * The batch degrades that entry to the download fallback and the turn + * still succeeds, so this callback is the only trace the failure leaves; + * it carries the cause so the reason is not lost with it. `index` is the + * position within the batch, not within the artifact's own file list — + * inherited files and files past the configured count never enter it. */ + readonly onInspectionUnavailable?: (index: number, cause: unknown) => void; } function throwIfContentBlocked( @@ -183,7 +189,7 @@ export async function preflightCodeOutputBatch( maxBytes: transportBytes, inspectContent: inspectionActive, }); - } catch (_error) { + } catch (error) { inspectedBytes += transportBytes; if (inspectionActive) { const blockedField = getBlockedUninspectableFileField(input.filters, selectedFields); @@ -191,7 +197,7 @@ export async function preflightCodeOutputBatch( throw new UninspectableFileError(blockedField); } } - input.onInspectionUnavailable?.(index); + input.onInspectionUnavailable?.(index, error); entries[index] = { ...entry, downloadFallback: true }; continue; }