diff --git a/open-sse/services/combo.ts b/open-sse/services/combo.ts index c9ccae9a97..982775f69b 100644 --- a/open-sse/services/combo.ts +++ b/open-sse/services/combo.ts @@ -235,6 +235,14 @@ import { resolveComboTargets, } from "./combo/comboStructure.ts"; import { getKnownContextOverflow } from "./combo/knownContextOverflow.ts"; +import { + createInvocationId, + finalizeComboTrace, + finishComboTrace, + getComboTrace, + recordComboDecision, + startComboTrace, +} from "./combo/decisionTrace.ts"; import { QUOTA_SOFT_DEPRIORITIZE_FACTOR, setCandidateQuotaSoftPenalty, @@ -607,7 +615,25 @@ export { pinIsDurablyUnhealthy }; /** @param {string} errorText */ /** @param {object} options */ -export async function handleComboChat({ +/** + * #10681 egress: every combo response carries the opaque trace id in an + * `X-OmniRoute-Combo-Trace` header so a post-incident lookup of the ordered + * per-target decisions is possible; the finalized summary is also emitted as + * one metadata-only log line for durability across restarts. + */ +export async function handleComboChat(options: HandleComboChatOptions): Promise { + const traceInvocationId = options.invocationId ?? createInvocationId(); + const response = await handleComboChatInner({ ...options, invocationId: traceInvocationId }); + response.headers.set("X-OmniRoute-Combo-Trace", traceInvocationId); + const trace = getComboTrace(traceInvocationId); + options.log.info( + "COMBO", + `combo trace ${traceInvocationId} terminal=${JSON.stringify(trace?.terminal ?? null)} decisions=${trace?.decisions.length ?? 0}` + ); + return response; +} + +async function handleComboChatInner({ body, combo, handleSingleModel, @@ -627,6 +653,7 @@ export async function handleComboChat({ sourceFormat = null, endpointPath = null, requestHeaders = null, + invocationId, }: HandleComboChatOptions): Promise { const comboCtx = createComboContext({ body, combo, settings, relayOptions, log }); const { @@ -643,6 +670,10 @@ export async function handleComboChat({ } = phaseComboSetup(comboCtx); body = comboCtx.body; + // #10681: opaque per-invocation decision trace (safe routing metadata only). + const traceInvocationId = invocationId ?? createInvocationId(); + startComboTrace(traceInvocationId, { strategy, comboName: combo.name }); + const handleSingleModelWithTimeout = buildTargetTimeoutRunner({ handleSingleModel, comboTargetTimeoutMs, @@ -1019,6 +1050,9 @@ export async function handleComboChat({ }); const runningTasks = new Set>(); let anySuccess = false; + // #10681: steps already recorded as dispatched (so per-target retries do not + // duplicate the decision). + const dispatchedTargets = new Set(); const abortControllers = new Map(); const zeroLatencyOptimizationsEnabled = config.zeroLatencyOptimizationsEnabled === true; const hasProtectedPriorityTarget = @@ -1044,6 +1078,12 @@ export async function handleComboChat({ const cb = getCircuitBreaker(provider); if (cb.getStatus().state === "OPEN") { log.info("COMBO", `Skipping ${modelStr} — circuit breaker OPEN for ${provider}`); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "circuit_open", + }); if (i > 0) fallbackCount++; return stopProtectedPriorityTarget(`Provider ${provider} circuit breaker is open`); } @@ -1054,6 +1094,12 @@ export async function handleComboChat({ isProviderInCooldown(provider, target.connectionId ?? undefined, resilienceSettings) ) { log.info("COMBO", `Skipping ${modelStr} — provider ${provider} in global cooldown`); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "provider_cooldown", + }); if (i > 0) fallbackCount++; return stopProtectedPriorityTarget(`Provider ${provider} is in cooldown`); } @@ -1081,6 +1127,12 @@ export async function handleComboChat({ ); if (exhaustedSkip) { log.info("COMBO", exhaustedSkip); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "request_exhaustion", + }); if (i > 0) fallbackCount++; return stopProtectedPriorityTarget(`Target ${modelStr} is unavailable`); } @@ -1088,6 +1140,12 @@ export async function handleComboChat({ // Pre-check: skip models locked by the resilience system (model-level lockout) if (provider && rawModel && isModelLocked(provider, target.connectionId || "", rawModel)) { log.info("COMBO", `Skipping ${modelStr} — model locked by resilience (cooldown active)`); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "model_lockout", + }); if (i > 0) fallbackCount++; return stopProtectedPriorityTarget(`Model ${modelStr} is locked`); } @@ -1114,6 +1172,12 @@ export async function handleComboChat({ "COMBO", `Skipping ${modelStr} — quota exhaustion cutoff (${quotaCutoff.reason || "quota_exhausted"})` ); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "quota_cutoff", + }); if (i > 0) fallbackCount++; observeFailure(true, target.executionKey); if (protectedPriorityTarget) { @@ -1162,6 +1226,12 @@ export async function handleComboChat({ "COMBO", `Skipping ${modelStr} — no credentials available or model excluded` ); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "availability", + }); if (i > 0) fallbackCount++; return stopProtectedPriorityTarget(`Model ${modelStr} is unavailable`); } @@ -1173,6 +1243,12 @@ export async function handleComboChat({ const gateResult = checkCredentialGate(connectionId, provider, modelStr); if (gateResult.allowed === false) { logCredentialSkip(log, modelStr, gateResult.reason || "Credential gate blocked"); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "credential_gate", + }); if (i > 0) fallbackCount++; return stopProtectedPriorityTarget(`Credential gate blocked ${modelStr}`); } @@ -1187,6 +1263,12 @@ export async function handleComboChat({ "COMBO", `Skipping ${modelStr} — connection ${connectionId} is at max concurrency cap (${maxConcurrentCap})` ); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "concurrency_cap", + }); if (i > 0) fallbackCount++; return stopProtectedPriorityTarget(`Connection capacity reached for ${modelStr}`); } @@ -1202,6 +1284,12 @@ export async function handleComboChat({ !(await perTargetAdmission({ modelStr, executionKey: target.executionKey, body })) ) { log.info("COMBO", `Skipping ${modelStr} — admission lane full (#9654)`); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "admission_lane", + }); if (i > 0) fallbackCount++; return null; } @@ -1257,6 +1345,12 @@ export async function handleComboChat({ "COMBO", `Predictive TTFT Circuit Breaker: skipping ${modelStr} (avg ${m.avgLatencyMs}ms > max ${config.predictiveTtftMs}ms)` ); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "skipped_before_dispatch", + reason: "predictive_ttft", + }); return stopProtectedPriorityTarget(`Predictive latency check rejected ${modelStr}`); } } @@ -1386,6 +1480,15 @@ export async function handleComboChat({ : "", fingerprint: resolveTargetFingerprint(target) ?? "", }); + // #10681: record dispatch once per target (retries keep the first decision). + if (!dispatchedTargets.has(target.executionKey)) { + dispatchedTargets.add(target.executionKey); + recordComboDecision(traceInvocationId, { + step: target.executionKey, + target: modelStr, + decision: "dispatched", + }); + } const result = await handleSingleModelWithTimeout(attemptBody, modelStr, { ...targetForAttempt, effectiveComboStrategy: strategy, @@ -2297,10 +2400,16 @@ export async function handleComboChat({ await Promise.race([globalPromise, Promise.all([...runningTasks])]); } + // #10681: finalize the decision trace (success). + finalizeComboTrace(traceInvocationId, orderedTargets); + finishComboTrace(traceInvocationId, { status: 200 }); if (anySuccess) { return await globalPromise; } + // #10681: finalize the decision trace (global timeout). + finalizeComboTrace(traceInvocationId, orderedTargets); + finishComboTrace(traceInvocationId, { status: 504 }); // Global combo timeout: return aggregated error immediately, skipping set retries. if (comboExpired) { const summary = buildRedactedSummary(comboErrors); @@ -2343,6 +2452,9 @@ export async function handleComboChat({ if (setTry < maxSetRetries) continue; // All set retries exhausted — return the final error + // #10681: finalize the decision trace (all targets failed or skipped). + finalizeComboTrace(traceInvocationId, orderedTargets); + finishComboTrace(traceInvocationId, { status: 503 }); if (!lastStatus) { if (recordedAttempts === 0) { notifyWebhookEvent("request.failed", { @@ -2443,6 +2555,9 @@ export async function handleComboChat({ } } + // #10681: finalize the decision trace with the aggregated terminal status. + finalizeComboTrace(traceInvocationId, orderedTargets); + finishComboTrace(traceInvocationId, { status }); // Retry-after decoration is separate from the wait decision above: only // rate-limit-class final statuses may carry a `(reset after ...)` suffix // (see unavailableRetryGate.ts — do not stitch a peer target's window onto diff --git a/open-sse/services/combo/decisionTrace.ts b/open-sse/services/combo/decisionTrace.ts new file mode 100644 index 0000000000..7660af7ea0 --- /dev/null +++ b/open-sse/services/combo/decisionTrace.ts @@ -0,0 +1,175 @@ +/** + * #10681: opaque per-invocation combo decision trace. + * + * Priority combos can be impossible to audit after a mixed fallback: dispatched + * attempts are persisted in call_logs, but candidates excluded before dispatch + * (circuit open, provider cooldown, model lockout, quota cutoff, availability, + * credential gate, concurrency cap, admission lane, predictive TTFT) leave no + * correlated decision record. This module records one ordered, allowlisted + * decision per target per invocation so operators can reconstruct what the + * chain actually did. + * + * SAFETY CONTRACT: the trace contains ONLY routing metadata — invocation id, + * strategy, combo name, per-target provider/model, decision, allowlisted skip + * reason, timestamps, terminal status. Never prompts, request/response bodies, + * headers, credentials, account ids, or raw upstream error strings. + * + * Retention: bounded in-memory (TTL + LRU cap) — see TRACE_TTL_MS/MAX_TRACES. + */ +import { randomUUID } from "node:crypto"; + +export const COMBO_SKIP_REASONS = [ + "circuit_open", + "provider_cooldown", + "request_exhaustion", + "model_lockout", + "quota_cutoff", + "availability", + "credential_gate", + "concurrency_cap", + "admission_lane", + "predictive_ttft", +] as const; + +export type ComboSkipReason = (typeof COMBO_SKIP_REASONS)[number]; + +export type ComboDecision = "dispatched" | "skipped_before_dispatch" | "not_reached"; + +export interface ComboTraceEntry { + /** Safe internal identifier of the combo step (execution key). */ + step: string; + /** Safe routing metadata: "/". */ + target: string; + decision: ComboDecision; + reason?: ComboSkipReason; + ts: number; +} + +export interface ComboTrace { + invocationId: string; + createdAt: number; + strategy: string | null; + comboName: string | null; + decisions: ComboTraceEntry[]; + terminal: { status: number | null; errorClass: string | null } | null; +} + +const TRACE_TTL_MS = 30 * 60 * 1000; +const MAX_TRACES = 2000; +const traces = new Map(); + +export function createInvocationId(): string { + return `combo-${randomUUID()}`; +} + +function isComboSkipReason(value: unknown): value is ComboSkipReason { + return typeof value === "string" && (COMBO_SKIP_REASONS as readonly string[]).includes(value); +} + +/** Test hook: clear the in-memory store. */ +export function resetComboTraceStore(): void { + traces.clear(); +} + +export function startComboTrace( + invocationId: string, + meta: { strategy?: string | null; comboName?: string | null } +): void { + pruneExpired(); + if (traces.size >= MAX_TRACES) { + // Prefer evicting a FINALIZED trace so in-flight (unfinalized) invocations + // survive a burst; fall back to the oldest trace overall. + let victim: ComboTrace | null = null; + for (const trace of traces.values()) { + if (trace.terminal !== null && (!victim || trace.createdAt < victim.createdAt)) { + victim = trace; + } + } + if (!victim) { + for (const trace of traces.values()) { + if (!victim || trace.createdAt < victim.createdAt) victim = trace; + } + } + if (victim) traces.delete(victim.invocationId); + } + if (!traces.has(invocationId)) { + traces.set(invocationId, { + invocationId, + createdAt: Date.now(), + strategy: meta.strategy ?? null, + comboName: meta.comboName ?? null, + decisions: [], + terminal: null, + }); + } +} + +export function recordComboDecision( + invocationId: string, + entry: Omit & { reason?: unknown } +): void { + const trace = traces.get(invocationId); + if (!trace) return; + if (entry.reason !== undefined && !isComboSkipReason(entry.reason)) { + throw new Error( + `invalid combo skip reason: ${String(entry.reason)} (allowlist: ${COMBO_SKIP_REASONS.join(", ")})` + ); + } + trace.decisions.push({ + step: entry.step, + target: entry.target, + decision: entry.decision, + reason: entry.reason as ComboSkipReason | undefined, + ts: Date.now(), + }); +} + +export function finishComboTrace( + invocationId: string, + terminal: { status: number | null; errorClass?: string | null } +): void { + const trace = traces.get(invocationId); + if (!trace) return; + trace.terminal = { status: terminal.status, errorClass: terminal.errorClass ?? null }; +} + +/** + * Mark every target that received no decision as not_reached and return the + * trace. Safe to call on success and failure paths; idempotent. + */ +export function finalizeComboTrace( + invocationId: string, + orderedTargets: Array<{ executionKey: string; modelStr: string }> +): ComboTrace | null { + const trace = traces.get(invocationId); + if (!trace) return null; + const decided = new Set(trace.decisions.map((d) => d.step)); + for (const t of orderedTargets) { + if (!decided.has(t.executionKey)) { + trace.decisions.push({ + step: t.executionKey, + target: t.modelStr, + decision: "not_reached", + ts: Date.now(), + }); + } + } + return trace; +} + +export function getComboTrace(invocationId: string): ComboTrace | null { + const trace = traces.get(invocationId); + if (!trace) return null; + if (Date.now() - trace.createdAt > TRACE_TTL_MS) { + traces.delete(invocationId); + return null; + } + return trace; +} + +function pruneExpired(): void { + const now = Date.now(); + for (const [id, trace] of traces) { + if (now - trace.createdAt > TRACE_TTL_MS) traces.delete(id); + } +} diff --git a/open-sse/services/combo/dispatchPrelude.ts b/open-sse/services/combo/dispatchPrelude.ts index 2f5361a4cf..8fbaff5c82 100644 --- a/open-sse/services/combo/dispatchPrelude.ts +++ b/open-sse/services/combo/dispatchPrelude.ts @@ -65,6 +65,7 @@ type RunCombo = (options: HandleComboChatOptions) => Promise; * hand back to it when it dispatches a nested combo-ref. */ type PreludeBaseOptionArgs = { + invocationId?: string; body: Record; combo: ComboLike; handleSingleModel: HandleSingleModel; @@ -103,6 +104,7 @@ function buildBaseOptions(a: PreludeBaseOptionArgs): HandleComboChatOptions { signal: a.signal, apiKeyAllowedConnections: a.apiKeyAllowedConnections, hiddenModelsByProvider: a.hiddenModelsByProvider, + invocationId: a.invocationId, clientManagedResponsesContext: a.clientManagedResponsesContext, perTargetAdmission: a.perTargetAdmission, deferContextOverflowWhenCompressible: a.deferContextOverflowWhenCompressible, diff --git a/open-sse/services/combo/types.ts b/open-sse/services/combo/types.ts index 03349e43c7..83a7f26693 100644 --- a/open-sse/services/combo/types.ts +++ b/open-sse/services/combo/types.ts @@ -100,6 +100,8 @@ export type ComboNestingContext = { export type HiddenModelsByProvider = ReadonlyMap>; export type HandleComboChatOptions = { + /** #10681: optional opaque parent invocation id for the decision trace. */ + invocationId?: string; body: Record; combo: ComboLike; handleSingleModel: HandleSingleModel; diff --git a/src/app/api/usage/combo-trace/[id]/route.ts b/src/app/api/usage/combo-trace/[id]/route.ts new file mode 100644 index 0000000000..0615daf309 --- /dev/null +++ b/src/app/api/usage/combo-trace/[id]/route.ts @@ -0,0 +1,25 @@ +import { NextResponse } from "next/server"; +import { requireManagementAuth } from "@/lib/api/requireManagementAuth"; +import { getComboTrace } from "@omniroute/open-sse/services/combo/decisionTrace.ts"; + +/** + * #10681: read the ordered per-target decision trace for one combo invocation. + * Safe by construction: the trace holds routing metadata only (provider/model, + * decision, allowlisted skip reason, terminal status) — never prompts, request + * or response bodies, headers, credentials, account ids, or raw upstream + * errors. Retention is bounded in-memory (30min TTL, 2000 invocations). + */ +export async function GET(request: Request, { params }: { params: Promise<{ id: string }> }) { + const authError = await requireManagementAuth(request); + if (authError) return authError; + + const { id } = await params; + if (!id || !id.startsWith("combo-")) { + return NextResponse.json({ error: "Invalid invocation id" }, { status: 400 }); + } + const trace = getComboTrace(id); + if (!trace) { + return NextResponse.json({ error: "Combo trace not found or expired" }, { status: 404 }); + } + return NextResponse.json(trace); +} diff --git a/tests/unit/combo/combo-decision-trace.test.ts b/tests/unit/combo/combo-decision-trace.test.ts new file mode 100644 index 0000000000..0da363ad34 --- /dev/null +++ b/tests/unit/combo/combo-decision-trace.test.ts @@ -0,0 +1,311 @@ +// #10681: combo decision trace — unit + integration (public handleComboChat). +import { test, beforeEach } 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-trace-")); +process.env.DATA_DIR = TEST_DATA_DIR; +process.env.API_KEY_SECRET = process.env.API_KEY_SECRET || "combo-decision-trace-secret"; + +const { + COMBO_SKIP_REASONS, + createInvocationId, + finalizeComboTrace, + getComboTrace, + recordComboDecision, + resetComboTraceStore, + startComboTrace, +} = await import("../../../open-sse/services/combo/decisionTrace.ts"); +const { handleComboChat } = await import("../../../open-sse/services/combo.ts"); +const { recordComboRequest, resetComboMetrics } = + await import("../../../open-sse/services/comboMetrics.ts"); + +const noop = () => {}; +const log = { info: noop, warn: noop, debug: noop, error: noop }; + +function okResponse(content: string) { + return new Response(JSON.stringify({ choices: [{ message: { role: "assistant", content } }] }), { + status: 200, + headers: { "Content-Type": "application/json" }, + }); +} +function rateLimitedResponse() { + return new Response( + JSON.stringify({ + error: { message: "rate limited", type: "rate_limit_error", code: "rate_limit" }, + }), + { status: 429, headers: { "Content-Type": "application/json" } } + ); +} + +beforeEach(() => resetComboTraceStore()); + +test("createInvocationId yields unique opaque ids", () => { + const a = createInvocationId(); + const b = createInvocationId(); + assert.ok(a.startsWith("combo-")); + assert.notEqual(a, b); +}); + +test("skip reasons are allowlisted (unknown reason is rejected)", () => { + startComboTrace("combo-t", { strategy: "priority", comboName: "x" }); + for (const reason of COMBO_SKIP_REASONS) { + recordComboDecision("combo-t", { + step: "s", + target: "p/m", + decision: "skipped_before_dispatch", + reason, + }); + } + assert.throws(() => + recordComboDecision("combo-t", { + step: "s", + target: "p/m", + decision: "skipped_before_dispatch", + reason: "freeform upstream error", + }) + ); + assert.equal(getComboTrace("combo-t")!.decisions.length, COMBO_SKIP_REASONS.length); +}); + +test("finalize marks never-iterated targets as not_reached", () => { + startComboTrace("combo-t", { strategy: "priority", comboName: "x" }); + recordComboDecision("combo-t", { step: "s1", target: "p/a", decision: "dispatched" }); + recordComboDecision("combo-t", { + step: "s2", + target: "p/b", + decision: "skipped_before_dispatch", + reason: "provider_cooldown", + }); + const trace = finalizeComboTrace("combo-t", [ + { executionKey: "s1", modelStr: "p/a" }, + { executionKey: "s2", modelStr: "p/b" }, + { executionKey: "s3", modelStr: "p/c" }, + ])!; + assert.deepEqual( + trace.decisions.map((d) => d.decision), + ["dispatched", "skipped_before_dispatch", "not_reached"] + ); +}); + +test("handleComboChat: mixed fallback produces an ordered decision trace", async () => { + const invocationId = createInvocationId(); + const calls: string[] = []; + const res = await handleComboChat({ + invocationId, + body: { messages: [{ role: "user", content: "ping" }] }, + combo: { + name: "trace-std", + strategy: "priority", + models: ["openai/a", "openai/b", "openai/c"], + config: { maxRetries: 0, retryDelayMs: 0, fallbackDelayMs: 0 }, + }, + handleSingleModel: async (_b: Record, modelStr: string) => { + calls.push(modelStr); + if (modelStr === "openai/a") return rateLimitedResponse(); + return okResponse("recovered"); + }, + isModelAvailable: async () => true, + log, + settings: null, + allCombos: null, + }); + assert.equal(res.status, 200); + assert.deepEqual(calls, ["openai/a", "openai/b"]); + + const trace = getComboTrace(invocationId)!; + assert.equal(trace.comboName, "trace-std"); + assert.equal(trace.strategy, "priority"); + assert.deepEqual( + trace.decisions.map((d) => ({ target: d.target, decision: d.decision })), + [ + { target: "openai/a", decision: "dispatched" }, + { target: "openai/b", decision: "dispatched" }, + { target: "openai/c", decision: "not_reached" }, + ] + ); + assert.equal(trace.terminal?.status, 200); +}); + +test("handleComboChat: predictive-TTFT skip records skipped_before_dispatch/predictive_ttft", async () => { + const comboName = "trace-predictive-ttft"; + resetComboMetrics(comboName); + // Seed enough samples (>= PREDICTIVE_TTFT_MIN_SAMPLES) with a high average + // latency for openai/a so the predictive-TTFT breaker trusts and trips on it. + for (let i = 0; i < 5; i++) { + recordComboRequest(comboName, "openai/a", { + success: true, + latencyMs: 5000, + strategy: "priority", + }); + } + + const invocationId = createInvocationId(); + const calls: string[] = []; + const res = await handleComboChat({ + invocationId, + body: { messages: [{ role: "user", content: "ping" }] }, + combo: { + name: comboName, + strategy: "priority", + models: ["openai/a", "openai/b"], + config: { + maxRetries: 0, + retryDelayMs: 0, + fallbackDelayMs: 0, + zeroLatencyOptimizationsEnabled: true, + predictiveTtftMs: 100, + }, + }, + handleSingleModel: async (_b: Record, modelStr: string) => { + calls.push(modelStr); + return okResponse(`ok-${modelStr}`); + }, + isModelAvailable: async () => true, + log, + settings: null, + allCombos: null, + }); + assert.equal(res.status, 200); + // openai/a must never be dispatched — it is skipped pre-flight by the + // predictive-TTFT breaker; only openai/b is actually called. + assert.deepEqual(calls, ["openai/b"]); + + const trace = getComboTrace(invocationId)!; + assert.deepEqual( + trace.decisions.map((d) => ({ + target: d.target, + decision: d.decision, + reason: d.reason ?? null, + })), + [ + { target: "openai/a", decision: "skipped_before_dispatch", reason: "predictive_ttft" }, + { target: "openai/b", decision: "dispatched", reason: null }, + ] + ); +}); + +test("handleComboChat: pre-dispatch skip records allowlisted reason", async () => { + const invocationId = createInvocationId(); + const res = await handleComboChat({ + invocationId, + body: { messages: [{ role: "user", content: "ping" }] }, + combo: { + name: "trace-skip", + strategy: "priority", + models: ["openai/a", "openai/b", "openai/c"], + config: { maxRetries: 0, retryDelayMs: 0, fallbackDelayMs: 0 }, + }, + handleSingleModel: async (_b, modelStr) => + modelStr === "openai/a" ? rateLimitedResponse() : okResponse(`ok-${modelStr}`), + isModelAvailable: async (_m: string, target?: { modelStr?: string }) => + target?.modelStr !== "openai/b", + log, + settings: null, + allCombos: null, + }); + assert.equal(res.status, 200); + const trace = getComboTrace(invocationId)!; + assert.deepEqual( + trace.decisions.map((d) => ({ + target: d.target, + decision: d.decision, + reason: d.reason ?? null, + })), + [ + { target: "openai/a", decision: "dispatched", reason: null }, + { target: "openai/b", decision: "skipped_before_dispatch", reason: "availability" }, + { target: "openai/c", decision: "dispatched", reason: null }, + ] + ); +}); + +test("egress: every response carries X-OmniRoute-Combo-Trace (success path)", async () => { + const invocationId = createInvocationId(); + const res = await handleComboChat({ + invocationId, + body: { messages: [{ role: "user", content: "ping" }] }, + combo: { + name: "egress-ok", + strategy: "priority", + models: ["openai/a", "openai/b"], + config: { maxRetries: 0, retryDelayMs: 0, fallbackDelayMs: 0 }, + }, + handleSingleModel: async () => okResponse("recovered"), + isModelAvailable: async () => true, + log, + settings: null, + allCombos: null, + }); + assert.equal(res.status, 200); + assert.equal(res.headers.get("X-OmniRoute-Combo-Trace"), invocationId); +}); + +test("egress: header present even when every target fails", async () => { + const invocationId = createInvocationId(); + const res = await handleComboChat({ + invocationId, + body: { messages: [{ role: "user", content: "ping" }] }, + combo: { + name: "egress-fail", + strategy: "priority", + models: ["openai/a", "openai/b"], + config: { maxRetries: 0, retryDelayMs: 0, fallbackDelayMs: 0 }, + }, + handleSingleModel: async () => rateLimitedResponse(), + isModelAvailable: async () => true, + log, + settings: null, + allCombos: null, + }); + assert.notEqual(res.status, 200); + assert.equal(res.headers.get("X-OmniRoute-Combo-Trace"), invocationId); +}); + +test("egress: finalized trace is emitted as one metadata-only log line", async () => { + const invocationId = createInvocationId(); + const infoCalls: string[] = []; + const capturingLog = { + info: (_cat: string, msg: string) => infoCalls.push(msg), + warn: noop, + debug: noop, + error: noop, + }; + const res = await handleComboChat({ + invocationId, + body: { messages: [{ role: "user", content: "ping" }] }, + combo: { + name: "egress-log", + strategy: "priority", + models: ["openai/a", "openai/b"], + config: { maxRetries: 0, retryDelayMs: 0, fallbackDelayMs: 0 }, + }, + handleSingleModel: async () => okResponse("recovered"), + isModelAvailable: async () => true, + log: capturingLog, + settings: null, + allCombos: null, + }); + assert.equal(res.status, 200); + const line = infoCalls.find((m) => m.includes("combo trace") && m.includes(invocationId)); + assert.ok(line, "finalized trace log line expected"); + assert.ok(line!.includes('"status":200'), "log line must carry the terminal status"); + assert.ok(!line!.includes("messages"), "log line must not carry request content"); +}); + +test("retention: in-flight traces are pinned against eviction (finalized evicted first)", () => { + resetComboTraceStore(); + for (let i = 0; i < 2000; i++) { + startComboTrace(`combo-t-${i}`, { strategy: "priority", comboName: "x" }); + } + // Only the FIRST trace is finalized; the other 1999 are still in flight. + finalizeComboTrace("combo-t-0", [{ executionKey: "s", modelStr: "p/m" }]); + // Burst beyond the cap: eviction must prefer the finalized trace. + startComboTrace("combo-t-2000", { strategy: "priority", comboName: "x" }); + assert.equal(getComboTrace("combo-t-0"), null, "finalized trace is the eviction victim"); + assert.ok(getComboTrace("combo-t-1"), "in-flight trace survives the burst"); + assert.ok(getComboTrace("combo-t-1999"), "in-flight trace survives the burst"); + assert.ok(getComboTrace("combo-t-2000"), "new trace is stored"); +});