diff --git a/changelog.d/fixes/12026-call-log-preserve-error-under-size-limit.md b/changelog.d/fixes/12026-call-log-preserve-error-under-size-limit.md new file mode 100644 index 0000000000..b4a8ae5538 --- /dev/null +++ b/changelog.d/fixes/12026-call-log-preserve-error-under-size-limit.md @@ -0,0 +1 @@ +- **Call logs:** keep the `error` field when an artifact exceeds the storage cap, instead of replacing it with the omission marker. The error is the only field that says *why* a request failed and is typically ~90 bytes next to the multi-hundred-KB bodies that trip the cap, so dropping it left a size-limited row undiagnosable — a provider outage, a local timeout and an upstream 400 all rendered identically. It is now preserved at every fallback stage, truncated to 4KB if it is itself large ([#12026](https://github.com/diegosouzapw/OmniRoute/issues/12026)). diff --git a/src/lib/usage/callLogArtifacts.ts b/src/lib/usage/callLogArtifacts.ts index 57d339a380..d0193b26a1 100644 --- a/src/lib/usage/callLogArtifacts.ts +++ b/src/lib/usage/callLogArtifacts.ts @@ -16,10 +16,41 @@ const SIZE_LIMIT_EXCEEDED_REASON = "call_log_artifact_size_limit_exceeded"; const OMITTED_FOR_SIZE_LIMIT = "[omitted: call log artifact size limit exceeded]"; const STREAM_CHUNKS_OMITTED_FOR_SIZE_LIMIT = "[stream chunks omitted: call log artifact size limit exceeded]"; -// Error strings are kept even in the size-limit fallback (truncated to this -// cap) so every log row stays diagnosable; see buildMinimalArtifactForSizeLimit. -const MAX_CALL_LOG_ARTIFACT_ERROR_BYTES = 4 * 1024; -const SIZE_LIMIT_EXCEEDED_SUFFIX = "…[truncated: call log artifact size limit exceeded]"; + +// The error is the only field that says *why* a request failed, and it is +// typically ~90 bytes next to the multi-hundred-KB bodies that trip the cap. +// Dropping it made a size-limited row undiagnosable: a provider outage, a local +// timeout and an upstream 400 all rendered as the same omission marker. It is +// kept at every fallback stage instead, truncated rather than discarded. +const MAX_PRESERVED_ERROR_BYTES = 4 * 1024; +const ERROR_TRUNCATED_FOR_SIZE_LIMIT = "[truncated: call log artifact size limit exceeded]"; + +function truncateUtf8(text: string, maxBytes: number): string { + const buffer = Buffer.from(text, "utf8"); + if (buffer.length <= maxBytes) return text; + // Cut back off a partial multi-byte sequence so the tail is not a U+FFFD. + let end = maxBytes; + while (end > 0 && (buffer[end] & 0xc0) === 0x80) end--; + return buffer.subarray(0, end).toString("utf8"); +} + +/** + * Keep the error through a size-limit fallback, truncating it if it is itself + * large. Returns the value unchanged when it already fits, so a normal-sized + * error is byte-identical to what a non-truncated artifact would carry. + */ +function preserveErrorForSizeLimit(error: unknown): unknown { + if (error === null || error === undefined) return null; + let serialized: string; + try { + serialized = typeof error === "string" ? error : JSON.stringify(error) ?? String(error); + } catch { + // A circular or unserializable error must not take the whole artifact down. + serialized = String(error); + } + if (Buffer.byteLength(serialized, "utf8") <= MAX_PRESERVED_ERROR_BYTES) return error; + return `${truncateUtf8(serialized, MAX_PRESERVED_ERROR_BYTES)} ${ERROR_TRUNCATED_FOR_SIZE_LIMIT}`; +} export type CallLogDetailState = "none" | "ready" | "missing" | "corrupt" | "legacy-inline"; @@ -141,7 +172,7 @@ function buildMinimalArtifactForSizeLimit(artifact: CallLogArtifact) { // failed (e.g. "Fetch timeout after 110000ms on https://..."). Diagnosing // provider outages from a log row that shows only an omission marker is // impossible; the error string is tiny next to the request/response bodies. - error: artifact.error ? truncateErrorForSizeLimit(artifact.error) : null, + error: preserveErrorForSizeLimit(artifact.error), pipeline: { error: { _omniroute_truncated: true, @@ -151,12 +182,6 @@ function buildMinimalArtifactForSizeLimit(artifact: CallLogArtifact) { }; } -function truncateErrorForSizeLimit(error: unknown): string { - const text = typeof error === "string" ? error : JSON.stringify(error) ?? String(error); - if (Buffer.byteLength(text) <= MAX_CALL_LOG_ARTIFACT_ERROR_BYTES) return text; - return `${text.slice(0, MAX_CALL_LOG_ARTIFACT_ERROR_BYTES)}${SIZE_LIMIT_EXCEEDED_SUFFIX}`; -} - function serializeFinalSizeLimitFallback(artifact: CallLogArtifact, maxBytes: number): string { const withSummary = JSON.stringify(buildMinimalArtifactForSizeLimit(artifact)); if (Buffer.byteLength(withSummary) <= maxBytes) { @@ -169,16 +194,20 @@ function serializeFinalSizeLimitFallback(artifact: CallLogArtifact, maxBytes: nu schemaVersion: artifact.schemaVersion, _omniroute_truncated: true, reason: SIZE_LIMIT_EXCEEDED_REASON, - error: artifact.error ? truncateErrorForSizeLimit(artifact.error) : null, + error: preserveErrorForSizeLimit(artifact.error), }); if (Buffer.byteLength(errorOnly) <= maxBytes) { return errorOnly; } + // Last resort: even the error-only payload did not fit. The error still + // rides along -- without it this row says only "something was too big", + // which is the state this change exists to remove. return JSON.stringify({ schemaVersion: artifact.schemaVersion, _omniroute_truncated: true, reason: SIZE_LIMIT_EXCEEDED_REASON, + error: preserveErrorForSizeLimit(artifact.error), }); } @@ -212,7 +241,7 @@ function serializeArtifactForStorage(artifact: CallLogArtifact): string { ...omitOversizedPipeline(artifact), requestBody: OMITTED_FOR_SIZE_LIMIT, responseBody: OMITTED_FOR_SIZE_LIMIT, - error: artifact.error ? truncateErrorForSizeLimit(artifact.error) : null, + error: preserveErrorForSizeLimit(artifact.error), }); if (Buffer.byteLength(minimal) <= maxBytes) { return minimal; diff --git a/tests/unit/call-log-size-limit-error.test.ts b/tests/unit/call-log-size-limit-error.test.ts new file mode 100644 index 0000000000..0ec7ad7db5 --- /dev/null +++ b/tests/unit/call-log-size-limit-error.test.ts @@ -0,0 +1,97 @@ +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"; + +import { useDecollidedMigrationsDir } from "./helpers/decollidedMigrationsDir.ts"; + +useDecollidedMigrationsDir(); +const TEST_DATA_DIR = fs.mkdtempSync(path.join(os.tmpdir(), "omniroute-call-log-size-")); +process.env.DATA_DIR = TEST_DATA_DIR; + +const { writeCallArtifact, readCallArtifact } = await import( + "../../src/lib/usage/callLogArtifacts.ts" +); + +const OMITTED = "[omitted: call log artifact size limit exceeded]"; +const TRUNCATED = "[truncated: call log artifact size limit exceeded]"; + +// The reported shape: a request body large enough to trip the 512KB cap on its +// own, next to an error small enough that keeping it costs nothing. +const HUGE_BODY = "x".repeat(900 * 1024); +const REAL_ERROR = "[504]: Fetch timeout after 110000ms on https://provider.example/v1/messages"; + +function artifact(overrides: Record = {}) { + return { + schemaVersion: 5 as const, + summary: { + id: `size-${Math.random().toString(16).slice(2)}`, + timestamp: new Date().toISOString(), + method: "POST", + path: "/v1/messages", + status: 504, + model: "opencode-go", + requestedModel: null, + }, + requestBody: HUGE_BODY, + responseBody: null, + error: REAL_ERROR, + ...overrides, + } as never; +} + +function roundTrip(input: ReturnType) { + const relativePath = `size-limit/${(input as { summary: { id: string } }).summary.id}.json`; + assert.ok(writeCallArtifact(input, relativePath), "artifact should be written"); + const { artifact: stored, state } = readCallArtifact(relativePath); + assert.equal(state, "ready"); + assert.ok(stored, "artifact should be readable"); + return stored as unknown as Record; +} + +test("a size-limited row keeps the error that says why the request failed", () => { + const stored = roundTrip(artifact()); + + // The bodies are what tripped the cap; they are still dropped. + assert.equal(stored.requestBody, OMITTED); + // The error is the only field that distinguishes a provider outage from a + // local timeout from an upstream 400. It survives. + assert.equal(stored.error, REAL_ERROR); +}); + +test("an oversized error is truncated, not discarded", () => { + const stored = roundTrip(artifact({ error: "e".repeat(64 * 1024) })); + + const error = stored.error as string; + assert.equal(typeof error, "string"); + assert.ok(error.startsWith("eeee"), "the beginning of the error is kept"); + assert.ok(error.endsWith(TRUNCATED), "and it says it was cut"); + assert.ok( + Buffer.byteLength(error, "utf8") <= 4 * 1024 + TRUNCATED.length + 1, + `truncated error should stay near the 4KB budget, got ${Buffer.byteLength(error, "utf8")}` + ); +}); + +test("truncation does not split a multi-byte character", () => { + // Every character is 3 bytes, so a byte-aligned cut lands mid-sequence. + const stored = roundTrip(artifact({ error: "验".repeat(8 * 1024) })); + + const error = stored.error as string; + assert.ok(!error.includes("�"), "no replacement character should appear"); + assert.ok(error.endsWith(TRUNCATED)); +}); + +test("a request with no error still stores null rather than a marker", () => { + const stored = roundTrip(artifact({ error: null })); + + assert.equal(stored.requestBody, OMITTED); + assert.equal(stored.error, null); +}); + +test("a non-string error is preserved as its own value when it fits", () => { + const structured = { status: 504, provider: "opencode-go", detail: "upstream timeout" }; + const stored = roundTrip(artifact({ error: structured })); + + assert.deepEqual(stored.error, structured); +});