diff --git a/src/agents/model-fallback.probe.test.ts b/src/agents/model-fallback.probe.test.ts index d7b359e10bd..ff9a0e045fd 100644 --- a/src/agents/model-fallback.probe.test.ts +++ b/src/agents/model-fallback.probe.test.ts @@ -2,6 +2,7 @@ import os from "node:os"; import path from "node:path"; import { afterEach, beforeAll, beforeEach, describe, expect, it, vi } from "vitest"; import type { OpenClawConfig } from "../config/config.js"; +import { createDiagnosticLogRecordCapture } from "../logging/test-helpers/diagnostic-log-capture.js"; import type { AuthProfileStore } from "./auth-profiles.js"; import { makeModelFallbackCfg } from "./test-helpers/model-fallback-config-fixture.js"; @@ -56,12 +57,11 @@ let mockedResolveAuthProfileOrder: ReturnType< >; let runWithModelFallback: ModelFallbackModule["runWithModelFallback"]; let _probeThrottleInternals: ModelFallbackModule["_probeThrottleInternals"]; -let registerLogTransport: LoggerModule["registerLogTransport"]; let resetLogger: LoggerModule["resetLogger"]; let setLoggerOverride: LoggerModule["setLoggerOverride"]; const makeCfg = makeModelFallbackCfg; -let unregisterLogTransport: (() => void) | undefined; +let cleanupLogCapture: (() => void) | undefined; async function loadModelFallbackProbeModules() { const authProfilesStoreModule = await import("./auth-profiles/store.js"); @@ -82,7 +82,6 @@ async function loadModelFallbackProbeModules() { mockedResolveAuthProfileOrder = vi.mocked(authProfilesOrderModule.resolveAuthProfileOrder); runWithModelFallback = modelFallbackModule.runWithModelFallback; _probeThrottleInternals = modelFallbackModule._probeThrottleInternals; - registerLogTransport = loggerModule.registerLogTransport; resetLogger = loggerModule.resetLogger; setLoggerOverride = loggerModule.setLoggerOverride; } @@ -236,8 +235,8 @@ describe("runWithModelFallback – probe logic", () => { afterEach(() => { Date.now = realDateNow; - unregisterLogTransport?.(); - unregisterLogTransport = undefined; + cleanupLogCapture?.(); + cleanupLogCapture = undefined; setLoggerOverride(null); resetLogger(); vi.restoreAllMocks(); @@ -275,16 +274,14 @@ describe("runWithModelFallback – probe logic", () => { it("logs primary metadata on probe success and failure fallback decisions", async () => { const cfg = makeCfg(); - const records: Array> = []; + const logCapture = createDiagnosticLogRecordCapture(); + cleanupLogCapture = logCapture.cleanup; mockedGetSoonestCooldownExpiry.mockReturnValue(NOW + 60 * 1000); setLoggerOverride({ level: "trace", consoleLevel: "silent", file: path.join(os.tmpdir(), `openclaw-model-fallback-probe-${Date.now()}.log`), }); - unregisterLogTransport = registerLogTransport((record) => { - records.push(record); - }); const run = vi.fn().mockResolvedValue("probed-ok"); @@ -311,6 +308,7 @@ describe("runWithModelFallback – probe logic", () => { .mockResolvedValueOnce("fallback-ok"); const fallbackResult = await runPrimaryCandidate(fallbackCfg, fallbackRun); + await logCapture.flush(); expect(fallbackResult.result).toBe("fallback-ok"); expect(fallbackRun).toHaveBeenNthCalledWith(1, "openai", "gpt-4.1-mini", { @@ -318,14 +316,9 @@ describe("runWithModelFallback – probe logic", () => { }); expect(fallbackRun).toHaveBeenNthCalledWith(2, "anthropic", "claude-haiku-3-5"); - const decisionPayloads = records - .filter( - (record) => - record["2"] === "model fallback decision" && - record["1"] && - typeof record["1"] === "object", - ) - .map((record) => record["1"] as Record); + const decisionPayloads = logCapture.records + .filter((record) => record.message === "model fallback decision") + .map((record) => record.attributes ?? {}); expect(decisionPayloads).toEqual( expect.arrayContaining([ diff --git a/src/agents/model-fallback.test.ts b/src/agents/model-fallback.test.ts index b11456ecb5c..e9be6319e88 100644 --- a/src/agents/model-fallback.test.ts +++ b/src/agents/model-fallback.test.ts @@ -1014,7 +1014,7 @@ describe("runWithModelFallback", () => { }); expect(result.result).toBe("ok"); - const warning = warnLogs.findText('Model "openai/gpt-6spoof" not found'); + const warning = await warnLogs.findText('Model "openai/gpt-6spoof" not found'); expect(warning).toContain('Model "openai/gpt-6spoof" not found'); expect(warning).not.toContain("\u001B"); expect(warning).not.toContain("\n"); diff --git a/src/agents/model-selection.test.ts b/src/agents/model-selection.test.ts index 57597e392cb..b7de04c4f7b 100644 --- a/src/agents/model-selection.test.ts +++ b/src/agents/model-selection.test.ts @@ -966,7 +966,7 @@ describe("model-selection", () => { } }); - it("sanitizes control characters in providerless-model warnings", () => { + it("sanitizes control characters in providerless-model warnings", async () => { const warnLogs = createWarnLogCapture("openclaw-model-selection-test"); try { const cfg: Partial = { @@ -987,7 +987,7 @@ describe("model-selection", () => { provider: "google", model: "\u001B[31mclaude-3-5-sonnet\nspoof", }); - const warning = warnLogs.findText('Falling back to "google/claude-3-5-sonnet"'); + const warning = await warnLogs.findText('Falling back to "google/claude-3-5-sonnet"'); expect(warning).toContain('Falling back to "google/claude-3-5-sonnet"'); expect(warning).not.toContain("\u001B"); expect(warning).not.toContain("\n"); diff --git a/src/agents/pi-embedded-runner.run-embedded-pi-agent.auth-profile-rotation.e2e.test.ts b/src/agents/pi-embedded-runner.run-embedded-pi-agent.auth-profile-rotation.e2e.test.ts index b242e091993..21ba2f372b3 100644 --- a/src/agents/pi-embedded-runner.run-embedded-pi-agent.auth-profile-rotation.e2e.test.ts +++ b/src/agents/pi-embedded-runner.run-embedded-pi-agent.auth-profile-rotation.e2e.test.ts @@ -106,8 +106,8 @@ const installRunEmbeddedMocks = () => { }; let runEmbeddedPiAgent: typeof import("./pi-embedded-runner/run.js").runEmbeddedPiAgent; -let unregisterLogTransport: (() => void) | undefined; -let registerLogTransportFn: typeof import("../logging/logger.js").registerLogTransport; +let createDiagnosticLogRecordCaptureFn: typeof import("../logging/test-helpers/diagnostic-log-capture.js").createDiagnosticLogRecordCapture; +let cleanupLogCapture: (() => void) | undefined; let resetLoggerFn: typeof import("../logging/logger.js").resetLogger; let setLoggerOverrideFn: typeof import("../logging/logger.js").setLoggerOverride; const originalFetch = globalThis.fetch; @@ -116,11 +116,10 @@ beforeAll(async () => { vi.resetModules(); installRunEmbeddedMocks(); ({ runEmbeddedPiAgent } = await import("./pi-embedded-runner/run.js")); - ({ - registerLogTransport: registerLogTransportFn, - resetLogger: resetLoggerFn, - setLoggerOverride: setLoggerOverrideFn, - } = await import("../logging/logger.js")); + ({ createDiagnosticLogRecordCapture: createDiagnosticLogRecordCaptureFn } = + await import("../logging/test-helpers/diagnostic-log-capture.js")); + ({ resetLogger: resetLoggerFn, setLoggerOverride: setLoggerOverrideFn } = + await import("../logging/logger.js")); }); async function runEmbeddedPiAgentInline( @@ -152,8 +151,8 @@ beforeEach(() => { afterEach(() => { globalThis.fetch = originalFetch; - unregisterLogTransport?.(); - unregisterLogTransport = undefined; + cleanupLogCapture?.(); + cleanupLogCapture = undefined; setLoggerOverrideFn(null); resetLoggerFn(); }); @@ -864,15 +863,13 @@ describe("runEmbeddedPiAgent auth profile rotation", () => { }); it("logs structured failover decision metadata for overloaded assistant rotation", async () => { - const records: Array> = []; + const logCapture = createDiagnosticLogRecordCaptureFn(); + cleanupLogCapture = logCapture.cleanup; setLoggerOverrideFn({ level: "trace", consoleLevel: "silent", file: path.join(os.tmpdir(), `openclaw-auth-rotation-${Date.now()}.log`), }); - unregisterLogTransport = registerLogTransportFn((record) => { - records.push(record); - }); await runAutoPinnedRotationCase({ errorMessage: @@ -880,18 +877,17 @@ describe("runEmbeddedPiAgent auth profile rotation", () => { sessionKey: "agent:test:overloaded-logging", runId: "run:overloaded-logging", }); + await logCapture.flush(); - const decisionRecord = records.find( + const decisionRecord = logCapture.records.find( (record) => - record["2"] === "embedded run failover decision" && - record["1"] && - typeof record["1"] === "object" && - (record["1"] as Record).decision === "rotate_profile", + record.message === "embedded run failover decision" && + record.attributes?.decision === "rotate_profile", ); expect(decisionRecord).toBeDefined(); const safeProfileId = redactIdentifier("openai:p1", { len: 12 }); - expect((decisionRecord as Record)["1"]).toMatchObject({ + expect(decisionRecord?.attributes).toMatchObject({ event: "embedded_run_failover_decision", runId: "run:overloaded-logging", decision: "rotate_profile", @@ -903,16 +899,14 @@ describe("runEmbeddedPiAgent auth profile rotation", () => { rawErrorPreview: expect.stringContaining('"request_id":"sha256:'), }); - const stateRecord = records.find( + const stateRecord = logCapture.records.find( (record) => - record["2"] === "auth profile failure state updated" && - record["1"] && - typeof record["1"] === "object" && - (record["1"] as Record).profileId === safeProfileId, + record.message === "auth profile failure state updated" && + record.attributes?.profileId === safeProfileId, ); expect(stateRecord).toBeDefined(); - expect((stateRecord as Record)["1"]).toMatchObject({ + expect(stateRecord?.attributes).toMatchObject({ event: "auth_profile_failure_state_updated", runId: "run:overloaded-logging", profileId: safeProfileId, diff --git a/src/logging/logger-transport.test.ts b/src/logging/logger-transport.test.ts new file mode 100644 index 00000000000..1a68a967881 --- /dev/null +++ b/src/logging/logger-transport.test.ts @@ -0,0 +1,60 @@ +import { afterAll, afterEach, beforeAll, describe, expect, it } from "vitest"; +import { importFreshModule } from "../../test/helpers/import-fresh.js"; +import { createSuiteLogPathTracker } from "./log-test-helpers.js"; + +type LoggerModule = typeof import("./logger.js"); + +const logPathTracker = createSuiteLogPathTracker("openclaw-logger-transport-"); +const importedModules: LoggerModule[] = []; + +async function importLoggerModule(scope: string): Promise { + const module = await importFreshModule( + import.meta.url, + `./logger.js?scope=${scope}`, + ); + importedModules.push(module); + module.setLoggerOverride({ + level: "info", + file: logPathTracker.nextPath(), + }); + return module; +} + +describe("logger transport registry", () => { + beforeAll(async () => { + await logPathTracker.setup(); + }); + + afterEach(() => { + while (importedModules.length > 0) { + const module = importedModules.pop(); + module?.resetLogger(); + module?.setLoggerOverride(null); + } + }); + + afterAll(async () => { + await logPathTracker.cleanup(); + }); + + it("does not expose production or test log transport registration", async () => { + const loggerModule = await importLoggerModule("public-api"); + + expect( + (loggerModule as unknown as Record).registerLogTransport, + ).toBeUndefined(); + expect( + (loggerModule.__test__ as unknown as Record).registerLogTransportForTest, + ).toBeUndefined(); + }); + + it("does not publish mutable log transport state on a well-known global symbol", async () => { + await importLoggerModule("global-state"); + + expect( + (globalThis as typeof globalThis & Record)[ + Symbol.for("openclaw.logging.transports") + ], + ).toBeUndefined(); + }); +}); diff --git a/src/logging/logger.ts b/src/logging/logger.ts index 7c401324806..5be11d17177 100644 --- a/src/logging/logger.ts +++ b/src/logging/logger.ts @@ -68,10 +68,7 @@ type ResolvedSettings = { maxFileBytes: number; }; export type LoggerResolvedSettings = ResolvedSettings; -export type LogTransportRecord = Record; -export type LogTransport = (logObj: LogTransportRecord) => void; - -const externalTransports = new Set(); +type TsLogRecord = Record; type DiagnosticLogCode = { line?: number; @@ -87,19 +84,6 @@ const DIAGNOSTIC_LOG_ATTRIBUTE_KEY_RE = /^[A-Za-z0-9_.:-]{1,64}$/u; type DiagnosticLogAttributes = Record; -function attachExternalTransport(logger: TsLogger, transport: LogTransport): void { - logger.attachTransport((logObj: LogObj) => { - if (!externalTransports.has(transport)) { - return; - } - try { - transport(logObj as LogTransportRecord); - } catch { - // never block on logging failures - } - }); -} - function clampDiagnosticLogText(value: string, maxChars: number): string { return value.length > maxChars ? `${value.slice(0, maxChars)}...(truncated)` : value; } @@ -237,7 +221,7 @@ function findLogTraceContext( return undefined; } -function buildDiagnosticLogRecord(logObj: LogTransportRecord) { +function buildDiagnosticLogRecord(logObj: TsLogRecord) { const meta = logObj._meta as | { logLevelName?: string; @@ -335,7 +319,7 @@ function buildDiagnosticLogRecord(logObj: LogTransportRecord) { function attachDiagnosticEventTransport(logger: TsLogger): void { logger.attachTransport((logObj: LogObj) => { try { - emitDiagnosticEvent(buildDiagnosticLogRecord(logObj as LogTransportRecord)); + emitDiagnosticEvent(buildDiagnosticLogRecord(logObj as TsLogRecord)); } catch { // never block on logging failures } @@ -425,9 +409,6 @@ function buildLogger(settings: ResolvedSettings): TsLogger { // Silent logging does not write files; skip all filesystem setup in this path. if (settings.level === "silent") { attachDiagnosticEventTransport(logger); - for (const transport of externalTransports) { - attachExternalTransport(logger, transport); - } return logger; } @@ -470,9 +451,6 @@ function buildLogger(settings: ResolvedSettings): TsLogger { } }); attachDiagnosticEventTransport(logger); - for (const transport of externalTransports) { - attachExternalTransport(logger, transport); - } return logger; } @@ -579,17 +557,6 @@ export function resetLogger() { loggingState.overrideSettings = null; } -export function registerLogTransport(transport: LogTransport): () => void { - externalTransports.add(transport); - const logger = loggingState.cachedLogger as TsLogger | null; - if (logger) { - attachExternalTransport(logger, transport); - } - return () => { - externalTransports.delete(transport); - }; -} - export const __test__ = { shouldSkipMutatingLoggingConfigRead, }; diff --git a/src/logging/test-helpers/diagnostic-log-capture.ts b/src/logging/test-helpers/diagnostic-log-capture.ts new file mode 100644 index 00000000000..f40b50619ea --- /dev/null +++ b/src/logging/test-helpers/diagnostic-log-capture.ts @@ -0,0 +1,25 @@ +import { + onInternalDiagnosticEvent, + type DiagnosticEventPayload, +} from "../../infra/diagnostic-events.js"; + +export type CapturedDiagnosticLogRecord = Extract; + +export function flushDiagnosticLogRecords(): Promise { + return new Promise((resolve) => setImmediate(resolve)); +} + +export function createDiagnosticLogRecordCapture() { + const records: CapturedDiagnosticLogRecord[] = []; + const unsubscribe = onInternalDiagnosticEvent((event) => { + if (event.type === "log.record") { + records.push(event); + } + }); + + return { + records, + flush: flushDiagnosticLogRecords, + cleanup: unsubscribe, + }; +} diff --git a/src/logging/test-helpers/warn-log-capture.ts b/src/logging/test-helpers/warn-log-capture.ts index cdd8dd9e771..1a0aac70207 100644 --- a/src/logging/test-helpers/warn-log-capture.ts +++ b/src/logging/test-helpers/warn-log-capture.ts @@ -1,31 +1,25 @@ import path from "node:path"; import { resolvePreferredOpenClawTmpDir } from "../../infra/tmp-openclaw-dir.js"; -import { - registerLogTransport, - resetLogger, - setLoggerOverride, - type LogTransportRecord, -} from "../logger.js"; +import { resetLogger, setLoggerOverride } from "../logger.js"; +import { createDiagnosticLogRecordCapture } from "./diagnostic-log-capture.js"; export function createWarnLogCapture(prefix: string) { - const records: LogTransportRecord[] = []; + const capture = createDiagnosticLogRecordCapture(); setLoggerOverride({ level: "warn", consoleLevel: "silent", file: path.join(resolvePreferredOpenClawTmpDir(), `${prefix}-${process.pid}-${Date.now()}.log`), }); - const unregister = registerLogTransport((record) => { - records.push(record); - }); return { - findText(needle: string): string | undefined { - return records - .flatMap((record) => Object.values(record)) + async findText(needle: string): Promise { + await capture.flush(); + return capture.records + .flatMap((record) => [record.message, ...Object.values(record.attributes ?? {})]) .filter((value): value is string => typeof value === "string") .find((value) => value.includes(needle)); }, cleanup() { - unregister(); + capture.cleanup(); setLoggerOverride(null); resetLogger(); }, diff --git a/src/plugin-sdk/diagnostics-otel.ts b/src/plugin-sdk/diagnostics-otel.ts index 684d273cd8c..b423d1cd4f8 100644 --- a/src/plugin-sdk/diagnostics-otel.ts +++ b/src/plugin-sdk/diagnostics-otel.ts @@ -17,7 +17,6 @@ export { isValidDiagnosticTraceId, parseDiagnosticTraceparent, } from "../infra/diagnostic-trace-context.js"; -export { registerLogTransport } from "../logging/logger.js"; export { redactSensitiveText } from "../logging/redact.js"; export { emptyPluginConfigSchema } from "../plugins/config-schema.js"; export type {