diff --git a/changelog.d/fixes/13597-calllogs-worker-error-detail.md b/changelog.d/fixes/13597-calllogs-worker-error-detail.md new file mode 100644 index 0000000000..19c50b3118 --- /dev/null +++ b/changelog.d/fixes/13597-calllogs-worker-error-detail.md @@ -0,0 +1 @@ +- **fix(usage):** the call-logs artifact worker's failure warning now includes the underlying error's message/code instead of the generic "detail omitted" — a crashed or non-zero-exit worker was previously undiagnosable in the logs (#13597) — thanks @afonsoft diff --git a/src/lib/usage/callLogArtifactWriter.ts b/src/lib/usage/callLogArtifactWriter.ts index 7cd8452340..64966afa04 100644 --- a/src/lib/usage/callLogArtifactWriter.ts +++ b/src/lib/usage/callLogArtifactWriter.ts @@ -116,8 +116,15 @@ function warnRateLimited(message: string): void { console.warn(message); } -function failOpen(warn = false): void { - if (warn) warnRateLimited("[callLogs] Call-log artifact worker failed; detail omitted."); +function describeFailureDetail(detail: unknown): string { + if (detail instanceof Error) return `${detail.name}: ${detail.message}`; + return String(detail ?? "unknown error"); +} + +function failOpen(warn = false, detail?: unknown): void { + if (warn) { + warnRateLimited(`[callLogs] Call-log artifact worker failed: ${describeFailureDetail(detail)}`); + } const failed = active ? [active, ...queue] : [...queue]; active = null; queue.length = 0; @@ -126,10 +133,24 @@ function failOpen(warn = false): void { notifyCloseWaiters(); } +let workerFileOverride: { workerFile: string; execArgv: string[] } | null = null; + +/** + * Test-only hook: force the next ensureWorker() call to spawn an arbitrary worker + * script/execArgv instead of the real callLogArtifactWorker file. Lets regression tests + * trigger a genuine worker_threads `error`/`exit` event without editing the production + * worker script. Never called from production code paths. + */ +export function __setCallLogWorkerOverrideForTests( + override: { workerFile: string; execArgv: string[] } | null +): void { + workerFileOverride = override; +} + function ensureWorker(): Worker { if (worker) return worker; - const { workerFile, execArgv } = resolveCallLogArtifactWorker(); + const { workerFile, execArgv } = workerFileOverride ?? resolveCallLogArtifactWorker(); // Reflect.construct keeps Next/Turbopack from interpreting the runtime-selected // worker path as a build-time glob and tracing tens of thousands of unrelated files. const created = Reflect.construct(Worker, [pathToFileURL(workerFile), { execArgv }]) as Worker; @@ -141,12 +162,12 @@ function ensureWorker(): Worker { completed.resolve(reply.result); pump(); }); - created.on("error", () => failOpen(true)); - created.on("messageerror", () => failOpen(true)); + created.on("error", (err) => failOpen(true, err)); + created.on("messageerror", (err) => failOpen(true, err)); created.on("exit", (code) => { if (worker !== created) return; worker = null; - if (code !== 0 || active) failOpen(true); + if (code !== 0 || active) failOpen(true, new Error(`worker exited with code ${code}`)); }); return created; } @@ -168,8 +189,8 @@ function pump(): void { artifact: next.artifact, environment: next.environment, }); - } catch { - failOpen(true); + } catch (err) { + failOpen(true, err); } } diff --git a/tests/unit/issue-13597-calllogs-worker-error-detail.test.ts b/tests/unit/issue-13597-calllogs-worker-error-detail.test.ts new file mode 100644 index 0000000000..8f6f770b73 --- /dev/null +++ b/tests/unit/issue-13597-calllogs-worker-error-detail.test.ts @@ -0,0 +1,99 @@ +import test from "node:test"; +import assert from "node:assert/strict"; +import fs from "node:fs"; +import os from "node:os"; +import path from "node:path"; + +// Regression test for GitHub issue #13597 (claim A): the callLogs artifact worker's +// failOpen() only ever logged a hardcoded "detail omitted" string — the real Error from +// the worker's `error`/`messageerror` events (and the exit code from a non-zero `exit`) +// were read and then discarded before warnRateLimited() was called, making the failure +// undiagnosable on a live system. +// +// This test forces a REAL worker_threads crash (a worker script that throws +// synchronously at import time) via the `__setCallLogWorkerOverrideForTests` test-only +// hook, so callLogArtifactWriter.ts's actual `worker.on("error", ...)` handler fires with +// a genuine Error object. It then asserts the resulting console.warn call carries that +// error's message. On the pre-fix code this assertion is RED: the only thing ever logged +// is the generic "detail omitted" string, with no trace of the injected error text. + +const TEST_DATA_DIR = fs.mkdtempSync(path.join(os.tmpdir(), "omniroute-issue-13597-")); +process.env.DATA_DIR = TEST_DATA_DIR; + +const { writeCallArtifactAsync, closeCallLogArtifactWriter, __setCallLogWorkerOverrideForTests } = + await import("../../src/lib/usage/callLogArtifactWriter.ts"); + +const CRASH_MESSAGE = "probe-13597-worker-init-crash"; +const crashWorkerFile = path.join(TEST_DATA_DIR, "crash-worker.mjs"); +fs.writeFileSync(crashWorkerFile, `throw new Error(${JSON.stringify(CRASH_MESSAGE)});\n`); + +test.after(async () => { + __setCallLogWorkerOverrideForTests(null); + await closeCallLogArtifactWriter(0); + fs.rmSync(TEST_DATA_DIR, { recursive: true, force: true, maxRetries: 5, retryDelay: 100 }); +}); + +function buildArtifact(id: string) { + return { + schemaVersion: 5 as const, + summary: { + id, + timestamp: "2026-09-15T00:00:00.000Z", + method: "POST", + path: "/v1/chat/completions", + status: 200, + model: "test-model", + requestedModel: null, + provider: "test-provider", + account: "test-account", + connectionId: null, + duration: 10, + tokens: { + in: 1, + out: 2, + cacheRead: null, + cacheWrite: null, + reasoning: null, + compressed: null, + }, + requestType: "chat", + sourceFormat: "openai", + targetFormat: "openai", + apiKeyId: null, + apiKeyName: null, + comboName: null, + comboStepId: null, + comboExecutionKey: null, + }, + requestBody: {}, + responseBody: { content: "unreachable — worker never comes up" }, + error: null, + }; +} + +test("issue #13597: a crashed call-log worker logs the underlying error detail, not 'detail omitted'", async () => { + __setCallLogWorkerOverrideForTests({ workerFile: crashWorkerFile, execArgv: [] }); + + const originalWarn = console.warn; + const warnings: string[] = []; + console.warn = (...args: unknown[]) => { + warnings.push(args.map(String).join(" ")); + }; + + try { + const result = await writeCallArtifactAsync(buildArtifact("issue-13597-crash-1")); + assert.equal(result, null); // fails open — existing, correct behavior + + const failureWarnings = warnings.filter((w) => w.includes("[callLogs]")); + assert.ok(failureWarnings.length > 0, "expected a [callLogs] warning to be logged"); + + const detailed = failureWarnings.some((w) => w.includes(CRASH_MESSAGE)); + assert.ok( + detailed, + `expected a [callLogs] warning to include the underlying error detail ` + + `("${CRASH_MESSAGE}"), got: ${JSON.stringify(failureWarnings)}` + ); + } finally { + console.warn = originalWarn; + } +});