From 9603ec1bf1e43c4f5ebd7abf8e4e762299490c60 Mon Sep 17 00:00:00 2001 From: Markus Hartung Date: Thu, 20 Aug 2026 20:34:38 -0300 Subject: [PATCH] fix(sse): log upstream error body in COMBO per-target failure warnings (#10597) --- .../fixes/10597-combo-log-error-body.md | 1 + open-sse/services/combo.ts | 10 +- .../combo-10597-error-body-logging.test.ts | 91 +++++++++++++++++++ 3 files changed, 100 insertions(+), 2 deletions(-) create mode 100644 changelog.d/fixes/10597-combo-log-error-body.md create mode 100644 tests/unit/combo-10597-error-body-logging.test.ts diff --git a/changelog.d/fixes/10597-combo-log-error-body.md b/changelog.d/fixes/10597-combo-log-error-body.md new file mode 100644 index 0000000000..ff6608947c --- /dev/null +++ b/changelog.d/fixes/10597-combo-log-error-body.md @@ -0,0 +1 @@ +- **fix(sse):** Include the redacted upstream error body in the per-target COMBO failure log (`Model X failed, trying next`) so operators can triage a 400/500 without reproducing the request ([#10597](https://github.com/diegosouzapw/OmniRoute/issues/10597)) diff --git a/open-sse/services/combo.ts b/open-sse/services/combo.ts index cf602cf98d..2268c2050c 100644 --- a/open-sse/services/combo.ts +++ b/open-sse/services/combo.ts @@ -2275,7 +2275,10 @@ async function handleComboChatInner({ ); } } - log.warn("COMBO", `Model ${modelStr} failed, trying next`, { status: result.status }); + log.warn("COMBO", `Model ${modelStr} failed, trying next`, { + status: result.status, + errorBody: redactConnectionLabel(errorText), + }); // #5976: per-model-quota providers (Gemini, GitHub, etc.) multiplex models // behind one connection. A model-level 500 or 429 (RPM) must NOT cool down @@ -3460,7 +3463,10 @@ async function handleRoundRobinCombo({ kind: classifyComboOutcome(result.status, errorText), }); if (offset > 0) fallbackCount++; - log.warn("COMBO-RR", `${modelStr} failed, trying next model`, { status: result.status }); + log.warn("COMBO-RR", `${modelStr} failed, trying next model`, { + status: result.status, + errorBody: redactConnectionLabel(errorText), + }); if ( resilienceSettings.providerCooldown.enabled && diff --git a/tests/unit/combo-10597-error-body-logging.test.ts b/tests/unit/combo-10597-error-body-logging.test.ts new file mode 100644 index 0000000000..6df6a2cf49 --- /dev/null +++ b/tests/unit/combo-10597-error-body-logging.test.ts @@ -0,0 +1,91 @@ +/** + * #10597 — When a combo target fails with a non-2xx status, the per-target + * "Model X failed, trying next" COMBO log line only carries `{ status }` — + * the upstream error BODY (e.g. Anthropic's "prompt is too long" or a + * tool_use/tool_result pairing 400) is captured in `errorText` but never + * logged, so operators cannot distinguish failure causes from server logs + * without reproducing the request. + */ +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"; + +const TEST_DATA_DIR = fs.mkdtempSync(path.join(os.tmpdir(), "omniroute-combo-10597-")); +process.env.DATA_DIR = TEST_DATA_DIR; +process.env.API_KEY_SECRET = process.env.API_KEY_SECRET || "combo-10597-test-secret"; + +const { handleComboChat } = await import("../../open-sse/services/combo.ts"); + +const DISTINCTIVE_ERROR_TEXT = + "messages.450: `tool_use` ids were found without `tool_result` blocks immediately after"; + +type WarnCall = { tag: string; msg: string; meta: unknown }; +const warnCalls: WarnCall[] = []; +const log = { + info: () => {}, + debug: () => {}, + error: () => {}, + warn: (tag: string, msg: string, meta?: unknown) => { + warnCalls.push({ tag, msg, meta }); + }, +}; + +function failing400() { + return new Response( + JSON.stringify({ + type: "error", + error: { type: "invalid_request_error", message: DISTINCTIVE_ERROR_TEXT }, + }), + { status: 400, headers: { "Content-Type": "application/json" } } + ); +} + +function healthy200(model: string) { + return new Response( + JSON.stringify({ + id: "ok", + object: "chat.completion", + model, + choices: [{ index: 0, message: { role: "assistant", content: "hello from " + model }, finish_reason: "stop" }], + }), + { status: 200, headers: { "Content-Type": "application/json" } } + ); +} + +function makeCombo(models: string[]) { + return { name: "test-combo-10597", strategy: "priority", models: models.map((m) => ({ model: m })) }; +} + +test("#10597 COMBO failure log must surface the upstream error body, not just the status code", async () => { + const modelsCalled: string[] = []; + const handleSingleModel = async (_body: unknown, modelStr: string) => { + modelsCalled.push(modelStr); + if (modelsCalled.length === 1) return failing400(); + return healthy200(modelStr); + }; + + const result = await handleComboChat({ + body: { model: "test", messages: [{ role: "user", content: "hi" }] }, + combo: makeCombo(["claude/claude-opus-4-8", "openai/gpt-4o-mini"]), + handleSingleModel, + log, + settings: {}, + allCombos: [], + }); + + assert.equal(result.status, 200); + assert.equal(modelsCalled.length, 2); + + const failureLog = warnCalls.find( + (c) => typeof c.msg === "string" && c.msg.includes("claude/claude-opus-4-8") && c.msg.includes("failed") + ); + assert.ok(failureLog, "expected a COMBO warn log for the failing leg"); + + const serialized = JSON.stringify(failureLog); + assert.ok( + serialized.includes("tool_use") || serialized.includes(DISTINCTIVE_ERROR_TEXT), + `expected the upstream error body to appear in the COMBO failure log, but got: ${serialized}` + ); +});