Files
OmniRoute/tests/unit/request-logger-endpoints.test.ts
Bob.Hou d6f315018a fix(chat): continue after a server-owned tool on Chat Completions (#12867)
Validado numa worktree combinada com as 16 PRs desta leva sobre `release/v3.8.51`: typecheck:core limpo, check-file-size e check-changelog-integrity OK, complexity 2788/3218 e cognitive 1261/1437, ESLint 0 erros nos 152 arquivos alterados, e a suíte vitest:ui completa (2149) verde.

Sobre esta PR especificamente: rodei os **23 arquivos de teste** que ela toca sobre o tip final, depois do merge da base — **392/392**. A migration `174_server_tool_executions.sql` não colide (o tip está em 173, e você já a renumerou em `c35f0fd7`).

O dono foi consultado antes do merge, porque o loop está atrás da flag `SERVER_OWNED_TOOL_LOOP_ENABLED` mas o primeiro send não-streaming mudou de dono sem flag, e a verificação manual em combo com Memory continuava desmarcada. A condição dele foi: entra se os testes focados passarem aqui. Passaram.

O lock de passthrough (`fetchCalls.length === 1`) é a parte que mais me convenceu — o double-dispatch que um `if (stream)` em volta do send existente causaria é exatamente o tipo de regressão que não aparece em teste de comportamento, só em contagem de chamada.

**Três ajustes meus na sua branch:**

1. `tests/unit/chatcore-stream-error-result.test.ts` procurava `"const legResult = await runNonStreamingProviderLeg"`, mas o seu commit final `6077b9dd` passou a reatribuir `legResult` e trocou para `let`. O guard falhava na sua própria branch (confirmei que o arquivo e o `chatCore.ts` eram byte-idênticos ao head da PR, então não era efeito da leva). Passou a aceitar `const|let` — a intenção do guard é o try/catch em volta da chamada, não a palavra-chave.

2. `tests/integration/skills-pipeline.test.ts` foi de 1156 para 1338 linhas e estourou o `testCap` de 1200. Segui o mesmo caminho que você já tinha tomado em `a1d2d20d` para os testes unitários: extraí os três casos do server-owned tool loop para `tests/integration/server-owned-tool-loop-pipeline.test.ts` (259 linhas), com instância própria do harness. O glob `tests/integration/*.test.ts` pega o arquivo novo sem registro adicional. 3/3 verdes isolados.

3. O arquivo novo herdou cinco `any` do original — que só passavam por estarem congelados no `eslint-suppressions.json` sob o nome antigo. Tipei como `Record<string, unknown>`. E `tests/unit/non-streaming-finalization.test.ts` tinha dois argumentos não usados em `trackPendingRequest`, agora prefixados com `_`.

Nada disso toca produção nem enfraquece asserção.
2026-09-07 09:15:00 -03:00

790 lines
30 KiB
TypeScript

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-reqlogger-ep-"));
process.env.DATA_DIR = TEST_DATA_DIR;
const core = await import("../../src/lib/db/core.ts");
const usageHistory = await import("../../src/lib/usage/usageHistory.ts");
const callLogs = await import("../../src/lib/usage/callLogs.ts");
test.after(() => {
core.resetDbInstance();
fs.rmSync(TEST_DATA_DIR, { recursive: true, force: true, maxRetries: 5, retryDelay: 100 });
});
// Captured stream chunks are prefixed with a per-chunk arrival timestamp
// ("[HH:MM:SS.mmm] ") by the request logger for streaming-latency observability
// (added in #5834 / correlation-id observability). Strip it before comparing the
// raw payload so these assertions verify the chunk content + ordering, not the clock.
const stripChunkTs = (chunk: string): string => chunk.replace(/^\[\d{2}:\d{2}:\d{2}\.\d{3}\] /, "");
// ─── Active log endpoint removal ─────────────────────────────────────────
test("/api/logs/active route is removed", () => {
assert.equal(
fs.existsSync("src/app/api/logs/active/route.ts"),
false,
"active logs must not expose an in-memory timing-sensitive endpoint"
);
});
test("RequestLoggerV2 detail fetch uses /api/logs/[id] and not /api/logs/active", () => {
const content = fs.readFileSync("src/shared/components/RequestLoggerV2.tsx", "utf8");
assert.match(content, /fetch\(`\/api\/logs\/\$\{[^}]+\.id\}`,\s*\{\s*cache:\s*"no-store"/);
assert.doesNotMatch(content, /fetch\(["'`]\/api\/logs\/active/);
assert.match(content, /detailState:\s*"pending"/);
});
// ─── usageHistory module behaviour ───────────────────────────────────────
test("trackPendingRequest creates a detail entry", () => {
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "conn-1", true, {
clientRequest: { messages: [{ role: "user", content: "hi" }] },
providerRequest: { model: "gpt-4" },
providerUrl: "https://api.openai.com/v1/chat/completions",
});
const pending = usageHistory.getPendingRequests();
const detail = pending.details["conn-1"]?.["gpt-4 (openai)"]?.[0];
assert.ok(detail, "should create detail entry");
assert.equal(detail.model, "gpt-4");
assert.equal(detail.provider, "openai");
assert.equal(detail.connectionId, "conn-1");
assert.ok(detail.id, "should have an id");
assert.ok(detail.startedAt > 0, "should have startedAt timestamp");
assert.ok(detail.clientRequest, "should preserve clientRequest");
assert.equal(detail.clientRequest.messages[0].content, "hi");
});
test("trackPendingRequest decrements and removes detail on finish", () => {
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "conn-1", true);
assert.equal(usageHistory.getPendingRequests().details["conn-1"]?.["gpt-4 (openai)"]?.length, 1);
usageHistory.trackPendingRequest("gpt-4", "openai", "conn-1", false);
const after = usageHistory.getPendingRequests();
assert.equal(after.details["conn-1"]?.["gpt-4 (openai)"]?.length ?? 0, 0);
});
test("trackPendingRequest does not go negative", () => {
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "conn-1", false);
usageHistory.trackPendingRequest("gpt-4", "openai", "conn-1", false);
const pending = usageHistory.getPendingRequests();
assert.equal(pending.byModel["gpt-4 (openai)"], 0);
});
test("updatePendingRequestStreamChunks stores stream chunks in the detail", () => {
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "conn-1", true);
const chunks = { provider: ['data: {"a":1}'], openai: [], client: [] };
usageHistory.updatePendingRequestStreamChunks("gpt-4", "openai", "conn-1", chunks);
const pending = usageHistory.getPendingRequests();
const detail = pending.details["conn-1"]?.["gpt-4 (openai)"]?.[0];
assert.ok(detail.streamChunks, "streamChunks should be set");
assert.equal(detail.streamChunks.provider.length, 1);
assert.equal(detail.streamChunks.provider[0], 'data: {"a":1}');
});
test("updatePendingRequest keeps pending detail API view in sync", () => {
usageHistory.clearPendingRequests();
const requestId = usageHistory.trackPendingRequest(
"claude-sonnet-4-6",
"cc-test",
"conn-1",
true,
{
clientRequest: { model: "cc-test/claude-sonnet-4-6", reasoning_effort: "xhigh" },
providerRequest: { model: "claude-sonnet-4-6", reasoning_effort: "xhigh" },
}
);
assert.ok(requestId, "trackPendingRequest should return an id");
usageHistory.updatePendingRequest("claude-sonnet-4-6", "cc-test", "conn-1", {
providerRequest: { model: "claude-sonnet-4-6", reasoning_effort: "high" },
stage: "provider_response_started",
});
const modelKey = "claude-sonnet-4-6 (cc-test)";
const detailFromQueue = usageHistory.getPendingRequests().details["conn-1"]?.[modelKey]?.[0];
const detailFromId = usageHistory.getPendingById().get(requestId);
assert.equal(detailFromId, detailFromQueue);
assert.deepEqual(detailFromId?.providerRequest, {
model: "claude-sonnet-4-6",
reasoning_effort: "high",
});
assert.deepEqual(detailFromId?.clientRequest, {
model: "cc-test/claude-sonnet-4-6",
reasoning_effort: "xhigh",
});
});
test("updatePendingRequestById updates and finalizes the exact overlapping request", () => {
usageHistory.clearPendingRequests();
const firstId = usageHistory.trackPendingRequest("claude-sonnet-4-6", "cc-test", "conn-1", true, {
providerRequest: { request: "first", reasoning_effort: "xhigh" },
});
const secondId = usageHistory.trackPendingRequest(
"claude-sonnet-4-6",
"cc-test",
"conn-1",
true,
{
providerRequest: { request: "second", reasoning_effort: "xhigh" },
}
);
assert.ok(firstId);
assert.ok(secondId);
const updated = usageHistory.updatePendingRequestById(firstId, {
providerRequest: { request: "first", reasoning_effort: "high" },
stage: "sending_to_provider",
});
assert.equal(updated, true);
const modelKey = "claude-sonnet-4-6 (cc-test)";
const details = usageHistory.getPendingRequests().details["conn-1"]?.[modelKey];
assert.equal(details?.length, 2);
assert.deepEqual(details?.[0]?.providerRequest, {
request: "first",
reasoning_effort: "high",
});
assert.deepEqual(details?.[1]?.providerRequest, {
request: "second",
reasoning_effort: "xhigh",
});
const completed = usageHistory.finalizePendingRequestById(firstId, {
clientResponse: { ok: true },
});
assert.equal(completed, true);
assert.deepEqual(usageHistory.getCompletedDetails().get(firstId)?.providerRequest, {
request: "first",
reasoning_effort: "high",
});
assert.equal(usageHistory.getPendingById().has(secondId), true);
});
test("updatePendingRequestStreamChunks stores empty streamChunks object (not null)", () => {
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "conn-1", true);
// Call with empty arrays (as pushStreamChunks does before data flows)
const empty = { provider: [], openai: [], client: [] };
usageHistory.updatePendingRequestStreamChunks("gpt-4", "openai", "conn-1", empty);
const pending = usageHistory.getPendingRequests();
const detail = pending.details["conn-1"]?.["gpt-4 (openai)"]?.[0];
assert.ok(detail.streamChunks, "streamChunks should be set even when empty");
assert.deepEqual(detail.streamChunks, { provider: [], openai: [], client: [] });
// Verify the reference is live: mutations to the original object are visible
empty.provider.push("data: hello");
assert.equal(detail.streamChunks.provider.length, 1);
assert.equal(detail.streamChunks.provider[0], "data: hello");
});
test("clearPendingRequests resets all counts and details", () => {
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("m1", "p1", "c1", true);
usageHistory.trackPendingRequest("m2", "p2", "c2", true);
assert.equal(Object.keys(usageHistory.getPendingRequests().byModel).length, 2);
usageHistory.clearPendingRequests();
const pending = usageHistory.getPendingRequests();
assert.equal(Object.keys(pending.byModel).length, 0);
assert.equal(Object.keys(pending.byAccount).length, 0);
assert.equal(Object.keys(pending.details).length, 0);
});
// ─── Pending request data remains available for internal usage stats ─────
test("pending request detail shape remains available internally", () => {
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("claude-3-opus", "anthropic", "conn-2", true, {
clientRequest: { messages: [{ role: "user", content: "hello" }] },
providerRequest: { model: "claude-3-opus" },
providerUrl: "https://api.anthropic.com/v1/messages",
});
const pending = usageHistory.getPendingRequests();
const entries = Object.entries(pending.details).flatMap(([connectionId, models]) =>
Object.entries(models).flatMap(([modelKey, details]) =>
details.map((detail) => ({
id: detail.id,
model: detail.model,
provider: detail.provider,
connectionId,
startedAt: detail.startedAt,
clientRequest: detail.clientRequest ?? null,
providerRequest: detail.providerRequest ?? null,
providerUrl: detail.providerUrl ?? null,
streamChunks: detail.streamChunks ?? null,
}))
)
);
assert.equal(entries.length, 1);
const row = entries[0];
assert.ok(row.id);
assert.equal(row.model, "claude-3-opus");
assert.equal(row.provider, "anthropic");
assert.equal(row.connectionId, "conn-2");
assert.ok(row.startedAt > 0);
assert.ok(row.clientRequest, "clientRequest should be present");
assert.ok(row.providerRequest, "providerRequest should be present");
assert.ok(row.providerUrl, "providerUrl should be present");
assert.equal(row.streamChunks, null, "streamChunks should be null initially");
});
// ─── /api/usage/call-logs/[id] route structure ────────────────────────────
test("GET /api/usage/call-logs/[id] route exists and uses auth", () => {
const content = fs.readFileSync("src/app/api/usage/call-logs/[id]/route.ts", "utf8");
assert.ok(content.includes("export async function GET"), "should export GET handler");
assert.ok(content.includes("requireManagementAuth"), "should check auth");
assert.ok(content.includes("getCallLogById"), "should import getCallLogById");
});
test("GET /api/usage/call-logs includes completed in-memory fallback rows", async () => {
const { buildCallLogListRows } = await import("../../src/app/api/usage/call-logs/route.ts");
usageHistory.clearPendingRequests();
const requestId = usageHistory.trackPendingRequest("gpt-4", "openai", "completed-conn-1", true, {
clientEndpoint: "/v1/chat/completions",
});
assert.ok(requestId);
const completed = usageHistory.finalizePendingRequestById(requestId, {
clientResponse: { choices: [{ message: { content: "done" } }] },
});
assert.equal(completed, true);
const completedDetail = usageHistory.getCompletedDetails().get(requestId);
assert.ok(completedDetail);
const rows = buildCallLogListRows({
logs: [],
connections: [{ id: "completed-conn-1", displayName: "Completed Account" }],
pendingDetails: usageHistory.getPendingById().values(),
completedDetails: usageHistory.getCompletedDetails().values(),
now: completedDetail!.startedAt + 60_000,
});
assert.equal(rows.length, 1);
assert.equal(rows[0].id, requestId);
assert.equal(rows[0].detailState, "in-memory");
assert.equal(rows[0].completed, true);
assert.equal(rows[0].account, "Completed Account");
assert.equal(rows[0].duration, completedDetail!.durationMs);
});
test("GET /api/usage/call-logs rows are ordered by priority then newest-first", async () => {
const { buildCallLogListRows } = await import("../../src/app/api/usage/call-logs/route.ts");
const rows = buildCallLogListRows({
logs: [
{
id: "persisted-newest",
timestamp: new Date(3000).toISOString(),
active: false,
},
{
id: "persisted-oldest",
timestamp: new Date(1000).toISOString(),
active: false,
},
],
connections: [],
pendingDetails: [],
completedDetails: [
{
id: "completed-middle",
model: "gpt-4",
provider: "openai",
connectionId: "conn",
startedAt: 2000,
completedAt: 2500,
durationMs: 500,
},
],
now: 4000,
});
// Rows sort by priority first (active=0 > completed in-memory=1 > persisted=2),
// then newest-first within each priority (#5834 correlation-id observability).
// The completed in-memory entry therefore floats above the persisted DB rows,
// which are ordered newest-first among themselves.
assert.deepEqual(
rows.map((row) => row.id),
["completed-middle", "persisted-newest", "persisted-oldest"]
);
});
test("getCallLogById returns null for unknown id", async () => {
const log = await callLogs.getCallLogById("nonexistent-id-12345");
assert.equal(log, null);
});
// ─── Merged view data shape ────────────────────────────────────────────
test("normalized active row has expected fields for the grid view", () => {
const rawRow = {
id: "test-id-1",
model: "gpt-4",
provider: "openai",
account: "conn-1",
startedAt: Date.now() - 5000,
runningTimeMs: 5000,
stage: "streaming",
stageUpdatedAt: Date.now(),
clientRequest: { messages: [] },
providerRequest: { model: "gpt-4" },
providerUrl: "https://api.openai.com/v1",
streamChunks: null,
};
const normalized = {
active: true,
id: rawRow.id,
model: rawRow.model,
provider: rawRow.provider,
account: rawRow.account,
timestamp: new Date(rawRow.startedAt).toISOString(),
duration: Math.max(0, Date.now() - rawRow.startedAt),
status: 0,
sourceFormat: null,
tokens: null,
comboName: null,
apiKeyName: null,
apiKeyId: null,
cacheSource: null,
requestedModel: null,
stage: rawRow.stage,
stageUpdatedAt: rawRow.stageUpdatedAt,
_activeRow: rawRow,
};
assert.equal(normalized.active, true);
assert.equal(normalized.id, "test-id-1");
assert.equal(normalized.model, "gpt-4");
assert.equal(normalized.provider, "openai");
assert.equal(normalized.status, 0);
assert.ok(normalized.duration >= 5000);
assert.ok(normalized.duration < 60000);
assert.equal(normalized.tokens, null);
assert.equal(normalized.cacheSource, null);
assert.equal(normalized.stage, "streaming");
});
// ─── requestLoggerSignature module ────────────────────────────────────────
const sigMod = await import("../../src/shared/components/requestLoggerSignature.ts");
test("resolveInitialVisibility returns true when document is undefined (SSR)", () => {
assert.equal(sigMod.resolveInitialVisibility(), true);
});
test("shouldAutoRefresh returns true when recording and on first page", () => {
assert.equal(sigMod.shouldAutoRefresh(true, 50, 50), true);
assert.equal(sigMod.shouldAutoRefresh(true, 25, 50), true);
});
test("shouldAutoRefresh returns false when not recording or past first page", () => {
assert.equal(sigMod.shouldAutoRefresh(false, 50, 50), false);
assert.equal(sigMod.shouldAutoRefresh(true, 100, 50), false);
assert.equal(sigMod.shouldAutoRefresh(false, 100, 50), false);
});
test("computeLogsSignature produces different signatures for different data", () => {
const a = sigMod.computeLogsSignature([
{ id: "1", status: 200, duration: 100, tokens: { out: 50 } },
]);
const b = sigMod.computeLogsSignature([
{ id: "1", status: 200, duration: 150, tokens: { out: 50 } },
]);
assert.notEqual(a, b, "different duration should change signature");
});
test("computeLogsSignature returns empty string for non-array input", () => {
assert.equal(sigMod.computeLogsSignature(null), "");
assert.equal(sigMod.computeLogsSignature(undefined), "");
assert.equal(sigMod.computeLogsSignature({}), "");
});
// ─── Duration live computation ───────────────────────────────────────────
test("duration is computed from startedAt and grows over time", () => {
const startedAt = Date.now() - 3000;
const duration = Math.max(0, Date.now() - startedAt);
assert.ok(duration >= 3000, "duration should be at least 3s");
assert.ok(duration < 60000, "duration should be within reason");
});
// ─── Navigation logic ────────────────────────────────────────────────────
test("handlePrev at first item closes modal (no wrap-around)", () => {
const items = [
{ id: "a", active: false },
{ id: "b", active: false },
{ id: "c", active: false },
];
const selectedId = "a";
const idx = items.findIndex((l) => l.id === selectedId);
assert.equal(idx, 0);
// handlePrev should NOT wrap to last item
if (idx > 0) {
assert.equal(items[idx - 1].id, "should not reach");
} else {
// closes modal
assert.ok(true, "prev at first item closes modal");
}
});
test("handlePrev navigates backward when not at first item", () => {
const items = [
{ id: "a", active: false },
{ id: "b", active: false },
{ id: "c", active: false },
];
const selectedId = "b";
const idx = items.findIndex((l) => l.id === selectedId);
assert.equal(idx, 1);
if (idx > 0) {
assert.equal(items[idx - 1].id, "a", "should navigate to previous item");
}
});
test("handleNext at last item closes modal (no wrap-around)", () => {
const items = [
{ id: "a", active: false },
{ id: "b", active: false },
];
const selectedId = "b";
const idx = items.findIndex((l) => l.id === selectedId);
assert.equal(idx, items.length - 1);
// handleNext at last item should close
if (idx < items.length - 1) {
assert.equal(items[idx + 1].id, "should not reach");
} else {
assert.ok(true, "next at last item closes modal");
}
});
test("handleNext navigates forward when not at last item", () => {
const items = [
{ id: "a", active: false },
{ id: "b", active: false },
];
const selectedId = "a";
const idx = items.findIndex((l) => l.id === selectedId);
if (idx < items.length - 1) {
assert.equal(items[idx + 1].id, "b", "should navigate to next item");
}
});
// ─── Detail endpoint polling ─────────────────────────────────────────────
test("deep-linked missing request id is kept pending for /api/logs/[id] polling", () => {
const content = fs.readFileSync("src/shared/components/RequestLoggerV2.tsx", "utf8");
assert.match(content, /pendingLookup:\s*true/);
// A deep-linked id that 404s while still active is kept pending...
assert.match(content, /setDetailData\(\{\s*detailState:\s*"pending"\s*\}\)/);
// ...and the detail-polling effect re-runs on that pending state.
assert.match(content, /detailData\?\.detailState/);
assert.doesNotMatch(content, /activeRequests|completedRows|completedRow/);
});
// ─── End-to-end streamChunks integration ──────────────────────────────────
test("createRequestLogger with connectionId/model/provider populates streamChunks on pending request", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
usageHistory.clearPendingRequests();
// track request so the pending detail entry exists
usageHistory.trackPendingRequest("gpt-4", "openai", "test-conn-1", true, {
clientRequest: { messages: [{ role: "user", content: "hi" }] },
});
const logger = await createRequestLogger("openai", "openai", "gpt-4", {
enabled: true,
captureStreamChunks: true,
connectionId: "test-conn-1",
model: "gpt-4",
provider: "openai",
});
// append a provider chunk — this should call pushStreamChunks() → updatePendingRequestStreamChunks()
logger.appendProviderChunk('data: {"content":"hello"}');
logger.appendProviderChunk('data: {"content":" world"}');
const pending = usageHistory.getPendingRequests();
const detail = pending.details["test-conn-1"]?.["gpt-4 (openai)"]?.[0];
assert.ok(detail, "pending request detail should exist");
assert.ok(detail.streamChunks, "streamChunks should be non-null after appendProviderChunk");
assert.ok(Array.isArray(detail.streamChunks.provider), "provider array should exist");
assert.equal(detail.streamChunks.provider.length, 2, "should have 2 provider chunks");
assert.equal(stripChunkTs(detail.streamChunks.provider[0]), 'data: {"content":"hello"}');
assert.equal(stripChunkTs(detail.streamChunks.provider[1]), 'data: {"content":" world"}');
assert.deepEqual(detail.streamChunks.openai, []);
assert.deepEqual(detail.streamChunks.client, []);
});
test("createRequestLogger requestId binds streamChunks to the exact pending request", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
usageHistory.clearPendingRequests();
const firstId = usageHistory.trackPendingRequest("gpt-4", "openai", "test-conn-a", true);
const secondId = usageHistory.trackPendingRequest("gpt-4", "openai", "test-conn-b", true);
const logger = await createRequestLogger("openai", "openai", "gpt-4", {
enabled: true,
captureStreamChunks: true,
requestId: secondId,
});
logger.appendProviderChunk('data: {"content":"second"}');
const first = usageHistory.getPendingById().get(firstId);
const second = usageHistory.getPendingById().get(secondId);
assert.equal(first?.streamChunks, undefined);
assert.equal(stripChunkTs(second?.streamChunks?.provider[0]), 'data: {"content":"second"}');
});
test("createRequestLogger fallback match does not cross connectionId boundaries", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "test-conn-a", true);
const secondId = usageHistory.trackPendingRequest("gpt-4", "openai", "test-conn-b", true);
const logger = await createRequestLogger("openai", "openai", "gpt-4", {
enabled: true,
captureStreamChunks: true,
connectionId: "test-conn-b",
model: "gpt-4",
provider: "openai",
});
logger.appendProviderChunk('data: {"content":"conn-b"}');
const second = usageHistory.getPendingById().get(secondId);
assert.equal(stripChunkTs(second?.streamChunks?.provider[0]), 'data: {"content":"conn-b"}');
});
test("createRequestLogger without connectionId does not populate streamChunks", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "test-conn-2", true, {
clientRequest: { messages: [{ role: "user", content: "hi" }] },
});
// create logger WITHOUT connectionId/model/provider — pushStreamChunks will bail
const logger = await createRequestLogger("openai", "openai", "gpt-4", {
enabled: true,
captureStreamChunks: true,
// intentionally omit connectionId, model, provider
});
logger.appendProviderChunk('data: {"content":"hello"}');
const pending = usageHistory.getPendingRequests();
const detail = pending.details["test-conn-2"]?.["gpt-4 (openai)"]?.[0];
assert.ok(detail, "pending request detail should exist");
assert.equal(
detail.streamChunks,
undefined,
"streamChunks should be undefined when connectionId not provided to createRequestLogger"
);
});
test("createRequestLogger appendOpenAIChunk and appendConvertedChunk also populate streamChunks", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("claude-3", "anthropic", "test-conn-3", true);
const logger = await createRequestLogger("anthropic", "openai", "claude-3", {
enabled: true,
captureStreamChunks: true,
connectionId: "test-conn-3",
model: "claude-3",
provider: "anthropic",
});
logger.appendOpenAIChunk('data: {"role":"assistant","content":"hi"}');
logger.appendConvertedChunk('data: {"content":"there"}');
const pending = usageHistory.getPendingRequests();
const detail = pending.details["test-conn-3"]?.["claude-3 (anthropic)"]?.[0];
assert.ok(detail?.streamChunks, "streamChunks should be set");
assert.equal(detail.streamChunks.openai.length, 1);
assert.equal(
stripChunkTs(detail.streamChunks.openai[0]),
'data: {"role":"assistant","content":"hi"}'
);
assert.equal(detail.streamChunks.client.length, 1);
assert.equal(stripChunkTs(detail.streamChunks.client[0]), 'data: {"content":"there"}');
});
test("createRequestLogger captures stream chunks even when enabled: false", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
usageHistory.clearPendingRequests();
usageHistory.trackPendingRequest("gpt-4", "openai", "test-conn-4", true);
// Logger is disabled (enabled: false) — previously this would return a
// no-op logger that didn't capture any chunks. Now stream chunks are
// always captured regardless of the enabled flag.
const logger = await createRequestLogger("openai", "openai", "gpt-4", {
enabled: false,
captureStreamChunks: true,
connectionId: "test-conn-4",
model: "gpt-4",
provider: "openai",
});
logger.appendProviderChunk('data: {"content":"hello"}');
const pending = usageHistory.getPendingRequests();
const detail = pending.details["test-conn-4"]?.["gpt-4 (openai)"]?.[0];
assert.ok(detail?.streamChunks, "streamChunks should be set even when logger is disabled");
assert.equal(detail.streamChunks.provider.length, 1);
assert.equal(stripChunkTs(detail.streamChunks.provider[0]), 'data: {"content":"hello"}');
// But getPipelinePayloads should return null when disabled
assert.equal(
logger.getPipelinePayloads(),
null,
"pipeline payloads should be null when disabled"
);
});
test("createRequestLogger disabled logger other methods are no-ops", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
const logger = await createRequestLogger("openai", "openai", "gpt-4", {
enabled: false,
captureStreamChunks: false,
});
// These should not throw
logger.logClientRawRequest("/endpoint", { foo: "bar" });
logger.logOpenAIRequest({ model: "gpt-4" });
logger.logTargetRequest("https://api.openai.com", {}, { model: "gpt-4" });
logger.logProviderResponse(200, "OK", {}, {});
logger.logConvertedResponse({ choices: [] });
logger.logError(new Error("test"));
logger.appendProviderChunk("test");
logger.appendOpenAIChunk("test");
logger.appendConvertedChunk("test");
assert.equal(logger.getPipelinePayloads(), null);
});
test("request logging never persists a raw hard-lease owner", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
const rawOwner = `vlo_${"A".repeat(43)}`;
const logger = await createRequestLogger("openai", "openai", "gpt-4", {
enabled: true,
captureStreamChunks: false,
});
logger.logClientRawRequest(
"/v1/chat/completions",
{},
{
"X-OmniRoute-Lease-Owner": rawOwner,
"X-OmniRoute-Lease-Generation": "7",
}
);
const payload = logger.getPipelinePayloads()?.clientRawRequest;
assert.deepEqual(payload?.headers, {
"X-OmniRoute-Lease-Owner": "[REDACTED]",
"X-OmniRoute-Lease-Generation": "7",
});
assert.doesNotMatch(JSON.stringify(payload), new RegExp(rawOwner));
});
test("generic client snapshots exclude hard-lease control headers", async () => {
const { buildClientRawRequest } = await import("../../src/sse/handlers/chat/clientRawRequest.ts");
const request = new Request("http://x/v1/chat/completions", {
headers: {
"X-OmniRoute-Lease-Owner": `vlo_${"A".repeat(43)}`,
"X-OmniRoute-Lease-Generation": "7",
"X-Session-Id": "independent-routing-session",
},
});
const out = buildClientRawRequest(request, { model: "m" });
assert.equal(out.headers["x-omniroute-lease-owner"], undefined);
assert.equal(out.headers["x-omniroute-lease-generation"], undefined);
assert.equal(out.headers["x-session-id"], "independent-routing-session");
});
function syntheticReceipt(index: number) {
return {
index,
connectionId: "conn-1",
provider: "openai",
model: "gpt-4o",
startedAt: "2026-01-01T00:00:00.000Z",
endedAt: "2026-01-01T00:00:01.000Z",
latencyMs: 10 + index,
httpStatus: 200,
errorType: null,
usage: { prompt_tokens: 1, completion_tokens: 1, total_tokens: 2 },
serviceTier: null,
computedCostUsd: 0.001,
toolCalls: [{ id: `call-${index}`, name: "memory_search" }],
termination: "completed",
clientVisible: true,
};
}
test("logToolLoopReceipt keeps first 4 receipts and clones them", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
const logger = await createRequestLogger("openai", "openai", "gpt-4o", {
enabled: true,
captureStreamChunks: false,
});
for (let i = 0; i < 5; i++) {
logger.logToolLoopReceipt(syntheticReceipt(i));
}
const payloads = logger.getPipelinePayloads();
assert.ok(payloads?.toolLoop);
assert.equal(payloads.toolLoop.legs.length, 4);
assert.deepEqual(
payloads.toolLoop.legs.map((leg) => (leg as { index: number }).index),
[0, 1, 2, 3]
);
assert.equal("arguments" in (payloads.toolLoop.legs[0] as object), false);
});
test("logToolLoopReceipt is a no-op when logger is disabled", async () => {
const { createRequestLogger } = await import("../../open-sse/utils/requestLogger.ts");
const logger = await createRequestLogger("openai", "openai", "gpt-4o", {
enabled: false,
captureStreamChunks: false,
});
logger.logToolLoopReceipt(syntheticReceipt(0));
assert.equal(logger.getPipelinePayloads(), null);
});