mirror of
https://github.com/diegosouzapw/OmniRoute.git
synced 2026-09-21 14:22:14 +03:00
fix(db): call_logs provider stats read true on empty and legacy data (#12832)
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.
This commit is contained in:
1
changelog.d/fixes/12832-call-logs-provider-stats.md
Normal file
1
changelog.d/fixes/12832-call-logs-provider-stats.md
Normal file
@@ -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
|
||||||
@@ -4,7 +4,7 @@ import pino from "pino";
|
|||||||
import { buildErrorBody } from "@omniroute/open-sse/utils/error.ts";
|
import { buildErrorBody } from "@omniroute/open-sse/utils/error.ts";
|
||||||
|
|
||||||
import { getProviderMetrics } from "@/lib/db/callLogStats";
|
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" });
|
const logger = pino({ name: "provider-metrics-api" });
|
||||||
|
|
||||||
@@ -22,7 +22,7 @@ export async function GET() {
|
|||||||
totalRequests: number;
|
totalRequests: number;
|
||||||
totalSuccesses: number;
|
totalSuccesses: number;
|
||||||
successRate: number;
|
successRate: number;
|
||||||
avgLatencyMs: number;
|
avgLatencyMs: number | null;
|
||||||
lastRequestAt: string | null;
|
lastRequestAt: string | null;
|
||||||
lastErrorAt: string | null;
|
lastErrorAt: string | null;
|
||||||
lastStatus: number | null;
|
lastStatus: number | null;
|
||||||
@@ -41,7 +41,7 @@ export async function GET() {
|
|||||||
: "unknown";
|
: "unknown";
|
||||||
const totalRequests = toNumber(row.totalRequests);
|
const totalRequests = toNumber(row.totalRequests);
|
||||||
const totalSuccesses = toNumber(row.totalSuccesses);
|
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 lastRequestAt = typeof row.lastRequestAt === "string" ? row.lastRequestAt : null;
|
||||||
const lastErrorAt = typeof row.lastErrorAt === "string" ? row.lastErrorAt : null;
|
const lastErrorAt = typeof row.lastErrorAt === "string" ? row.lastErrorAt : null;
|
||||||
const lastStatus = row.lastStatus == null ? null : toNumber(row.lastStatus);
|
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
|
// 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
|
// a failure. A provider with a historical lastErrorAt but a recent success
|
||||||
// (lastStatus 2xx/3xx) must not be shown as currently errored (#3619).
|
// (lastStatus 2xx/3xx) must not be shown as currently errored (#3619).
|
||||||
const isCurrentlyInError =
|
const isCurrentlyInError = lastStatus !== null && (lastStatus < 200 || lastStatus >= 400);
|
||||||
lastStatus !== null && (lastStatus < 200 || lastStatus >= 400);
|
|
||||||
const errorTs = isCurrentlyInError && lastErrorAt ? Date.parse(lastErrorAt) : 0;
|
const errorTs = isCurrentlyInError && lastErrorAt ? Date.parse(lastErrorAt) : 0;
|
||||||
if (Number.isFinite(errorTs) && errorTs > errorProviderTs) {
|
if (Number.isFinite(errorTs) && errorTs > errorProviderTs) {
|
||||||
errorProvider = provider;
|
errorProvider = provider;
|
||||||
|
|||||||
@@ -16,7 +16,7 @@ export async function GET(request: Request) {
|
|||||||
|
|
||||||
const providers: Record<
|
const providers: Record<
|
||||||
string,
|
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) {
|
for (const row of providerStats) {
|
||||||
const costPerQuery = SEARCH_PROVIDERS[row.provider]?.costPerQuery || 0;
|
const costPerQuery = SEARCH_PROVIDERS[row.provider]?.costPerQuery || 0;
|
||||||
|
|||||||
@@ -18,7 +18,7 @@ export interface ProviderMetricRow {
|
|||||||
provider: string;
|
provider: string;
|
||||||
totalRequests: number;
|
totalRequests: number;
|
||||||
totalSuccesses: number;
|
totalSuccesses: number;
|
||||||
avgLatencyMs: number;
|
avgLatencyMs: number | null;
|
||||||
lastRequestAt: string | null;
|
lastRequestAt: string | null;
|
||||||
lastErrorAt: string | null;
|
lastErrorAt: string | null;
|
||||||
lastStatus: number | null;
|
lastStatus: number | null;
|
||||||
@@ -37,7 +37,7 @@ export interface ProviderUsageRow {
|
|||||||
export interface SearchProviderStatRow {
|
export interface SearchProviderStatRow {
|
||||||
provider: string;
|
provider: string;
|
||||||
requests: number;
|
requests: number;
|
||||||
avg_latency_ms: number;
|
avg_latency_ms: number | null;
|
||||||
}
|
}
|
||||||
|
|
||||||
export interface SearchRecentRow {
|
export interface SearchRecentRow {
|
||||||
@@ -126,10 +126,9 @@ export function getProviderMetrics(): ProviderMetricRow[] {
|
|||||||
*
|
*
|
||||||
* Deliberately NOT `getProviderMetrics()` with a `since` parameter: that query
|
* Deliberately NOT `getProviderMetrics()` with a `since` parameter: that query
|
||||||
* carries two correlated subqueries (`lastStatus`, `lastErrorStatus`) which a
|
* carries two correlated subqueries (`lastStatus`, `lastErrorStatus`) which a
|
||||||
* ranking never displays, and they dominate its cost — `call_logs` is indexed
|
* ranking never displays, and they dominate its cost. Here a single bounded
|
||||||
* on `timestamp` alone, so each correlated pass rescans the whole window per
|
* `GROUP BY` leans on `idx_cl_timestamp` plus `idx_cl_provider_timestamp` /
|
||||||
* provider. Here a single bounded `GROUP BY` uses `idx_cl_timestamp` and stops
|
* `idx_cl_request_provider` (migration 174) and stops there. The rules are shared with its neighbour, not the query: same success
|
||||||
* there. The rules are shared with its neighbour, not the query: same success
|
|
||||||
* definition, same `#10714` guard against providers whose connections are gone.
|
* definition, same `#10714` guard against providers whose connections are gone.
|
||||||
*/
|
*/
|
||||||
export function getProviderUsageSince(since: string): ProviderUsageRow[] {
|
export function getProviderUsageSince(since: string): ProviderUsageRow[] {
|
||||||
@@ -259,17 +258,17 @@ export function getFallbackStats(
|
|||||||
.prepare(
|
.prepare(
|
||||||
`
|
`
|
||||||
SELECT
|
SELECT
|
||||||
SUM(CASE WHEN (combo_name IS NULL OR combo_name = '') THEN 1 ELSE 0 END) as total,
|
COALESCE(SUM(CASE WHEN (combo_name IS NULL OR combo_name = '') THEN 1 ELSE 0 END), 0) 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,
|
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,
|
||||||
SUM(CASE
|
COALESCE(SUM(CASE
|
||||||
WHEN (combo_name IS NULL OR combo_name = '')
|
WHEN (combo_name IS NULL OR combo_name = '')
|
||||||
AND requested_model IS NOT NULL
|
AND requested_model IS NOT NULL
|
||||||
AND requested_model != ''
|
AND requested_model != ''
|
||||||
AND model IS NOT NULL
|
AND model IS NOT NULL
|
||||||
AND model != ''
|
AND model != ''
|
||||||
THEN 1 ELSE 0 END
|
THEN 1 ELSE 0 END
|
||||||
) as fallback_eligible,
|
), 0) as fallback_eligible,
|
||||||
SUM(CASE
|
COALESCE(SUM(CASE
|
||||||
WHEN (combo_name IS NULL OR combo_name = '')
|
WHEN (combo_name IS NULL OR combo_name = '')
|
||||||
AND requested_model IS NOT NULL
|
AND requested_model IS NOT NULL
|
||||||
AND requested_model != ''
|
AND requested_model != ''
|
||||||
@@ -277,7 +276,7 @@ export function getFallbackStats(
|
|||||||
AND model != ''
|
AND model != ''
|
||||||
AND LOWER(CASE WHEN instr(requested_model, '/') > 0 THEN substr(requested_model, instr(requested_model, '/') + 1) ELSE requested_model END) != LOWER(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
|
THEN 1 ELSE 0 END
|
||||||
) as fallbacks
|
), 0) as fallbacks
|
||||||
FROM call_logs
|
FROM call_logs
|
||||||
${whereClause}
|
${whereClause}
|
||||||
`
|
`
|
||||||
@@ -289,8 +288,9 @@ export function getFallbackStats(
|
|||||||
/**
|
/**
|
||||||
* Failure-family breakdown over `call_logs` for the usage analytics endpoint.
|
* Failure-family breakdown over `call_logs` for the usage analytics endpoint.
|
||||||
* Failures are rows with status >= 400 or a non-empty error summary; successes
|
* 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
|
* are excluded in SQL. Rows predating migration 158 (`error_type` NULL,
|
||||||
* recognize (null family) land in the explicit `unclassified` bucket.
|
* `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
|
* @param whereClause - SQL WHERE clause (may be empty string) using the same
|
||||||
* named params as the usage_history queries.
|
* named params as the usage_history queries.
|
||||||
@@ -305,7 +305,9 @@ export function getErrorTypeBreakdown(
|
|||||||
.prepare(
|
.prepare(
|
||||||
`
|
`
|
||||||
SELECT
|
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
|
COUNT(*) AS count
|
||||||
FROM call_logs
|
FROM call_logs
|
||||||
${whereClause} ${whereClause ? "AND" : "WHERE"} (status >= 400 OR error_summary IS NOT NULL)
|
${whereClause} ${whereClause ? "AND" : "WHERE"} (status >= 400 OR error_summary IS NOT NULL)
|
||||||
|
|||||||
@@ -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_timestamp ON call_logs(timestamp);
|
||||||
CREATE INDEX IF NOT EXISTS idx_cl_status ON call_logs(status);
|
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 (
|
CREATE TABLE IF NOT EXISTS proxy_logs (
|
||||||
id TEXT PRIMARY KEY,
|
id TEXT PRIMARY KEY,
|
||||||
|
|||||||
@@ -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);
|
||||||
119
tests/unit/db/call-logs-provider-stats.test.ts
Normal file
119
tests/unit/db/call-logs-provider-stats.test.ts
Normal file
@@ -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<string, { avgLatencyMs: number | null }>;
|
||||||
|
};
|
||||||
|
// 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}`);
|
||||||
|
});
|
||||||
Reference in New Issue
Block a user