Add otel span for client component loading (#62296)

This adds a new span to allow tracking the sum of all client component loading times for a specific request along with the count of items loaded. Closes NEXT-2540 --------- Co-authored-by: Zack Tanner <zacktanner@gmail.com>
vercel · Feb 20, 2024 · 6feb803 · 6feb803
1 parent f4ac92d
commit 6feb803
Show file tree

Hide file tree

Showing 4 changed files with 77 additions and 3 deletions.
diff --git a/packages/next/src/server/app-render/app-render.tsx b/packages/next/src/server/app-render/app-render.tsx
@@ -51,7 +51,7 @@ import {
   getRedirectStatusCodeFromError,
 } from '../../client/components/redirect'
 import { addImplicitTags } from '../lib/patch-fetch'
-import { AppRenderSpan } from '../lib/trace/constants'
+import { AppRenderSpan, NextNodeServerSpan } from '../lib/trace/constants'
 import { getTracer } from '../lib/trace/tracer'
 import { FlightRenderResult } from './flight-render-result'
 import {
@@ -615,14 +615,71 @@ async function renderToHTMLOrFlightImpl(
     enableTainting,
   } = renderOpts
 
+  // Combined load times for loading client components
+  let clientComponentLoadStart = 0
+  let clientComponentLoadTimes = 0
+  let clientComponentLoadCount = 0
+
   // We need to expose the bundled `require` API globally for
   // react-server-dom-webpack. This is a hack until we find a better way.
   if (ComponentMod.__next_app__) {
     // @ts-ignore
-    globalThis.__next_require__ = ComponentMod.__next_app__.require
+    globalThis.__next_require__ = (...args: any[]) => {
+      if (clientComponentLoadStart === 0) {
+        clientComponentLoadStart = Date.now()
+      }
+
+      const startTime = Date.now()
+      try {
+        clientComponentLoadCount += 1
+        return ComponentMod.__next_app__.require(...args)
+      } finally {
+        clientComponentLoadTimes += Date.now() - startTime
+      }
+    }
 
     // @ts-ignore
-    globalThis.__next_chunk_load__ = ComponentMod.__next_app__.loadChunk
+    globalThis.__next_chunk_load__ = (...args: any[]) => {
+      const startTime = Date.now()
+      try {
+        clientComponentLoadCount += 1
+        return ComponentMod.__next_app__.loadChunk(...args)
+      } finally {
+        clientComponentLoadTimes += Date.now() - startTime
+      }
+    }
+  }
+
+  if (typeof req.on === 'function') {
+    req.on('end', () => {
+      const type = NextNodeServerSpan.clientComponentLoading
+      const startTime = clientComponentLoadStart
+      const endTime = clientComponentLoadStart + clientComponentLoadTimes
+      getTracer()
+        .startSpan(type, {
+          startTime,
+          attributes: {
+            'next.clientComponentLoadCount': clientComponentLoadCount,
+          },
+        })
+        .end(endTime)
+
+      if (
+        typeof performance !== 'undefined' &&
+        process.env.NEXT_OTEL_PERFORMANCE_PREFIX
+      ) {
+        const { timeOrigin } = performance
+        performance.measure(
+          `${process.env.NEXT_OTEL_PERFORMANCE_PREFIX}:next-${(
+            type.split('.').pop() || ''
+          ).replace(/[A-Z]/g, (match: string) => '-' + match.toLowerCase())}`,
+          {
+            start: startTime - timeOrigin,
+            end: endTime - timeOrigin,
+          }
+        )
+      }
+    })
   }
 
   const metadata: AppPageRenderResultMetadata = {}

diff --git a/packages/next/src/server/lib/trace/constants.ts b/packages/next/src/server/lib/trace/constants.ts
@@ -39,6 +39,7 @@ enum NextNodeServerSpan {
   compression = 'NextNodeServer.compression',
   getBuildId = 'NextNodeServer.getBuildId',
   createComponentTree = 'NextNodeServer.createComponentTree',
+  clientComponentLoading = 'NextNodeServer.clientComponentLoading',
   getLayoutOrPageModule = 'NextNodeServer.getLayoutOrPageModule',
   generateStaticRoutes = 'NextNodeServer.generateStaticRoutes',
   generateFsStaticRoutes = 'NextNodeServer.generateFsStaticRoutes',
@@ -134,13 +135,15 @@ export const NextVanillaSpanAllowlist = [
   NextNodeServerSpan.findPageComponents,
   NextNodeServerSpan.getLayoutOrPageModule,
   NextNodeServerSpan.startResponse,
+  NextNodeServerSpan.clientComponentLoading,
 ]
 
 // These Spans are allowed to be always logged
 // when the otel log prefix env is set
 export const LogSpanAllowList = [
   NextNodeServerSpan.findPageComponents,
   NextNodeServerSpan.createComponentTree,
+  NextNodeServerSpan.clientComponentLoading,
 ]
 
 export {

diff --git a/packages/next/src/server/lib/trace/tracer.ts b/packages/next/src/server/lib/trace/tracer.ts
@@ -144,6 +144,7 @@ type NextAttributeNames =
   | 'next.segment'
   | 'next.span_name'
   | 'next.span_type'
+  | 'next.clientComponentLoadCount'
 type OTELAttributeNames = `http.${string}` | `net.${string}`
 type AttributeNames = NextAttributeNames | OTELAttributeNames
 

diff --git a/test/e2e/opentelemetry/opentelemetry.test.ts b/test/e2e/opentelemetry/opentelemetry.test.ts
@@ -162,6 +162,16 @@ createNextDescribe(
                         kind: 0,
                         status: { code: 0 },
                       },
+                      {
+                        attributes: {
+                          'next.clientComponentLoadCount': 4,
+                        },
+                        kind: 0,
+                        name: 'NextNodeServer.clientComponentLoading',
+                        status: {
+                          code: 0,
+                        },
+                      },
                       {
                         name: 'start response',
                         attributes: {
@@ -771,6 +781,9 @@ createNextDescribe(
                     {
                       name: 'generateMetadata /app/[param]/rsc-fetch/page',
                     },
+                    {
+                      name: 'NextNodeServer.clientComponentLoading',
+                    },
                     {
                       name: 'start response',
                     },