vercel/next.js · #99322

Scope client component loading metrics to HTML renders

gnoff · merged Sep 29, 202621 files · 1309 + / 352 −
packages/next/src/server/app-render/app-render.tsx195 + / 120 −
@@ -210,7 +210,7 @@ import { } from './dynamic-rendering' import { logBuildDebugHint } from './blocking-route-messages' import {-  getClientComponentLoaderMetrics,+  ClientComponentLoadTracker,   wrapClientComponentLoader, } from '../client-component-renderer-logger' import { isNodeNextRequest, isNodeNextResponse } from '../base-http/helpers'@@ -2586,18 +2586,17 @@ export type BinaryStreamOf<T> = AnyStream  /**  * Extracted to a separate function to prevent V8 from retaining the entire- * `prepareAppPageRender` closure scope through globalThis.__next_require__.+ * the render initialization scope through globalThis.__next_require__.  * V8 shares a single Context object per scope for all closures; by creating  * these closures in their own function scope, the globalThis references only  * retain `instrumented` and `cacheComponents`, not request-specific data like  * req/res/workStore.  */ function installGlobalModuleLoadingHandlers(   ComponentMod: AppPageModule,-  cacheComponents: boolean,-  isTracingEnabled: boolean+  cacheComponents: boolean ) {-  const instrumented = wrapClientComponentLoader(ComponentMod, isTracingEnabled)+  const instrumented = wrapClientComponentLoader(ComponentMod)    // When we are prerendering if there is a cacheSignal for tracking   // cache reads we track calls to `loadChunk` and `require`. This allows us@@ -2682,6 +2681,55 @@ const generatePrerenderRequestId: GenerateRequestId = async (req) => {   ).toString('hex') } +function initializeClientComponentLoadTracking(+  renderOpts: RenderOpts,+  workStore: WorkStore+): ClientComponentLoadTracker | undefined {+  if (!renderOpts.ComponentMod.__next_app__) return undefined++  // Capture the request's span before the HTML render creates its own span.+  const parentSpan = getTracer().getActiveScopeSpan()+  const isTracingEnabled = parentSpan?.isRecording() ?? false++  let tracker: ClientComponentLoadTracker | undefined+  if (+    'performance' in globalThis &&+    (process.env.NEXT_OTEL_PERFORMANCE_PREFIX || isTracingEnabled)+  ) {+    tracker = new ClientComponentLoadTracker((metrics) => {+      if (+        process.env.NEXT_RUNTIME !== 'edge' &&+        isTracingEnabled &&+        metrics &&+        metrics.clientComponentLoadEnd >= metrics.clientComponentLoadStart+      ) {+        getTracer()+          .startSpan(NextNodeServerSpan.clientComponentLoading, {+            parentSpan,+            startTime: metrics.clientComponentLoadStart,+            attributes: {+              'next.clientComponentLoadCount': metrics.clientComponentLoadCount,+              'next.span_type': NextNodeServerSpan.clientComponentLoading,+            },+          })+          .end(metrics.clientComponentLoadEnd)+      }+    })+    workStore.clientComponentLoadTracker = tracker+  }+  return tracker+}++function finishClientComponentLoadTrackingOnReady(+  tracker: ClientComponentLoadTracker | undefined,+  allReady: Promise<unknown>+) {+  if (tracker) {+    const finish = () => tracker.finish()+    void allReady.then(finish, finish)+  }+}+ async function prepareAppPageRender(   req: BaseNextRequest,   res: BaseNextResponse,@@ -2719,18 +2767,6 @@ async function prepareAppPageRender(     setIsrStatus,   } = renderOpts -  // 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__) {-    const isTracingEnabled =-      getTracer().getActiveScopeSpan()?.isRecording() ?? false-    installGlobalModuleLoadingHandlers(-      ComponentMod,-      cacheComponents,-      isTracingEnabled-    )-  }-   if (process.env.__NEXT_DEV_SERVER && setIsrStatus && !cacheComponents) {     // Reset the ISR status at start of request.     const { pathname } = new URL(req.url || '/', 'http://n')@@ -2752,27 +2788,6 @@ async function prepareAppPageRender(       // report them at that time.       workStore.shouldTrackFetchMetrics = false     })--    req.originalRequest.on('end', () => {-      if ('performance' in globalThis) {-        const metrics = getClientComponentLoaderMetrics({ reset: true })-        if (-          metrics &&-          metrics.clientComponentLoadEnd >= metrics.clientComponentLoadStart-        ) {-          getTracer()-            .startSpan(NextNodeServerSpan.clientComponentLoading, {-              startTime: metrics.clientComponentLoadStart,-              attributes: {-                'next.clientComponentLoadCount':-                  metrics.clientComponentLoadCount,-                'next.span_type': NextNodeServerSpan.clientComponentLoading,-              },-            })-            .end(metrics.clientComponentLoadEnd)-        }-      }-    })   }    const metadata: AppPageRenderResultMetadata = {@@ -2910,14 +2925,21 @@ async function prerenderAppPage({     prerenderToStream   ) -  const response = await prerenderToStreamWithTracing(-    req,-    res,-    ctx,-    metadata,-    loaderTree,-    fallbackRouteParams-  )+  const tracker = initializeClientComponentLoadTracking(renderOpts, workStore)+  metadata.clientComponentLoadTracker = tracker+  let response: PrerenderToStreamResult+  try {+    response = await prerenderToStreamWithTracing(+      req,+      res,+      ctx,+      metadata,+      loaderTree,+      fallbackRouteParams+    )+  } finally {+    tracker?.finish()+  }    // If we're debugging partial prerendering, print all the dynamic API accesses   // that occurred during the render.@@ -3141,7 +3163,12 @@ async function renderAppPage(         )       } else {         // MARK: RSC dynamic-        return generateDynamicFlightRenderResult(req, ctx, requestStore)+        return generateDynamicFlightRenderResult(+          req,+          ctx,+          requestStore,+          undefined+        )       }     }   }@@ -3167,23 +3194,35 @@ async function renderAppPage(         const notFoundLoaderTree = createNotFoundLoaderTree(loaderTree)         res.statusCode = 404         metadata.statusCode = 404-        const stream = await renderToStream(-          requestStore,-          req,-          res,-          ctx,-          notFoundLoaderTree,-          formState,-          postponedState,-          metadata,-          undefined, // Prevent restartable-render behavior in dev + Cache Components mode-          stagedFallbackParams+        const tracker = initializeClientComponentLoadTracking(+          renderOpts,+          workStore         )+        metadata.clientComponentLoadTracker = tracker+        try {+          const stream = await renderToStream(+            requestStore,+            req,+            res,+            ctx,+            notFoundLoaderTree,+            formState,+            postponedState,+            metadata,+            undefined, // Prevent restartable-render behavior in dev + Cache Components mode+            stagedFallbackParams,+            tracker+          ) -        return new RenderResult(stream, {-          metadata,-          contentType: HTML_CONTENT_TYPE_HEADER,-        })+          return new RenderResult(stream, {+            metadata,+            contentType: HTML_CONTENT_TYPE_HEADER,+          })+        } catch (renderError) {+          // Failed setup may never reach the SSR readiness callback.+          tracker?.finish()+          throw renderError+        }       } else if (actionRequestResult.type === 'done') {         if (actionRequestResult.result) {           actionRequestResult.result.assignMetadata(metadata)@@ -3202,66 +3241,76 @@ async function renderAppPage(     contentType: HTML_CONTENT_TYPE_HEADER,   } -  const stream = await renderToStream(-    // NOTE: in Cache Components (dev), if the render is restarted, it will use a different requestStore-    // than the one that we're passing in here.-    requestStore,-    req,-    res,-    ctx,-    loaderTree,-    formState,-    postponedState,-    metadata,-    // If we're rendering HTML after an action, we don't want restartable-render behavior-    // because the result should be dynamic, like it is in prod.-    // Also, the request store might have been mutated by the action (e.g. enabling draftMode)-    // and we currently we don't copy changes over when creating a new store,-    // so the restarted render wouldn't be correct.-    didExecuteServerAction ? undefined : createRequestStore,-    stagedFallbackParams-  )--  // Forward an invalid-dynamic-usage error recorded by `'use cache'` only-  // when userland caught it (try/catch around the cache call). If userland-  // didn't catch, the rejection propagated into the React render, and React's-  // `serverComponentsErrorHandler` already stamped a digest on the error and-  // emitted it as a Flight error chunk — surfacing it again here would-  // duplicate the entry in the dev overlay.-  //-  // The cacheComponents paths forward this themselves via-  // `runValidationInDev` and the validation-skipped fallback in-  // `generateDynamicFlightRenderResultWithStagesInDev`. Here we cover the-  // non-cacheComponents dev path where neither runs.-  if (-    process.env.__NEXT_DEV_SERVER &&-    !cacheComponents &&-    workStore.invalidDynamicUsageError &&-    !(workStore.invalidDynamicUsageError as { digest?: unknown }).digest-  ) {-    void logMessagesAndSendErrorsToBrowser(-      [workStore.invalidDynamicUsageError],-      ctx+  const tracker = initializeClientComponentLoadTracking(renderOpts, workStore)+  metadata.clientComponentLoadTracker = tracker+  try {+    const stream = await renderToStream(+      // NOTE: in Cache Components (dev), if the render is restarted, it will use a different requestStore+      // than the one that we're passing in here.+      requestStore,+      req,+      res,+      ctx,+      loaderTree,+      formState,+      postponedState,+      metadata,+      // If we're rendering HTML after an action, we don't want restartable-render behavior+      // because the result should be dynamic, like it is in prod.+      // Also, the request store might have been mutated by the action (e.g. enabling draftMode)+      // and we currently we don't copy changes over when creating a new store,+      // so the restarted render wouldn't be correct.+      didExecuteServerAction ? undefined : createRequestStore,+      stagedFallbackParams,+      tracker     )-  } -  // If we have pending revalidates, wait until they are all resolved.-  const maybeRevalidatesPromise = executeRevalidates(workStore)-  if (maybeRevalidatesPromise !== false) {-    const revalidatesPromise = maybeRevalidatesPromise.finally(() => {-      if (process.env.NEXT_PRIVATE_DEBUG_CACHE) {-        console.log('pending revalidates promise finished for:', url.href)+    // Forward an invalid-dynamic-usage error recorded by `'use cache'` only+    // when userland caught it (try/catch around the cache call). If userland+    // didn't catch, the rejection propagated into the React render, and React's+    // `serverComponentsErrorHandler` already stamped a digest on the error and+    // emitted it as a Flight error chunk — surfacing it again here would+    // duplicate the entry in the dev overlay.+    //+    // The cacheComponents paths forward this themselves via+    // `runValidationInDev` and the validation-skipped fallback in+    // `generateDynamicFlightRenderResultWithStagesInDev`. Here we cover the+    // non-cacheComponents dev path where neither runs.+    if (+      process.env.__NEXT_DEV_SERVER &&+      !cacheComponents &&+      workStore.invalidDynamicUsageError &&+      !(workStore.invalidDynamicUsageError as { digest?: unknown }).digest+    ) {+      void logMessagesAndSendErrorsToBrowser(+        [workStore.invalidDynamicUsageError],+        ctx+      )+    }++    // If we have pending revalidates, wait until they are all resolved.+    const maybeRevalidatesPromise = executeRevalidates(workStore)+    if (maybeRevalidatesPromise !== false) {+      const revalidatesPromise = maybeRevalidatesPromise.finally(() => {+        if (process.env.NEXT_PRIVATE_DEBUG_CACHE) {+          console.log('pending revalidates promise finished for:', url.href)+        }+      })+      if (renderOpts.waitUntil) {+        renderOpts.waitUntil(revalidatesPromise)+      } else {+        options.waitUntil = revalidatesPromise       }-    })-    if (renderOpts.waitUntil) {-      renderOpts.waitUntil(revalidatesPromise)-    } else {-      options.waitUntil = revalidatesPromise     }-  } -  // Create the new render result for the response.-  return new RenderResult(stream, options)+    // Create the new render result for the response.+    return new RenderResult(stream, options)+  } catch (renderError) {+    // Returning a stream may precede SSR readiness, which finishes success.+    // Only failures finish here; a finally would seal successful renders early.+    tracker?.finish()+    throw renderError+  } }  async function renderToHTMLOrFlightImpl(@@ -3280,6 +3329,12 @@ async function renderToHTMLOrFlightImpl(   fallbackRouteParams: OpaqueFallbackRouteParams | null,   routeMatch: RouteMatch ) {+  if (renderOpts.ComponentMod.__next_app__) {+    installGlobalModuleLoadingHandlers(+      renderOpts.ComponentMod,+      renderOpts.cacheComponents+    )+  }   const prepared = await prepareAppPageRender(     req,     res,@@ -3321,6 +3376,12 @@ async function prerenderToHTMLOrFlightImpl(   fallbackRouteParams: OpaqueFallbackRouteParams | null,   routeMatch: RouteMatch ) {+  if (renderOpts.ComponentMod.__next_app__) {+    installGlobalModuleLoadingHandlers(+      renderOpts.ComponentMod,+      renderOpts.cacheComponents+    )+  }   const isRoutePPREnabled = renderOpts.experimental.isRoutePPREnabled === true   const prepared = await prepareAppPageRender(     req,@@ -3607,7 +3668,8 @@ async function renderToStream(   postponedState: PostponedState | null,   metadata: AppPageRenderResultMetadata,   createRequestStore: (() => RequestStore) | undefined,-  stagedFallbackParams: OpaqueFallbackRouteParams | null+  stagedFallbackParams: OpaqueFallbackRouteParams | null,+  tracker: ClientComponentLoadTracker | undefined ): Promise<AnyStream> {   /* eslint-disable @next/internal/no-ambiguous-jsx -- React Client */   // MARK: renderToStream setup@@ -4184,6 +4246,7 @@ async function renderToStream(              // End the span since there's no async rendering in this path             if (renderSpan.isRecording()) renderSpan.end()+            tracker?.finish()             return chainStreams(               inlinedDataStream,               createDocumentClosingStream()@@ -4219,7 +4282,11 @@ async function renderToStream(                 resumeToFizzStream,                 resumeAppElement,                 postponed,-                { onError: htmlRendererErrorHandler, nonce }+                {+                  onError: htmlRendererErrorHandler,+                  onAllReady: tracker ? () => tracker.finish() : undefined,+                  nonce,+                }               )              // End the render span only after React completed rendering (including anything inside Suspense boundaries)@@ -4266,6 +4333,7 @@ async function renderToStream(          const fizzOptions = {           onError: htmlRendererErrorHandler,+          onAllReady: tracker ? () => tracker.finish() : undefined,           nonce,           onHeaders: (headers: { [header: string]: string }) => {             for (const key in headers) {@@ -4325,6 +4393,7 @@ async function renderToStream(              // End the span since there's no async rendering in this path             if (renderSpan.isRecording()) renderSpan.end()+            tracker?.finish()             return chainStreams(               inlinedDataStream,               createDocumentClosingStream()@@ -4367,6 +4436,7 @@ async function renderToStream(             allReady.finally(() => {               if (renderSpan.isRecording()) renderSpan.end()             })+            finishClientComponentLoadTrackingOnReady(tracker, allReady)              return await continueDynamicHTMLResumeWeb(htmlStream, {               delayDataUntilFirstHtmlChunk:@@ -4429,6 +4499,7 @@ async function renderToStream(         allReady.finally(() => {           if (renderSpan.isRecording()) renderSpan.end()         })+        finishClientComponentLoadTrackingOnReady(tracker, allReady)          return await continueFizzStream(htmlStream, {           inlinedDataStream: createWebInlinedDataStream(@@ -4583,6 +4654,7 @@ async function renderToStream(                 bootstrapScriptContent: errorBootstrapScriptContent,                 bootstrapScripts: [errorBootstrapScript],                 formState,+                onAllReady: tracker ? () => tracker.finish() : undefined,               },               { waitForAllReady }             )@@ -4685,6 +4757,7 @@ async function renderToStream(           errorAllReady.finally(() => {             if (renderSpan.isRecording()) renderSpan.end()           })+          finishClientComponentLoadTrackingOnReady(tracker, errorAllReady)            return await continueFizzStream(errorHtmlStream, {             inlinedDataStream: createWebInlinedDataStream(@@ -6807,6 +6880,7 @@ function buildDevValidationWorkStore(     refreshTagsByCacheKind: new Map(),     runInCleanSnapshot: createSnapshot(),     shouldTrackFetchMetrics: false,+    clientComponentLoadTracker: undefined,     reactServerErrorsByDigest: new Map(),     afterContext: noopAfterContext,     // Dev validation only ever runs under Cache Components.@@ -6854,7 +6928,7 @@ export async function runValidationInDevFromSnapshot(   // so `react-server-dom-*` can resolve client references during the validation   // prerenders, exactly as the main render does after loading its module.   if (componentMod.__next_app__) {-    installGlobalModuleLoadingHandlers(componentMod, true, false)+    installGlobalModuleLoadingHandlers(componentMod, true)   }    // `requestFallbackRouteParams` reproduces `ctx.getDynamicParamFromSegment`@@ -8557,6 +8631,7 @@ async function validateInstantConfigInBuildWithSample(     refreshTagsByCacheKind: new Map(),     runInCleanSnapshot: outerWorkStore.runInCleanSnapshot,     shouldTrackFetchMetrics: false,+    clientComponentLoadTracker: undefined,     reactServerErrorsByDigest: new Map(),   } 
packages/next/src/server/app-render/work-async-storage.external.ts2 + / 0 −
@@ -13,6 +13,7 @@ import { workAsyncStorageInstance } from './work-async-storage-instance' with { import type { LazyResult } from '../lib/lazy-result' import type { DigestedError } from './create-error-handler' import type { ActionRevalidationKind } from '../../shared/lib/action-revalidation-kind'+import type { ClientComponentLoadTracker } from '../client-component-renderer-logger'  export interface WorkStore {   /**@@ -101,6 +102,7 @@ export interface WorkStore {    fetchMetrics?: FetchMetrics   shouldTrackFetchMetrics: boolean+  clientComponentLoadTracker: ClientComponentLoadTracker | undefined    /**    * Tracks pending `"use cache"` invocations within the current request scope,
packages/next/src/server/async-storage/work-store.ts1 + / 0 −
@@ -147,6 +147,7 @@ function createWorkStoreImpl(     refreshTagsByCacheKind: createRefreshTagsByCacheKind(),     runInCleanSnapshot: createSnapshot(),     shouldTrackFetchMetrics,+    clientComponentLoadTracker: undefined,     reactServerErrorsByDigest: new Map(),   } 
packages/next/src/server/client-component-renderer-logger.test.ts266 + / 126 −
@@ -1,8 +1,14 @@+import { AsyncLocalStorage } from 'async_hooks' import type { AppPageModule } from './route-modules/app-page/module'-import {-  getClientComponentLoaderMetrics,-  wrapClientComponentLoader,-} from './client-component-renderer-logger'+import type { WorkStore } from './app-render/work-async-storage.external'++type LoggerMod = typeof import('./client-component-renderer-logger')+type WASMod = typeof import('./app-render/work-async-storage.external')++let ClientComponentLoadTracker: LoggerMod['ClientComponentLoadTracker']+let getClientComponentLoaderMetrics: LoggerMod['getClientComponentLoaderMetrics']+let wrapClientComponentLoader: LoggerMod['wrapClientComponentLoader']+let workAsyncStorage: WASMod['workAsyncStorage']  function createComponentModule(   require: (@@ -17,121 +23,213 @@ function createComponentModule(   } as unknown as AppPageModule } +function createTrackedWorkStore(+  page: string = '/test/page',+  route: string = '/test'+): WorkStore {+  return {+    page,+    route,+    clientComponentLoadTracker: new ClientComponentLoadTracker(),+  } as WorkStore+}++function runWithTrackedWorkStore<T>(fn: () => T): T {+  return workAsyncStorage.run(createTrackedWorkStore(), fn)+}+ describe('client component renderer logger', () => {+  beforeAll(async () => {+    // AsyncLocalStorage must be available before workAsyncStorage is imported.+    // @ts-expect-error+    globalThis.AsyncLocalStorage = AsyncLocalStorage++    const logger = await import('./client-component-renderer-logger')+    ClientComponentLoadTracker = logger.ClientComponentLoadTracker+    getClientComponentLoaderMetrics = logger.getClientComponentLoaderMetrics+    wrapClientComponentLoader = logger.wrapClientComponentLoader+    const workStorage = await import('./app-render/work-async-storage.external')+    workAsyncStorage = workStorage.workAsyncStorage+  })+   afterEach(() => {     getClientComponentLoaderMetrics({ reset: true })     jest.restoreAllMocks()   }) -  it('tracks elapsed boundaries separately from sequential load time', () => {-    jest-      .spyOn(performance, 'now')-      .mockReturnValueOnce(100)-      .mockReturnValueOnce(110)-      .mockReturnValueOnce(150)-      .mockReturnValueOnce(160)+  it('tracks elapsed boundaries separately from sequential load time', () =>+    runWithTrackedWorkStore(() => {+      jest+        .spyOn(performance, 'now')+        .mockReturnValueOnce(100)+        .mockReturnValueOnce(110)+        .mockReturnValueOnce(150)+        .mockReturnValueOnce(160) -    const loader = wrapClientComponentLoader(-      createComponentModule(-        () => undefined,-        async () => undefined-      ),-      true-    )+      const loader = wrapClientComponentLoader(+        createComponentModule(+          () => undefined,+          async () => undefined+        )+      ) -    loader.require('first')-    loader.require('second')+      loader.require('first')+      loader.require('second') -    expect(getClientComponentLoaderMetrics()).toEqual({-      clientComponentLoadStart: 100,-      clientComponentLoadEnd: 160,-      clientComponentLoadTimes: 20,-      clientComponentLoadCount: 2,-    })-  })+      expect(getClientComponentLoaderMetrics()).toEqual({+        clientComponentLoadStart: 100,+        clientComponentLoadEnd: 160,+        clientComponentLoadTimes: 20,+        clientComponentLoadCount: 2,+      })+    })) -  it('preserves accumulated load time for nested requires', () => {-    jest-      .spyOn(performance, 'now')-      .mockReturnValueOnce(100)-      .mockReturnValueOnce(110)-      .mockReturnValueOnce(120)-      .mockReturnValueOnce(130)+  it('preserves accumulated load time for nested requires', () =>+    runWithTrackedWorkStore(() => {+      jest+        .spyOn(performance, 'now')+        .mockReturnValueOnce(100)+        .mockReturnValueOnce(110)+        .mockReturnValueOnce(120)+        .mockReturnValueOnce(130) -    let loader: AppPageModule['__next_app__']-    loader = wrapClientComponentLoader(-      createComponentModule(-        (id) => {-          if (id === 'outer') {-            loader.require('inner')-          }-        },-        async () => undefined-      ),-      true-    )+      let loader: AppPageModule['__next_app__']+      loader = wrapClientComponentLoader(+        createComponentModule(+          (id) => {+            if (id === 'outer') {+              loader.require('inner')+            }+          },+          async () => undefined+        )+      ) -    loader.require('outer')+      loader.require('outer') -    expect(getClientComponentLoaderMetrics()).toEqual({-      clientComponentLoadStart: 100,-      clientComponentLoadEnd: 130,-      clientComponentLoadTimes: 40,-      clientComponentLoadCount: 2,-    })-  })+      expect(getClientComponentLoaderMetrics()).toEqual({+        clientComponentLoadStart: 100,+        clientComponentLoadEnd: 130,+        clientComponentLoadTimes: 40,+        clientComponentLoadCount: 2,+      })+    })) -  it('tracks the last settlement across overlapping chunk loads', async () => {-    jest-      .spyOn(performance, 'now')-      .mockReturnValueOnce(100)-      .mockReturnValueOnce(110)-      .mockReturnValueOnce(130)-      .mockReturnValueOnce(170)--    let resolveFirst!: () => void-    let resolveSecond!: () => void-    const first = new Promise<void>((resolve) => {-      resolveFirst = resolve-    })-    const second = new Promise<void>((resolve) => {-      resolveSecond = resolve-    })-    const loader = wrapClientComponentLoader(-      createComponentModule(-        () => undefined,-        (id) => (id === 'first' ? first : second)-      ),-      true-    )+  it('tracks the last settlement across overlapping chunk loads', () =>+    runWithTrackedWorkStore(async () => {+      jest+        .spyOn(performance, 'now')+        .mockReturnValueOnce(100)+        .mockReturnValueOnce(110)+        .mockReturnValueOnce(130)+        .mockReturnValueOnce(170) -    expect(loader.loadChunk('first')).toBe(first)-    expect(loader.loadChunk('second')).toBe(second)+      let resolveFirst!: () => void+      let resolveSecond!: () => void+      const first = new Promise<void>((resolve) => {+        resolveFirst = resolve+      })+      const second = new Promise<void>((resolve) => {+        resolveSecond = resolve+      })+      const loader = wrapClientComponentLoader(+        createComponentModule(+          () => undefined,+          (id) => (id === 'first' ? first : second)+        )+      ) -    resolveSecond()-    await second-    expect(getClientComponentLoaderMetrics()).toEqual({-      clientComponentLoadStart: 100,-      clientComponentLoadEnd: 130,-      clientComponentLoadTimes: 20,-      clientComponentLoadCount: 0,-    })+      expect(loader.loadChunk('first')).toBe(first)+      expect(loader.loadChunk('second')).toBe(second) -    resolveFirst()-    await first-    expect(getClientComponentLoaderMetrics()).toEqual({-      clientComponentLoadStart: 100,-      clientComponentLoadEnd: 170,-      clientComponentLoadTimes: 90,-      clientComponentLoadCount: 0,-    })-  })+      resolveSecond()+      await second+      expect(getClientComponentLoaderMetrics()).toEqual({+        clientComponentLoadStart: 100,+        clientComponentLoadEnd: 130,+        clientComponentLoadTimes: 20,+        clientComponentLoadCount: 0,+      }) -  it('leaves the end boundary unset while a chunk load is pending', async () => {+      resolveFirst()+      await first+      expect(getClientComponentLoaderMetrics()).toEqual({+        clientComponentLoadStart: 100,+        clientComponentLoadEnd: 170,+        clientComponentLoadTimes: 90,+        clientComponentLoadCount: 0,+      })+    }))++  it('leaves the end boundary unset while a chunk load is pending', () =>+    runWithTrackedWorkStore(async () => {+      jest+        .spyOn(performance, 'now')+        .mockReturnValueOnce(100)+        .mockReturnValueOnce(150)++      let resolveChunk!: () => void+      const chunk = new Promise<void>((resolve) => {+        resolveChunk = resolve+      })+      const loader = wrapClientComponentLoader(+        createComponentModule(+          () => undefined,+          () => chunk+        )+      )++      expect(loader.loadChunk('pending')).toBe(chunk)+      expect(getClientComponentLoaderMetrics()).toEqual({+        clientComponentLoadStart: 100,+        clientComponentLoadEnd: 0,+        clientComponentLoadTimes: 0,+        clientComponentLoadCount: 0,+      })++      resolveChunk()+      await chunk+      expect(getClientComponentLoaderMetrics()).toEqual({+        clientComponentLoadStart: 100,+        clientComponentLoadEnd: 150,+        clientComponentLoadTimes: 50,+        clientComponentLoadCount: 0,+      })+    }))++  it('tracks rejected chunk loads without changing the returned promise', () =>+    runWithTrackedWorkStore(async () => {+      jest+        .spyOn(performance, 'now')+        .mockReturnValueOnce(100)+        .mockReturnValueOnce(150)++      const error = new Error('chunk failed')+      const chunk = Promise.reject(error)+      const loader = wrapClientComponentLoader(+        createComponentModule(+          () => undefined,+          () => chunk+        )+      )++      expect(loader.loadChunk('rejected')).toBe(chunk)+      await expect(chunk).rejects.toBe(error)+      expect(getClientComponentLoaderMetrics()).toEqual({+        clientComponentLoadStart: 100,+        clientComponentLoadEnd: 150,+        clientComponentLoadTimes: 50,+        clientComponentLoadCount: 0,+      })+    }))++  it('attributes a pending chunk to its render while another render runs', async () => {     jest       .spyOn(performance, 'now')       .mockReturnValueOnce(100)-      .mockReturnValueOnce(150)+      .mockReturnValueOnce(200)+      .mockReturnValueOnce(220)+      .mockReturnValueOnce(300)      let resolveChunk!: () => void     const chunk = new Promise<void>((resolve) => {@@ -141,50 +239,92 @@ describe('client component renderer logger', () => {       createComponentModule(         () => undefined,         () => chunk-      ),-      true+      )     )+    const firstWorkStore = createTrackedWorkStore('/first/page', '/first')+    const secondWorkStore = createTrackedWorkStore('/second/page', '/second')+    expect(+      workAsyncStorage.run(firstWorkStore, () => loader.loadChunk('first'))+    ).toBe(chunk) -    expect(loader.loadChunk('pending')).toBe(chunk)-    expect(getClientComponentLoaderMetrics()).toEqual({-      clientComponentLoadStart: 100,-      clientComponentLoadEnd: 0,-      clientComponentLoadTimes: 0,-      clientComponentLoadCount: 0,-    })-+    workAsyncStorage.run(secondWorkStore, () => loader.require('second'))     resolveChunk()     await chunk-    expect(getClientComponentLoaderMetrics()).toEqual({++    expect(+      workAsyncStorage.run(firstWorkStore, () =>+        getClientComponentLoaderMetrics()+      )+    ).toEqual({       clientComponentLoadStart: 100,-      clientComponentLoadEnd: 150,-      clientComponentLoadTimes: 50,+      clientComponentLoadEnd: 300,+      clientComponentLoadTimes: 200,       clientComponentLoadCount: 0,     })+    expect(+      workAsyncStorage.run(secondWorkStore, () =>+        getClientComponentLoaderMetrics()+      )+    ).toEqual({+      clientComponentLoadStart: 200,+      clientComponentLoadEnd: 220,+      clientComponentLoadTimes: 20,+      clientComponentLoadCount: 1,+    })   }) -  it('tracks rejected chunk loads without changing the returned promise', async () => {-    jest-      .spyOn(performance, 'now')-      .mockReturnValueOnce(100)-      .mockReturnValueOnce(150)+  it('finishes once and ignores loads started afterward', async () => {+    const report = jest.fn()+    const tracker = new ClientComponentLoadTracker(report)+    tracker.beginRequire(100)+    tracker.finishRequire(100, 120)+    tracker.finish()+    tracker.finish() -    const error = new Error('chunk failed')-    const chunk = Promise.reject(error)+    const workStore = createTrackedWorkStore()+    workStore.clientComponentLoadTracker = tracker     const loader = wrapClientComponentLoader(       createComponentModule(         () => undefined,-        () => chunk-      ),-      true+        async () => undefined+      )     )+    workAsyncStorage.run(workStore, () => loader.require('after-finish'))+    await Promise.resolve() -    expect(loader.loadChunk('rejected')).toBe(chunk)-    await expect(chunk).rejects.toBe(error)-    expect(getClientComponentLoaderMetrics()).toEqual({+    expect(report).toHaveBeenCalledTimes(1)+    expect(report).toHaveBeenCalledWith({       clientComponentLoadStart: 100,-      clientComponentLoadEnd: 150,-      clientComponentLoadTimes: 50,+      clientComponentLoadEnd: 120,+      clientComponentLoadTimes: 20,+      clientComponentLoadCount: 1,+    })+  })++  it('reports once after every pending chunk settles', async () => {+    let resolveReport!: () => void+    const reported = new Promise<void>((resolve) => {+      resolveReport = resolve+    })+    const report = jest.fn(() => resolveReport())+    const tracker = new ClientComponentLoadTracker(report)+    tracker.beginChunk(100)+    tracker.beginChunk(110)+    tracker.finish()+    await Promise.resolve()+    expect(report).not.toHaveBeenCalled()++    tracker.finishChunk(110, 130)+    await Promise.resolve()+    expect(report).not.toHaveBeenCalled()++    tracker.finishChunk(100, 170)+    await reported+    expect(report).toHaveBeenCalledTimes(1)+    expect(report).toHaveBeenCalledWith({+      clientComponentLoadStart: 100,+      clientComponentLoadEnd: 170,+      clientComponentLoadTimes: 90,       clientComponentLoadCount: 0,     })   })
packages/next/src/server/client-component-renderer-logger.ts133 + / 44 −
@@ -1,53 +1,149 @@ import type { AppPageModule } from './route-modules/app-page/module'+import { workAsyncStorage } from './app-render/work-async-storage.external' -// Combined load times for loading client components-let clientComponentLoadStart = 0-let clientComponentLoadEnd = 0-let clientComponentLoadTimes = 0-let clientComponentLoadCount = 0+export type ClientComponentLoaderMetrics = {+  clientComponentLoadStart: number+  clientComponentLoadEnd: number+  clientComponentLoadTimes: number+  clientComponentLoadCount: number+}++/** Metrics owned by one render, including chunks that settle after rendering. */+export class ClientComponentLoadTracker {+  private clientComponentLoadStart = 0+  private clientComponentLoadEnd = 0+  private clientComponentLoadTimes = 0+  private clientComponentLoadCount = 0+  private hasLoads = false+  private pending = 0+  private sealed = false+  private resolveCompletion:+    | ((metrics: ClientComponentLoaderMetrics | undefined) => void)+    | undefined = undefined++  constructor(+    private readonly report: (+      metrics: ClientComponentLoaderMetrics | undefined+    ) => void = () => {}+  ) {}++  isSealed(): boolean {+    return this.sealed+  }++  beginRequire(startTime: number): void {+    this.recordStart(startTime)+    this.clientComponentLoadCount+++    this.pending+++  }++  finishRequire(startTime: number, endTime: number): void {+    this.recordSettlement(startTime, endTime)+  }++  beginChunk(startTime: number): void {+    this.recordStart(startTime)+    this.pending+++  }++  finishChunk(startTime: number, endTime: number): void {+    this.recordSettlement(startTime, endTime)+  }++  snapshot(): ClientComponentLoaderMetrics | undefined {+    if (!this.hasLoads) {+      return undefined+    }++    return {+      clientComponentLoadStart: this.clientComponentLoadStart,+      clientComponentLoadEnd: this.clientComponentLoadEnd,+      clientComponentLoadTimes: this.clientComponentLoadTimes,+      clientComponentLoadCount: this.clientComponentLoadCount,+    }+  }++  /** Stop accepting new loads and report after any in-flight loads settle. */+  finish(): void {+    if (this.sealed) return+    this.sealed = true+    let completion: Promise<ClientComponentLoaderMetrics | undefined>+    if (this.pending === 0) {+      completion = Promise.resolve(this.snapshot())+    } else {+      completion = new Promise((resolve) => {+        this.resolveCompletion = resolve+      })+    }++    // Telemetry is best-effort and must not keep the response open or mask a+    // render error, including when reporting fails.+    void completion.then(this.report).catch((error) => {+      console.error('Failed to report client component loading metrics:', error)+    })+  }++  private recordStart(startTime: number): void {+    if (!this.hasLoads) {+      this.hasLoads = true+      this.clientComponentLoadStart = startTime+    }+  }++  private recordSettlement(startTime: number, endTime: number): void {+    this.clientComponentLoadEnd = endTime+    this.clientComponentLoadTimes += endTime - startTime+    this.pending--++    if (this.sealed && this.pending === 0 && this.resolveCompletion) {+      const resolve = this.resolveCompletion+      this.resolveCompletion = undefined+      resolve(this.snapshot())+    }+  }+}  export function wrapClientComponentLoader(-  ComponentMod: AppPageModule,-  isTracingEnabled: boolean+  ComponentMod: AppPageModule ): AppPageModule['__next_app__'] {-  if (-    !('performance' in globalThis) ||-    (!process.env.NEXT_OTEL_PERFORMANCE_PREFIX && !isTracingEnabled)-  ) {+  if (!('performance' in globalThis)) {     return ComponentMod.__next_app__   }    return {     require: (...args) => {-      const startTime = performance.now()--      if (clientComponentLoadStart === 0) {-        clientComponentLoadStart = startTime+      const tracker = workAsyncStorage.getStore()?.clientComponentLoadTracker+      if (tracker === undefined || tracker.isSealed()) {+        return ComponentMod.__next_app__.require(...args)       } +      const startTime = performance.now()+      tracker.beginRequire(startTime)       try {-        clientComponentLoadCount += 1         return ComponentMod.__next_app__.require(...args)       } finally {-        const endTime = performance.now()-        clientComponentLoadEnd = endTime-        clientComponentLoadTimes += endTime - startTime+        tracker.finishRequire(startTime, performance.now())       }     },     loadChunk: (...args) => {-      const startTime = performance.now()+      const tracker = workAsyncStorage.getStore()?.clientComponentLoadTracker+      if (tracker === undefined || tracker.isSealed()) {+        return ComponentMod.__next_app__.loadChunk(...args)+      } -      if (clientComponentLoadStart === 0) {-        clientComponentLoadStart = startTime+      const startTime = performance.now()+      tracker.beginChunk(startTime)+      let result: ReturnType<AppPageModule['__next_app__']['loadChunk']>+      try {+        result = ComponentMod.__next_app__.loadChunk(...args)+      } catch (error) {+        tracker.finishChunk(startTime, performance.now())+        throw error       } -      const result = ComponentMod.__next_app__.loadChunk(...args)-      // Avoid wrapping `loadChunk`'s result in an extra promise in case something like React depends on its identity.-      // We only need to know when it's settled.+      // React can depend on the original promise identity.       const onSettled = () => {-        const endTime = performance.now()-        clientComponentLoadEnd = endTime-        clientComponentLoadTimes += endTime - startTime+        tracker.finishChunk(startTime, performance.now())       }       result.then(onSettled, onSettled)       return result@@ -57,22 +153,15 @@ export function wrapClientComponentLoader(  export function getClientComponentLoaderMetrics(   options: { reset?: boolean } = {}-) {-  const metrics =-    clientComponentLoadStart === 0-      ? undefined-      : {-          clientComponentLoadStart,-          clientComponentLoadEnd,-          clientComponentLoadTimes,-          clientComponentLoadCount,-        }--  if (options.reset) {-    clientComponentLoadStart = 0-    clientComponentLoadEnd = 0-    clientComponentLoadTimes = 0-    clientComponentLoadCount = 0+): ClientComponentLoaderMetrics | undefined {+  const workStore = workAsyncStorage.getStore()+  const tracker = workStore?.clientComponentLoadTracker+  const metrics = tracker?.snapshot()++  if (options.reset && workStore) {+    // Pending settlements still hold their original tracker. Detaching it only+    // affects subsequent reads and loads in this render.+    workStore.clientComponentLoadTracker = undefined   }    return metrics
packages/next/src/server/dev/use-cache-probe-worker.ts1 + / 0 −
@@ -217,6 +217,7 @@ function buildProbeWorkStore(msg: ProbeMessage): WorkStore {     refreshTagsByCacheKind: new Map(),     runInCleanSnapshot: createSnapshot(),     shouldTrackFetchMetrics: false,+    clientComponentLoadTracker: undefined,     reactServerErrorsByDigest: new Map(),     afterContext,     cacheComponentsEnabled: true,
packages/next/src/server/pipe-readable.test.ts104 + / 1 −
@@ -7,11 +7,12 @@ import type { AddressInfo } from 'node:net' import { EventEmitter } from 'node:events' import http from 'node:http' import zlib from 'node:zlib'-import { Readable } from 'node:stream'+import { PassThrough, Readable } from 'node:stream' import { promisify } from 'node:util' import setupCompression from 'next/dist/compiled/compression'  import { pipeNodeReadableToNodeResponse } from './pipe-readable'+import { ClientComponentLoadTracker } from './client-component-renderer-logger'  const gunzip = promisify(zlib.gunzip) @@ -173,3 +174,105 @@ describe('pipeNodeReadableToNodeResponse', () => {     expect(decompressed.every((byte) => byte === FILL)).toBe(true)   }) })++describe('client component loading measurement at first write', () => {+  let server: http.Server | undefined+  let measure: jest.SpyInstance+  let pipe: typeof import('./pipe-readable')+  const previousPrefix = process.env.NEXT_OTEL_PERFORMANCE_PREFIX++  beforeAll(() => {+    process.env.NEXT_OTEL_PERFORMANCE_PREFIX = 'test'+    jest.isolateModules(() => {+      pipe = require('./pipe-readable') as typeof import('./pipe-readable')+    })+  })++  afterAll(() => {+    if (previousPrefix === undefined) {+      delete process.env.NEXT_OTEL_PERFORMANCE_PREFIX+    } else {+      process.env.NEXT_OTEL_PERFORMANCE_PREFIX = previousPrefix+    }+  })++  beforeEach(() => {+    measure = jest.spyOn(performance, 'measure').mockImplementation(() => {+      return {} as PerformanceMeasure+    })+  })++  afterEach(async () => {+    measure.mockRestore()+    if (server) {+      server.closeAllConnections()+      await new Promise<void>((resolve) => server!.close(() => resolve()))+      server = undefined+    }+  })++  it.each(['web', 'node'] as const)(+    'measures the explicit %s tracker when the first chunk is written',+    async (streamKind) => {+      const tracker = new ClientComponentLoadTracker()+      tracker.beginRequire(100)+      tracker.finishRequire(100, 115)+      tracker.beginRequire(150)+      tracker.finishRequire(150, 160)+      tracker.beginChunk(200)+      const firstWrite = new Promise<void>((resolve) => {+        measure.mockImplementation(() => {+          resolve()+          return {} as PerformanceMeasure+        })+      })++      function loadAfterFirstWrite() {+        tracker.beginRequire(300)+        tracker.finishRequire(300, 330)+      }++      server = http.createServer((_req, res) => {+        if (streamKind === 'web') {+          const readable = new ReadableStream<Uint8Array>({+            start(controller) {+              setImmediate(() => {+                tracker.finishChunk(200, 250)+                controller.enqueue(new TextEncoder().encode('hello'))+                void firstWrite.then(() => {+                  loadAfterFirstWrite()+                  controller.enqueue(new TextEncoder().encode(' world'))+                  controller.close()+                })+              })+            },+          })+          void pipe+            .pipeToNodeResponse(readable, res, undefined, tracker)+            .catch((error) => res.destroy(error))+        } else {+          const readable = new PassThrough()+          void pipe+            .pipeNodeReadableToNodeResponse(readable, res, undefined, tracker)+            .catch((error) => res.destroy(error))+          setImmediate(() => {+            tracker.finishChunk(200, 250)+            readable.write('hello')+            void firstWrite.then(() => {+              loadAfterFirstWrite()+              readable.end(' world')+            })+          })+        }+      })++      const url = await listen(server)+      expect(await (await fetch(url)).text()).toBe('hello world')+      expect(measure).toHaveBeenCalledTimes(1)+      expect(measure).toHaveBeenCalledWith(+        'test:next-client-component-loading',+        { start: 100, end: 175 }+      )+    }+  )+})
packages/next/src/server/pipe-readable.ts14 + / 7 −
@@ -8,7 +8,7 @@ import { import { createPromiseWithResolvers } from '../shared/lib/promise-with-resolvers' import { getTracer } from './lib/trace/tracer' import { NextNodeServerSpan } from './lib/trace/constants'-import { getClientComponentLoaderMetrics } from './client-component-renderer-logger'+import type { ClientComponentLoadTracker } from './client-component-renderer-logger'  export function isAbortError(e: any): e is Error & { name: 'AbortError' } {   return e?.name === 'AbortError' || e?.name === ResponseAbortedName@@ -19,7 +19,8 @@ const HAS_CLIENT_COMPONENT_METRICS_ENABLED =  function createWriterFromResponse(   res: ServerResponse,-  waitUntilForEnd?: Promise<unknown>+  waitUntilForEnd?: Promise<unknown>,+  clientComponentLoadTracker?: ClientComponentLoadTracker ): WritableStream<Uint8Array> {   let started = false @@ -55,7 +56,7 @@ function createWriterFromResponse(         started = true          if (HAS_CLIENT_COMPONENT_METRICS_ENABLED) {-          const metrics = getClientComponentLoaderMetrics()+          const metrics = clientComponentLoadTracker?.snapshot()           if (metrics) {             performance.measure(               `${process.env.NEXT_OTEL_PERFORMANCE_PREFIX}:next-client-component-loading`,@@ -124,7 +125,8 @@ function createWriterFromResponse( export async function pipeToNodeResponse(   readable: ReadableStream<Uint8Array>,   res: ServerResponse,-  waitUntilForEnd?: Promise<unknown>+  waitUntilForEnd?: Promise<unknown>,+  clientComponentLoadTracker?: ClientComponentLoadTracker ) {   try {     // If the response has already errored, then just return now.@@ -135,7 +137,11 @@ export async function pipeToNodeResponse(     // client disconnects.     const controller = createAbortController(res) -    const writer = createWriterFromResponse(res, waitUntilForEnd)+    const writer = createWriterFromResponse(+      res,+      waitUntilForEnd,+      clientComponentLoadTracker+    )      await readable.pipeTo(writer, { signal: controller.signal })   } catch (err: any) {@@ -149,7 +155,8 @@ export async function pipeToNodeResponse( export async function pipeNodeReadableToNodeResponse(   readable: Readable,   res: ServerResponse,-  waitUntilForEnd?: Promise<unknown>+  waitUntilForEnd?: Promise<unknown>,+  clientComponentLoadTracker?: ClientComponentLoadTracker ) {   try {     const { errored, destroyed } = res@@ -201,7 +208,7 @@ export async function pipeNodeReadableToNodeResponse(           'performance' in globalThis &&           process.env.NEXT_OTEL_PERFORMANCE_PREFIX         ) {-          const metrics = getClientComponentLoaderMetrics()+          const metrics = clientComponentLoadTracker?.snapshot()           if (metrics) {             performance.measure(               `${process.env.NEXT_OTEL_PERFORMANCE_PREFIX}:next-client-component-loading`,
packages/next/src/server/render-result.ts15 + / 2 −
@@ -3,6 +3,7 @@ import type { Readable } from 'stream' import type { CacheControl } from './lib/cache-control' import type { FetchMetrics } from './base-http' import type { PrefetchHints } from '../shared/lib/app-router-types'+import type { ClientComponentLoadTracker } from './client-component-renderer-logger'  import {   chainStreams,@@ -31,6 +32,8 @@ type ContentTypeOption =   | typeof TEXT_PLAIN_CONTENT_TYPE_HEADER // For simplified errors  export type AppPageRenderResultMetadata = {+  /** Request-local metrics for the first response write. Never cache this. */+  clientComponentLoadTracker?: ClientComponentLoadTracker   flightData?: Buffer   cacheControl?: CacheControl   staticBailoutInfo?: {@@ -431,9 +434,19 @@ export default class RenderResult<       !Array.isArray(this.response) &&       isNodeReadable(this.response)     ) {-      await pipeNodeReadableToNodeResponse(this.response, res, this.waitUntil)+      await pipeNodeReadableToNodeResponse(+        this.response,+        res,+        this.waitUntil,+        this.metadata.clientComponentLoadTracker+      )       return     }-    await pipeToNodeResponse(this.readable, res, this.waitUntil)+    await pipeToNodeResponse(+      this.readable,+      res,+      this.waitUntil,+      this.metadata.clientComponentLoadTracker+    )   } }
test/e2e/opentelemetry/instrumentation/app/api/app/[param]/client-component-flush/route.tsadded18 + / 0 −
@@ -0,0 +1,18 @@+const forceFlushKey = Symbol.for('opentelemetry.test/forceFlush')++export const runtime = 'nodejs'++export async function POST() {+  const flush = (+    globalThis as typeof globalThis &+      Record<symbol, (() => Promise<void>) | undefined>+  )[forceFlushKey]+  if (!flush) {+    return new Response('OpenTelemetry test flush hook is unavailable', {+      status: 503,+    })+  }++  await flush()+  return new Response(null, { status: 204 })+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-action/action-only-client.tsxadded5 + / 0 −
@@ -0,0 +1,5 @@+'use client'++export default function ActionOnlyClient() {+  return <span>Action-only client component</span>+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-action/page.tsxadded39 + / 0 −
@@ -0,0 +1,39 @@+import { trace } from '@opentelemetry/api'+import { cookies } from 'next/headers'+import EarlyClient from '../client-component-loading/early-client'+import LateClient from '../client-component-loading/late-client'+import ActionOnlyClient from './action-only-client'++export default async function Page() {+  const marker =+    (await cookies()).get('client-component-action-marker')?.value ?? 'none'+  const capturedClient = ActionOnlyClient++  async function setMarker(formData: FormData) {+    'use server'+    if (!capturedClient) {+      throw new Error('Missing captured client component')+    }+    const value = formData.get('marker')+    if (typeof value !== 'string') {+      throw new Error('Missing action marker')+    }+    ;(await cookies()).set('client-component-action-marker', value)+    trace+      .getTracer('client-component-loading-test')+      .startSpan('test.serverActionCompleted')+      .end()+  }++  return (+    <>+      <EarlyClient />+      <LateClient />+      <p id="action-result">{marker}</p>+      <form action={setMarker}>+        <input type="hidden" name="marker" value="action-completed" />+        <button type="submit">Run action</button>+      </form>+    </>+  )+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-html-boundary/async-client.tsxadded7 + / 0 −
@@ -0,0 +1,7 @@+'use client'++await Promise.resolve()++export default function AsyncClient() {+  return <span id="unused-client">unused client component</span>+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-html-boundary/initially-closed-panel.tsxadded19 + / 0 −
@@ -0,0 +1,19 @@+'use client'++import { useState, type ReactNode } from 'react'++export default function InitiallyClosedPanel({+  children,+}: {+  children: ReactNode+}) {+  const [open, setOpen] = useState(false)+  return (+    <section id="closed-panel">+      <button type="button" onClick={() => setOpen(true)}>+        Open+      </button>+      {open ? children : 'closed'}+    </section>+  )+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-html-boundary/page.tsxadded28 + / 0 −
@@ -0,0 +1,28 @@+import { Suspense } from 'react'+import AsyncClient from './async-client'+import InitiallyClosedPanel from './initially-closed-panel'++async function SlowDetails({ id }: { id: string }) {+  const response = await fetch(+    `http://localhost:${process.env.TEST_CLIENT_COMPONENT_GATE_PORT}/?key=${id}`,+    { cache: 'no-store' }+  )+  if (!response.ok) throw new Error('Details gate failed')+  return <AsyncClient />+}++export default async function Page({+  searchParams,+}: {+  searchParams: Promise<{ id?: string }>+}) {+  const { id } = await searchParams+  if (!id) throw new Error('Missing details gate id')+  return (+    <InitiallyClosedPanel>+      <Suspense fallback={<span id="details-fallback">waiting</span>}>+        <SlowDetails id={id} />+      </Suspense>+    </InitiallyClosedPanel>+  )+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-loading/early-client.tsxadded5 + / 0 −
@@ -0,0 +1,5 @@+'use client'++export default function EarlyClient() {+  return <span id="early-client">early client component</span>+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-loading/extra-late-client.tsxadded5 + / 0 −
@@ -0,0 +1,5 @@+'use client'++export default function ExtraLateClient() {+  return <span id="extra-late-client">extra late client component</span>+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-loading/late-client.tsxadded5 + / 0 −
@@ -0,0 +1,5 @@+'use client'++export default function LateClient() {+  return <span id="late-client">late client component</span>+}
test/e2e/opentelemetry/instrumentation/app/app/[param]/client-component-loading/page.tsxadded45 + / 0 −
@@ -0,0 +1,45 @@+import { Suspense } from 'react'+import EarlyClient from './early-client'+import ExtraLateClient from './extra-late-client'+import LateClient from './late-client'++async function GatedContent({ id, extra }: { id: string; extra: boolean }) {+  const response = await fetch(+    `http://localhost:${process.env.TEST_CLIENT_COMPONENT_GATE_PORT}/?key=${id}`,+    { cache: 'no-store' }+  )+  if (!response.ok) {+    throw new Error(`Gate request failed: ${response.status}`)+  }++  return (+    <>+      <LateClient />+      {extra && <ExtraLateClient />}+    </>+  )+}++export default async function Page({+  searchParams,+}: {+  searchParams: Promise<{ [key: string]: string | string[] | undefined }>+}) {+  const { id, variant } = await searchParams+  if (typeof id !== 'string') {+    throw new Error('Missing client component gate id')+  }+  if (variant !== undefined && variant !== 'extra') {+    throw new Error('Invalid client component loading variant')+  }+  const extra = variant === 'extra'++  return (+    <>+      <EarlyClient />+      <Suspense fallback={<span id="waiting">waiting</span>}>+        <GatedContent id={id} extra={extra} />+      </Suspense>+    </>+  )+}
test/e2e/opentelemetry/instrumentation/instrumentation-test.ts26 + / 2 −
@@ -28,6 +28,7 @@ import { import { SavedSpan } from './constants'  const customKey = Symbol.for('opentelemetry.test/custom')+const forceFlushKey = Symbol.for('opentelemetry.test/forceFlush')  const serializeSpan = (span: ReadableSpan): SavedSpan => ({   runtime: process.env.NEXT_RUNTIME,@@ -46,12 +47,26 @@ const serializeSpan = (span: ReadableSpan): SavedSpan => ({ })  class TestExporter implements SpanExporter {+  private pendingExports = new Set<Promise<void>>()+   constructor(private port: number) {} -  async export(+  export(     spans: ReadableSpan[],     resultCallback: (result: ExportResult) => void-  ) {+  ): void {+    const pending = this.exportSpans(spans, resultCallback)+    this.pendingExports.add(pending)+    void pending.then(+      () => this.pendingExports.delete(pending),+      () => this.pendingExports.delete(pending)+    )+  }++  private async exportSpans(+    spans: ReadableSpan[],+    resultCallback: (result: ExportResult) => void+  ): Promise<void> {     try {       const response = await fetch(`http://localhost:${this.port}`, {         method: 'POST',@@ -82,6 +97,12 @@ class TestExporter implements SpanExporter {   shutdown(): Promise<void> {     return Promise.resolve()   }++  async forceFlush(): Promise<void> {+    // SimpleSpanProcessor does not await ordinary exports in forceFlush, so+    // drain this test exporter's pending HTTP requests explicitly.+    await Promise.all(this.pendingExports)+  } }  export const register = () => {@@ -107,6 +128,9 @@ export const register = () => {       propagators: [new CustomPropagator(), new W3CTraceContextPropagator()],     }),   })+  ;(globalThis as typeof globalThis & Record<symbol, () => Promise<void>>)[+    forceFlushKey+  ] = () => provider.forceFlush() }  class CustomPropagator implements TextMapPropagator {
test/e2e/opentelemetry/instrumentation/opentelemetry.test.ts376 + / 50 −
@@ -1,5 +1,7 @@ import { FileRef, isNextDev, isNextStart, nextTestSetup } from 'e2e-utils' import { retry } from 'next-test-utils'+import { createTestDataServer } from 'test-data-service/writer'+import { createTestLog } from 'test-log' import { NEXT_RSC_UNION_QUERY } from 'next/dist/client/components/app-router-headers' import path from 'path' @@ -15,6 +17,7 @@ const COLLECTOR_PORT = 9001 const ROUTE_PREPARATION_COLLECTOR_PORT = 9002 const INSTRUMENTATION_STARTUP_COLLECTOR_PORT = 9003 const APP_ROUTE_MODULE_LOADING_COLLECTOR_PORT = 9004+const CLIENT_COMPONENT_GATE_PORT = 9005  type NextInstance = ReturnType<typeof nextTestSetup>['next'] @@ -54,6 +57,7 @@ function setup({ useDirectEntrypointHandler, useNodeMiddleware }) {       ? {           env: {             TEST_OTEL_COLLECTOR_PORT: String(COLLECTOR_PORT),+            TEST_CLIENT_COMPONENT_GATE_PORT: String(CLIENT_COMPONENT_GATE_PORT),             NEXT_TELEMETRY_DISABLED: '1',           },         }@@ -147,6 +151,329 @@ describe.each(     expect(response.headers.get('connection')).toBe('close')   }) +  // The custom entrypoint server has an explicit route table and does not+  // include this streamed page.+  if (!useDirectEntrypointHandler) {+    describe('client component loading across streamed renders', () => {+      const pendingGates = new Map<string, () => void>()+      const gateServer = createTestDataServer((id, response) => {+        pendingGates.set(id, () => response.resolve())+        gateArrivals.log(id)+      })+      let gateArrivals = createTestLog()+      let traceNumber = 0++      function newTraceId() {+        return (++traceNumber).toString(16).padStart(32, '0')+      }++      function traceparent(traceId: string) {+        return `00-${traceId}-${'1'.repeat(16)}-01`+      }++      beforeAll(() => gateServer.listen(CLIENT_COMPONENT_GATE_PORT))+      beforeEach(() => {+        gateArrivals = createTestLog()+      })+      afterEach(() => {+        for (const release of pendingGates.values()) release()+        pendingGates.clear()+      })+      afterAll(() => gateServer.close())++      function releaseGate(id: string) {+        const gate = pendingGates.get(id)+        expect(gate).toBeDefined()+        pendingGates.delete(id)+        gate!()+      }++      async function openPage({+        id,+        traceId,+        extra = false,+      }: {+        id: string+        traceId: string+        extra?: boolean+      }) {+        const responsePromise = next.fetch(+          `/app/test/client-component-loading?id=${id}${extra ? '&variant=extra' : ''}`,+          { headers: { traceparent: traceparent(traceId) } }+        )+        await gateArrivals.waitFor([id])+        const response = await responsePromise+        expect(response.status).toBe(200)+        return response+      }++      async function finishPage(response: Response, extra = false) {+        const html = await response.text()+        expect(html).toContain('<span id="early-client">')+        expect(html).toContain('<span id="late-client">')+        if (extra) expect(html).toContain('<span id="extra-late-client">')+      }++      function loadingSpans(traceId: string): SavedSpan[] {+        return getCollector()+          .getSpans()+          .filter(+            (span) =>+              span.traceId === traceId &&+              span.attributes?.['next.span_type'] ===+                'NextNodeServer.clientComponentLoading'+          )+      }++      async function expectNoLoadingSpanWhileBlocked(traceId: string) {+        // Flush in-flight exports before making a negative assertion.+        const response = await next.fetch(+          '/api/app/test/client-component-flush',+          { method: 'POST' }+        )+        expect(response.status).toBe(204)+        expect(loadingSpans(traceId)).toEqual([])+      }++      async function loadCount(traceId: string): Promise<number> {+        return retry(() => {+          const spans = loadingSpans(traceId)+          expect(spans).toHaveLength(1)+          const requestSpans = getCollector()+            .getSpans()+            .filter(+              (span) =>+                span.traceId === traceId &&+                span.attributes?.['next.span_type'] ===+                  'BaseServer.handleRequest'+            )+          expect(requestSpans).toHaveLength(1)+          expect(spans[0].parentId).toBe(requestSpans[0].id)+          const count = spans[0].attributes?.[+            'next.clientComponentLoadCount'+          ] as number+          expect(count).toBeGreaterThan(0)+          return count+        })+      }++      async function renderBaseline(extra: boolean): Promise<number> {+        const traceId = newTraceId()+        const id = `baseline-${traceId}`+        const response = await openPage({ id, traceId, extra })+        releaseGate(id)+        await finishPage(response, extra)+        return loadCount(traceId)+      }++      it.each(['a', 'b'] as const)(+        'keeps overlapping render metrics when %s finishes first',+        async (finishFirst) => {+          // Warm both module sets before measuring the sequential baselines.+          await renderBaseline(false)+          await renderBaseline(true)+          const normalCount = await renderBaseline(false)+          const extraCount = await renderBaseline(true)+          expect(extraCount).toBeGreaterThan(normalCount)++          const traceA = newTraceId()+          const traceB = newTraceId()+          const responseA = await openPage({ id: 'a', traceId: traceA })+          const responseB = await openPage({+            id: 'b',+            traceId: traceB,+            extra: true,+          })+          await expectNoLoadingSpanWhileBlocked(traceA)+          await expectNoLoadingSpanWhileBlocked(traceB)++          const requests = {+            a: {+              id: 'a',+              response: responseA,+              traceId: traceA,+              count: normalCount,+              extra: false,+            },+            b: {+              id: 'b',+              response: responseB,+              traceId: traceB,+              count: extraCount,+              extra: true,+            },+          }+          const first = requests[finishFirst]+          const second = requests[finishFirst === 'a' ? 'b' : 'a']++          releaseGate(first.id)+          await finishPage(first.response, first.extra)+          expect(await loadCount(first.traceId)).toBe(first.count)++          expect(pendingGates.has(second.id)).toBe(true)+          await expectNoLoadingSpanWhileBlocked(second.traceId)+          releaseGate(second.id)+          await finishPage(second.response, second.extra)+          expect(await loadCount(second.traceId)).toBe(second.count)+        }+      )++      const actionPath = '/app/test/client-component-action'++      async function getActionPage(traceId: string) {+        const $ = await next.render$(actionPath, undefined, {+          headers: { traceparent: traceparent(traceId) },+        })+        expect($('#action-result').text()).toBe('none')+        return { $, count: await loadCount(traceId) }+      }++      it('reports HTML loading after a form POST and leaves the next GET unchanged', async () => {+        await getActionPage(newTraceId())+        const { $, count: baseline } = await getActionPage(newTraceId())+        const form = $('form').first()+        expect(form.length).toBe(1)+        const formData = new FormData()+        form.find('input[type="hidden"]').each((_, input) => {+          const name = $(input).attr('name')+          if (name) formData.append(name, $(input).attr('value') ?? '')+        })+        formData.set('marker', 'action-completed')++        const actionTrace = newTraceId()+        const response = await next.fetch(actionPath, {+          method: 'POST',+          headers: {+            traceparent: traceparent(actionTrace),+            origin: new URL(next.url).origin,+          },+          body: formData,+        })+        expect(response.status).toBe(200)+        expect(await response.text()).toContain(+          '<p id="action-result">action-completed</p>'+        )+        await retry(() => {+          expect(+            getCollector()+              .getSpans()+              .filter(+                (span) =>+                  span.traceId === actionTrace &&+                  span.name === 'test.serverActionCompleted'+              )+          ).toHaveLength(1)+        })+        await loadCount(actionTrace)++        const { count: nextGetCount } = await getActionPage(newTraceId())+        expect(nextGetCount).toBe(baseline)+      })++      it('does not report HTML loading metrics for an enhanced Server Action', async () => {+        const browser = await next.browser(actionPath)+        expect(await browser.elementByCss('#action-result').text()).toBe('none')++        // Flush the initial document's metrics before measuring the action.+        const flush = async () => {+          const response = await next.fetch(+            '/api/app/test/client-component-flush',+            { method: 'POST' }+          )+          expect(response.status).toBe(204)+        }+        await flush()+        getCollector().reset()++        await browser.elementByCss('button[type="submit"]').click()+        await retry(async () => {+          expect(await browser.elementByCss('#action-result').text()).toBe(+            'action-completed'+          )+        })+        await flush()+        const actionRequest = await retry(() => {+          const requests = getCollector()+            .getSpans()+            .filter(+              (span) =>+                span.attributes?.['http.method'] === 'POST' &&+                span.attributes?.['http.target'] === actionPath &&+                span.attributes?.['next.span_type'] ===+                  'BaseServer.handleRequest'+            )+          expect(requests).toHaveLength(1)+          return requests[0]+        })+        await retry(() => {+          expect(+            getCollector()+              .getSpans()+              .filter(+                (span) =>+                  span.traceId === actionRequest.traceId &&+                  span.name === 'test.serverActionCompleted'+              )+          ).toHaveLength(1)+        })+        expect(loadingSpans(actionRequest.traceId)).toEqual([])+      })++      it('reports HTML loading before unused delayed Flight content finishes', async () => {+        const traceId = newTraceId()+        const id = `html-boundary-${traceId}`+        const responsePromise = next.fetch(+          `/app/test/client-component-html-boundary?id=${id}`,+          { headers: { traceparent: traceparent(traceId) } }+        )+        await gateArrivals.waitFor([id])+        const response = await responsePromise+        expect(response.status).toBe(200)++        const flush = async () => {+          const result = await next.fetch(+            '/api/app/test/client-component-flush',+            { method: 'POST' }+          )+          expect(result.status).toBe(204)+        }+        await flush()++        let html: string+        let earlySpan: SavedSpan | undefined+        try {+          // The closed panel lets HTML finish even though its unused Flight+          // child remains behind the gate.+          await retry(() => {+            const renderSpans = getCollector()+              .getSpans()+              .filter(+                (span) =>+                  span.traceId === traceId &&+                  span.attributes?.['next.span_type'] ===+                    'AppRender.getBodyResult'+              )+            expect(renderSpans).toHaveLength(1)+            const spans = loadingSpans(traceId)+            expect(spans).toHaveLength(1)+            earlySpan = spans[0]+          })+          expect(pendingGates.has(id)).toBe(true)+        } finally {+          releaseGate(id)+          html = await response.text()+        }++        expect(html).toContain('id="closed-panel"')+        expect(html).toContain('closed')+        expect(html).not.toContain('id="unused-client"')+        expect(earlySpan).toBeDefined()+        await flush()+        expect(loadingSpans(traceId)).toEqual([earlySpan])+      })+    })+  }+   // Edge runtime is currently not implemented in custom-entrypoint-server.ts   const itEdge = useDirectEntrypointHandler ? it.skip : it @@ -197,6 +524,15 @@ describe.each(                 traceId: env.span.traceId,                 parentId: env.span.rootParentId,                 spans: [+                  {+                    attributes: {+                      'next.clientComponentLoadCount': isNextDev ? 8 : 7,+                      'next.span_type': 'NextNodeServer.clientComponentLoading',+                    },+                    kind: 0,+                    name: 'NextNodeServer.clientComponentLoading',+                    status: { code: 0 },+                  },                   {                     name: 'render route (app) /app/[param]/rsc-fetch',                     attributes: {@@ -277,18 +613,6 @@ describe.each(                         kind: 0,                         status: { code: 0 },                       },-                      {-                        attributes: {-                          'next.clientComponentLoadCount': isNextDev ? 8 : 7,-                          'next.span_type':-                            'NextNodeServer.clientComponentLoading',-                        },-                        kind: 0,-                        name: 'NextNodeServer.clientComponentLoading',-                        status: {-                          code: 0,-                        },-                      },                       {                         name: 'start response',                         attributes: {@@ -894,6 +1218,15 @@ describe.each(                 traceId: env.span.traceId,                 parentId: env.span.rootParentId,                 spans: [+                  {+                    attributes: {+                      'next.clientComponentLoadCount': isNextDev ? 12 : 10,+                      'next.span_type': 'NextNodeServer.clientComponentLoading',+                    },+                    kind: 0,+                    name: 'NextNodeServer.clientComponentLoading',+                    status: { code: 0 },+                  },                   {                     name: 'render route (app) /app/[param]/rsc-fetch/error',                     attributes: {@@ -961,18 +1294,6 @@ describe.each(                         kind: 0,                         status: { code: 0 },                       },-                      {-                        attributes: {-                          'next.clientComponentLoadCount': isNextDev ? 12 : 10,-                          'next.span_type':-                            'NextNodeServer.clientComponentLoading',-                        },-                        kind: 0,-                        name: 'NextNodeServer.clientComponentLoading',-                        status: {-                          code: 0,-                        },-                      },                       {                         name: 'start response',                         attributes: {@@ -1027,6 +1348,15 @@ describe.each(                 traceId: env.span.traceId,                 parentId: env.span.rootParentId,                 spans: [+                  {+                    attributes: {+                      'next.clientComponentLoadCount': isNextDev ? 9 : 8,+                      'next.span_type': 'NextNodeServer.clientComponentLoading',+                    },+                    kind: 0,+                    name: 'NextNodeServer.clientComponentLoading',+                    status: { code: 0 },+                  },                   {                     name: 'render route (app) /app/[param]/loading/error',                     attributes: {@@ -1089,18 +1419,6 @@ describe.each(                         kind: 0,                         status: { code: 0 },                       },-                      {-                        attributes: {-                          'next.clientComponentLoadCount': isNextDev ? 9 : 8,-                          'next.span_type':-                            'NextNodeServer.clientComponentLoading',-                        },-                        kind: 0,-                        name: 'NextNodeServer.clientComponentLoading',-                        status: {-                          code: 0,-                        },-                      },                       {                         name: 'start response',                         attributes: {@@ -1485,6 +1803,16 @@ describe.each(                   },                   ...(isNextDev                     ? [+                        {+                          name: 'NextNodeServer.clientComponentLoading',+                          attributes: {+                            'next.clientComponentLoadCount': expect.any(Number),+                            'next.span_type':+                              'NextNodeServer.clientComponentLoading',+                          },+                          kind: 0,+                          status: { code: 0 },+                        },                         {                           name: 'render route (app) /_not-found',                           attributes: {@@ -2176,6 +2504,9 @@ describe('opentelemetry with disabled fetch tracing', () => {               traceId: '[trace-id]',               parentId: undefined,               spans: [+                {+                  name: 'NextNodeServer.clientComponentLoading',+                },                 {                   name: 'render route (app) /app/[param]/rsc-fetch',                   spans: [@@ -2196,9 +2527,6 @@ describe('opentelemetry with disabled fetch tracing', () => {                     {                       name: 'generateMetadata /app/[param]/rsc-fetch/page',                     },-                    {-                      name: 'NextNodeServer.clientComponentLoading',-                    },                     {                       name: 'start response',                     },@@ -2266,6 +2594,15 @@ describe('opentelemetry with custom server', () => {             kind: 1,             status: { code: 0 },             spans: [+              {+                attributes: {+                  'next.clientComponentLoadCount': isNextDev ? 8 : 7,+                  'next.span_type': 'NextNodeServer.clientComponentLoading',+                },+                kind: 0,+                name: 'NextNodeServer.clientComponentLoading',+                status: { code: 0 },+              },               {                 name: 'render route (app) /app/[param]/rsc-fetch',                 attributes: {@@ -2342,17 +2679,6 @@ describe('opentelemetry with custom server', () => {                     kind: 0,                     status: { code: 0 },                   },-                  {-                    attributes: {-                      'next.clientComponentLoadCount': isNextDev ? 8 : 7,-                      'next.span_type': 'NextNodeServer.clientComponentLoading',-                    },-                    kind: 0,-                    name: 'NextNodeServer.clientComponentLoading',-                    status: {-                      code: 0,-                    },-                  },                   {                     name: 'start response',                     attributes: {