Add debug logging

Author: ascorbic

.gitignore

@@ -130,3 +130,4 @@ dist
 .pnp.*
 .tsup
 .DS_Store
+.wrangler

demos/cache-handlers/astro.config.mjs

@@ -10,10 +10,6 @@ export default defineConfig({
 			enabled: true,
 			persist: true,
 		},
+		workerEntryPoint: { path: "src/worker.ts" },
 	}),
-	vite: {
-		build: {
-			minify: false, // Better error messages during development
-		},
-	},
 });

demos/cache-handlers/src/pages/api/invalidate.ts

@@ -13,20 +13,20 @@ export async function POST({ request }: { request: Request }) {
         if (!value) {
           return Response.json({ success: false, error: "Tag value is required" }, { status: 400 });
         }
-        const tagCount = await invalidateByTag(value);
+        const tagCount = await invalidateByTag(value, { debug: true });
         result = { success: true, count: tagCount };
         break;
 
       case "path":
         if (!value) {
           return Response.json({ success: false, error: "Path value is required" }, { status: 400 });
         }
-        const pathCount = await invalidateByPath(value);
+        const pathCount = await invalidateByPath(value, { debug: true });
         result = { success: true, count: pathCount };
         break;
 
       case "all":
-        const allCount = await invalidateAll();
+        const allCount = await invalidateAll({ debug: true });
         result = { success: true, count: allCount };
         break;
 
@@ -46,7 +46,7 @@ export async function POST({ request }: { request: Request }) {
 
 export async function GET() {
   try {
-    const stats = await getCacheStats();
+    const stats = await getCacheStats({ debug: true });
     return Response.json({
       success: true,
       stats,

demos/cache-handlers/src/worker.ts

@@ -35,21 +35,25 @@ export function createExports(manifest: SSRManifest) {
 						conditionalRequests: { etag: "generate" },
 						cacheStatusHeader: "demo-cache",
 					},
+					debug: {
+						enabled: true,
+						logLevel: "verbose",
+					},
 				});
 
 				if (url.pathname.endsWith("/blocking")) {
 					return cacheHandle(request, {
 						swr: "blocking",
-						runInBackground: ctx.waitUntil,
+						runInBackground: ctx.waitUntil.bind(ctx),
 					});
 				}
 				if (url.pathname.endsWith("/off")) {
 					return cacheHandle(request, {
 						swr: "off",
-						runInBackground: ctx.waitUntil,
+						runInBackground: ctx.waitUntil.bind(ctx),
 					});
 				}
-				return cacheHandle(request, { runInBackground: ctx.waitUntil });
+				return cacheHandle(request, { runInBackground: ctx.waitUntil.bind(ctx) });
 			},
 		},
 	};

packages/cache-handlers/README.md

@@ -100,7 +100,7 @@ const handle = createCacheHandler({
 export default {
 	async fetch(request, env, ctx) {
 		return handle(request, {
-			runInBackground: ctx.waitUntil,
+			runInBackground: ctx.waitUntil.bind(ctx),
 		});
 	},
 };
@@ -133,7 +133,7 @@ import handler from "./handler.js";
 addEventListener("fetch", (event) => {
 	const handle = createCacheHandler({
 		handler: handleRequest,
-		runInBackground: event.waitUntil,
+		runInBackground: event.waitUntil.bind(event),
 	});
 	event.respondWith(handle(event.request));
 });
@@ -284,13 +284,97 @@ import type {
 } from "cache-handlers";
 ```
 
+## Important Caveats & behaviour
+
+### Race Conditions
+
+**Concurrent Cache Writes**: Multiple simultaneous requests for the same resource may result in duplicate cache writes. The last write wins, but all requests will complete successfully. This is generally harmless but may cause temporary inconsistency during high concurrency.
+
+**Background Revalidation**: When using `stale-while-revalidate`, multiple concurrent requests during the SWR window will each trigger their own background revalidation. The library does not deduplicate these - each will run independently. Consider using request deduplication at the application level if this is a concern.
+
+**Invalidation During Revalidation**: Cache invalidation operations may occur while background revalidation is in progress. The invalidation will complete immediately, but in-flight revalidations may still write back to the cache, potentially restoring stale data.
+
+### Platform-Specific CacheStorage behaviour
+
+Different platforms implement the Web Standard `CacheStorage` API with varying capabilities and limitations:
+
+#### Cloudflare Workers
+```ts
+// ✅ Full support for all features
+// ✅ Persistent across requests within the same data center
+// ✅ Automatic geographic distribution
+// ⚠️  Cache keys limited to ~8KB total URL length
+// ⚠️  Cache entries expire after ~1 hour of inactivity
+```
+
+#### Deno Deploy
+```ts
+// ✅ Full CacheStorage support
+// ✅ Persistent across deployments in same region
+// ⚠️  Regional caches - not globally distributed
+// ⚠️  Cache may not persist during deployment updates
+```
+
+#### Node.js (with undici polyfill)
+```ts
+// ✅ Works via undici polyfill
+// ⚠️  In-memory only by default - not persistent across restarts
+// ⚠️  Limited to single process - no cross-process sharing
+// 💡 Consider using Redis or similar for production Node.js deployments
+```
+
+#### Netlify Edge Functions
+```ts
+// ✅ CacheStorage available
+// ⚠️  Cache is per-edge location, not globally consistent
+// ⚠️  Cache may be cleared during deployments
+```
+
+#### Vercel Edge Runtime
+```ts
+// ❌ CacheStorage not available
+// 💡 Use Vercel's built-in caching mechanisms instead
+```
+
+### Memory and Performance Considerations
+
+**Large Responses**: Caching large responses (>1MB) may impact performance and memory usage. Consider streaming or chunked responses for large payloads.
+
+**Cache Key Generation**: Complex cache key generation (e.g., with many vary parameters) can impact performance. Keep cache keys simple when possible.
+
+**Metadata Overhead**: Cache tag metadata is stored separately and may grow large with many tagged entries. Monitor cache statistics and clean up unused tags periodically.
+
+### Debugging and Monitoring
+
+Enable debug logging to understand cache behaviour:
+
+```ts
+createCacheHandler({
+  debug: {
+    enabled: true,
+    logLevel: 'verbose' // Use 'basic' in production
+  }
+});
+```
+
+Monitor cache statistics:
+
+```ts
+import { getCacheStats } from 'cache-handlers';
+const stats = await getCacheStats();
+console.log(`Cache: ${stats.totalEntries} entries, ${Object.keys(stats.entriesByTag).length} tags`);
+```
+
 ## Best Practices
 
 1. Always bound TTLs with `maxTtl`.
 2. Use `stale-while-revalidate` for latency-sensitive endpoints.
 3. Include cache tags for selective purge (`cache-tag: user:123, list:users`).
 4. Generate or preserve ETags to leverage client 304s.
 5. Keep cache keys stable & explicit if customizing via `getCacheKey`.
+6. Test cache behaviour thoroughly across your target platforms.
+7. Monitor cache hit rates and adjust TTLs based on usage patterns.
+8. Use debug logging during development to understand cache behaviour.
 
 ## License
 

packages/cache-handlers/src/debug.ts

@@ -0,0 +1,112 @@
+import type { DebugConfig } from "./types.ts";
+
+/**
+ * Debug logger utility for cache operations
+ */
+export class DebugLogger {
+	private config: DebugConfig;
+
+	constructor(config: DebugConfig = {}) {
+		this.config = {
+			enabled: false,
+			logger: console.log,
+			logLevel: 'basic',
+			...config,
+		};
+	}
+
+	/**
+	 * Check if debug logging is enabled
+	 */
+	get isEnabled(): boolean {
+		return this.config.enabled === true;
+	}
+
+	/**
+	 * Check if verbose logging is enabled
+	 */
+	get isVerbose(): boolean {
+		return this.isEnabled && this.config.logLevel === 'verbose';
+	}
+
+	/**
+	 * Log a basic debug message
+	 */
+	log(operation: string, message: string, ...args: unknown[]): void {
+		if (!this.isEnabled) return;
+		
+		const timestamp = new Date().toISOString();
+		const prefix = `[${timestamp}] [cache-handlers:${operation}]`;
+		this.config.logger!(`${prefix} ${message}`, ...args);
+	}
+
+	/**
+	 * Log a verbose debug message (only if verbose mode is enabled)
+	 */
+	verbose(operation: string, message: string, ...args: unknown[]): void {
+		if (!this.isVerbose) return;
+		this.log(operation, message, ...args);
+	}
+
+	/**
+	 * Log cache read operation
+	 */
+	logCacheRead(url: string, result: 'hit' | 'miss' | 'stale', metadata?: unknown): void {
+		this.log('read', `Cache ${result} for ${url}`);
+		if (this.isVerbose && metadata) {
+			this.verbose('read', 'Cache metadata:', metadata);
+		}
+	}
+
+	/**
+	 * Log cache write operation
+	 */
+	logCacheWrite(url: string, ttl?: number, tags?: string[]): void {
+		this.log('write', `Writing to cache: ${url}${ttl ? ` (TTL: ${ttl}s)` : ''}`);
+		if (this.isVerbose && tags?.length) {
+			this.verbose('write', `Cache tags: ${tags.join(', ')}`);
+		}
+	}
+
+	/**
+	 * Log cache invalidation operation
+	 */
+	logInvalidation(type: 'tag' | 'path' | 'all', value: string, count: number): void {
+		this.log('invalidation', `Invalidated ${count} entries by ${type}: ${value}`);
+	}
+
+	/**
+	 * Log conditional request operation
+	 */
+	logConditionalRequest(url: string, type: 'etag' | 'last-modified', result: '304' | 'fresh'): void {
+		this.log('conditional', `${type} check for ${url}: ${result}`);
+	}
+
+	/**
+	 * Log background revalidation
+	 */
+	logBackgroundRevalidation(url: string, triggered: boolean): void {
+		const status = triggered ? 'triggered' : 'skipped';
+		this.log('background', `Background revalidation ${status} for ${url}`);
+	}
+
+	/**
+	 * Log error
+	 */
+	logError(operation: string, error: Error, context?: string): void {
+		this.log('error', `Error in ${operation}${context ? ` (${context})` : ''}: ${error.message}`);
+		if (this.isVerbose) {
+			this.verbose('error', 'Stack trace:', error.stack);
+		}
+	}
+}
+
+/**
+ * Create a debug logger instance from config
+ */
+export function createDebugLogger(config?: boolean | DebugConfig): DebugLogger {
+	if (typeof config === 'boolean') {
+		return new DebugLogger({ enabled: config });
+	}
+	return new DebugLogger(config);
+}

packages/cache-handlers/src/handlers.ts

@@ -8,6 +8,7 @@ import type {
 } from "./types.ts";
 import { readFromCache } from "./read.ts";
 import { writeToCache } from "./write.ts";
+import { createDebugLogger } from "./debug.ts";
 
 export function createCacheHandler<
 	TRequest extends MinimalRequest = Request,
@@ -17,13 +18,15 @@ export function createCacheHandler<
 ): CacheHandle<TRequest, TResponse> {
 	const baseHandler: HandlerFunction<TRequest, TResponse> | undefined =
 		options.handler;
+	const debug = createDebugLogger(options.debug);
 
 	const handle: CacheHandle<TRequest, TResponse> = async (
 		request,
 		callOpts = {},
 	): Promise<TResponse> => {
 		// Only cache GET
 		if (request.method !== "GET") {
+			debug.log('handler', `Non-GET request (${request.method}), bypassing cache: ${request.url}`);
 			const handler = callOpts.handler || baseHandler;
 			if (!handler) {
 				return new Response("No handler provided", {
@@ -37,6 +40,12 @@ export function createCacheHandler<
 			request,
 			options,
 		);
+		
+		if (cached) {
+			debug.logCacheRead(request.url, needsBackgroundRevalidation ? 'stale' : 'hit');
+		} else {
+			debug.logCacheRead(request.url, 'miss');
+		}
 		const statusSetting = options.features?.cacheStatusHeader;
 		const enableStatus = !!statusSetting;
 		const cacheStatusName =
@@ -50,12 +59,14 @@ export function createCacheHandler<
 					const handler = baseHandler || callOpts.handler;
 					if (handler) {
 						try {
+							debug.log('handler', `Blocking revalidation for ${request.url}`);
 							const fresh = await handler(request, {
 								mode: "stale",
 								background: false,
 							});
 							return await writeToCache(request, fresh, options);
 						} catch (err) {
+							debug.logError('handler', err as Error, 'SWR blocking revalidation');
 							console.warn(
 								"SWR blocking revalidation failed; serving stale",
 								err,
@@ -65,16 +76,20 @@ export function createCacheHandler<
 				} else if (policy === "background") {
 					const handler = baseHandler || callOpts.handler;
 					if (handler) {
+						debug.logBackgroundRevalidation(request.url, true);
 						const scheduler = callOpts.runInBackground ||
 							options.runInBackground;
 						const revalidatePromise = (async () => {
 							try {
+								debug.log('handler', `Background revalidation starting for ${request.url}`);
 								const response = await handler(request, {
 									mode: "stale",
 									background: true,
 								});
 								await writeToCache(request, response, options);
+								debug.log('handler', `Background revalidation completed for ${request.url}`);
 							} catch (err) {
+								debug.logError('handler', err as Error, 'SWR background revalidation');
 								console.warn("SWR background revalidation failed", err);
 							}
 						})();
@@ -86,6 +101,7 @@ export function createCacheHandler<
 					}
 				} else if (policy === "off") {
 					// Treat stale-while-revalidate as disabled: delete and proceed as miss
+					debug.log('handler', `SWR disabled, deleting stale entry for ${request.url}`);
 					try {
 						await caches.open(options.cacheName || "cache-primitives-default")
 							.then((c) => c.delete(request as unknown as Request));
@@ -143,6 +159,7 @@ export function createCacheHandler<
 		}
 
 		// Cache miss
+		debug.log('handler', `Cache miss, calling handler for ${request.url}`);
 		const handler = callOpts.handler || baseHandler;
 		if (!handler) {
 			return new Response("Cache miss and no handler provided", {