feat(logging): add credential-redaction safety net in the pino logger (#4140)

Credential-redaction safety net (FCC port, Fase 8.3): defense-in-depth pino logMethod hook, ReDoS-bounded patterns, behavior-preserving. Integrado em release/v3.8.29.

src/shared/utils/logRedaction.ts

@@ -0,0 +1,108 @@
+/**
+ * Log redaction safety net (free-claude-code port, Fase 8.3).
+ *
+ * Final defense-in-depth layer: scrubs credentials that slip into log MESSAGES or
+ * arbitrary object/error values, regardless of call site. It complements — does not
+ * replace — the call-site maskers (`src/mitm/maskSecrets.ts`, `src/lib/logPayloads.ts`),
+ * and runs in the pino `hooks.logMethod` (main thread, so it works with transports).
+ *
+ * Patterns are strictly bounded (single, non-overlapping character classes with `{n,}`
+ * limits) to avoid catastrophic backtracking on untrusted input — see CLAUDE.md
+ * "PII & Stream Sanitization Learnings" §1.
+ */
+
+const CENSOR = "[REDACTED]";
+
+// Cheap pre-test: skip the (still bounded) replace work entirely for clean strings.
+const SECRET_HINT = /bearer|telegram\.org\/bot|api[_-]?key|authorization|sk-/i;
+
+const PATTERNS: ReadonlyArray<readonly [RegExp, string]> = [
+  // Authorization: Bearer <token>  /  authorization=Bearer <token>
+  [/(authorization\s*[:=]\s*bearer\s+)[\w.\-]{6,}/gi, `$1${CENSOR}`],
+  // bare "Bearer <token>"
+  [/\bbearer\s+[\w.\-]{12,}/gi, `Bearer ${CENSOR}`],
+  // x-api-key: <val>  /  api_key=<val>
+  [/((?:x-api-key|api[_-]?key)\s*[:=]\s*)[\w.\-]{6,}/gi, `$1${CENSOR}`],
+  // Telegram bot token in a URL: api.telegram.org/bot<digits>:<token>
+  [/(api\.telegram\.org\/bot)\d{6,}:[\w\-]{20,}/gi, `$1${CENSOR}`],
+  // OpenAI-style keys: sk-... (also sk-proj-...)
+  [/\bsk-[A-Za-z0-9_\-]{16,}/g, `sk-${CENSOR}`],
+];
+
+const MAX_DEPTH = 6;
+const MAX_NODES = 2000;
+
+/** Redact secrets from a single string. Returns the same string when nothing matches. */
+export function redactSecrets(text: string): string {
+  if (typeof text !== "string" || text.length === 0 || !SECRET_HINT.test(text)) return text;
+  let out = text;
+  for (const [pattern, replacement] of PATTERNS) {
+    out = out.replace(pattern, replacement);
+  }
+  return out;
+}
+
+interface RedactState {
+  budget: number;
+  seen: WeakSet<object>;
+}
+
+function redactValue(value: unknown, depth: number, state: RedactState): unknown {
+  if (state.budget <= 0 || depth > MAX_DEPTH) return value;
+  state.budget -= 1;
+
+  if (typeof value === "string") return redactSecrets(value);
+  if (value === null || typeof value !== "object") return value;
+  if (state.seen.has(value)) return value; // circular guard
+  state.seen.add(value);
+
+  if (value instanceof Error) {
+    const message = redactSecrets(value.message || "");
+    const stack = redactSecrets(value.stack || "");
+    // Untouched error → keep the original instance so pino's err serializer still runs.
+    if (message === (value.message || "") && stack === (value.stack || "")) return value;
+    // Return a redacted CLONE (not the original — it may be used elsewhere) that is still
+    // a real Error, so pino's err serializer produces the usual {type, message, stack}.
+    const cloned = new Error(message);
+    cloned.name = value.name;
+    cloned.stack = stack;
+    return cloned;
+  }
+
+  if (Array.isArray(value)) {
+    let changed = false;
+    const out = value.map((item) => {
+      const redacted = redactValue(item, depth + 1, state);
+      if (redacted !== item) changed = true;
+      return redacted;
+    });
+    return changed ? out : value;
+  }
+
+  let changed = false;
+  const out: Record<string, unknown> = {};
+  for (const key of Object.keys(value as Record<string, unknown>)) {
+    const original = (value as Record<string, unknown>)[key];
+    const redacted = redactValue(original, depth + 1, state);
+    if (redacted !== original) changed = true;
+    out[key] = redacted;
+  }
+  return changed ? out : value;
+}
+
+/**
+ * Redact every log argument (message string + structured objects/errors). Allocation-
+ * and behavior-preserving: when nothing is redacted the original arguments are returned
+ * unchanged. Bounded by node budget + depth and circular-reference safe.
+ */
+export function redactLogArgs(args: unknown[]): unknown[] {
+  if (!Array.isArray(args) || args.length === 0) return args;
+  const state: RedactState = { budget: MAX_NODES, seen: new WeakSet() };
+  let changed = false;
+  const out = args.map((arg) => {
+    const redacted = redactValue(arg, 0, state);
+    if (redacted !== arg) changed = true;
+    return redacted;
+  });
+  return changed ? out : args;
+}

src/shared/utils/logger.ts

@@ -17,6 +17,7 @@ import pino from "pino";
 import { resolve } from "path";
 import { getLogConfig, initLogRotation } from "@/lib/logRotation";
 import { getAppLogLevel } from "@/lib/logEnv";
+import { redactLogArgs } from "@/shared/utils/logRedaction";
 
 const isDev = process.env.NODE_ENV !== "production";
 
@@ -29,6 +30,13 @@ const baseConfig: pino.LoggerOptions = {
       return { level: label };
     },
   },
+  // Final defense-in-depth redaction net: runs in the main thread (transport-safe) and
+  // scrubs credentials that slip into any log message/object/error. See logRedaction.ts.
+  hooks: {
+    logMethod(inputArgs: unknown[], method: (...args: unknown[]) => void) {
+      return (method as (...a: unknown[]) => void).apply(this, redactLogArgs(inputArgs));
+    },
+  },
 };
 
 function getTransportCompatibleConfig(): pino.LoggerOptions {

tests/unit/log-redaction.test.ts

@@ -0,0 +1,101 @@
+import { test } from "node:test";
+import assert from "node:assert/strict";
+
+import { redactSecrets, redactLogArgs } from "../../src/shared/utils/logRedaction.ts";
+
+test("redactSecrets removes Authorization: Bearer tokens", () => {
+  const out = redactSecrets("upstream failed; Authorization: Bearer sk-abc123DEF456ghi789");
+  assert.match(out, /Authorization: Bearer \[REDACTED\]/);
+  assert.doesNotMatch(out, /sk-abc123/);
+});
+
+test("redactSecrets removes a bare bearer token", () => {
+  const out = redactSecrets("header bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.payload.sig");
+  assert.match(out, /Bearer \[REDACTED\]/i);
+});
+
+test("redactSecrets removes x-api-key values", () => {
+  const out = redactSecrets("sent x-api-key: 9f8e7d6c5b4a3210ffff");
+  assert.match(out, /x-api-key: \[REDACTED\]/i);
+  assert.doesNotMatch(out, /9f8e7d6c/);
+});
+
+test("redactSecrets removes a Telegram bot token in a URL", () => {
+  const out = redactSecrets("posting to https://api.telegram.org/bot123456789:AAExampleTokenValue_abcdEFGH/send");
+  assert.match(out, /api\.telegram\.org\/bot\[REDACTED\]/);
+  assert.doesNotMatch(out, /AAExampleTokenValue/);
+});
+
+test("redactSecrets removes sk- style API keys anywhere", () => {
+  const out = redactSecrets("key=sk-proj-ABCDEFGHIJ1234567890 done");
+  assert.match(out, /sk-\[REDACTED\]/);
+  assert.doesNotMatch(out, /ABCDEFGHIJ1234567890/);
+});
+
+test("redactSecrets returns clean strings unchanged (same reference)", () => {
+  const clean = "request completed in 42ms for model gpt-4o";
+  assert.equal(redactSecrets(clean), clean);
+});
+
+test("redactSecrets is bounded on adversarial input (no catastrophic backtracking)", () => {
+  const huge = "Authorization: Bearer " + "a".repeat(2_000_000);
+  const start = Date.now();
+  const out = redactSecrets(huge);
+  assert.ok(Date.now() - start < 1000, "must not hang");
+  assert.match(out, /\[REDACTED\]/);
+});
+
+test("redactLogArgs scrubs a string message argument", () => {
+  const [msg] = redactLogArgs(["call failed: Authorization: Bearer sk-secret1234567890abcd"]);
+  assert.doesNotMatch(String(msg), /sk-secret/);
+  assert.match(String(msg), /\[REDACTED\]/);
+});
+
+test("redactLogArgs scrubs nested object string values", () => {
+  const [obj] = redactLogArgs([
+    { req: { headers: { authorization: "Bearer sk-deadbeefdeadbeef1234" } }, model: "gpt-4o" },
+  ]) as [{ req: { headers: { authorization: string } }; model: string }];
+  assert.doesNotMatch(obj.req.headers.authorization, /sk-deadbeef/);
+  assert.match(obj.req.headers.authorization, /\[REDACTED\]/);
+  assert.equal(obj.model, "gpt-4o", "non-secret fields are preserved");
+});
+
+test("redactLogArgs scrubs an Error's message and stack when a secret is present", () => {
+  const err = new Error("connect failed with Authorization: Bearer sk-leakedKey1234567890");
+  const [scrubbed] = redactLogArgs([err]) as [Error];
+  assert.notEqual(scrubbed, err, "a secret-bearing error is replaced with a redacted clone");
+  assert.ok(scrubbed instanceof Error, "the redacted view is still a real Error");
+  assert.doesNotMatch(scrubbed.message, /sk-leakedKey/);
+  assert.match(scrubbed.message, /\[REDACTED\]/);
+  assert.doesNotMatch(String(scrubbed.stack), /sk-leakedKey/);
+});
+
+test("redactLogArgs leaves a clean Error untouched (preserves pino's serializer)", () => {
+  const err = new Error("plain timeout after 30s");
+  const [same] = redactLogArgs([err]);
+  assert.equal(same, err, "no secret → original Error instance is returned unchanged");
+});
+
+test("redactLogArgs returns the original object when nothing was redacted (no allocation)", () => {
+  const obj = { model: "gpt-4o", tokens: 42, nested: { a: "b" } };
+  const [same] = redactLogArgs([obj]);
+  assert.equal(same, obj, "clean object identity is preserved");
+});
+
+test("redactLogArgs survives circular references", () => {
+  const a: Record<string, unknown> = { name: "a" };
+  a.self = a;
+  assert.doesNotThrow(() => redactLogArgs([a]));
+});
+
+test("redactLogArgs is bounded on huge/deep objects", () => {
+  const deep: Record<string, unknown> = {};
+  let cur = deep;
+  for (let i = 0; i < 10_000; i++) {
+    cur.next = { token: "Bearer sk-xxxxxxxxxxxxxxxx" };
+    cur = cur.next as Record<string, unknown>;
+  }
+  const start = Date.now();
+  assert.doesNotThrow(() => redactLogArgs([deep]));
+  assert.ok(Date.now() - start < 1000, "must stay bounded on pathological structures");
+});

tests/unit/logger-redaction-wiring.test.ts

@@ -0,0 +1,47 @@
+import { test } from "node:test";
+import assert from "node:assert/strict";
+import { mkdtempSync, readFileSync, existsSync } from "node:fs";
+import { tmpdir } from "node:os";
+import { join } from "node:path";
+
+// Configure file logging BEFORE importing the logger (buildLogger runs at import time).
+const dir = mkdtempSync(join(tmpdir(), "omniroute-logredact-"));
+const logFile = join(dir, "app.log");
+process.env.NODE_ENV = "production"; // JSON to file, no pino-pretty
+process.env.APP_LOG_TO_FILE = "true";
+process.env.APP_LOG_FILE_PATH = logFile;
+process.env.APP_LOG_LEVEL = "debug";
+
+const { createLogger } = await import("../../src/shared/utils/logger.ts");
+
+/** Poll the (worker-thread-written) log file until the predicate holds or timeout. */
+async function readLogWhen(
+  predicate: (contents: string) => boolean,
+  timeoutMs = 4000
+): Promise<string> {
+  const start = Date.now();
+  while (Date.now() - start < timeoutMs) {
+    if (existsSync(logFile)) {
+      const contents = readFileSync(logFile, "utf8");
+      if (predicate(contents)) return contents;
+    }
+    await new Promise((r) => setTimeout(r, 50));
+  }
+  return existsSync(logFile) ? readFileSync(logFile, "utf8") : "";
+}
+
+test("logger redacts a Bearer secret in a free-form message and an error stack (end-to-end)", async () => {
+  const log = createLogger("redact-test");
+
+  log.info("upstream call Authorization: Bearer sk-superSecretKey1234567890done");
+  const err = new Error("boom while sending Authorization: Bearer sk-anotherSecretABCDEFGH12");
+  log.error({ err }, "request failed");
+
+  const contents = await readLogWhen(
+    (c) => c.includes("[REDACTED]") && !c.includes("sk-superSecretKey") && !c.includes("sk-anotherSecret")
+  );
+
+  assert.match(contents, /\[REDACTED\]/, "redaction marker must appear in the log output");
+  assert.doesNotMatch(contents, /sk-superSecretKey/, "message secret must be redacted");
+  assert.doesNotMatch(contents, /sk-anotherSecret/, "error-stack secret must be redacted");
+});