From 15abf90ae344258f99dc04c6243e3bbea971c106 Mon Sep 17 00:00:00 2001 From: Max Date: Sun, 20 Sep 2026 00:42:39 +0200 Subject: [PATCH] fix(proxy-logs): keep the HTTP status the provider actually returned on search rows Search proxy-log rows always read null (no response received), even when the provider answered with a 429, 403, or 500, so operators could not tell a real refusal from a transport failure. Forward response.status at the four emitEvent call sites; locally synthesized codes (envelope, transport) stay null, matching the chat writer. Verified: new test 6/6 RED-then-GREEN, neighbor search-432 7/7. --- .../14220-search-proxy-log-upstream-status.md | 1 + open-sse/handlers/search/searchProxy.ts | 28 +++- .../unit/search-proxy-upstream-status.test.ts | 157 ++++++++++++++++++ 3 files changed, 181 insertions(+), 5 deletions(-) create mode 100644 changelog.d/fixes/14220-search-proxy-log-upstream-status.md create mode 100644 tests/unit/search-proxy-upstream-status.test.ts diff --git a/changelog.d/fixes/14220-search-proxy-log-upstream-status.md b/changelog.d/fixes/14220-search-proxy-log-upstream-status.md new file mode 100644 index 00000000000..8f2cdebf59a --- /dev/null +++ b/changelog.d/fixes/14220-search-proxy-log-upstream-status.md @@ -0,0 +1 @@ +- **fix(proxy-logs):** search proxy-log rows keep the HTTP status the provider actually returned (`upstream_status`, null when no response arrived), matching the chat writer ([#14220](https://github.com/diegosouzapw/OmniRoute/pull/14220)) — thanks @maxmad64bis diff --git a/open-sse/handlers/search/searchProxy.ts b/open-sse/handlers/search/searchProxy.ts index ffc7872299a..d8f825275be 100644 --- a/open-sse/handlers/search/searchProxy.ts +++ b/open-sse/handlers/search/searchProxy.ts @@ -80,6 +80,13 @@ export async function fetchWithSearchProxy( /** * Emit a sanitized proxy event for a search provider attempt. * Never includes query, API key, proxy username, or proxy password. + * + * `upstreamStatus` carries the HTTP status the provider actually returned for + * this attempt (null when no response arrived). The other proxy-log writers + * correctly keep null: the history websocket writer derives its status + * post-hoc (fallbacks instead of a received response), and the provider-test + * writer sometimes synthesizes its status code (network failure, refresh + * failure) — copying either number would fabricate a status. */ export async function emitSearchProxyEvent( provider: string, @@ -88,7 +95,8 @@ export async function emitSearchProxyEvent( proxyLevel: string, targetUrl: string, startTime: number, - status: string + status: string, + upstreamStatus: number | null = null ): Promise { try { const { logProxyEvent } = await import("@/lib/proxyLogger"); @@ -112,6 +120,7 @@ export async function emitSearchProxyEvent( : null; logProxyEvent({ status, + upstreamStatus, proxy: proxyInfo, level: proxyLevel, levelId: connectionId || null, @@ -187,8 +196,17 @@ export async function executeProviderFetch( ): Promise { const { config, url, init, controller, timer, query, searchType, maxResults, startTime } = p; const { connectionId, proxy, proxyLevel, log, normalize } = p; - const emitEvent = (status: string) => - emitSearchProxyEvent(config.id, connectionId, proxy, proxyLevel, url, startTime, status); + const emitEvent = (status: string, upstreamStatus: number | null = null) => + emitSearchProxyEvent( + config.id, + connectionId, + proxy, + proxyLevel, + url, + startTime, + status, + upstreamStatus + ); const logCall = (fields: Record) => saveCallLog({ method: config.method, @@ -227,7 +245,7 @@ export async function executeProviderFetch( duration: Date.now() - startTime, error: errorText.slice(0, 500), }); - await emitEvent("error"); + await emitEvent("error", response.status); return { success: false, status: response.status, @@ -246,7 +264,7 @@ export async function executeProviderFetch( tokens: { prompt_tokens: 0, completion_tokens: 0 }, responseBody: { results_count: results.length, cached: false }, }); - await emitEvent("success"); + await emitEvent("success", response.status); return { success: true, diff --git a/tests/unit/search-proxy-upstream-status.test.ts b/tests/unit/search-proxy-upstream-status.test.ts new file mode 100644 index 00000000000..1d107893b1e --- /dev/null +++ b/tests/unit/search-proxy-upstream-status.test.ts @@ -0,0 +1,157 @@ +import test from "node:test"; +import assert from "node:assert/strict"; +import fs from "node:fs"; +import http from "node:http"; +import os from "node:os"; +import path from "node:path"; +import type { AddressInfo } from "node:net"; + +// Search proxy-log rows keep the HTTP status the provider actually +// returned. Real codes (incl. 429/500 from the wire) land on the journal line; +// locally synthesized codes (transport/timeout, envelope errors) stay null. + +const TEST_DATA_DIR = fs.mkdtempSync(path.join(os.tmpdir(), "omniroute-search-upstream-")); +process.env.DATA_DIR = TEST_DATA_DIR; +process.env.API_KEY_SECRET = process.env.API_KEY_SECRET || "search-upstream-test-secret"; +process.env.DISABLE_SQLITE_AUTO_BACKUP = "true"; + +const core = await import("../../src/lib/db/core.ts"); +const proxyLogger = await import("../../src/lib/proxyLogger.ts"); +const searchProxy = await import("../../open-sse/handlers/search/searchProxy.ts"); +const { SEARCH_PROVIDERS } = await import("../../open-sse/config/searchRegistry.ts"); +const { closeCallLogSaves } = await import("../../src/lib/usage/callLogs.ts"); + +let server: http.Server; +let baseUrl = ""; + +test.before(async () => { + server = http.createServer((req, res) => { + const url = new URL(req.url ?? "/", "http://local"); + const code = Number(url.searchParams.get("code") ?? 200); + if (url.searchParams.get("hang") === "1") return; // never respond -> caller aborts + res.writeHead(code, { "Content-Type": "application/json", Connection: "close" }); + if (code >= 200 && code < 300) { + res.end(JSON.stringify({ results: [], total: 0 })); + } else { + res.end(JSON.stringify({ error: `provider error ${code}` })); + } + }); + await new Promise((resolve) => server.listen(0, "127.0.0.1", () => resolve())); + baseUrl = `http://127.0.0.1:${(server.address() as AddressInfo).port}`; +}); + +test.after(async () => { + await new Promise((resolve) => server.close(() => resolve())); + proxyLogger.clearProxyLogs(); + await closeCallLogSaves(500).catch(() => {}); + try { + core.resetDbInstance(); + } catch {} + try { + fs.rmSync(TEST_DATA_DIR, { recursive: true, force: true, maxRetries: 5, retryDelay: 100 }); + } catch {} +}); + +test.beforeEach(() => { + proxyLogger.clearProxyLogs(); +}); + +function fetchParams(pathSuffix: string, timeoutMs = 5000) { + const controller = new AbortController(); + const timer = setTimeout(() => controller.abort(), timeoutMs); + timer.unref?.(); + return { + config: SEARCH_PROVIDERS["tavily-search"], + url: `${baseUrl}${pathSuffix}`, + init: { method: "POST", headers: { "Content-Type": "application/json" } }, + controller, + timer, + query: "test query", + searchType: "web", + maxResults: 5, + startTime: Date.now(), + connectionId: undefined, + proxy: null, + proxyLevel: "direct", + normalize: () => ({ results: [], totalResults: 0 }), + }; +} + +async function latestUpstreamStatus() { + const [entry] = proxyLogger.getProxyLogs(); + assert.ok(entry, "a proxy log line must have been emitted"); + return entry.upstreamStatus; +} + +test("a real 429 from the wire lands on the journal line", async () => { + const p = fetchParams("/search?code=429"); + try { + const result = await searchProxy.executeProviderFetch(p); + assert.equal(result.success, false); + assert.equal(result.status, 429); + assert.equal(await latestUpstreamStatus(), 429); + } finally { + clearTimeout(p.timer); + } +}); + +test("a real 200 from the wire lands on the journal line", async () => { + const p = fetchParams("/search?code=200"); + try { + const result = await searchProxy.executeProviderFetch(p); + assert.equal(result.success, true); + assert.equal(await latestUpstreamStatus(), 200); + } finally { + clearTimeout(p.timer); + } +}); + +test("a real 500 from the wire lands on the journal line (not the 502 transport code)", async () => { + const p = fetchParams("/search?code=500"); + try { + const result = await searchProxy.executeProviderFetch(p); + assert.equal(result.success, false); + assert.equal(result.status, 500); + assert.equal(await latestUpstreamStatus(), 500); + } finally { + clearTimeout(p.timer); + } +}); + +test("a caller abort (no response received) keeps null", async () => { + const p = fetchParams("/search?hang=1", 200); + try { + const result = await searchProxy.executeProviderFetch(p); + assert.equal(result.success, false); + assert.equal(await latestUpstreamStatus(), null); + } finally { + clearTimeout(p.timer); + } +}); + +for (const quota of [true, false]) { + test(`an AnySearch envelope error (quota=${quota}) keeps null despite result.status`, async () => { + const p = fetchParams("/search?code=200"); + const envelope = new Error("AnySearch envelope error") as Error & { quota?: boolean }; + envelope.name = "AnysearchSearchEnvelopeError"; + envelope.quota = quota; + const failingNormalize = () => { + throw envelope; + }; + try { + const result = await searchProxy.executeProviderFetch({ + ...p, + normalize: failingNormalize, + }); + assert.equal(result.success, false); + assert.equal(result.status, quota ? 402 : 502); + assert.equal( + await latestUpstreamStatus(), + null, + "synthesized envelope codes must never reach upstream_status" + ); + } finally { + clearTimeout(p.timer); + } + }); +}