-
Notifications
You must be signed in to change notification settings - Fork 52
fix(cache): correctness fixes and stale window bump #1124
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -146,6 +146,16 @@ const stats = { | |||||||||||||||||||||
| unit: "ms", | ||||||||||||||||||||||
| valueType: ValueType.DOUBLE, | ||||||||||||||||||||||
| }), | ||||||||||||||||||||||
| cacheEntrySize: meter.createHistogram("loader_cache_entry_size", { | ||||||||||||||||||||||
| description: "size of cached loader responses in bytes", | ||||||||||||||||||||||
| unit: "bytes", | ||||||||||||||||||||||
| valueType: ValueType.DOUBLE, | ||||||||||||||||||||||
| }), | ||||||||||||||||||||||
| bgRevalidation: meter.createHistogram("loader_bg_revalidation", { | ||||||||||||||||||||||
| description: "duration of background stale-while-revalidate calls", | ||||||||||||||||||||||
| unit: "ms", | ||||||||||||||||||||||
| valueType: ValueType.DOUBLE, | ||||||||||||||||||||||
| }), | ||||||||||||||||||||||
| }; | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| let maybeCache: Cache | undefined; | ||||||||||||||||||||||
|
|
@@ -155,6 +165,9 @@ caches?.open("loader") | |||||||||||||||||||||
| .catch(() => maybeCache = undefined); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| const MAX_AGE_S = parseInt(Deno.env.get("CACHE_MAX_AGE_S") ?? "60"); // 60 seconds | ||||||||||||||||||||||
| const CACHE_MAX_ENTRY_SIZE = parseInt( | ||||||||||||||||||||||
| Deno.env.get("CACHE_MAX_ENTRY_SIZE") ?? "2097152", // 2 MB | ||||||||||||||||||||||
| ) || 2097152; | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| // Reuse TextEncoder instance to avoid repeated instantiation | ||||||||||||||||||||||
| const textEncoder = new TextEncoder(); | ||||||||||||||||||||||
|
|
@@ -248,7 +261,14 @@ const wrapLoader = ( | |||||||||||||||||||||
| !shouldNotCache && ctx.vary?.push(cacheKeyValue); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| status = "bypass"; | ||||||||||||||||||||||
| stats.cache.add(1, { status, loader }); | ||||||||||||||||||||||
| const bypassReason = isCacheNoStore | ||||||||||||||||||||||
| ? "no-store" | ||||||||||||||||||||||
| : isCacheNoCache | ||||||||||||||||||||||
| ? "no-cache" | ||||||||||||||||||||||
| : isCacheKeyNull | ||||||||||||||||||||||
| ? "null-key" | ||||||||||||||||||||||
| : "disabled"; | ||||||||||||||||||||||
| stats.cache.add(1, { status, loader, reason: bypassReason }); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| RequestContext?.signal?.throwIfAborted(); | ||||||||||||||||||||||
| return await handler(props, req, ctx); | ||||||||||||||||||||||
|
|
@@ -297,6 +317,19 @@ const wrapLoader = ( | |||||||||||||||||||||
| // Serialize and encode once on the main thread. | ||||||||||||||||||||||
| const jsonStringEncoded = textEncoder.encode(JSON.stringify(json)); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| // Skip caching oversized entries to protect disk and memory. | ||||||||||||||||||||||
| // Also evict any existing stale entry so it doesn't stay pinned forever. | ||||||||||||||||||||||
| if (jsonStringEncoded.length > CACHE_MAX_ENTRY_SIZE) { | ||||||||||||||||||||||
| cache.delete(request).catch((error) => | ||||||||||||||||||||||
| logger.error(`loader error ${error}`) | ||||||||||||||||||||||
| ); | ||||||||||||||||||||||
| return json; | ||||||||||||||||||||||
|
Comment on lines
+322
to
+326
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Await the eviction in the oversized branch. This path returns before the delete settles. In the stale-while-revalidate flow, another request can still hit the old stale entry even though this refresh already decided it must be removed. 🐛 Proposed fix if (jsonStringEncoded.length > CACHE_MAX_ENTRY_SIZE) {
- cache.delete(request).catch((error) =>
+ await cache.delete(request).catch((error) =>
logger.error(`loader error ${error}`)
);
return json;
}📝 Committable suggestion
Suggested change
🤖 Prompt for AI Agents |
||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| if (OTEL_ENABLE_EXTRA_METRICS) { | ||||||||||||||||||||||
| stats.cacheEntrySize.record(jsonStringEncoded.length, { loader }); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| const expires = new Date(Date.now() + (cacheMaxAge * 1e3)) | ||||||||||||||||||||||
| .toUTCString(); | ||||||||||||||||||||||
| const headerPairs: [string, string][] = [ | ||||||||||||||||||||||
|
|
@@ -336,13 +369,44 @@ const wrapLoader = ( | |||||||||||||||||||||
| status = "stale"; | ||||||||||||||||||||||
| stats.cache.add(1, { status, loader }); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| bgFlights.do(request.url, callHandlerAndCache) | ||||||||||||||||||||||
| .catch((error) => logger.error(`loader error ${error}`)); | ||||||||||||||||||||||
| // Timer lives inside the singleFlight fn so it records exactly once | ||||||||||||||||||||||
| // per revalidation, not once per concurrent waiter on the same key. | ||||||||||||||||||||||
| bgFlights.do(request.url, async () => { | ||||||||||||||||||||||
| const bgStart = performance.now(); | ||||||||||||||||||||||
| try { | ||||||||||||||||||||||
| return await callHandlerAndCache(); | ||||||||||||||||||||||
| } finally { | ||||||||||||||||||||||
| if (OTEL_ENABLE_EXTRA_METRICS) { | ||||||||||||||||||||||
| stats.bgRevalidation.record( | ||||||||||||||||||||||
| performance.now() - bgStart, | ||||||||||||||||||||||
| { loader }, | ||||||||||||||||||||||
| ); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| }).catch((error) => logger.error(`loader error ${error}`)); | ||||||||||||||||||||||
| } else { | ||||||||||||||||||||||
| status = "hit"; | ||||||||||||||||||||||
| stats.cache.add(1, { status, loader }); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| if (OTEL_ENABLE_EXTRA_METRICS) { | ||||||||||||||||||||||
| const cl = parseInt( | ||||||||||||||||||||||
| matched.headers.get("Content-Length") ?? "0", | ||||||||||||||||||||||
| ); | ||||||||||||||||||||||
| if (cl > 0) { | ||||||||||||||||||||||
| stats.cacheEntrySize.record(cl, { loader, status }); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| if (OTEL_ENABLE_EXTRA_METRICS) { | ||||||||||||||||||||||
| const parseStart = performance.now(); | ||||||||||||||||||||||
| const result = await matched.json(); | ||||||||||||||||||||||
| stats.latency.record(performance.now() - parseStart, { | ||||||||||||||||||||||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. P2: Record cached JSON parse time in a separate metric instead of Prompt for AI agents |
||||||||||||||||||||||
| loader, | ||||||||||||||||||||||
| status: "json_parse", | ||||||||||||||||||||||
| }); | ||||||||||||||||||||||
| return result; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| return await matched.json(); | ||||||||||||||||||||||
| }; | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
|
|
||||||||||||||||||||||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -46,6 +46,15 @@ export const withInstrumentation = ( | |
| const result = getCacheStatus(isMatch); | ||
|
|
||
| span.setAttribute("cache_status", result); | ||
| if (isMatch) { | ||
| const cl = isMatch.headers.get("Content-Length"); | ||
| if (cl) span.setAttribute("content_length", parseInt(cl)); | ||
| const tier = isMatch.headers.get("X-Cache-Tier"); | ||
| if (tier) { | ||
| span.setAttribute("cache_tier", parseInt(tier)); | ||
| isMatch.headers.delete("X-Cache-Tier"); | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. P2: Don't delete Prompt for AI agents |
||
| } | ||
| } | ||
| cacheHit.add(1, { | ||
| result, | ||
| engine, | ||
|
|
||
| Original file line number | Diff line number | Diff line change | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| @@ -1,11 +1,19 @@ | ||||||||||||||
| import { LRUCache } from "npm:lru-cache@10.2.0"; | ||||||||||||||
| import { ValueType } from "../../deps.ts"; | ||||||||||||||
| import { logger } from "../../observability/otel/config.ts"; | ||||||||||||||
| import { meter } from "../../observability/otel/metrics.ts"; | ||||||||||||||
| import { | ||||||||||||||
| assertCanBeCached, | ||||||||||||||
| assertNoOptions, | ||||||||||||||
| baseCache, | ||||||||||||||
| createBaseCacheStorage, | ||||||||||||||
| } from "./utils.ts"; | ||||||||||||||
|
|
||||||||||||||
| const lruEvictionCounter = meter.createCounter("lru_cache_eviction", { | ||||||||||||||
| unit: "1", | ||||||||||||||
| valueType: ValueType.DOUBLE, | ||||||||||||||
| }); | ||||||||||||||
|
|
||||||||||||||
| // keep compatible with old variable name | ||||||||||||||
| const CACHE_MAX_SIZE = parseInt( | ||||||||||||||
| Deno.env.get("CACHE_MAX_SIZE") ?? Deno.env.get("MAX_CACHE_SIZE") ?? | ||||||||||||||
|
|
@@ -18,10 +26,11 @@ const CACHE_TTL_AUTOPURGE = Deno.env.get("CACHE_TTL_AUTOPURGE") === "true"; // c | |||||||||||||
| const CACHE_TTL_RESOLUTION = parseInt( | ||||||||||||||
| Deno.env.get("CACHE_TTL_RESOLUTION") ?? "1000", | ||||||||||||||
| ); // updates the lru cache timer every 1 second | ||||||||||||||
| // Additional time-to-live increment in milliseconds to extend the cache expiration beyond the response's Expires header. | ||||||||||||||
| // If not set, the cache will use only the expiration timestamp from response headers | ||||||||||||||
| // How long stale content remains serveable (and stays on disk) beyond its expires header. | ||||||||||||||
| // Default: 1 hour — long enough for low-traffic sites to keep serving cached content across | ||||||||||||||
| // quiet periods while background revalidation catches up. | ||||||||||||||
| const STALE_TTL_PERIOD = parseInt( | ||||||||||||||
| Deno.env.get("STALE_TTL_PERIOD") ?? "30000", | ||||||||||||||
| Deno.env.get("STALE_TTL_PERIOD") ?? "3600000", // 1h | ||||||||||||||
| ); | ||||||||||||||
|
|
||||||||||||||
| const cacheOptions = (cache: Cache) => ( | ||||||||||||||
|
|
@@ -30,18 +39,65 @@ const cacheOptions = (cache: Cache) => ( | |||||||||||||
| maxSize: CACHE_MAX_SIZE, | ||||||||||||||
| ttlAutopurge: CACHE_TTL_AUTOPURGE, | ||||||||||||||
| ttlResolution: CACHE_TTL_RESOLUTION, | ||||||||||||||
| dispose: async (_value: boolean, key: string) => { | ||||||||||||||
| dispose: async (_value: boolean, key: string, reason: string) => { | ||||||||||||||
| lruEvictionCounter.add(1, { reason }); | ||||||||||||||
| await cache.delete(key); | ||||||||||||||
| }, | ||||||||||||||
|
Comment on lines
+42
to
45
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🧩 Analysis chain🌐 Web query:
💡 Result: For npm:lru-cache@10.2.0, the dispose(value, key, reason) callback is synchronous and not awaited. It is called before the item is fully removed from the cache. The reason values emitted are: - overwrite (set): "set" - explicit delete: "delete" - expiration: "expire" - eviction: "evict" Citations:
Only delete the backing cache for true evictions.
🤖 Prompt for AI Agents |
||||||||||||||
| } | ||||||||||||||
| ); | ||||||||||||||
|
|
||||||||||||||
| const lruSizeGauge = meter.createObservableGauge("lru_cache_keys", { | ||||||||||||||
| description: "number of keys in the LRU cache", | ||||||||||||||
| unit: "1", | ||||||||||||||
| valueType: ValueType.DOUBLE, | ||||||||||||||
| }); | ||||||||||||||
|
|
||||||||||||||
| const lruBytesGauge = meter.createObservableGauge("lru_cache_bytes", { | ||||||||||||||
| description: "total bytes tracked by the LRU cache", | ||||||||||||||
| unit: "bytes", | ||||||||||||||
| valueType: ValueType.DOUBLE, | ||||||||||||||
| }); | ||||||||||||||
|
|
||||||||||||||
| // deno-lint-ignore no-explicit-any | ||||||||||||||
| const activeCaches = new Map<string, LRUCache<string, any>>(); | ||||||||||||||
|
|
||||||||||||||
| lruSizeGauge.addCallback((observer) => { | ||||||||||||||
| for (const [name, lru] of activeCaches) { | ||||||||||||||
| observer.observe(lru.size, { cache: name }); | ||||||||||||||
| } | ||||||||||||||
| }); | ||||||||||||||
|
|
||||||||||||||
| // Warn when LRU disk usage exceeds this fraction of CACHE_MAX_SIZE. | ||||||||||||||
| // At this point the LRU is evicting aggressively and disk is nearly full. | ||||||||||||||
| const LRU_DISK_WARN_RATIO = parseFloat( | ||||||||||||||
| Deno.env.get("LRU_DISK_WARN_RATIO") ?? "0.9", | ||||||||||||||
| ); | ||||||||||||||
|
|
||||||||||||||
| lruBytesGauge.addCallback((observer) => { | ||||||||||||||
| for (const [name, lru] of activeCaches) { | ||||||||||||||
| observer.observe(lru.calculatedSize, { cache: name }); | ||||||||||||||
| const ratio = lru.calculatedSize / CACHE_MAX_SIZE; | ||||||||||||||
| if (ratio >= LRU_DISK_WARN_RATIO) { | ||||||||||||||
| logger.warn( | ||||||||||||||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. P3: This warning path is unthrottled, so a cache that remains above the threshold will log on every gauge callback execution. Prompt for AI agents |
||||||||||||||
| `lru_cache: disk usage for cache "${name}" is at ` + | ||||||||||||||
| `${Math.round(lru.calculatedSize / 1024 / 1024)}MB / ` + | ||||||||||||||
| `${Math.round(CACHE_MAX_SIZE / 1024 / 1024)}MB (${Math.round(ratio * 100)}%). ` + | ||||||||||||||
| `LRU is evicting aggressively. Consider increasing CACHE_MAX_SIZE or reducing CACHE_MAX_AGE_S.`, | ||||||||||||||
| ); | ||||||||||||||
|
Comment on lines
+82
to
+86
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
CI is red for 🧰 Tools🪛 GitHub Actions: ci[error] 84-86: deno fmt --check: Text differed by line endings (diff shown at runtime/caches/lrucache.ts:84-86). 🤖 Prompt for AI Agents |
||||||||||||||
| } | ||||||||||||||
| } | ||||||||||||||
| }); | ||||||||||||||
|
|
||||||||||||||
| function createLruCacheStorage(cacheStorageInner: CacheStorage): CacheStorage { | ||||||||||||||
| const openedCachesByName = new Map<string, Promise<Cache>>(); | ||||||||||||||
| const caches = createBaseCacheStorage( | ||||||||||||||
| cacheStorageInner, | ||||||||||||||
| (_cacheName, cacheInner, requestURLSHA1) => { | ||||||||||||||
| const existing = openedCachesByName.get(_cacheName); | ||||||||||||||
| if (existing) return existing; | ||||||||||||||
| const fileCache = new LRUCache(cacheOptions(cacheInner)); | ||||||||||||||
| return Promise.resolve({ | ||||||||||||||
| activeCaches.set(_cacheName, fileCache); | ||||||||||||||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. P2: Tracking opened caches in a global map without any cleanup leaks cache instances and stale metric labels for every distinct cache name. Prompt for AI agents |
||||||||||||||
| const cache = Promise.resolve({ | ||||||||||||||
| ...baseCache, | ||||||||||||||
| delete: async ( | ||||||||||||||
| request: RequestInfo | URL, | ||||||||||||||
|
|
@@ -58,8 +114,7 @@ function createLruCacheStorage(cacheStorageInner: CacheStorage): CacheStorage { | |||||||||||||
| assertNoOptions(options); | ||||||||||||||
| const cacheKey = await requestURLSHA1(request); | ||||||||||||||
| if (fileCache.has(cacheKey)) { | ||||||||||||||
| const result = cacheInner.match(cacheKey); | ||||||||||||||
| return result; | ||||||||||||||
| return cacheInner.match(cacheKey); | ||||||||||||||
|
Comment on lines
116
to
+117
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🧩 Analysis chain🌐 Web query:
💡 Result: For npm:lru-cache@10.2.0, cache.has(key) does NOT update recency / LRU ordering by default. Use cache.get(key) when read hits must keep entries hot. Citations:
Use
♻️ Proposed fix- if (fileCache.has(cacheKey)) {
+ if (fileCache.get(cacheKey) !== undefined) {
return cacheInner.match(cacheKey);
}📝 Committable suggestion
Suggested change
🤖 Prompt for AI Agents |
||||||||||||||
| } | ||||||||||||||
| return undefined; | ||||||||||||||
| }, | ||||||||||||||
|
|
@@ -96,6 +151,8 @@ function createLruCacheStorage(cacheStorageInner: CacheStorage): CacheStorage { | |||||||||||||
| return cacheInner.put(cacheKey, response); | ||||||||||||||
| }, | ||||||||||||||
| }); | ||||||||||||||
| openedCachesByName.set(_cacheName, cache); | ||||||||||||||
| return cache; | ||||||||||||||
| }, | ||||||||||||||
| ); | ||||||||||||||
| return caches; | ||||||||||||||
|
|
||||||||||||||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Keep
CACHE_MAX_ENTRY_SIZE=0distinguishable from "unset".parseInt(...) || 2097152turns an explicit0into the default, so this knob can't intentionally disable writes or force the oversized path in staging. Use an explicit parse-failure check instead.♻️ Proposed fix
📝 Committable suggestion
🤖 Prompt for AI Agents