mirror of
https://github.com/danny-avila/LibreChat.git
synced 2026-10-22 18:13:27 +00:00
🪵 fix: Log Code API Auth Header Failures With Request Context (#15592)
* 🪵 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
This commit is contained in:
parent
c00acb36a0
commit
ee0a51ac19
7 changed files with 203 additions and 14 deletions
|
|
@ -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",
|
||||
|
|
|
|||
10
package-lock.json
generated
10
package-lock.json
generated
|
|
@ -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",
|
||||
|
|
|
|||
|
|
@ -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",
|
||||
|
|
|
|||
|
|
@ -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<string, never>;
|
||||
|
||||
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');
|
||||
});
|
||||
});
|
||||
|
|
|
|||
|
|
@ -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<string, string>> | Record<string, string>,
|
||||
context: Pick<CodeExecutionContext, 'executionProfile' | 'bridgeWorkerId'>,
|
||||
): Promise<Record<string, string>> {
|
||||
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;
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -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');
|
||||
});
|
||||
});
|
||||
|
|
|
|||
|
|
@ -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 {
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue