From 3b515d90b3848cfa49ce7d8f0f718bcde59cf507 Mon Sep 17 00:00:00 2001 From: Diego Rodrigues de Sa e Souza Date: Tue, 28 Jul 2026 03:55:20 -0300 Subject: [PATCH] fix(api): stop /v1/models rebuilding the catalog on almost every request (#8833) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * 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 --- .../fixes/8833-models-catalog-cache-ttl.md | 1 + src/app/api/settings/cache-config/route.ts | 4 +- src/app/api/v1/models/catalogCache.ts | 25 +++- src/types/databaseSettings.ts | 7 +- tests/unit/v1-models-catalog-ttl.test.ts | 133 ++++++++++++++++++ 5 files changed, 166 insertions(+), 4 deletions(-) create mode 100644 changelog.d/fixes/8833-models-catalog-cache-ttl.md create mode 100644 tests/unit/v1-models-catalog-ttl.test.ts 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` + ); +});