🔊 fix: Preserve Log Metadata on Console for Warn/Error Levels

api/config/__tests__/parsers.spec.js

@@ -0,0 +1,136 @@
+const { formatConsoleMeta, redactMessage } = 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('');
+  });
+
+  it('redacts sensitive patterns inside string metadata values', () => {
+    const meta = formatConsoleMeta({
+      level: 'error',
+      message: 'leak test',
+      timestamp: 'ts',
+      openaiKey: 'sk-abc123def456',
+      auth: 'Bearer eyJhbGciOi...tokenvalue',
+      google: 'https://example.com/?key=AIzaSyXX',
+    });
+
+    expect(meta).not.toContain('sk-abc123def456');
+    expect(meta).not.toContain('eyJhbGciOi...tokenvalue');
+    expect(meta).not.toContain('AIzaSyXX');
+    expect(meta).toContain('sk-[REDACTED]');
+    expect(meta).toContain('Bearer [REDACTED]');
+    expect(meta).toContain('key=[REDACTED]');
+  });
+
+  it('redacts multiple occurrences of the same pattern in one value', () => {
+    const meta = formatConsoleMeta({
+      level: 'error',
+      message: 'two keys',
+      timestamp: 'ts',
+      combined: 'first sk-aaa and then sk-bbb',
+    });
+
+    expect(meta).not.toContain('sk-aaa');
+    expect(meta).not.toContain('sk-bbb');
+    expect(meta.match(/sk-\[REDACTED\]/g)?.length).toBe(2);
+  });
+});
+
+describe('redactMessage', () => {
+  it('redacts sk- keys that are not at line start (inside JSON-like text)', () => {
+    const input = '{"apiKey":"sk-abc123"}';
+    expect(redactMessage(input)).toBe('{"apiKey":"sk-[REDACTED]"}');
+  });
+
+  it('redacts all sk- occurrences in a single pass', () => {
+    const input = 'sk-one sk-two sk-three';
+    expect(redactMessage(input)).toBe('sk-[REDACTED] sk-[REDACTED] sk-[REDACTED]');
+  });
+
+  it('trims redacted output when trimLength is provided', () => {
+    const input = 'Bearer supersecretvalue';
+    expect(redactMessage(input, 10)).toBe('Bearer [RE...');
+  });
+
+  it('returns empty string for falsy input', () => {
+    expect(redactMessage('')).toBe('');
+    expect(redactMessage(undefined)).toBe('');
+  });
+});

api/config/parsers.js

@@ -8,26 +8,12 @@ const CONSOLE_JSON_STRING_LENGTH = parseInt(process.env.CONSOLE_JSON_STRING_LENG
 const DEBUG_MESSAGE_LENGTH = parseInt(process.env.DEBUG_MESSAGE_LENGTH) || 150;
 
 const sensitiveKeys = [
-  /^(sk-)[^\s]+/, // OpenAI API key pattern
-  /(Bearer )[^\s]+/, // Header: Bearer token pattern
-  /(api-key:? )[^\s]+/, // Header: API key pattern
-  /(key=)[^\s]+/, // URL query param: sensitive key pattern (Google)
+  /(sk-)[^\s"']+/g, // OpenAI API key pattern (also catches keys embedded in JSON/quoted strings)
+  /(Bearer )[^\s"']+/g, // Header: Bearer token pattern
+  /(api-key:? )[^\s"']+/g, // Header: API key pattern
+  /(key=)[^\s"']+/g, // URL query param: sensitive key pattern (Google)
 ];
 
-/**
- * Determines if a given value string is sensitive and returns matching regex patterns.
- *
- * @param {string} valueStr - The value string to check.
- * @returns {Array<RegExp>} An array of regex patterns that match the value string.
- */
-function getMatchingSensitivePatterns(valueStr) {
-  if (valueStr) {
-    // Filter and return all regex patterns that match the value string
-    return sensitiveKeys.filter((regex) => regex.test(valueStr));
-  }
-  return [];
-}
-
 /**
  * Redacts sensitive information from a console message and trims it to a specified length if provided.
  * @param {string} str - The console message to be redacted.
@@ -39,16 +25,16 @@ function redactMessage(str, trimLength) {
     return '';
   }
 
-  const patterns = getMatchingSensitivePatterns(str);
-  patterns.forEach((pattern) => {
-    str = str.replace(pattern, '$1[REDACTED]');
-  });
+  let redacted = str;
+  for (const pattern of sensitiveKeys) {
+    redacted = redacted.replace(pattern, '$1[REDACTED]');
+  }
 
-  if (trimLength !== undefined && str.length > trimLength) {
-    return `${str.substring(0, trimLength)}...`;
+  if (trimLength !== undefined && redacted.length > trimLength) {
+    return `${redacted.substring(0, trimLength)}...`;
   }
 
-  return str;
+  return redacted;
 }
 
 /**
@@ -96,6 +82,64 @@ 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') {
+        return value;
+      }
+      const safe = redactMessage(value);
+      return safe.length > CONSOLE_JSON_STRING_LENGTH
+        ? `${safe.substring(0, CONSOLE_JSON_STRING_LENGTH)}...`
+        : safe;
+    });
+  } catch {
+    return '';
+  }
+}
+
 /**
  * Formats log messages for debugging purposes.
  * - Truncates long strings within log messages.
@@ -121,15 +165,17 @@ 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;
     }
 
     if (!metadata) {
       return msg;
     }
 
-    const debugValue = metadata[SPLAT_SYMBOL]?.[0];
+    const debugValue = metadata[SPLAT_SYMBOL]?.[0] ?? extractMetaObject(metadata);
 
     if (!debugValue) {
       return msg;
@@ -229,4 +275,5 @@ module.exports = {
   redactMessage,
   debugTraverse,
   jsonTruncateFormat,
+  formatConsoleMeta,
 };

api/config/winston.js

@@ -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 || isWarn) {
+      return redactMessage(line);
+    }
+
+    return line;
   }),
 );
 

api/test/__mocks__/logger.js

@@ -56,5 +56,6 @@ jest.mock('~/config/parsers', () => {
     redactMessage: jest.fn(),
     redactFormat: jest.fn(),
     debugTraverse: jest.fn(),
+    formatConsoleMeta: jest.fn(() => ''),
   };
 });