From 30e547a05448bac735adcb2d1912cf175b5610c9 Mon Sep 17 00:00:00 2001 From: Will Binns-Smith Date: Thu, 24 Oct 2024 17:27:28 -0700 Subject: [PATCH] Trace upload: only send traces for current session MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The `.next/trace` file contains trace events spanning multiple traces from different sessions. This changes our upload process to only send trace events for the current session that’s ending. Before this change, we would send a single set of metadata for many traces, but these older session traces could have been invoked with different parameters like `mode`, `isTurboSession`, etc. Because of this, we started including `isTurboSession` as a span attribute on spans, but this value was dependent on an environment variable that wasn’t always set. In this case, the top-level `next-dev` span never had the correct value. This makes it so the metadata, now always determined at upload time, always reflects the session sent, and never any others. Other bugs fixed: - Trace events within a single logical session had different trace ids because of worker threads. This aligns them. - Because we upload traces out-of-process, the Telemetry `sessionId` did not reflect the real session id of other analytics sent. This passes it along to the external process. Test Plan: In a test app, using `NEXT_TRACE_UPLOAD_DEBUG=1` and a running Otel server: - Start a non-turbopack dev session and end it. Verify trace events are sent with `isTurboSession: false` and note the trace id. - Start a turbopack dev session and end it. Verify trace events are sent with `isTurboSession: true` and note events are sent for this trace, and not the previous one. - Start a build and verify trace events are sent with `mode: build` and `isTurboSession: false` and that no older trace events are sent. --- packages/next/src/build/index.ts | 1 + packages/next/src/cli/next-dev.ts | 4 +++ packages/next/src/trace/report/to-json.ts | 8 +---- packages/next/src/trace/shared.ts | 7 ++++ packages/next/src/trace/trace-uploader.ts | 44 +++++++++++++---------- packages/next/src/trace/trace.ts | 4 --- packages/next/src/trace/upload-trace.ts | 10 ++++++ 7 files changed, 49 insertions(+), 29 deletions(-) diff --git a/packages/next/src/build/index.ts b/packages/next/src/build/index.ts index 355627ee4fe25..8dfb7e0b9e17a 100644 --- a/packages/next/src/build/index.ts +++ b/packages/next/src/build/index.ts @@ -3865,6 +3865,7 @@ export default async function build( mode: 'build', projectDir: dir, distDir: loadedConfig.distDir, + isTurboSession: turboNextBuild, sync: true, }) } diff --git a/packages/next/src/cli/next-dev.ts b/packages/next/src/cli/next-dev.ts index ee58538022cfe..d4ac9d067a32c 100644 --- a/packages/next/src/cli/next-dev.ts +++ b/packages/next/src/cli/next-dev.ts @@ -37,6 +37,7 @@ import os from 'os' import { once } from 'node:events' import { clearTimeout } from 'timers' import { flushAllTraces, trace } from '../trace' +import { traceId } from '../trace/shared' export type NextDevOptions = { turbo?: boolean @@ -137,6 +138,7 @@ const handleSessionStop = async (signal: NodeJS.Signals | number | null) => { mode: 'dev', projectDir: dir, distDir: config.distDir, + isTurboSession, }) } @@ -277,6 +279,7 @@ const nextDev = async ( ...defaultEnv, TURBOPACK: process.env.TURBOPACK, NEXT_PRIVATE_WORKER: '1', + NEXT_PRIVATE_TRACE_ID: traceId, NODE_EXTRA_CA_CERTS: startServerOptions.selfSignedCertificate ? startServerOptions.selfSignedCertificate.rootCA : defaultEnv.NODE_EXTRA_CA_CERTS, @@ -309,6 +312,7 @@ const nextDev = async ( mode: 'dev', projectDir: dir, distDir: config.distDir, + isTurboSession, sync: true, }) } diff --git a/packages/next/src/trace/report/to-json.ts b/packages/next/src/trace/report/to-json.ts index e97a09b9bdd0b..9e1baafb71343 100644 --- a/packages/next/src/trace/report/to-json.ts +++ b/packages/next/src/trace/report/to-json.ts @@ -1,5 +1,4 @@ -import { randomBytes } from 'crypto' -import { traceGlobals } from '../shared' +import { traceGlobals, traceId } from '../shared' import fs from 'fs' import path from 'path' import { PHASE_DEVELOPMENT_SERVER } from '../../shared/lib/constants' @@ -44,7 +43,6 @@ export function batcher(reportEvents: (evts: Event[]) => Promise) { } let writeStream: RotatingWriteStream -let traceId: string let batch: ReturnType | undefined const writeStreamOptions = { @@ -117,10 +115,6 @@ const reportToLocalHost = (event: TraceEvent) => { return } - if (!traceId) { - traceId = process.env.TRACE_ID || randomBytes(8).toString('hex') - } - if (!batch) { batch = batcher(async (events: Event[]) => { if (!writeStream) { diff --git a/packages/next/src/trace/shared.ts b/packages/next/src/trace/shared.ts index e1bf40422e5d9..eb490797299c9 100644 --- a/packages/next/src/trace/shared.ts +++ b/packages/next/src/trace/shared.ts @@ -1,3 +1,5 @@ +import { randomBytes } from 'node:crypto' + let _traceGlobals: Map = (global as any)._traceGlobals if (!_traceGlobals) { @@ -9,3 +11,8 @@ export const traceGlobals: Map = _traceGlobals export const setGlobal = (key: any, val: any) => { traceGlobals.set(key, val) } + +export const traceId = + process.env.TRACE_ID || + process.env.NEXT_PRIVATE_TRACE_ID || + randomBytes(8).toString('hex') diff --git a/packages/next/src/trace/trace-uploader.ts b/packages/next/src/trace/trace-uploader.ts index 0eb965154a06d..505f394b5b525 100644 --- a/packages/next/src/trace/trace-uploader.ts +++ b/packages/next/src/trace/trace-uploader.ts @@ -7,7 +7,6 @@ import os from 'os' import { createInterface } from 'readline' import { createReadStream } from 'fs' import path from 'path' -import { Telemetry } from '../telemetry/storage' const COMMON_ALLOWED_EVENTS = ['memory-usage'] @@ -66,7 +65,19 @@ const { const isDebugEnabled = !!NEXT_TRACE_UPLOAD_DEBUG || !!NEXT_TRACE_UPLOAD_FULL const shouldUploadFullTrace = !!NEXT_TRACE_UPLOAD_FULL -const [, , traceUploadUrl, mode, projectDir, distDir] = process.argv +const [ + , + , + traceUploadUrl, + mode, + projectDir, + distDir, + _isTurboSession, + traceId, + anonymousId, + sessionId, +] = process.argv +const isTurboSession = _isTurboSession === 'true' type TraceRequestBody = { metadata: TraceMetadata @@ -105,8 +116,6 @@ interface TraceMetadata { ) ).version - const telemetry = new Telemetry({ distDir }) - const projectPkgJsonPath = await findUp('package.json') assert(projectPkgJsonPath) @@ -129,11 +138,15 @@ interface TraceMetadata { crlfDelay: Infinity, }) - let isTurboSession = false - const traces = new Map() + const sessionTrace = [] for await (const line of readLineInterface) { const lineEvents: TraceEvent[] = JSON.parse(line) for (const event of lineEvents) { + if (event.traceId !== traceId) { + // Only consider events for the current session + continue + } + if ( // Always include root spans event.parentId === undefined || @@ -142,22 +155,14 @@ interface TraceMetadata { ? DEV_ALLOWED_EVENTS.has(event.name) : BUILD_ALLOWED_EVENTS.has(event.name)) ) { - let trace = traces.get(event.traceId) - if (trace === undefined) { - trace = [] - traces.set(event.traceId, trace) - } - if (typeof event.tags.isTurbopack === 'boolean') { - isTurboSession = event.tags.isTurbopack - } - trace.push(event) + sessionTrace.push(event) } } } const body: TraceRequestBody = { metadata: { - anonymousId: telemetry.anonymousId, + anonymousId, arch: os.arch(), commit, cpus: os.cpus().length, @@ -166,9 +171,12 @@ interface TraceMetadata { nextVersion, pkgName, platform: os.platform(), - sessionId: telemetry.sessionId, + sessionId, }, - traces: [...traces.values()], + // The trace file can contain events spanning multiple sessions. + // Only submit traces for the current session, as the metadata we send is + // intended for this session only. + traces: [sessionTrace], } if (isDebugEnabled) { diff --git a/packages/next/src/trace/trace.ts b/packages/next/src/trace/trace.ts index 918b5b393ad4a..52e08321386b0 100644 --- a/packages/next/src/trace/trace.ts +++ b/packages/next/src/trace/trace.ts @@ -52,10 +52,6 @@ export class Span { this.name = name this.parentId = parentId ?? defaultParentSpanId this.attrs = attrs ? { ...attrs } : {} - if (this.parentId === undefined) { - // Attach additional information to root spans - this.attrs.isTurbopack = Boolean(process.env.TURBOPACK) - } this.status = SpanStatus.Started this.id = getId() diff --git a/packages/next/src/trace/upload-trace.ts b/packages/next/src/trace/upload-trace.ts index d93474cefed94..0f6b2f5ce3c3a 100644 --- a/packages/next/src/trace/upload-trace.ts +++ b/packages/next/src/trace/upload-trace.ts @@ -1,17 +1,23 @@ +import { traceId } from './shared' +import { Telemetry } from '../telemetry/storage' + export default function uploadTrace({ traceUploadUrl, mode, projectDir, distDir, + isTurboSession, sync, }: { traceUploadUrl: string mode: 'dev' | 'build' projectDir: string distDir: string + isTurboSession: boolean sync?: boolean }) { const { NEXT_TRACE_UPLOAD_DEBUG } = process.env + const telemetry = new Telemetry({ distDir }) // Note: cross-spawn is not used here as it causes // a new command window to appear when we don't want it to @@ -33,6 +39,10 @@ export default function uploadTrace({ mode, projectDir, distDir, + String(isTurboSession), + traceId, + telemetry.anonymousId, + telemetry.sessionId, ], { detached: !NEXT_TRACE_UPLOAD_DEBUG,