mirror of
https://github.com/diegosouzapw/OmniRoute.git
synced 2026-08-03 13:52:09 +03:00
fix(api): stop /v1/models rebuilding the catalog on almost every request (#8833)
* fix(api): stop /v1/models rebuilding the catalog on almost every request The response cache added by #6408 memoized the serialized body for `modelCatalogCacheTtlMs`, defaulted to 1500 ms. On a real install the builder takes far longer than that: measured on the production VPS, ~49 s for a 1.3 MB / 2645-model catalog. Any two requests more than 1.5 s apart therefore both missed the fresh window, and the second fell into stale-while-revalidate — which rebuilds via `setTimeout(…, 0)` and, because the builder is overwhelmingly synchronous under the single-threaded App Router, pins the event loop, so even the "served immediately" stale body only reaches the client once the rebuild finishes. Net effect: ~50 s on essentially every call. Measured on the VPS (1 cold build + 5 sequential requests): cold = 48.93s req1 = 3.19s ← the only hit req2 = 50.51s req3 = 50.93s req4 = 47.43s req5 = 52.28s Raise the default to 60 s. A short TTL is redundant with the invalidation this cache already has: `invalidateDbCache()` bumps `modelCatalogCacheVersion` on every settings/connections/combos/pricing write and `dropCatalogCacheIfStateChanged()` drops the whole cache the moment it moves, so post-write freshness never depended on the TTL. What the TTL governs is the "nothing was written" case, where replaying a body built seconds ago is the point of the cache. 60 s matches the ceiling the settings schema already allows for the override, so the default can never exceed what an operator may configure. The value that actually takes effect is the settings default, not the constant: `catalog.ts` resolves `dbSettings.cache?.modelCatalogCacheTtlMs ?? CATALOG_CACHE_TTL_MS_DEFAULT`, and the `??` never falls through while a settings default is declared. Raising only the constant is a silent no-op — which is how the first attempt at this fix measured identical to no fix at all. All three declarations are aligned and a test pins them together. * docs(changelog): add fragment for #8833 --------- Co-authored-by: diegosouzapw <diegosouzapw@users.noreply.github.com>
This commit is contained in:
committed by
GitHub
parent
aa85fa02bb
commit
3b515d90b3
1
changelog.d/fixes/8833-models-catalog-cache-ttl.md
Normal file
1
changelog.d/fixes/8833-models-catalog-cache-ttl.md
Normal file
@@ -0,0 +1 @@
|
||||
- **fix(api):** `GET /v1/models` no longer rebuilds the whole catalog on almost every request. The response cache added by [#6408](https://github.com/diegosouzapw/OmniRoute/pull/6408) memoized the body for `modelCatalogCacheTtlMs`, defaulted to 1500 ms — shorter than a single build (~49 s for a 1.3 MB / 2645-model catalog on a real install), so any two requests more than 1.5 s apart both missed the fresh window and the second fell into a stale-while-revalidate rebuild that pins the single-threaded event loop, delaying even the "immediate" stale response. The default is now 60 s, matching the ceiling the settings schema already allows for the override. A short TTL was redundant with the cache's existing invalidation: `invalidateDbCache()` bumps the catalog cache version on every settings/connections/combos/pricing write, so post-write freshness never depended on the TTL. ([#8833](https://github.com/diegosouzapw/OmniRoute/pull/8833))
|
||||
@@ -39,7 +39,9 @@ const DEFAULTS = {
|
||||
promptCacheStrategy: "auto",
|
||||
alwaysPreserveClientCache: "auto",
|
||||
idempotencyWindowMs: 5000,
|
||||
modelCatalogCacheTtlMs: 1500,
|
||||
// Mirrors DEFAULT_DATABASE_SETTINGS.cache.modelCatalogCacheTtlMs so the value this
|
||||
// endpoint reports matches the one the catalog actually uses.
|
||||
modelCatalogCacheTtlMs: 60_000,
|
||||
};
|
||||
|
||||
export async function GET(request: NextRequest) {
|
||||
|
||||
@@ -41,8 +41,29 @@ export type CatalogPayload = {
|
||||
*/
|
||||
export const CATALOG_STALE_WHILE_REVALIDATE_MS = 30_000;
|
||||
|
||||
/** Fallback memoization window; overridden by `settings.cache.modelCatalogCacheTtlMs`. */
|
||||
export const CATALOG_CACHE_TTL_MS_DEFAULT = 1500;
|
||||
/**
|
||||
* Fallback memoization window; overridden by `settings.cache.modelCatalogCacheTtlMs`.
|
||||
*
|
||||
* This does NOT govern post-write freshness — `invalidateDbCache()` bumps
|
||||
* `modelCatalogCacheVersion` on every settings/connections/combos/pricing write and
|
||||
* `dropCatalogCacheIfStateChanged()` drops the whole cache the moment it moves, so a
|
||||
* write is reflected on the very next read regardless of this value. What it governs is
|
||||
* the "nothing was written" case, where replaying a body built seconds ago is precisely
|
||||
* the point of the cache.
|
||||
*
|
||||
* It was 1500 ms, which was shorter than a single build: measured 2026-07-28 on the
|
||||
* production VPS, the builder takes ~49 s for a 1.3 MB / 2645-model catalog. Any two
|
||||
* requests more than 1.5 s apart therefore both missed the fresh window, and the second
|
||||
* fell into stale-while-revalidate — which rebuilds via `setTimeout(…, 0)` and, because
|
||||
* the builder is overwhelmingly synchronous under the single-threaded App Router, pins
|
||||
* the event loop so even the "served immediately" stale body only reaches the client
|
||||
* once the rebuild finishes. Net effect: ~50 s on essentially every call.
|
||||
*
|
||||
* Held at 60 s to match the ceiling the settings schema already allows for the override
|
||||
* (`settingsSchemas.ts`, `.max(60000)`), so the default can never exceed what an
|
||||
* operator is permitted to configure.
|
||||
*/
|
||||
export const CATALOG_CACHE_TTL_MS_DEFAULT = 60_000;
|
||||
|
||||
const catalogCache = new Map<string, CachedCatalog>();
|
||||
const catalogInFlight = new Map<string, Promise<CachedCatalog>>();
|
||||
|
||||
@@ -103,7 +103,12 @@ export const DEFAULT_DATABASE_SETTINGS: Omit<DatabaseSettings, "location" | "sta
|
||||
promptCacheEnabled: true,
|
||||
promptCacheStrategy: "auto",
|
||||
alwaysPreserveClientCache: "auto",
|
||||
modelCatalogCacheTtlMs: 1500,
|
||||
// Keep in sync with CATALOG_CACHE_TTL_MS_DEFAULT
|
||||
// (src/app/api/v1/models/catalogCache.ts) — this value is what actually takes
|
||||
// effect, since catalog.ts reads it as `dbSettings.cache?.modelCatalogCacheTtlMs
|
||||
// ?? CATALOG_CACHE_TTL_MS_DEFAULT` and the `??` never falls through while a
|
||||
// default is declared here. Guarded by tests/unit/v1-models-catalog-ttl.test.ts.
|
||||
modelCatalogCacheTtlMs: 60_000,
|
||||
},
|
||||
retention: {
|
||||
quotaSnapshots: 7,
|
||||
|
||||
133
tests/unit/v1-models-catalog-ttl.test.ts
Normal file
133
tests/unit/v1-models-catalog-ttl.test.ts
Normal file
@@ -0,0 +1,133 @@
|
||||
// Regression guard — GET /v1/models re-ran the full builder on almost every request.
|
||||
//
|
||||
// The response cache added by #6408 memoized the serialized body for
|
||||
// CATALOG_CACHE_TTL_MS_DEFAULT, which was 1500 ms. On a real install the builder
|
||||
// takes tens of seconds (measured 2026-07-28 on the production VPS: ~49 s for a
|
||||
// 1.3 MB / 2645-model catalog), so any two requests more than 1.5 s apart both
|
||||
// missed the fresh window. The second one fell into the stale-while-revalidate
|
||||
// path, which kicks off the rebuild via setTimeout(…, 0) — and because the builder
|
||||
// is overwhelmingly synchronous (SQLite reads + 8 registry walks) under the
|
||||
// single-threaded App Router, it pins the event loop, so even the "served
|
||||
// immediately" stale response only reaches the client once the rebuild finishes.
|
||||
// Net effect: a ~50 s response on essentially every call.
|
||||
//
|
||||
// A short TTL is redundant with the invalidation this cache already has:
|
||||
// invalidateDbCache() bumps modelCatalogCacheVersion on every settings/connections/
|
||||
// combos/pricing write, and dropCatalogCacheIfStateChanged() drops the whole cache
|
||||
// the moment it moves. So post-write freshness does not depend on the TTL at all —
|
||||
// the TTL only governs the "nothing was written" case, where serving a body that is
|
||||
// a few seconds old is exactly what a cache is for.
|
||||
//
|
||||
// This test pins that: with DB state untouched, a request arriving well after the
|
||||
// old 1.5 s window must still be served from cache without a second builder run.
|
||||
|
||||
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-catalog-ttl-"));
|
||||
process.env.DATA_DIR = TEST_DATA_DIR;
|
||||
process.env.API_KEY_SECRET = process.env.API_KEY_SECRET || "catalog-ttl-test-secret";
|
||||
|
||||
const core = await import("../../src/lib/db/core.ts");
|
||||
const apiKeysDb = await import("../../src/lib/db/apiKeys.ts");
|
||||
const v1ModelsCatalog = await import("../../src/app/api/v1/models/catalog.ts");
|
||||
const catalogCache = await import("../../src/app/api/v1/models/catalogCache.ts");
|
||||
|
||||
/** Comfortably past the old 1500 ms TTL, and a realistic client poll gap. */
|
||||
const GAP_MS = 10_000;
|
||||
|
||||
test.beforeEach(() => {
|
||||
core.resetDbInstance();
|
||||
apiKeysDb.resetApiKeyState();
|
||||
fs.rmSync(TEST_DATA_DIR, { recursive: true, force: true });
|
||||
fs.mkdirSync(TEST_DATA_DIR, { recursive: true });
|
||||
v1ModelsCatalog.__resetCatalogBuilderRunsForTest();
|
||||
});
|
||||
|
||||
test.after(() => {
|
||||
core.resetDbInstance();
|
||||
apiKeysDb.resetApiKeyState();
|
||||
fs.rmSync(TEST_DATA_DIR, { recursive: true, force: true });
|
||||
});
|
||||
|
||||
test("the settings default and the constant agree on the catalog TTL", async () => {
|
||||
// catalog.ts resolves the TTL as `dbSettings.cache?.modelCatalogCacheTtlMs ??
|
||||
// CATALOG_CACHE_TTL_MS_DEFAULT`. The `??` never falls through while the settings
|
||||
// default is defined, so the settings value is the one that takes effect and raising
|
||||
// only the constant is a silent no-op — which is exactly how the first attempt at
|
||||
// this fix measured identical to no fix at all.
|
||||
const { DEFAULT_DATABASE_SETTINGS } = await import("../../src/types/databaseSettings.ts");
|
||||
assert.equal(
|
||||
DEFAULT_DATABASE_SETTINGS.cache.modelCatalogCacheTtlMs,
|
||||
catalogCache.CATALOG_CACHE_TTL_MS_DEFAULT,
|
||||
"settings default and CATALOG_CACHE_TTL_MS_DEFAULT drifted — the settings value wins, " +
|
||||
"so the constant alone does not change runtime behavior"
|
||||
);
|
||||
});
|
||||
|
||||
test("the effective TTL stays within what the settings schema accepts", async () => {
|
||||
const { databaseSettingsSchema } = await import("../../src/shared/validation/settingsSchemas.ts");
|
||||
// An operator must be able to configure the value the product ships with; a default
|
||||
// above the schema ceiling would be rejected the moment anyone saved settings.
|
||||
const parsed = databaseSettingsSchema.shape.cache.shape.modelCatalogCacheTtlMs.safeParse(
|
||||
catalogCache.CATALOG_CACHE_TTL_MS_DEFAULT
|
||||
);
|
||||
assert.ok(
|
||||
parsed.success,
|
||||
`default TTL ${catalogCache.CATALOG_CACHE_TTL_MS_DEFAULT} ms is outside the range the ` +
|
||||
`settings schema allows`
|
||||
);
|
||||
});
|
||||
|
||||
test("the default TTL outlives a realistic gap between catalog polls", () => {
|
||||
assert.ok(
|
||||
catalogCache.CATALOG_CACHE_TTL_MS_DEFAULT >= GAP_MS,
|
||||
`default catalog TTL is ${catalogCache.CATALOG_CACHE_TTL_MS_DEFAULT} ms — too short to ` +
|
||||
`survive a ${GAP_MS} ms gap, so every poll pays a full rebuild (~49 s in production)`
|
||||
);
|
||||
});
|
||||
|
||||
test("a request after the old 1.5s window is served from cache, without a second builder run", async (t) => {
|
||||
// Fake Date so the cache's expiresAt comparison sees the gap without sleeping.
|
||||
// Timer callbacks stay real: scheduleBackgroundRefresh() uses setTimeout(…, 0),
|
||||
// and mocking that away would hide the very rebuild this test must not trigger.
|
||||
t.mock.timers.enable({ apis: ["Date"] });
|
||||
|
||||
const res1 = await v1ModelsCatalog.getUnifiedModelsResponse(
|
||||
new Request("http://localhost/v1/models")
|
||||
);
|
||||
assert.equal(res1.status, 200);
|
||||
assert.equal(
|
||||
v1ModelsCatalog.__getCatalogBuilderRunsForTest(),
|
||||
1,
|
||||
"cold request must run the builder exactly once"
|
||||
);
|
||||
const body1 = await res1.text();
|
||||
|
||||
t.mock.timers.tick(GAP_MS);
|
||||
|
||||
const res2 = await v1ModelsCatalog.getUnifiedModelsResponse(
|
||||
new Request("http://localhost/v1/models")
|
||||
);
|
||||
assert.equal(res2.status, 200);
|
||||
assert.equal(await res2.text(), body1, "cached response must be byte-identical");
|
||||
|
||||
// The stale path returns the body immediately and rebuilds via setTimeout(…, 0), so
|
||||
// reading the counter right here would still show 1 even when the request missed the
|
||||
// fresh window. Let any scheduled refresh settle first — a rebuild that happens at all
|
||||
// is the defect: in production it pins the event loop and the "immediate" stale
|
||||
// response is only flushed ~49 s later.
|
||||
await catalogCache.__flushCatalogBackgroundRefreshForTest();
|
||||
await new Promise((resolve) => setTimeout(resolve, 0));
|
||||
await catalogCache.__flushCatalogBackgroundRefreshForTest();
|
||||
|
||||
assert.equal(
|
||||
v1ModelsCatalog.__getCatalogBuilderRunsForTest(),
|
||||
1,
|
||||
`builder re-ran ${GAP_MS} ms after the first request with no DB write in between — ` +
|
||||
`the caller pays a full rebuild on every poll`
|
||||
);
|
||||
});
|
||||
Reference in New Issue
Block a user