From ba597b631d22d85e56db6982f24b7d1ebe238df9 Mon Sep 17 00:00:00 2001 From: Dizzle <112548150+maxmad64bis@users.noreply.github.com> Date: Tue, 8 Sep 2026 14:31:32 +0200 Subject: [PATCH] fix(db): call_logs provider stats read true on empty and legacy data (#12832) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Validado numa worktree combinada com a onda de persistência desta leva sobre `release/v3.8.51`: check-file-size e check-changelog-integrity OK, typecheck:core limpo, check-api-typecheck OK (289), 70 testes focados no runner Node e 1 no vitest, todos verdes. "Zeros continuam zeros, latências ausentes continuam ausentes, falhas pré-coluna ganham o próprio balde" — a distinção entre ausência e zero é o miolo aqui. Um install novo mostrando 0ms como se tivesse medido é pior que mostrar nada, porque parece dado. **Uma mudança minha na sua branch: a migration foi renumerada de 174 para 175.** A `174_server_tool_executions.sql` entrou no #12867, mergeado horas antes desta leva, então `174_call_logs_provider_stats_indexes.sql` colidia. Renomeei o arquivo e ajustei o rótulo do teste ("migration 174 creates..." → 175). Confirmei que não sobrou prefixo duplicado em `src/lib/db/migrations/` e revalidei o `call-logs-provider-stats`: 4/4. Os dois índices compostos são a parte que paga a longo prazo — rollup por provider parando de varrer a tabela. --- .../fixes/12832-call-logs-provider-stats.md | 1 + src/app/api/provider-metrics/route.ts | 9 +- src/app/api/search/stats/route.ts | 2 +- src/lib/db/callLogStats.ts | 32 ++--- src/lib/db/core.ts | 2 + .../175_call_logs_provider_stats_indexes.sql | 6 + .../unit/db/call-logs-provider-stats.test.ts | 119 ++++++++++++++++++ 7 files changed, 150 insertions(+), 21 deletions(-) create mode 100644 changelog.d/fixes/12832-call-logs-provider-stats.md create mode 100644 src/lib/db/migrations/175_call_logs_provider_stats_indexes.sql create mode 100644 tests/unit/db/call-logs-provider-stats.test.ts diff --git a/changelog.d/fixes/12832-call-logs-provider-stats.md b/changelog.d/fixes/12832-call-logs-provider-stats.md new file mode 100644 index 0000000000..9e4ef7c433 --- /dev/null +++ b/changelog.d/fixes/12832-call-logs-provider-stats.md @@ -0,0 +1 @@ +- **fix(db):** provider stats stay truthful on empty and legacy databases: fallback counts default to `0` instead of `null`, latency averages read `null` (not `0`) when no durations were recorded, failures logged before the error-type column existed group under `pre_migration` instead of `unclassified`, and per-provider queries use two new composite indexes ([#12832](https://github.com/diegosouzapw/OmniRoute/pull/12832)) — thanks @maxmad64bis diff --git a/src/app/api/provider-metrics/route.ts b/src/app/api/provider-metrics/route.ts index 3b6e16a0a7..ad2d0e06d7 100644 --- a/src/app/api/provider-metrics/route.ts +++ b/src/app/api/provider-metrics/route.ts @@ -4,7 +4,7 @@ import pino from "pino"; import { buildErrorBody } from "@omniroute/open-sse/utils/error.ts"; import { getProviderMetrics } from "@/lib/db/callLogStats"; -import { toNumber } from "@/shared/utils/numeric"; +import { toNumber, toNumberOrNull } from "@/shared/utils/numeric"; const logger = pino({ name: "provider-metrics-api" }); @@ -22,7 +22,7 @@ export async function GET() { totalRequests: number; totalSuccesses: number; successRate: number; - avgLatencyMs: number; + avgLatencyMs: number | null; lastRequestAt: string | null; lastErrorAt: string | null; lastStatus: number | null; @@ -41,7 +41,7 @@ export async function GET() { : "unknown"; const totalRequests = toNumber(row.totalRequests); const totalSuccesses = toNumber(row.totalSuccesses); - const avgLatencyMs = toNumber(row.avgLatencyMs); + const avgLatencyMs = toNumberOrNull(row.avgLatencyMs); const lastRequestAt = typeof row.lastRequestAt === "string" ? row.lastRequestAt : null; const lastErrorAt = typeof row.lastErrorAt === "string" ? row.lastErrorAt : null; const lastStatus = row.lastStatus == null ? null : toNumber(row.lastStatus); @@ -66,8 +66,7 @@ export async function GET() { // Only flag as errorProvider if the provider's MOST RECENT request was itself // a failure. A provider with a historical lastErrorAt but a recent success // (lastStatus 2xx/3xx) must not be shown as currently errored (#3619). - const isCurrentlyInError = - lastStatus !== null && (lastStatus < 200 || lastStatus >= 400); + const isCurrentlyInError = lastStatus !== null && (lastStatus < 200 || lastStatus >= 400); const errorTs = isCurrentlyInError && lastErrorAt ? Date.parse(lastErrorAt) : 0; if (Number.isFinite(errorTs) && errorTs > errorProviderTs) { errorProvider = provider; diff --git a/src/app/api/search/stats/route.ts b/src/app/api/search/stats/route.ts index bf0992f1a4..6559ff732a 100644 --- a/src/app/api/search/stats/route.ts +++ b/src/app/api/search/stats/route.ts @@ -16,7 +16,7 @@ export async function GET(request: Request) { const providers: Record< string, - { requests: number; avg_latency_ms: number; total_cost: number } + { requests: number; avg_latency_ms: number | null; total_cost: number } > = {}; for (const row of providerStats) { const costPerQuery = SEARCH_PROVIDERS[row.provider]?.costPerQuery || 0; diff --git a/src/lib/db/callLogStats.ts b/src/lib/db/callLogStats.ts index f3845f31f1..8498ce3331 100644 --- a/src/lib/db/callLogStats.ts +++ b/src/lib/db/callLogStats.ts @@ -18,7 +18,7 @@ export interface ProviderMetricRow { provider: string; totalRequests: number; totalSuccesses: number; - avgLatencyMs: number; + avgLatencyMs: number | null; lastRequestAt: string | null; lastErrorAt: string | null; lastStatus: number | null; @@ -37,7 +37,7 @@ export interface ProviderUsageRow { export interface SearchProviderStatRow { provider: string; requests: number; - avg_latency_ms: number; + avg_latency_ms: number | null; } export interface SearchRecentRow { @@ -126,10 +126,9 @@ export function getProviderMetrics(): ProviderMetricRow[] { * * Deliberately NOT `getProviderMetrics()` with a `since` parameter: that query * carries two correlated subqueries (`lastStatus`, `lastErrorStatus`) which a - * ranking never displays, and they dominate its cost — `call_logs` is indexed - * on `timestamp` alone, so each correlated pass rescans the whole window per - * provider. Here a single bounded `GROUP BY` uses `idx_cl_timestamp` and stops - * there. The rules are shared with its neighbour, not the query: same success + * ranking never displays, and they dominate its cost. Here a single bounded + * `GROUP BY` leans on `idx_cl_timestamp` plus `idx_cl_provider_timestamp` / + * `idx_cl_request_provider` (migration 174) and stops there. The rules are shared with its neighbour, not the query: same success * definition, same `#10714` guard against providers whose connections are gone. */ export function getProviderUsageSince(since: string): ProviderUsageRow[] { @@ -259,17 +258,17 @@ export function getFallbackStats( .prepare( ` SELECT - SUM(CASE WHEN (combo_name IS NULL OR combo_name = '') THEN 1 ELSE 0 END) as total, - SUM(CASE WHEN requested_model IS NOT NULL AND requested_model != '' AND (combo_name IS NULL OR combo_name = '') THEN 1 ELSE 0 END) as with_requested, - SUM(CASE + COALESCE(SUM(CASE WHEN (combo_name IS NULL OR combo_name = '') THEN 1 ELSE 0 END), 0) as total, + COALESCE(SUM(CASE WHEN requested_model IS NOT NULL AND requested_model != '' AND (combo_name IS NULL OR combo_name = '') THEN 1 ELSE 0 END), 0) as with_requested, + COALESCE(SUM(CASE WHEN (combo_name IS NULL OR combo_name = '') AND requested_model IS NOT NULL AND requested_model != '' AND model IS NOT NULL AND model != '' THEN 1 ELSE 0 END - ) as fallback_eligible, - SUM(CASE + ), 0) as fallback_eligible, + COALESCE(SUM(CASE WHEN (combo_name IS NULL OR combo_name = '') AND requested_model IS NOT NULL AND requested_model != '' @@ -277,7 +276,7 @@ export function getFallbackStats( AND model != '' AND LOWER(CASE WHEN instr(requested_model, '/') > 0 THEN substr(requested_model, instr(requested_model, '/') + 1) ELSE requested_model END) != LOWER(model) THEN 1 ELSE 0 END - ) as fallbacks + ), 0) as fallbacks FROM call_logs ${whereClause} ` @@ -289,8 +288,9 @@ export function getFallbackStats( /** * Failure-family breakdown over `call_logs` for the usage analytics endpoint. * Failures are rows with status >= 400 or a non-empty error summary; successes - * are excluded in SQL. Pre-migration rows and failures the classifier does not - * recognize (null family) land in the explicit `unclassified` bucket. + * are excluded in SQL. Rows predating migration 158 (`error_type` NULL, + * `timestamp` before 2026-08-20) land in `pre_migration`; other NULL families + * land in `unclassified`. * * @param whereClause - SQL WHERE clause (may be empty string) using the same * named params as the usage_history queries. @@ -305,7 +305,9 @@ export function getErrorTypeBreakdown( .prepare( ` SELECT - COALESCE(error_type, 'unclassified') AS errorType, + -- '2026-08-20' = commit 4c15c05f9 that added error_type (migration 158). + -- Lower bound, not exact: late upgraders have post-cutoff rows with NULL values. + CASE WHEN error_type IS NULL AND timestamp < '2026-08-20' THEN 'pre_migration' WHEN error_type IS NULL THEN 'unclassified' ELSE error_type END AS errorType, COUNT(*) AS count FROM call_logs ${whereClause} ${whereClause ? "AND" : "WHERE"} (status >= 400 OR error_summary IS NOT NULL) diff --git a/src/lib/db/core.ts b/src/lib/db/core.ts index 3c3769c066..a69db56e64 100644 --- a/src/lib/db/core.ts +++ b/src/lib/db/core.ts @@ -407,6 +407,8 @@ const SCHEMA_SQL = ` ); CREATE INDEX IF NOT EXISTS idx_cl_timestamp ON call_logs(timestamp); CREATE INDEX IF NOT EXISTS idx_cl_status ON call_logs(status); + CREATE INDEX IF NOT EXISTS idx_cl_provider_timestamp ON call_logs(provider, timestamp); + CREATE INDEX IF NOT EXISTS idx_cl_request_provider ON call_logs(request_type, provider); CREATE TABLE IF NOT EXISTS proxy_logs ( id TEXT PRIMARY KEY, diff --git a/src/lib/db/migrations/175_call_logs_provider_stats_indexes.sql b/src/lib/db/migrations/175_call_logs_provider_stats_indexes.sql new file mode 100644 index 0000000000..b6a8a7b5d1 --- /dev/null +++ b/src/lib/db/migrations/175_call_logs_provider_stats_indexes.sql @@ -0,0 +1,6 @@ +-- GROUP BY provider support. (provider,timestamp) backs the bare +-- GROUP BY provider in getProviderMetrics; (request_type,provider) +-- backs WHERE request_type='search' GROUP BY provider. Non-covering for the +-- real queries (duration/status outside the index) by design — no third index. +CREATE INDEX IF NOT EXISTS idx_cl_provider_timestamp ON call_logs(provider, timestamp); +CREATE INDEX IF NOT EXISTS idx_cl_request_provider ON call_logs(request_type, provider); diff --git a/tests/unit/db/call-logs-provider-stats.test.ts b/tests/unit/db/call-logs-provider-stats.test.ts new file mode 100644 index 0000000000..3f3a503d58 --- /dev/null +++ b/tests/unit/db/call-logs-provider-stats.test.ts @@ -0,0 +1,119 @@ +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-call-logs-stats-")); +process.env.DATA_DIR = TEST_DATA_DIR; +process.env.NODE_ENV = "test"; +process.env.DISABLE_SQLITE_AUTO_BACKUP = "true"; + +const core = await import("../../../src/lib/db/core.ts"); +const stats = await import("../../../src/lib/db/callLogStats.ts"); + +function resetDb() { + core.resetDbInstance(); + fs.rmSync(TEST_DATA_DIR, { recursive: true, force: true, maxRetries: 5, retryDelay: 100 }); + fs.mkdirSync(TEST_DATA_DIR, { recursive: true }); +} + +test.beforeEach(() => { + resetDb(); +}); + +test.after(() => { + core.resetDbInstance(); + fs.rmSync(TEST_DATA_DIR, { recursive: true, force: true, maxRetries: 5, retryDelay: 100 }); +}); + +test("getFallbackStats on empty DB returns zeros, not nulls", () => { + core.getDbInstance(); // plays SCHEMA + runMigrations on the file DB + const row = stats.getFallbackStats("", {}); + assert.deepEqual(row, { + total: 0, + with_requested: 0, + fallback_eligible: 0, + fallbacks: 0, + }); +}); + +test("avgLatencyMs is null when all durations are NULL, and the route propagates null", async () => { + const db = core.getDbInstance(); + const now = new Date().toISOString(); + db.prepare( + `INSERT INTO provider_connections (id, provider, created_at, updated_at) + VALUES ('conn-1', 'openai', ?, ?)` + ).run(now, now); + db.prepare( + `INSERT INTO call_logs (id, timestamp, provider, status, duration) + VALUES ('log-1', ?, 'openai', 200, NULL)` + ).run(now); + + const { toNumberOrNull } = await import("../../../src/shared/utils/numeric.ts"); + const rows = stats.getProviderMetrics(); + assert.equal(rows.length, 1); + // Lib-level: passes before AND after (the driver already returns null — only + // the TS type lied). Kept as documentation, not as red/green proof. + assert.equal(toNumberOrNull(rows[0].avgLatencyMs), null); + + const { GET } = await import("../../../src/app/api/provider-metrics/route.ts"); + const res = await GET(); + const body = (await res.json()) as { + metrics: Record; + }; + // Route-level: THIS is the red/green proof (toNumber(null) → 0 before fix). + assert.equal(body.metrics["openai"].avgLatencyMs, null); +}); + +test("error_type NULL splits into pre_migration vs unclassified by timestamp", () => { + const db = core.getDbInstance(); + const now = new Date().toISOString(); + db.prepare( + `INSERT INTO provider_connections (id, provider, created_at, updated_at) + VALUES ('conn-1', 'openai', ?, ?)` + ).run(now, now); + db.prepare( + `INSERT INTO call_logs (id, timestamp, provider, status, error_type) + VALUES ('old-1', '2026-08-01T00:00:00.000Z', 'openai', 500, NULL), + ('new-1', ?, 'openai', 500, NULL)` + ).run(now); + + const breakdown = stats.getErrorTypeBreakdown("", {}); + const byType = new Map(breakdown.map((b) => [b.errorType, b.count])); + assert.equal(byType.get("pre_migration"), 1); + assert.equal(byType.get("unclassified"), 1); +}); + +test("migration 175 creates provider GROUP BY indexes used by search stats", () => { + const db = core.getDbInstance(); + + const names = ( + db.prepare("SELECT name FROM sqlite_master WHERE type = 'index'").all() as Array<{ + name: string; + }> + ).map((r) => r.name); + assert.ok( + names.includes("idx_cl_provider_timestamp"), + "idx_cl_provider_timestamp must exist after migrations" + ); + assert.ok( + names.includes("idx_cl_request_provider"), + "idx_cl_request_provider must exist after migrations" + ); + + const plan = ( + db + .prepare( + "EXPLAIN QUERY PLAN SELECT provider, COUNT(*), AVG(duration) FROM call_logs WHERE request_type = 'search' GROUP BY provider" + ) + .all() as Array<{ detail: string }> + ) + .map((r) => r.detail) + .join(" | "); + assert.ok( + plan.includes("USING INDEX idx_cl_request_provider"), + `planner must use idx_cl_request_provider, got: ${plan}` + ); + assert.ok(!plan.includes("SCAN TABLE"), `must not table-scan, got: ${plan}`); +});