Fix name and url shown for HIT/STALE items in subrequest profiler (#2021

) * Rename variable * Sort properties in SR events * Store debugInfo in CacheAPI during development * Calculate endTime earlier * Changesets * Changesets
Shopify · Apr 19, 2024 · e842f68 · e842f68
1 parent 48218c3
commit e842f68
Show file tree

Hide file tree

Showing 4 changed files with 57 additions and 18 deletions.
diff --git a/.changeset/many-cycles-invite.md b/.changeset/many-cycles-invite.md
@@ -0,0 +1,5 @@
+---
+'@shopify/hydrogen': patch
+---
+
+Fix names and URLs shown for HIT/STALE items in the Subrequest Profiler.
diff --git a/packages/hydrogen/src/cache/fetch.ts b/packages/hydrogen/src/cache/fetch.ts
@@ -108,9 +108,11 @@ export async function runWithCache<T = unknown>(
     ...(typeof cacheKey === 'string' ? [cacheKey] : cacheKey),
   ]);
 
-  let debugData: DebugInfo;
+  let cachedDebugInfo: DebugInfo | undefined;
+  let userDebugInfo: DebugInfo | undefined;
+
   const addDebugData = (info: AddDebugDataParam) => {
-    debugData = {
+    userDebugInfo = {
       displayName: info.displayName,
       url: info.response?.url,
       responseInit: {
@@ -121,6 +123,20 @@ export async function runWithCache<T = unknown>(
     };
   };
 
+  const mergeDebugInfo = () => ({
+    ...cachedDebugInfo,
+    ...debugInfo,
+    url:
+      userDebugInfo?.url ||
+      debugInfo?.url ||
+      cachedDebugInfo?.url ||
+      getKeyUrl(key),
+    displayName:
+      debugInfo?.displayName ||
+      userDebugInfo?.displayName ||
+      cachedDebugInfo?.displayName,
+  });
+
   const logSubRequestEvent =
     process.env.NODE_ENV === 'development'
       ? ({
@@ -133,20 +149,19 @@ export async function runWithCache<T = unknown>(
           overrideStartTime?: number;
         }) => {
           globalThis.__H2O_LOG_EVENT?.({
+            ...mergeDebugInfo(),
             eventType: 'subrequest',
             startTime: overrideStartTime || startTime,
+            endTime: Date.now(),
             cacheStatus,
             responsePayload: (result && result[0]) || result,
-            responseInit: (result && result[1]) || debugData?.responseInit,
+            responseInit: (result && result[1]) || userDebugInfo?.responseInit,
             cache: {
               status: cacheStatus,
               strategy: generateCacheControlHeader(strategy || {}),
               key,
             },
             waitUntil,
-            ...debugInfo,
-            url: debugData?.url || debugInfo?.url || getKeyUrl(key),
-            displayName: debugInfo?.displayName || debugData?.displayName,
           });
         }
       : undefined;
@@ -158,11 +173,30 @@ export async function runWithCache<T = unknown>(
     return result;
   }
 
-  const cachedItem = await getItemFromCache(cacheInstance, key);
+  type CachedItem = {
+    value: Awaited<T>;
+    debugInfo?: DebugInfo;
+  };
+
+  const storeInCache = (value: CachedItem['value']) =>
+    setItemInCache(
+      cacheInstance,
+      key,
+      {
+        value,
+        debugInfo:
+          process.env.NODE_ENV === 'development' ? mergeDebugInfo() : undefined,
+      } satisfies CachedItem,
+      strategy,
+    );
+
+  const cachedItem = await getItemFromCache<CachedItem>(cacheInstance, key);
   // console.log('--- Cache', cachedItem ? 'HIT' : 'MISS');
 
-  if (cachedItem) {
-    const [cachedResult, cacheInfo] = cachedItem;
+  if (cachedItem && typeof cachedItem[0] !== 'string') {
+    const [{value: cachedResult, debugInfo}, cacheInfo] = cachedItem;
+    cachedDebugInfo = debugInfo;
+
     const cacheStatus = isStale(key, cacheInfo) ? 'STALE' : 'HIT';
 
     if (!swrLock.has(key) && cacheStatus === 'STALE') {
@@ -175,7 +209,7 @@ export async function runWithCache<T = unknown>(
           const result = await actionFn({addDebugData});
 
           if (shouldCacheResult(result)) {
-            await setItemInCache(cacheInstance, key, result, strategy);
+            await storeInCache(result);
 
             // Log PUT requests with the revalidate start time
             logSubRequestEvent?.({
@@ -220,17 +254,17 @@ export async function runWithCache<T = unknown>(
    * Important: Do this async
    */
   if (shouldCacheResult(result)) {
-    const setItemInCachePromise = Promise.resolve().then(async () => {
+    const cacheStoringPromise = Promise.resolve().then(async () => {
       const putStartTime = Date.now();
-      await setItemInCache(cacheInstance, key, result, strategy);
+      await storeInCache(result);
       logSubRequestEvent?.({
         result,
         cacheStatus: 'PUT',
         overrideStartTime: putStartTime,
       });
     });
 
-    waitUntil?.(setItemInCachePromise);
+    waitUntil?.(cacheStoringPromise);
   }
 
   return result;

diff --git a/packages/hydrogen/src/cache/sub-request.ts b/packages/hydrogen/src/cache/sub-request.ts
@@ -35,10 +35,10 @@ export function generateSubRequestCacheControlHeader(
  * as the response itself so it can be checked for staleness.
  * @private
  */
-export async function getItemFromCache(
+export async function getItemFromCache<T = any>(
   cache: Cache,
   key: string,
-): Promise<undefined | [any, Response]> {
+): Promise<undefined | [T | string, Response]> {
   if (!cache) return;
   const url = getKeyUrl(key);
   const request = new Request(url);

diff --git a/packages/hydrogen/src/storefront.ts b/packages/hydrogen/src/storefront.ts
@@ -329,12 +329,12 @@ export function createStorefrontClient<TI18n extends I18nBase>(
       shouldCacheResponse: checkGraphQLErrors,
       waitUntil,
       debugInfo: {
+        requestId: requestInit.headers[STOREFRONT_REQUEST_GROUP_ID_HEADER],
+        displayName,
         url,
+        stackInfo,
         graphql: graphqlData,
-        requestId: requestInit.headers[STOREFRONT_REQUEST_GROUP_ID_HEADER],
         purpose: storefrontHeaders?.purpose,
-        stackInfo,
-        displayName,
       },
     });