From 6feb803f78eec02fc52d2552a777be60f216b942 Mon Sep 17 00:00:00 2001 From: JJ Kasper Date: Tue, 20 Feb 2024 13:27:16 -0800 Subject: [PATCH] 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 --- .../next/src/server/app-render/app-render.tsx | 63 ++++++++++++++++++- .../next/src/server/lib/trace/constants.ts | 3 + packages/next/src/server/lib/trace/tracer.ts | 1 + test/e2e/opentelemetry/opentelemetry.test.ts | 13 ++++ 4 files changed, 77 insertions(+), 3 deletions(-) diff --git a/packages/next/src/server/app-render/app-render.tsx b/packages/next/src/server/app-render/app-render.tsx index 2d667ca730484..69c07ce8192ef 100644 --- 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 index 93450fcf067c0..b452194adade4 100644 --- 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,6 +135,7 @@ export const NextVanillaSpanAllowlist = [ NextNodeServerSpan.findPageComponents, NextNodeServerSpan.getLayoutOrPageModule, NextNodeServerSpan.startResponse, + NextNodeServerSpan.clientComponentLoading, ] // These Spans are allowed to be always logged @@ -141,6 +143,7 @@ export const NextVanillaSpanAllowlist = [ 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 index f4003106d1e1c..3d35bb76b57c3 100644 --- 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 index 941ede9ce0526..e1e204bf31df1 100644 --- 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', },