chore: add some timestamps to debug logs

Author: pieh

src/run/handlers/use-cache-handler.ts

@@ -86,6 +86,8 @@ function getPendingSets(): PendingSets {
   return pendingSets
 }
 
+const debugLog = (...args: unknown[]) => console.log(new Date().toISOString(), ...args)
+
 // eslint-disable-next-line @typescript-eslint/no-empty-function
 const tmpResolvePendingBeforeCreatingAPromise = () => {}
 
@@ -207,6 +209,10 @@ const WIPNetlifyDefaultUseCacheHandler = {
   },
   async refreshTags(): Promise<void> {
     // we check tags on demand, so we don't need to do anything here
+    // additionally this is blocking and we do need to check tags in
+    // persisted storage, so if we would maintain in-memory tags manifests
+    // we would need to check more tags than current request needs
+    // while blocking pipeline
   },
   getExpiration: function (...tags: string[]): ReturnType<CacheHandler['getExpiration']> {
     return getTracer().withActiveSpan(
@@ -243,10 +249,10 @@ const WIPNetlifyDefaultUseCacheHandler = {
 function createDebugUseCacheHandler(cacheHandlerToDebug: CacheHandler): CacheHandler {
   return {
     get: function (cacheKey: string): Promise<undefined | CacheEntry> {
-      console.log('NetlifyDefaultUseCacheHandler::get start', { cacheKey })
+      debugLog('NetlifyDefaultUseCacheHandler::get start', { cacheKey })
       return cacheHandlerToDebug.get(cacheKey).then(async (entry) => {
         if (!entry) {
-          console.log('NetlifyDefaultUseCacheHandler::get MISS', { cacheKey })
+          debugLog('NetlifyDefaultUseCacheHandler::get MISS', { cacheKey })
           return entry
         }
 
@@ -256,7 +262,7 @@ function createDebugUseCacheHandler(cacheHandlerToDebug: CacheHandler): CacheHan
         const [returnStream, debugStream] = cloneStream.tee()
 
         const text = await new Response(debugStream).text()
-        console.log('NetlifyDefaultUseCacheHandler::get HIT', { cacheKey, entry, text })
+        debugLog('NetlifyDefaultUseCacheHandler::get HIT', { cacheKey, entry, text })
 
         return {
           ...entry,
@@ -265,7 +271,7 @@ function createDebugUseCacheHandler(cacheHandlerToDebug: CacheHandler): CacheHan
       })
     },
     set: async function (cacheKey: string, pendingEntry: Promise<CacheEntry>): Promise<void> {
-      console.log('NetlifyDefaultUseCacheHandler::set start', { cacheKey })
+      debugLog('NetlifyDefaultUseCacheHandler::set start', { cacheKey })
       const entry = await pendingEntry
       const [storeStream, debugStream] = entry.value.tee()
 
@@ -276,33 +282,35 @@ function createDebugUseCacheHandler(cacheHandlerToDebug: CacheHandler): CacheHan
 
       const text = await new Response(debugStream).text()
 
-      console.log('NetlifyDefaultUseCacheHandler::set awaited pending entry', {
+      debugLog('NetlifyDefaultUseCacheHandler::set awaited pending entry', {
         cacheKey,
         entry,
         text,
       })
 
       const setPromise = cacheHandlerToDebug.set(cacheKey, toSetEntry).then(() => {
-        console.log('NetlifyDefaultUseCacheHandler::set finish', { cacheKey })
+        debugLog('NetlifyDefaultUseCacheHandler::set finish', { cacheKey })
       })
 
       getRequestContext()?.trackBackgroundWork(setPromise)
 
       return setPromise
     },
     refreshTags: function (): Promise<void> {
-      console.log('NetlifyDefaultUseCacheHandler::refreshTags')
-      return cacheHandlerToDebug.refreshTags()
+      debugLog('NetlifyDefaultUseCacheHandler::refreshTags start')
+      return cacheHandlerToDebug.refreshTags().then(() => {
+        debugLog('NetlifyDefaultUseCacheHandler::refreshTags end')
+      })
     },
     getExpiration: function (...tags: string[]): Promise<Timestamp> {
-      console.log('NetlifyDefaultUseCacheHandler::getExpiration start', { tags })
+      debugLog('NetlifyDefaultUseCacheHandler::getExpiration start', { tags })
       return cacheHandlerToDebug.getExpiration(...tags).then((expiration) => {
-        console.log('NetlifyDefaultUseCacheHandler::getExpiration finish', { tags, expiration })
+        debugLog('NetlifyDefaultUseCacheHandler::getExpiration finish', { tags, expiration })
         return expiration
       })
     },
     expireTags: function (...tags: string[]): Promise<void> {
-      console.log('NetlifyDefaultUseCacheHandler::expireTags', { tags })
+      debugLog('NetlifyDefaultUseCacheHandler::expireTags', { tags })
       return cacheHandlerToDebug.expireTags(...tags)
     },
   }