diff --git a/changelog.d/fixes/8833-models-catalog-cache-ttl.md b/changelog.d/fixes/8833-models-catalog-cache-ttl.md new file mode 100644 index 0000000000..278de5d984 --- /dev/null +++ b/changelog.d/fixes/8833-models-catalog-cache-ttl.md @@ -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)) diff --git a/src/app/api/settings/cache-config/route.ts b/src/app/api/settings/cache-config/route.ts index 14f6ce9981..fc5a6634aa 100644 --- a/src/app/api/settings/cache-config/route.ts +++ b/src/app/api/settings/cache-config/route.ts @@ -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) { diff --git a/src/app/api/v1/models/catalogCache.ts b/src/app/api/v1/models/catalogCache.ts index 7ae78f1806..316120293c 100644 --- a/src/app/api/v1/models/catalogCache.ts +++ b/src/app/api/v1/models/catalogCache.ts @@ -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(); const catalogInFlight = new Map>(); diff --git a/src/types/databaseSettings.ts b/src/types/databaseSettings.ts index a03e1750fe..6bcc210e5f 100644 --- a/src/types/databaseSettings.ts +++ b/src/types/databaseSettings.ts @@ -103,7 +103,12 @@ export const DEFAULT_DATABASE_SETTINGS: Omit { + 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` + ); +});