fix(quality): detect duplicate tool_calls entries in one response (#12446)

Validado em lote numa worktree combinada com os 9 PRs desta leva sobre o tip de `release/v3.8.51` (já com a leva anterior dentro): os nove boardaram **sem um único conflito**, `typecheck:core` limpo e **80/80** nos 6 arquivos de teste que os PRs trazem.

O crescimento de arquivo próprio da leva foi rebaselinado num registro datado (`_rebaseline_2026_09_03_hartmark_batch`): `combos/page.tsx` 5012→5018 (#12355, tratar o estado degradado quando o bundling de tiktoken de um provider sem relação falha) e `open-sse/services/combo.ts` 4023→4036 (#12338, os fixes do universal-handoff). As violações restantes (`codex.ts`, `stream.ts`) foram medidas também no tip puro e são drift da base, não desta leva.

Obrigado, @hartmark.
This commit is contained in:
Markus Hartung
2026-09-03 18:01:25 +02:00
committed by GitHub
parent 4ec4ce410e
commit 2e4a79ca50
4 changed files with 162 additions and 3 deletions

View File

@@ -13,6 +13,7 @@
import { extractProviderWarnings } from "@/lib/compliance/providerAudit";
import { logAuditEvent } from "@/lib/compliance";
import { emit } from "@/lib/events/eventBus";
import { maybeLogToolCallSpecViolation } from "./toolCallSpecViolationAudit.ts";
import type { RequestCompletedPayload, RequestFailedPayload } from "@/lib/events/types";
import { saveCallLog } from "@/lib/usageDb";
import type { VideoBridgeLogRedactionEntry } from "@/lib/guardrails/videoBridge";
@@ -392,6 +393,15 @@ export function persistAttemptLogs(args: PersistAttemptLogsArgs, ctx: PersistAtt
});
}
maybeLogToolCallSpecViolation({
responseBody,
provider,
model,
connectionId: finalConnectionId,
httpStatus: status,
requestId: skillRequestId,
});
const capturedPipeline = reqLogger?.getPipelinePayloads?.() ?? null;
const pipelinePayloads = detailedLoggingEnabled
? (capturedPipeline ?? {})

View File

@@ -0,0 +1,46 @@
/**
* Post-request on-spec audit for duplicated tool_calls.
*
* Extracted from persistAttemptLogs so attemptLogging.ts stays at the frozen
* complexity count. validateResponseQuality's streaming peek only sees the
* START of a stream, so a duplicate that arrives after real content has
* already been relayed cannot fail the attempt over — this is the first
* point the fully assembled body is available. Too late to retry; a durable
* audit row still beats a clean HTTP 200 with no trace.
*
* Observed: minimax-m3:free via OpenRouter/GMICloud, 2026-09-02, duplicated
* a heartbeat_respond call byte-for-byte.
*/
import { logAuditEvent } from "@/lib/compliance";
import { findToolCallSpecViolation } from "../../services/combo/validateQuality.ts";
export function maybeLogToolCallSpecViolation(input: {
responseBody: unknown;
provider: string | null | undefined;
model: string | null | undefined;
connectionId: string | null;
httpStatus: number;
requestId: string;
}): void {
const violation = findToolCallSpecViolation(input.responseBody);
if (!violation) return;
logAuditEvent({
action: "provider.spec_violation",
actor: "system",
target:
[input.provider, input.connectionId].filter(Boolean).join(":") ||
input.provider ||
input.model,
resourceType: "provider_spec_violation",
status: "warning",
requestId: input.requestId,
details: {
provider: input.provider,
model: input.model,
connectionId: input.connectionId,
httpStatus: input.httpStatus,
violation,
},
});
}

View File

