mirror of
https://github.com/danny-avila/LibreChat.git
synced 2026-05-13 16:07:30 +00:00
🔊 fix: Preserve Log Metadata on Console for Warn/Error Levels
The default console formatter discarded every structured metadata key on the winston info object — only `CONSOLE_JSON=true` preserved it. That meant failures emitted by the agents SDK (e.g. "Summarization LLM call failed") reached stdout without the provider, model, or underlying error attached, leaving users unable to diagnose the root cause. - Add `formatConsoleMeta` helper to serialize non-reserved metadata as a compact JSON trailer, with per-value string truncation and safe handling of circular references. - Append the metadata trailer to warn/error console lines; info/debug behavior is unchanged. - Relax `debugTraverse`'s debug-only gate so warn/error messages routed through the debug formatter also surface their metadata. - Add a `formatConsoleMeta` stub to the shared logger mock so existing tests keep working.
This commit is contained in:
parent
b579390287
commit
59371be035
4 changed files with 166 additions and 7 deletions
83
api/config/__tests__/parsers.spec.js
Normal file
83
api/config/__tests__/parsers.spec.js
Normal file
|
|
@ -0,0 +1,83 @@
|
|||
const { formatConsoleMeta } = jest.requireActual('../parsers');
|
||||
|
||||
describe('formatConsoleMeta', () => {
|
||||
it('returns empty string when there is no user metadata', () => {
|
||||
expect(
|
||||
formatConsoleMeta({
|
||||
level: 'error',
|
||||
message: 'oops',
|
||||
timestamp: '2026-04-18 02:25:22',
|
||||
}),
|
||||
).toBe('');
|
||||
});
|
||||
|
||||
it('serializes user-supplied metadata keys', () => {
|
||||
const meta = formatConsoleMeta({
|
||||
level: 'error',
|
||||
message: '[agents:summarize] Summarization LLM call failed',
|
||||
timestamp: '2026-04-18 02:25:22',
|
||||
provider: 'azureOpenAI',
|
||||
model: 'gpt-5.4-mini',
|
||||
messagesToRefineCount: 42,
|
||||
});
|
||||
|
||||
expect(meta).toContain('"provider":"azureOpenAI"');
|
||||
expect(meta).toContain('"model":"gpt-5.4-mini"');
|
||||
expect(meta).toContain('"messagesToRefineCount":42');
|
||||
});
|
||||
|
||||
it('ignores reserved winston keys and underscore-prefixed internals', () => {
|
||||
const meta = formatConsoleMeta({
|
||||
level: 'error',
|
||||
message: 'boom',
|
||||
timestamp: 'ts',
|
||||
splat: [1, 2],
|
||||
_internal: 'skip',
|
||||
userField: 'keep',
|
||||
});
|
||||
|
||||
expect(meta).toBe('{"userField":"keep"}');
|
||||
});
|
||||
|
||||
it('drops empty, null, undefined, function, and symbol values', () => {
|
||||
const meta = formatConsoleMeta({
|
||||
level: 'warn',
|
||||
message: 'noise',
|
||||
timestamp: 'ts',
|
||||
empty: '',
|
||||
nullish: null,
|
||||
undef: undefined,
|
||||
fn: () => 1,
|
||||
sym: Symbol('x'),
|
||||
kept: 'yes',
|
||||
});
|
||||
|
||||
expect(meta).toBe('{"kept":"yes"}');
|
||||
});
|
||||
|
||||
it('truncates very long string values to avoid console spam', () => {
|
||||
const longString = 'x'.repeat(5000);
|
||||
const meta = formatConsoleMeta({
|
||||
level: 'error',
|
||||
message: 'long',
|
||||
timestamp: 'ts',
|
||||
errorStack: longString,
|
||||
});
|
||||
|
||||
expect(meta.length).toBeLessThan(longString.length);
|
||||
expect(meta).toContain('...');
|
||||
});
|
||||
|
||||
it('gracefully handles circular objects', () => {
|
||||
const circular = {};
|
||||
circular.self = circular;
|
||||
const meta = formatConsoleMeta({
|
||||
level: 'error',
|
||||
message: 'circular',
|
||||
timestamp: 'ts',
|
||||
circular,
|
||||
});
|
||||
|
||||
expect(meta).toBe('');
|
||||
});
|
||||
});
|
||||
|
|
@ -96,6 +96,61 @@ const condenseArray = (item) => {
|
|||
return item;
|
||||
};
|
||||
|
||||
const RESERVED_LOG_KEYS = new Set(['level', 'message', 'timestamp', 'splat']);
|
||||
|
||||
/**
|
||||
* Extracts user-supplied metadata from a winston info object, filtering out
|
||||
* reserved keys, internal underscore-prefixed keys, and non-serializable values.
|
||||
*
|
||||
* @param {Record<string, unknown>} source - The object to extract metadata from.
|
||||
* @returns {Record<string, unknown> | undefined} - The extracted metadata, or undefined if empty.
|
||||
*/
|
||||
function extractMetaObject(source) {
|
||||
if (source == null || typeof source !== 'object') {
|
||||
return undefined;
|
||||
}
|
||||
const meta = {};
|
||||
for (const key of Object.keys(source)) {
|
||||
if (RESERVED_LOG_KEYS.has(key) || key.startsWith('_')) {
|
||||
continue;
|
||||
}
|
||||
const value = source[key];
|
||||
if (value === undefined || value === null || value === '') {
|
||||
continue;
|
||||
}
|
||||
if (typeof value === 'function' || typeof value === 'symbol') {
|
||||
continue;
|
||||
}
|
||||
meta[key] = value;
|
||||
}
|
||||
return Object.keys(meta).length > 0 ? meta : undefined;
|
||||
}
|
||||
|
||||
/**
|
||||
* Formats the metadata portion of a winston info object as a compact
|
||||
* single-line JSON trailer, suitable for appending to the console message.
|
||||
* Returns an empty string when there is no meaningful metadata.
|
||||
*
|
||||
* @param {Record<string, unknown>} info - The winston info object.
|
||||
* @returns {string} - The serialized metadata, or an empty string.
|
||||
*/
|
||||
function formatConsoleMeta(info) {
|
||||
const meta = extractMetaObject(info);
|
||||
if (!meta) {
|
||||
return '';
|
||||
}
|
||||
try {
|
||||
return JSON.stringify(meta, (_key, value) => {
|
||||
if (typeof value === 'string' && value.length > CONSOLE_JSON_STRING_LENGTH) {
|
||||
return `${value.substring(0, CONSOLE_JSON_STRING_LENGTH)}...`;
|
||||
}
|
||||
return value;
|
||||
});
|
||||
} catch {
|
||||
return '';
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Formats log messages for debugging purposes.
|
||||
* - Truncates long strings within log messages.
|
||||
|
|
@ -121,7 +176,9 @@ const debugTraverse = winston.format.printf(({ level, message, timestamp, ...met
|
|||
|
||||
let msg = `${timestamp} ${level}: ${truncateLongStrings(message?.trim(), DEBUG_MESSAGE_LENGTH)}`;
|
||||
try {
|
||||
if (level !== 'debug') {
|
||||
const levelStr = typeof level === 'string' ? level : String(level);
|
||||
const isErrorOrWarn = levelStr.includes('error') || levelStr.includes('warn');
|
||||
if (level !== 'debug' && !isErrorOrWarn) {
|
||||
return msg;
|
||||
}
|
||||
|
||||
|
|
@ -129,7 +186,7 @@ const debugTraverse = winston.format.printf(({ level, message, timestamp, ...met
|
|||
return msg;
|
||||
}
|
||||
|
||||
const debugValue = metadata[SPLAT_SYMBOL]?.[0];
|
||||
const debugValue = metadata[SPLAT_SYMBOL]?.[0] ?? extractMetaObject(metadata);
|
||||
|
||||
if (!debugValue) {
|
||||
return msg;
|
||||
|
|
@ -229,4 +286,5 @@ module.exports = {
|
|||
redactMessage,
|
||||
debugTraverse,
|
||||
jsonTruncateFormat,
|
||||
formatConsoleMeta,
|
||||
};
|
||||
|
|
|
|||
|
|
@ -2,7 +2,13 @@ const path = require('path');
|
|||
const fs = require('fs');
|
||||
const winston = require('winston');
|
||||
require('winston-daily-rotate-file');
|
||||
const { redactFormat, redactMessage, debugTraverse, jsonTruncateFormat } = require('./parsers');
|
||||
const {
|
||||
redactFormat,
|
||||
redactMessage,
|
||||
debugTraverse,
|
||||
jsonTruncateFormat,
|
||||
formatConsoleMeta,
|
||||
} = require('./parsers');
|
||||
|
||||
/**
|
||||
* Determine the log directory.
|
||||
|
|
@ -110,12 +116,23 @@ const consoleFormat = winston.format.combine(
|
|||
winston.format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }),
|
||||
// redactErrors(),
|
||||
winston.format.printf((info) => {
|
||||
const message = `${info.timestamp} ${info.level}: ${info.message}`;
|
||||
if (info.level.includes('error')) {
|
||||
return redactMessage(message);
|
||||
const base = `${info.timestamp} ${info.level}: ${info.message}`;
|
||||
const isError = info.level.includes('error');
|
||||
const isWarn = info.level.includes('warn');
|
||||
|
||||
let line = base;
|
||||
if (isError || isWarn) {
|
||||
const metaTrailer = formatConsoleMeta(info);
|
||||
if (metaTrailer) {
|
||||
line = `${base} ${metaTrailer}`;
|
||||
}
|
||||
}
|
||||
|
||||
return message;
|
||||
if (isError) {
|
||||
return redactMessage(line);
|
||||
}
|
||||
|
||||
return line;
|
||||
}),
|
||||
);
|
||||
|
||||
|
|
|
|||
|
|
@ -56,5 +56,6 @@ jest.mock('~/config/parsers', () => {
|
|||
redactMessage: jest.fn(),
|
||||
redactFormat: jest.fn(),
|
||||
debugTraverse: jest.fn(),
|
||||
formatConsoleMeta: jest.fn(() => ''),
|
||||
};
|
||||
});
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue