fix(logging): redact subsystem console output before colorizing

This commit is contained in:
Peter Steinberger
2026-04-28 07:24:37 +01:00
parent f2df49ab4b
commit df4d3fa5a9
2 changed files with 50 additions and 16 deletions

View File

@@ -9,10 +9,10 @@ import { createSubsystemLogger } from "./subsystem.js";
const logPathTracker = createSuiteLogPathTracker("openclaw-subsystem-log-");
function installConsoleMethodSpy(method: "warn" | "error") {
function installConsoleMethodSpy(method: "log" | "warn" | "error") {
const spy = vi.fn();
loggingState.rawConsole = {
log: vi.fn(),
log: method === "log" ? spy : vi.fn(),
info: vi.fn(),
warn: method === "warn" ? spy : vi.fn(),
error: method === "error" ? spy : vi.fn(),
@@ -29,6 +29,7 @@ afterEach(() => {
setLoggerOverride(null);
loggingState.rawConsole = null;
resetLogger();
vi.unstubAllEnvs();
vi.useRealTimers();
});
@@ -233,6 +234,36 @@ describe("createSubsystemLogger().isEnabled", () => {
expect(written).toContain("Bearer ");
});
it("redacts before colorizing subsystem console messages so ANSI reset codes survive", () => {
vi.stubEnv("FORCE_COLOR", "1");
setLoggerOverride({ level: "silent", consoleLevel: "info" });
const logSpy = installConsoleMethodSpy("log");
const log = createSubsystemLogger("gateway/auth");
const secret = "sk-abcdefghijklmnopqrstuvwxyz123456";
log.info(`provider API_KEY=${secret}`);
expect(logSpy).toHaveBeenCalledTimes(1);
const written = String(logSpy.mock.calls[0]?.[0] ?? "");
expect(written).not.toContain(secret);
expect(written).toContain("API_KEY=***");
expect(written.endsWith("\u001B[39m")).toBe(true);
});
it("redacts sensitive tokens from raw subsystem console output", () => {
setLoggerOverride({ level: "silent", consoleLevel: "info" });
const logSpy = installConsoleMethodSpy("log");
const log = createSubsystemLogger("gateway/auth");
const secret = "sk-rawtokenabcdefghijklmnopqrstuvwxyz123456";
log.raw(`raw token ${secret}`);
expect(logSpy).toHaveBeenCalledTimes(1);
const written = String(logSpy.mock.calls[0]?.[0] ?? "");
expect(written).not.toContain(secret);
expect(written).toContain("sk-raw…3456");
});
it("keeps long-lived subsystem loggers on the current-day rolling file", () => {
const logDir = path.dirname(logPathTracker.nextPath());
const firstDay = path.join(logDir, "openclaw-2026-01-01.log");

View File

@@ -216,13 +216,15 @@ function formatConsoleLine(opts: {
const displaySubsystem =
opts.style === "json" ? opts.subsystem : formatSubsystemForConsole(opts.subsystem);
if (opts.style === "json") {
return JSON.stringify({
time: formatConsoleTimestamp("json"),
level: opts.level,
subsystem: displaySubsystem,
message: opts.message,
...opts.meta,
});
return redactSensitiveText(
JSON.stringify({
time: formatConsoleTimestamp("json"),
level: opts.level,
subsystem: displaySubsystem,
message: opts.message,
...opts.meta,
}),
);
}
const color = getColorForConsole();
const prefix = `[${displaySubsystem}]`;
@@ -235,7 +237,8 @@ function formatConsoleLine(opts: {
: opts.level === "debug" || opts.level === "trace"
? color.gray
: color.cyan;
const displayMessage = stripRedundantSubsystemPrefixForConsole(opts.message, displaySubsystem);
const redactedMessage = redactSensitiveText(opts.message);
const displayMessage = stripRedundantSubsystemPrefixForConsole(redactedMessage, displaySubsystem);
const time = (() => {
if (opts.style === "pretty") {
return color.gray(formatConsoleTimestamp("pretty"));
@@ -250,18 +253,17 @@ function formatConsoleLine(opts: {
return `${head} ${levelColor(displayMessage)}`;
}
function writeConsoleLine(level: LogLevel, line: string) {
function writeConsoleLine(level: LogLevel, line: string, opts: { redacted?: boolean } = {}) {
clearActiveProgressLine();
const sanitized =
process.platform === "win32" && process.env.GITHUB_ACTIONS === "true"
? line.replace(/[\uD800-\uDBFF][\uDC00-\uDFFF]/g, "?").replace(/[\uD800-\uDFFF]/g, "?")
: line;
// Subsystem console output bypasses the patched console.* capture handler in
// ./console.ts to avoid recursion, so the sink-boundary redaction applied
// there does not run for these writes (#73284). Redact at this exit instead
// so secrets reaching subsystem loggers as message strings or formatted meta
// do not appear verbatim on the terminal.
const redacted = redactSensitiveText(sanitized);
// ./console.ts to avoid recursion. Normal formatted messages are redacted
// before colorization; keep this exit guard for raw writes and structured
// lines that reach the sink already serialized (#73284).
const redacted = opts.redacted ? sanitized : redactSensitiveText(sanitized);
const sink = loggingState.rawConsole ?? console;
if (loggingState.forceConsoleToStderr || level === "error" || level === "fatal") {
(sink.error ?? console.error)(redacted);
@@ -378,6 +380,7 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
style: consoleSettings.style,
meta: fileMeta,
}),
{ redacted: true },
);
};