From ee0a51ac1950d0f608f5a89ec2de0e14e9679e1d Mon Sep 17 00:00:00 2001 From: Danny Avila Date: Fri, 4 Sep 2026 10:38:49 -0400 Subject: [PATCH] =?UTF-8?q?=F0=9F=AA=B5=20fix:=20Log=20Code=20API=20Auth?= =?UTF-8?q?=20Header=20Failures=20With=20Request=20Context=20(#15592)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * ๐Ÿชต fix: Log Code API Auth Header Failures With Request Context Every Code API tool LibreChat builds โ€” `execute_code`, `bash_tool` and the PTC tools โ€” resolves its auth headers through `codeExecutionAuthHeaders`. When that throws, `@librechat/agents` replaces it with a fixed "Code execution is not authorized" string before either the model or the operator sees it, and the SDK's own console diagnostic carries no request or user id. Log the failure here before rethrowing. Winston attaches requestId, userId and tenantId to every record, so this is the only line that can be correlated with the `[code-env:inject]` events surrounding a failed execution. Rethrowing unchanged keeps the SDK's sanitization intact โ€” the model-facing message does not change. * ๐Ÿงต fix: Carry Non-Error Auth Failures Into the Log Message winston folds an `Error` meta's message and stack into `info.message` before any format runs, so an Error cause already survives the plain console format that prints `info.message` alone. A non-Error rejection does not: winston drops a string or plain-object meta from that format entirely, leaving the same generic line the SDK's sanitization produces. Append the cause to the message only when it is not an Error, so the Error path stays free of a duplicated message. A new spec renders both paths through a real winston transport whose format prints nothing but `info.message`, which is what pins the distinction. * ๐Ÿงฏ fix: Keep the Auth Failure Cause Out of Winston Metadata Passing the caught value as positional metadata had three separate failure modes, all measured against real winston. Winston merges object metadata onto the log record, so a rejection carrying `tenantId`, `userId` or `event_name` lands on top of the fields `attachRequestContext` fills in โ€” and that function deliberately keeps an already-present value, so the failure would be attributed to the wrong user or have its identity stripped by a matching event name. An `Error` is no safer: only its custom enumerable properties are copied, which is exactly the reachable set. Any metadata also arms `format.splat()`, which then treats a `%s` in the cause as a substitution token: rejecting with `service said %s unavailable` rendered `service said service said %s unavailable unavailable`. And `String()` throws on a null-prototype object, so an exotic rejection made the catch block throw its own formatting error instead of logging and rethrowing the original. The cause is now derived through a guarded formatter and inlined in the message, with no metadata at all โ€” which is also what makes it visible on the console format that prints `info.message` alone. The rendering spec now runs through `errors()` and `splat()` as well as the bare printf, and restores each transport's previous `silent` value rather than assuming it was false. * ๐Ÿ”‘ fix: Keep Signing Material Out of Code API Key Load Failures Node 24's JSON `SyntaxError` quotes an excerpt of the source around the offending token, so a malformed `CODEAPI_JWT_PRIVATE_JWK_JSON` produces `Unexpected token 'M', ..."d":MIIEvgIBAD"... is not valid JSON` โ€” private key material inside an error message, which every caller then logs. The message redaction patterns do not recognize a bare base64 fragment, so nothing downstream would have caught it. `createSigningKey` now converts any load failure into a diagnostic naming the failure and the key format it attempted, and nothing more. That makes the message safe by construction rather than by scrubbing, which matters because the log added in this branch is what would have persisted it. Also guard the `name`/`message` reads in the cause formatter: a proxy can throw from either accessor, which would have replaced the rejection with a formatting error and logged nothing at all. * chore: bump agents sdk --- api/package.json | 2 +- package-lock.json | 10 +- packages/api/package.json | 2 +- packages/api/src/agents/execution.spec.ts | 124 ++++++++++++++++++++++ packages/api/src/agents/execution.ts | 42 +++++++- packages/api/src/auth/codeapi.spec.ts | 18 ++++ packages/api/src/auth/codeapi.ts | 19 +++- 7 files changed, 203 insertions(+), 14 deletions(-) diff --git a/api/package.json b/api/package.json index 71959412f2..bb5fe8efb9 100644 --- a/api/package.json +++ b/api/package.json @@ -46,7 +46,7 @@ "@azure/storage-blob": "^12.30.0", "@google/genai": "^2.8.0", "@keyv/redis": "5.1.6", - "@librechat/agents": "^3.7.20", + "@librechat/agents": "^3.7.21", "@librechat/api": "*", "@librechat/data-schemas": "*", "@microsoft/microsoft-graph-client": "^3.0.7", diff --git a/package-lock.json b/package-lock.json index 12bb93691e..84203145b1 100644 --- a/package-lock.json +++ b/package-lock.json @@ -63,7 +63,7 @@ "@azure/storage-blob": "^12.30.0", "@google/genai": "^2.8.0", "@keyv/redis": "5.1.6", - "@librechat/agents": "^3.7.20", + "@librechat/agents": "^3.7.21", "@librechat/api": "*", "@librechat/data-schemas": "*", "@microsoft/microsoft-graph-client": "^3.0.7", @@ -10627,9 +10627,9 @@ } }, "node_modules/@librechat/agents": { - "version": "3.7.20", - "resolved": "https://registry.npmjs.org/@librechat/agents/-/agents-3.7.20.tgz", - "integrity": "sha512-YnfBpC5MK7QDgP+6VpmOYBTA2mXbaA+fDggfi7n/bsB56FSqenCzizSpC+Nn83lhwJz7GNntJpYNX53nRhFGgw==", + "version": "3.7.21", + "resolved": "https://registry.npmjs.org/@librechat/agents/-/agents-3.7.21.tgz", + "integrity": "sha512-n0dd7Xzh8Rnx4TGYBOqSGzSBoDMwyV28710Xn/q/Id6p7Z0CEnv4sLuQTHR1UMvhmOHs4kz2/pYynnaz60WbaA==", "license": "MIT", "dependencies": { "@anthropic-ai/sdk": "^0.115.0", @@ -42681,7 +42681,7 @@ "@azure/storage-blob": "^12.30.0", "@google/genai": "^2.8.0", "@keyv/redis": "5.1.6", - "@librechat/agents": "^3.7.20", + "@librechat/agents": "^3.7.21", "@librechat/data-schemas": "*", "@modelcontextprotocol/sdk": "^1.30.0", "@opentelemetry/api": "^1.9.0", diff --git a/packages/api/package.json b/packages/api/package.json index 66f436c601..9e905bbff9 100644 --- a/packages/api/package.json +++ b/packages/api/package.json @@ -113,7 +113,7 @@ "@azure/storage-blob": "^12.30.0", "@google/genai": "^2.8.0", "@keyv/redis": "5.1.6", - "@librechat/agents": "^3.7.20", + "@librechat/agents": "^3.7.21", "@librechat/data-schemas": "*", "@modelcontextprotocol/sdk": "^1.30.0", "@opentelemetry/api": "^1.9.0", diff --git a/packages/api/src/agents/execution.spec.ts b/packages/api/src/agents/execution.spec.ts index ca8c332097..b12f16e932 100644 --- a/packages/api/src/agents/execution.spec.ts +++ b/packages/api/src/agents/execution.spec.ts @@ -1,3 +1,6 @@ +import winston from 'winston'; +import { Writable } from 'node:stream'; +import { logger } from '@librechat/data-schemas'; import { codeExecutionAuthHeaders, codeExecutionHeaders, @@ -317,3 +320,124 @@ describe('resolveCodeExecutionContext', () => { ).toThrow('Stateful code environment "missing-vm" is not configured'); }); }); + +describe('codeExecutionAuthHeaders', () => { + let errorSpy: jest.SpyInstance; + + beforeEach(() => { + errorSpy = jest.spyOn(logger, 'error').mockImplementation(() => logger); + }); + + afterEach(() => { + errorSpy.mockRestore(); + }); + + it('logs the failure that reaches the model as a generic authorization error', async () => { + const failure = new Error('code API signing key is not configured'); + + await expect( + codeExecutionAuthHeaders(() => Promise.reject(failure), { + executionProfile: 'stateful', + bridgeWorkerId: 'opaque-worker-id', + }), + ).rejects.toBe(failure); + + expect(errorSpy).toHaveBeenCalledTimes(1); + expect(errorSpy).toHaveBeenCalledWith( + '[codeExecutionAuthHeaders] Failed to resolve Code API auth headers | Profile: stateful | Worker: opaque-worker-id | Cause: Error: code API signing key is not configured', + ); + }); + + it('omits the worker from the log when the request is not bridged', async () => { + await expect( + codeExecutionAuthHeaders( + () => { + throw new Error('boom'); + }, + { executionProfile: 'default' }, + ), + ).rejects.toThrow('boom'); + + expect(errorSpy).toHaveBeenCalledWith( + '[codeExecutionAuthHeaders] Failed to resolve Code API auth headers | Profile: default | Cause: Error: boom', + ); + }); + + it('describes a rejection that cannot be converted to a string, and still rethrows it', async () => { + const hostile = Object.create(null) as Record; + + await expect( + codeExecutionAuthHeaders(() => Promise.reject(hostile), { + executionProfile: 'default', + }), + ).rejects.toBe(hostile); + + expect(errorSpy).toHaveBeenCalledWith( + '[codeExecutionAuthHeaders] Failed to resolve Code API auth headers | Profile: default | Cause: undescribable rejection', + ); + }); + + it('describes a rejection whose accessors throw, and still rethrows it', async () => { + const hostile = new Proxy(new Error('boom'), { + get(): never { + throw new Error('accessor exploded'); + }, + }); + + await expect( + codeExecutionAuthHeaders(() => Promise.reject(hostile), { + executionProfile: 'default', + }), + ).rejects.toBe(hostile); + + expect(errorSpy).toHaveBeenCalledWith( + '[codeExecutionAuthHeaders] Failed to resolve Code API auth headers | Profile: default | Cause: undescribable rejection', + ); + }); + + it('renders the cause verbatim through the formats a deployment actually uses', async () => { + errorSpy.mockRestore(); + const rendered: string[] = []; + const capture = new winston.transports.Stream({ + stream: new Writable({ + write(chunk: Buffer, _encoding: string, done: () => void) { + rendered.push(String(chunk)); + done(); + }, + }), + /* `splat()` is what would consume a `%s` in the cause as a substitution + token, and the bare printf is the console transport that prints + `info.message` alone. Both have to leave the cause intact. */ + format: winston.format.combine( + winston.format.errors({ stack: true }), + winston.format.splat(), + winston.format.printf((info) => `${info.level}: ${info.message}`), + ), + }); + const silenced = logger.transports.map((transport) => { + const previous = transport.silent; + transport.silent = true; + return { transport, previous }; + }); + logger.add(capture); + + try { + await codeExecutionAuthHeaders( + () => Promise.reject(new Error('code API signing key is not configured')), + { executionProfile: 'stateful' }, + ).catch(() => undefined); + await codeExecutionAuthHeaders(() => Promise.reject('service said %s unavailable'), { + executionProfile: 'stateful', + }).catch(() => undefined); + } finally { + logger.remove(capture); + silenced.forEach(({ transport, previous }) => { + transport.silent = previous; + }); + } + + const output = rendered.join(''); + expect(output).toContain('Cause: Error: code API signing key is not configured'); + expect(output).toContain('Cause: service said %s unavailable'); + }); +}); diff --git a/packages/api/src/agents/execution.ts b/packages/api/src/agents/execution.ts index 6446ad9e24..5c7c9cadeb 100644 --- a/packages/api/src/agents/execution.ts +++ b/packages/api/src/agents/execution.ts @@ -1,4 +1,5 @@ import { createHash } from 'node:crypto'; +import { logger } from '@librechat/data-schemas'; import { Constants, getCodeBaseURL } from '@librechat/agents'; import type { CodeEnvironmentUserConfigSchema, @@ -192,14 +193,47 @@ export function codeExecutionHeaders( }; } +/** + * The cause belongs in the message rather than in winston metadata. A caught + * value passed as metadata is merged onto the log record, so a rejection + * carrying `tenantId`, `userId` or `event_name` would overwrite the request + * identity this log exists to provide; and any metadata makes `format.splat()` + * treat a `%s` in the cause as a substitution token. Every read is guarded: + * `String()` throws on a null-prototype object and a proxy can throw from a + * `name` or `message` accessor, either of which would otherwise replace the + * rejection with a formatting error and log nothing. + */ +function describeAuthFailure(error: unknown): string { + try { + return error instanceof Error ? `${error.name}: ${error.message}` : String(error); + } catch { + return 'undescribable rejection'; + } +} + +/** + * `@librechat/agents` replaces any throw from this callback with a fixed + * "not authorized" string before the model or the operator sees it, and its own + * console diagnostic carries no request or user id. This log is the only + * request-correlated record of why the headers could not be resolved. + */ export async function codeExecutionAuthHeaders( authHeaders: ( bridgeWorkerId?: string, ) => Promise> | Record, context: Pick, ): Promise> { - return { - ...(await authHeaders(context.bridgeWorkerId)), - ...codeExecutionHeaders(context), - }; + try { + return { + ...(await authHeaders(context.bridgeWorkerId)), + ...codeExecutionHeaders(context), + }; + } catch (error) { + logger.error( + `[codeExecutionAuthHeaders] Failed to resolve Code API auth headers | Profile: ${context.executionProfile}` + + (context.bridgeWorkerId != null ? ` | Worker: ${context.bridgeWorkerId}` : '') + + ` | Cause: ${describeAuthFailure(error)}`, + ); + throw error; + } } diff --git a/packages/api/src/auth/codeapi.spec.ts b/packages/api/src/auth/codeapi.spec.ts index 2d55c6ad19..59e5e9dbfc 100644 --- a/packages/api/src/auth/codeapi.spec.ts +++ b/packages/api/src/auth/codeapi.spec.ts @@ -361,4 +361,22 @@ describe('Code API JWT minting', () => { delete process.env.CODEAPI_JWT_ENABLED; await expect(getCodeApiAuthHeaders(baseRequest())).resolves.toEqual({}); }); + + it('does not echo signing material when the private JWK is malformed', async () => { + process.env.CODEAPI_JWT_PRIVATE_JWK_JSON = + '{"kty":"OKP","crv":"Ed25519","d":MIIEvgIBADANBgkqhkiG9w0BAQEFAASCBKgw,"x":"abc"}'; + + let failure: unknown; + try { + await mintCodeApiToken(baseRequest()); + } catch (caught) { + failure = caught; + } + + expect(failure).toBeInstanceOf(Error); + expect((failure as Error).message).toBe( + 'Code API JWT signing key could not be loaded (JWK format)', + ); + expect((failure as Error).message).not.toContain('MIIEvgIBAD'); + }); }); diff --git a/packages/api/src/auth/codeapi.ts b/packages/api/src/auth/codeapi.ts index 1d2688a1af..08048f7714 100644 --- a/packages/api/src/auth/codeapi.ts +++ b/packages/api/src/auth/codeapi.ts @@ -116,11 +116,24 @@ function parseCappedSeconds(value: string | undefined, fallback: number, max: nu return Math.min(Math.floor(parsed), max); } +/** + * A parse failure here must not propagate verbatim. Node's JSON `SyntaxError` + * quotes an excerpt of the source around the offending token, so a malformed + * private JWK puts signing material into a message that callers log; the + * message redaction patterns do not recognize a bare base64 fragment. Callers + * get the failure and its key format, never the key. + */ function createSigningKey(rawKey: string): KeyObject { - if (rawKey.startsWith('{')) { - return createPrivateKey({ key: JSON.parse(rawKey) as JsonWebKey, format: 'jwk' }); + const isJwk = rawKey.startsWith('{'); + try { + return isJwk + ? createPrivateKey({ key: JSON.parse(rawKey) as JsonWebKey, format: 'jwk' }) + : createPrivateKey(rawKey); + } catch { + throw new Error( + `Code API JWT signing key could not be loaded (${isJwk ? 'JWK' : 'PEM'} format)`, + ); } - return createPrivateKey(rawKey); } function getSigningConfig(): SigningConfig {