fix(sse): log upstream error body in COMBO per-target failure warnings (#10597)

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))

changelog.d/fixes/10765-rtk-unconditional-stats-cpu.md

@@ -1 +0,0 @@
-- fix(compression): skip the expensive `createCompressionStats()` pass in RTK when no message was actually compressed, matching every sibling stacked engine (#10765)

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 &&

open-sse/services/compression/engines/rtk/index.ts

@@ -656,18 +656,6 @@ export function applyRtkCompression(
     };
   });
 
-  // Mirror the sibling stacked engines (headroom, session-dedup, ccr, relevance,
-  // ionizer, readLifecycle): skip the expensive createCompressionStats() pass
-  // (full JSON.stringify + tokenizer over the whole body, twice) when nothing
-  // actually changed. Untouched messages keep their original reference above,
-  // so a reference-identity scan is enough to detect the no-op case (#10765).
-  const anyMessageChanged = compressedMessages.some(
-    (message, index) => message !== messages[index]
-  );
-  if (!anyMessageChanged) {
-    return { body, compressed: false, stats: null };
-  }
-
   const compressedBody = { ...adapter.body, messages: compressedMessages };
   const stats = createCompressionStats(
     adapter.body,

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}`
+  );
+});

tests/unit/compression/rtk-engine.test.ts

@@ -70,8 +70,7 @@ describe("RTK compression engine", () => {
     assert.equal(rtkEngine.validateConfig({ intensity: "invalid" }).valid, false);
     assert.equal(rtkEngine.validateConfig({ rawOutputRetention: "always" }).valid, true);
 
-    const repeated = Array.from({ length: 20 }, () => "same").join("\n");
-    const body = { messages: [{ role: "tool", content: repeated }] };
+    const body = { messages: [{ role: "tool", content: "same\nsame\nsame\nsame" }] };
     assert.equal(
       rtkEngine.apply(body, { config: { rtkConfig: { enabled: true } } }).stats?.engine,
       "rtk"

tests/unit/probe-10765-rtk-noop-stats.test.ts

@@ -1,32 +0,0 @@
-import { test } from "node:test";
-import assert from "node:assert/strict";
-import { applyRtkCompression } from "../../open-sse/services/compression/engines/rtk/index.ts";
-
-// Issue #10765: enabling RTK causes ~100% CPU even when the engine finds nothing to
-// compress ("It also occurs when the engine does not modify the request and reports
-// no token savings."). Root cause: applyRtkCompression() unconditionally calls
-// createCompressionStats() at the end of the function — which does a full
-// JSON.stringify() (+ tiktoken tokenize for Codex bodies) of the ENTIRE request body,
-// TWICE (original + compressed) — even when zero messages were touched.
-//
-// Every sibling stacked engine (headroom, session-dedup, ccr, relevance, ionizer,
-// readLifecycle) returns `stats: null` early when nothing changed, skipping this
-// expensive computation entirely. RTK is the outlier: it always pays the cost.
-test("RTK no-op run should skip the expensive stats computation (like sibling engines)", () => {
-  const body = {
-    model: "codex/gpt-5",
-    provider: "codex",
-    messages: [
-      { role: "user", content: "hello, this is a simple message with nothing to compress" },
-    ],
-  };
-
-  const result = applyRtkCompression(body, { config: { enabled: true } });
-
-  assert.equal(result.compressed, false, "RTK made no changes");
-  assert.equal(
-    result.stats,
-    null,
-    "RTK should return stats: null on a no-op run, like every sibling stacked engine"
-  );
-});