[.next/trace] Serialize trace info across workers to preserve .next/t…

…race with webpackBuildWorker (#57761)

This PR sets up the webpack build workers (webpackBuildWorker: true) to serialize debug trace information across the worker boundary so that it can appear in the final .next/trace file at the end of the build.

Currently, when webpackBuildWorker is turned on, all traces that appear under the webpack compilation are lost. After this PR, they will appear in the trace file just like when the workers are not enabled.

packages/next/src/build/webpack-build/impl.ts

@@ -21,7 +21,13 @@ import {
 } from '../build-context'
 import { createEntrypoints } from '../entries'
 import loadConfig from '../../server/config'
-import { trace } from '../../trace'
+import {
+  getTraceEvents,
+  initializeTraceState,
+  trace,
+  type TraceEvent,
+  type TraceState,
+} from '../../trace'
 import { WEBPACK_LAYERS } from '../../lib/constants'
 import { TraceEntryPointsPlugin } from '../webpack/plugins/next-trace-entrypoints-plugin'
 import type { BuildTraceContext } from '../webpack/plugins/next-trace-entrypoints-plugin'
@@ -331,10 +337,18 @@ export async function webpackBuildImpl(
 export async function workerMain(workerData: {
   compilerName: keyof typeof COMPILER_INDEXES
   buildContext: typeof NextBuildContext
-}) {
+  traceState: TraceState
+}): Promise<
+  Awaited<ReturnType<typeof webpackBuildImpl>> & {
+    debugTraceEvents: TraceEvent[]
+  }
+> {
   // setup new build context from the serialized data passed from the parent
   Object.assign(NextBuildContext, workerData.buildContext)
 
+  // Initialize tracer state from the parent
+  initializeTraceState(workerData.traceState)
+
   // Resume plugin state
   resumePluginState(NextBuildContext.pluginState)
 
@@ -343,7 +357,9 @@ export async function workerMain(workerData: {
     PHASE_PRODUCTION_BUILD,
     NextBuildContext.dir!
   )
-  NextBuildContext.nextBuildSpan = trace('next-build')
+  NextBuildContext.nextBuildSpan = trace(
+    `worker-main-${workerData.compilerName}`
+  )
 
   const result = await webpackBuildImpl(workerData.compilerName)
   const { entriesTrace, chunksTrace } = result.buildTraceContext ?? {}
@@ -361,5 +377,6 @@ export async function workerMain(workerData: {
     const entryNameFilesMap = chunksTrace.entryNameFilesMap
     result.buildTraceContext!.chunksTrace!.entryNameFilesMap = entryNameFilesMap
   }
-  return result
+  NextBuildContext.nextBuildSpan.stop()
+  return { ...result, debugTraceEvents: getTraceEvents() }
 }

packages/next/src/build/webpack-build/index.ts

@@ -6,6 +6,7 @@ import { Worker } from 'next/dist/compiled/jest-worker'
 import origDebug from 'next/dist/compiled/debug'
 import type { ChildProcess } from 'child_process'
 import path from 'path'
+import { exportTraceState, recordTraceEvents } from '../../trace'
 
 const debug = origDebug('next:build:webpack-build')
 
@@ -83,7 +84,15 @@ async function webpackBuildWithWorker(
     const curResult = await worker.workerMain({
       buildContext: prunedBuildContext,
       compilerName,
+      traceState: {
+        ...exportTraceState(),
+        defaultParentSpanId: nextBuildSpan?.id,
+        shouldSaveTraceEvents: true,
+      },
     })
+    if (nextBuildSpan && curResult.debugTraceEvents) {
+      recordTraceEvents(curResult.debugTraceEvents)
+    }
     // destroy worker so it's not sticking around using memory
     await worker.end()
 

packages/next/src/trace/index.ts

@@ -1,6 +1,25 @@
-import { trace, flushAllTraces, Span, SpanStatus } from './trace'
-import type { SpanId } from './shared'
+import {
+  trace,
+  exportTraceState,
+  flushAllTraces,
+  getTraceEvents,
+  initializeTraceState,
+  recordTraceEvents,
+  Span,
+  SpanStatus,
+} from './trace'
 import { setGlobal } from './shared'
+import type { SpanId, TraceEvent, TraceState } from './types'
 
-export { trace, flushAllTraces, Span, setGlobal, SpanStatus }
-export type { SpanId }
+export {
+  trace,
+  exportTraceState,
+  flushAllTraces,
+  getTraceEvents,
+  initializeTraceState,
+  recordTraceEvents,
+  Span,
+  setGlobal,
+  SpanStatus,
+}
+export type { SpanId, TraceEvent, TraceState }

packages/next/src/trace/report/index.test.ts

@@ -0,0 +1,60 @@
+import { mkdtemp, readFile } from 'fs/promises'
+import { reporter } from '.'
+import { setGlobal } from '../shared'
+import { join } from 'path'
+import { tmpdir } from 'os'
+
+const TRACE_EVENT = {
+  name: 'test-span',
+  duration: 321,
+  timestamp: Date.now(),
+  id: 127,
+  startTime: Date.now(),
+}
+const WEBPACK_INVALIDATED_EVENT = {
+  name: 'webpack-invalidated',
+  duration: 100,
+  timestamp: Date.now(),
+  id: 112,
+  startTime: Date.now(),
+}
+
+describe('Trace Reporter', () => {
+  describe('JSON reporter', () => {
+    it('should write the trace events to JSON file', async () => {
+      const tmpDir = await mkdtemp(join(tmpdir(), 'json-reporter'))
+      setGlobal('distDir', tmpDir)
+      setGlobal('phase', 'anything')
+      reporter.report(TRACE_EVENT)
+      await reporter.flushAll()
+      const traceFilename = join(tmpDir, 'trace')
+      const traces = JSON.parse(await readFile(traceFilename, 'utf-8'))
+      expect(traces.length).toEqual(1)
+      expect(traces[0].name).toEqual('test-span')
+      expect(traces[0].id).toEqual(127)
+      expect(traces[0].duration).toEqual(321)
+      expect(traces[0].traceId).toBeDefined()
+    })
+  })
+
+  describe('Telemetry reporter', () => {
+    it('should record telemetry event', async () => {
+      const recordMock = jest.fn()
+      const telemetryMock = {
+        record: recordMock,
+      }
+      setGlobal('telemetry', telemetryMock)
+      // This should be ignored.
+      reporter.report(TRACE_EVENT)
+      expect(recordMock).toBeCalledTimes(0)
+      reporter.report(WEBPACK_INVALIDATED_EVENT)
+      expect(recordMock).toBeCalledTimes(1)
+      expect(recordMock).toHaveBeenCalledWith({
+        eventName: 'WEBPACK_INVALIDATED',
+        payload: {
+          durationInMicroseconds: 100,
+        },
+      })
+    })
+  })
+})

packages/next/src/trace/report/index.ts

@@ -1,19 +1,7 @@
-import type { SpanId } from '../shared'
+import type { TraceEvent } from '../types'
 import reportToTelemetry from './to-telemetry'
 import reportToJson from './to-json'
-
-type Reporter = {
-  flushAll: () => Promise<void> | void
-  report: (
-    spanName: string,
-    duration: number,
-    timestamp: number,
-    id: SpanId,
-    parentId?: SpanId,
-    attrs?: Object,
-    startTime?: number
-  ) => void
-}
+import type { Reporter } from './types'
 
 class MultiReporter implements Reporter {
   private reporters: Reporter[] = []
@@ -26,26 +14,8 @@ class MultiReporter implements Reporter {
     await Promise.all(this.reporters.map((reporter) => reporter.flushAll()))
   }
 
-  report(
-    spanName: string,
-    duration: number,
-    timestamp: number,
-    id: SpanId,
-    parentId?: SpanId,
-    attrs?: Object,
-    startTime?: number
-  ) {
-    this.reporters.forEach((reporter) =>
-      reporter.report(
-        spanName,
-        duration,
-        timestamp,
-        id,
-        parentId,
-        attrs,
-        startTime
-      )
-    )
+  report(event: TraceEvent) {
+    this.reporters.forEach((reporter) => reporter.report(event))
   }
 }
 

packages/next/src/trace/report/to-json.ts

@@ -3,23 +3,16 @@ import { traceGlobals } from '../shared'
 import fs from 'fs'
 import path from 'path'
 import { PHASE_DEVELOPMENT_SERVER } from '../../shared/lib/constants'
+import type { TraceEvent } from '../types'
 
 const localEndpoint = {
   serviceName: 'nextjs',
   ipv4: '127.0.0.1',
   port: 9411,
 }
 
-type Event = {
-  traceId: string
-  parentId?: number
-  name: string
-  id: number
-  timestamp: number
-  duration: number
+type Event = TraceEvent & {
   localEndpoint?: typeof localEndpoint
-  tags?: Object
-  startTime?: number
 }
 
 // Batch events as zipkin allows for multiple events to be sent in one go
@@ -116,15 +109,7 @@ class RotatingWriteStream {
   }
 }
 
-const reportToLocalHost = (
-  name: string,
-  duration: number,
-  timestamp: number,
-  id: number,
-  parentId?: number,
-  attrs?: Object,
-  startTime?: number
-) => {
+const reportToLocalHost = (event: TraceEvent) => {
   const distDir = traceGlobals.get('distDir')
   const phase = traceGlobals.get('phase')
   if (!distDir || !phase) {
@@ -136,7 +121,7 @@ const reportToLocalHost = (
   }
 
   if (!batch) {
-    batch = batcher(async (events) => {
+    batch = batcher(async (events: Event[]) => {
       if (!writeStream) {
         await fs.promises.mkdir(distDir, { recursive: true })
         const file = path.join(distDir, 'trace')
@@ -156,14 +141,8 @@ const reportToLocalHost = (
   }
 
   batch.report({
+    ...event,
     traceId,
-    parentId,
-    name,
-    id,
-    timestamp,
-    duration,
-    tags: attrs,
-    startTime,
   })
 }
 

packages/next/src/trace/report/to-telemetry.ts

@@ -1,14 +1,15 @@
 import type { Telemetry } from '../../telemetry/storage'
 import { traceGlobals } from '../shared'
+import type { TraceEvent } from '../types'
 
 const TRACE_EVENT_ACCESSLIST = new Map(
   Object.entries({
     'webpack-invalidated': 'WEBPACK_INVALIDATED',
   })
 )
 
-const reportToTelemetry = (spanName: string, duration: number) => {
-  const eventName = TRACE_EVENT_ACCESSLIST.get(spanName)
+const reportToTelemetry = ({ name, duration }: TraceEvent) => {
+  const eventName = TRACE_EVENT_ACCESSLIST.get(name)
   if (!eventName) {
     return
   }

packages/next/src/trace/report/types.ts

@@ -0,0 +1,6 @@
+import type { TraceEvent } from '../types'
+
+export type Reporter = {
+  flushAll: () => Promise<void> | void
+  report: (event: TraceEvent) => void
+}

packages/next/src/trace/shared.ts

@@ -1,5 +1,3 @@
-export type SpanId = number
-
 let _traceGlobals: Map<any, any> = (global as any)._traceGlobals
 
 if (!_traceGlobals) {