@@ -16,6 +16,45 @@ import { evaluateResponseValidation, type ResponseValidationConfig } from "./res
import { getReasoningTokens } from "../../../src/lib/usage/tokenAccounting.ts";
import type { ComboRetryAfter } from "./types.ts";
/**
* Detects tool_calls entries within one assistant message that repeat the
* exact same function name + arguments verbatim -- always a bug (no
* legitimate use calls one tool twice with identical arguments in the same
* turn), and a real observed failure mode of at least one free-tier
* streaming model (minimax-m3:free via OpenRouter/GMICloud, 2026-09-02:
* duplicated a heartbeat_respond call byte-for-byte, confirmed at the raw
* SSE wire level -- an upstream bug, not an OmniRoute reconstruction
* artifact). Used two ways: to fail a non-streaming response over to a
* sibling combo target (see validateResponseQuality below), and, post-
* stream, to flag an already-relayed streaming response as an on-spec
* violation despite its clean HTTP 200 (see attemptLogging.ts's
* persistAttemptLogs) -- a streaming response can't be retried once real
* content has started reaching the client (the quality-gate peek below only
* ever validates the START of a stream, by design, to avoid buffering the
* whole response and defeating streaming's latency purpose), so flagging it
* after the fact is what's actually achievable for that path.
*/
export function findToolCallSpecViolation(responseBody: unknown): string | null {
const json = isRecord(responseBody) ? responseBody : null;
const choices = json?.choices;
const firstChoice = Array.isArray(choices) ? choices[0] : null;
const message = isRecord(firstChoice) ? firstChoice.message : null;
const toolCalls = isRecord(message) ? message.tool_calls : null;
if (!Array.isArray(toolCalls) || toolCalls.length < 2) return null;
const seen = new Set<string>();
for (const call of toolCalls) {
const fn = isRecord(call) ? call.function : null;
if (!isRecord(fn) || typeof fn.name !== "string" || typeof fn.arguments !== "string") {
continue;
}
const signature = `${fn.name}\u0000${fn.arguments}`;
if (seen.has(signature)) return `duplicate tool_calls entry for "${fn.name}"`;
seen.add(signature);
}
return null;
}
export function toRetryAfterDisplayValue(value: ComboRetryAfter): string | Date {
if (typeof value !== "number") return value;
if (value > 0 && value < 1_000_000_000) {
@@ -327,9 +366,9 @@ export async function validateResponseQuality(
function isTerminalUsageOnlyChunk(parsed: Record<string, unknown>, eventType: string): boolean {
return Boolean(
parsed.usage &&
typeof parsed.usage === "object" &&
!Array.isArray(parsed.choices) &&
!eventType.startsWith("response.")
typeof parsed.usage === "object" &&
!Array.isArray(parsed.choices) &&
!eventType.startsWith("response.")
);
}
@@ -734,6 +773,11 @@ export async function validateResponseQuality(
}
const hasToolCalls = Array.isArray(toolCalls) && toolCalls.length > 0;
const specViolation = findToolCallSpecViolation(json);
if (specViolation) {
return { valid: false, reason: specViolation };
}
if (!hasContent && !hasToolCalls) {
return { valid: false, reason: "empty content and no tool_calls in response" };
}

View File

@@ -16,6 +16,7 @@ process.env.DATA_DIR = testDataDir;
const coreDb = await import("../../src/lib/db/core.ts");
const { getCallLogById } = await import("../../src/lib/usage/callLogs.ts");
const { persistAttemptLogs } = await import("../../open-sse/handlers/chatCore/attemptLogging.ts");
const { getAuditLog } = await import("../../src/lib/compliance/index.ts");
type CodexRotationEnvelope = {
_omniroute?: {
@@ -136,3 +137,61 @@ test("connectionId falls back to credentials.connectionId when null, and error i
assert.equal(row.status, 502);
assert.match(String(row.error ?? ""), /upstream boom/);
});
function duplicateHeartbeatBody() {
return {
choices: [
{
message: {
tool_calls: [
{ function: { name: "heartbeat_respond", arguments: "{}" } },
{ function: { name: "heartbeat_respond", arguments: "{}" } },
],
},
},
],
};
}
test("duplicate tool_calls in the assembled body writes provider.spec_violation audit", () => {
persistAttemptLogs(
{ status: 200, responseBody: duplicateHeartbeatBody() },
baseCtx({ pendingRequestId: "attempt-spec-violation-1", skillRequestId: "skill-spec-1" })
);
// logAuditEvent is synchronous; do not wait on the fire-and-forget saveCallLog.
const rows = getAuditLog({ action: "provider.spec_violation", requestId: "skill-spec-1" });
assert.equal(rows.length, 1);
assert.equal(rows[0]?.resourceType, "provider_spec_violation");
const details = rows[0]?.details;
assert.ok(details && typeof details === "object");
assert.equal(
(details as { violation?: string }).violation,
'duplicate tool_calls entry for "heartbeat_respond"'
);
});
test("unique tool_calls do not write provider.spec_violation audit", () => {
persistAttemptLogs(
{
status: 200,
responseBody: {
choices: [
{
message: {
tool_calls: [
{ function: { name: "heartbeat_respond", arguments: "{}" } },
{ function: { name: "other_tool", arguments: "{}" } },
],
},
},
],
},
},
baseCtx({ pendingRequestId: "attempt-spec-clean-1", skillRequestId: "skill-spec-clean-1" })
);
const rows = getAuditLog({
action: "provider.spec_violation",
requestId: "skill-spec-clean-1",
});
assert.equal(rows.length, 0);
});