From 600f16145bc4b844c2424cd39fab3324d9c0b671 Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Wed, 27 Jan 2021 15:38:12 -0800 Subject: [PATCH 01/13] Add granular Webpack tracing --- .../build/webpack/plugins/profiling-plugin.ts | 58 +++++++++++++++++++ 1 file changed, 58 insertions(+) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 908164d6aa5d6..1dcef199dde13 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -1,5 +1,6 @@ import { tracer } from '../../tracer' import { webpack, isWebpack5 } from 'next/dist/compiled/webpack/webpack' +import { Span } from '@opentelemetry/api' const pluginName = 'ProfilingPlugin' @@ -22,6 +23,11 @@ export class ProfilingPlugin { return } + this.traceTopLevelHooks(compiler) + this.traceCompilationHooks(compiler) + } + + traceTopLevelHooks(compiler: any) { compiler.hooks.compile.tap(pluginName, () => { const span = tracer.startSpan('webpack-compile', { attributes: { name: compiler.name }, @@ -31,6 +37,27 @@ export class ProfilingPlugin { compiler.hooks.done.tap(pluginName, () => { spans.get(compiler).end() }) + } + + traceHookPair(spanName: string, startHook: any, stopHook: any) { + const reportedSpanName = `webpack-compilation-${spanName}` + let span: Span | null = null + startHook.tap(pluginName, () => (span = tracer.startSpan(reportedSpanName))) + stopHook.tap(pluginName, () => span?.end()) + } + + traceLoopedHook(spanName: string, startHook: any, stopHook: any) { + const reportedSpanName = `webpack-compilation-${spanName}` + let span: Span | null = null + startHook.tap(pluginName, () => { + if (span) { + span = tracer.startSpan(reportedSpanName) + } + }) + stopHook.tap(pluginName, () => span?.end()) + } + + traceCompilationHooks(compiler: any) { compiler.hooks.compilation.tap(pluginName, (compilation: any) => { compilation.hooks.buildModule.tap(pluginName, (module: any) => { tracer.withSpan(spans.get(compiler), () => { @@ -51,6 +78,37 @@ export class ProfilingPlugin { compilation.hooks.succeedModule.tap(pluginName, (module: any) => { spans.get(module).end() }) + + this.traceHookPair( + 'chunk-graph', + compilation.hooks.beforeChunks, + compilation.hooks.afterChunks + ) + this.traceHookPair( + 'optimize', + compilation.hooks.optimize, + compilation.hooks.reviveModules + ) + this.traceLoopedHook( + 'optimize-modules', + compilation.hooks.optimizeModules, + compilation.hooks.afterOptimizeModules + ) + this.traceLoopedHook( + 'optimize-chunks', + compilation.hooks.optimizeChunks, + compilation.hooks.afterOptimizeChunks + ) + this.traceHookPair( + 'optimize-tree', + compilation.hooks.optimizeTree, + compilation.hooks.afterOptimizeTree + ) + this.traceHookPair( + 'hash', + compilation.hooks.beforeHash, + compilation.hooks.afterHash + ) }) } } From ae3e5426c357f6e19d405e0e30a1e2b8aad5eeb4 Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Wed, 27 Jan 2021 23:05:37 -0800 Subject: [PATCH 02/13] Add tracing for hot reload. --- .../build/webpack/plugins/profiling-plugin.ts | 19 ++++++++++++++++++- packages/next/server/hot-reloader.ts | 7 +++++++ 2 files changed, 25 insertions(+), 1 deletion(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 1dcef199dde13..0f048ef8cd4af 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -3,6 +3,7 @@ import { webpack, isWebpack5 } from 'next/dist/compiled/webpack/webpack' import { Span } from '@opentelemetry/api' const pluginName = 'ProfilingPlugin' +const forceTrace = false export const spans = new WeakMap() @@ -19,7 +20,7 @@ export class ProfilingPlugin { apply(compiler: any) { // Only enabled when instrumentation is loaded const currentSpan = tracer.getCurrentSpan() - if (!currentSpan || !currentSpan.isRecording()) { + if (!currentSpan || (!currentSpan.isRecording() && !forceTrace)) { return } @@ -37,6 +38,22 @@ export class ProfilingPlugin { compiler.hooks.done.tap(pluginName, () => { spans.get(compiler).end() }) + + compiler.hooks.watchRun.tap(pluginName, () => { + const span = tracer.startSpan('webpack-watchrun') + spans.set(compiler, span) + }) + compiler.hooks.watchClose.tap(pluginName, () => { + spans.get(compiler)?.end() + }) + + compiler.hooks.environment.tap(pluginName, () => { + const span = tracer.startSpan('webpack-prepare-env') + spans.set(compiler, span) + }) + compiler.hooks.afterEnvironment.tap(pluginName, () => { + spans.get(compiler)?.end() + }) } traceHookPair(spanName: string, startHook: any, stopHook: any) { diff --git a/packages/next/server/hot-reloader.ts b/packages/next/server/hot-reloader.ts index 177a420fa2310..2d6146fe2165a 100644 --- a/packages/next/server/hot-reloader.ts +++ b/packages/next/server/hot-reloader.ts @@ -33,6 +33,8 @@ import { stringify } from 'querystring' import { Rewrite } from '../lib/load-custom-routes' import { difference } from '../build/utils' import { NextConfig } from '../next-server/server/config' +import { tracer } from '../build/tracer' +import { Span } from '@opentelemetry/api' export async function renderScriptError( res: ServerResponse, @@ -139,6 +141,7 @@ function erroredPages(compilation: webpack.compilation.Compilation) { } export default class HotReloader { + private span: Span | null private dir: string private buildId: string private middlewares: any[] @@ -180,6 +183,7 @@ export default class HotReloader { this.stats = null this.serverStats = null this.serverPrevDocumentHash = null + this.span = null this.config = config this.previewProps = previewProps @@ -191,6 +195,7 @@ export default class HotReloader { res: ServerResponse, parsedUrl: UrlObject ): Promise<{ finished?: true }> { + this.span = tracer.startSpan('hot-reload') // Usually CORS support is not needed for the hot-reloader (this is dev only feature) // With when the app runs for multi-zones support behind a proxy, // the current page is trying to access this URL via assetPrefix. @@ -261,6 +266,8 @@ export default class HotReloader { }) } + this.span?.end?.() + return { finished } } From 7b0f8c068daa03cbd4e6b01e1beb968e7b82f0fb Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Wed, 27 Jan 2021 23:34:41 -0800 Subject: [PATCH 03/13] Create new spans with correct context. --- .../build/webpack/plugins/profiling-plugin.ts | 47 ++++++++++++++++--- 1 file changed, 41 insertions(+), 6 deletions(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 0f048ef8cd4af..bf0adcfec2211 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -56,25 +56,54 @@ export class ProfilingPlugin { }) } - traceHookPair(spanName: string, startHook: any, stopHook: any) { + traceHookPair( + spanName: string, + parentSpan: Span, + startHook: any, + stopHook: any + ) { const reportedSpanName = `webpack-compilation-${spanName}` let span: Span | null = null - startHook.tap(pluginName, () => (span = tracer.startSpan(reportedSpanName))) - stopHook.tap(pluginName, () => span?.end()) + startHook.tap(pluginName, () => { + tracer.withSpan(parentSpan, () => { + span = tracer.startSpan(reportedSpanName) + }) + }) + stopHook.tap(pluginName, () => span?.end?.()) } - traceLoopedHook(spanName: string, startHook: any, stopHook: any) { + traceLoopedHook( + spanName: string, + parentSpan: Span, + startHook: any, + stopHook: any + ) { const reportedSpanName = `webpack-compilation-${spanName}` let span: Span | null = null startHook.tap(pluginName, () => { if (span) { - span = tracer.startSpan(reportedSpanName) + tracer.withSpan(parentSpan, () => { + span = tracer.startSpan(reportedSpanName) + }) } }) - stopHook.tap(pluginName, () => span?.end()) + stopHook.tap(pluginName, () => span?.end?.()) } traceCompilationHooks(compiler: any) { + let compilationSpan: Span | null = null + compiler.hooks.compilation.intercept({ + tap() { + const parentSpan = spans.get(compiler) + tracer.withSpan(parentSpan, () => { + compilationSpan = tracer.startSpan('compile') + }) + }, + done() { + compilationSpan?.end?.() + }, + }) + compiler.hooks.compilation.tap(pluginName, (compilation: any) => { compilation.hooks.buildModule.tap(pluginName, (module: any) => { tracer.withSpan(spans.get(compiler), () => { @@ -98,31 +127,37 @@ export class ProfilingPlugin { this.traceHookPair( 'chunk-graph', + compilationSpan || spans.get(compiler), compilation.hooks.beforeChunks, compilation.hooks.afterChunks ) this.traceHookPair( 'optimize', + compilationSpan || spans.get(compiler), compilation.hooks.optimize, compilation.hooks.reviveModules ) this.traceLoopedHook( 'optimize-modules', + compilationSpan || spans.get(compiler), compilation.hooks.optimizeModules, compilation.hooks.afterOptimizeModules ) this.traceLoopedHook( 'optimize-chunks', + compilationSpan || spans.get(compiler), compilation.hooks.optimizeChunks, compilation.hooks.afterOptimizeChunks ) this.traceHookPair( 'optimize-tree', + compilationSpan || spans.get(compiler), compilation.hooks.optimizeTree, compilation.hooks.afterOptimizeTree ) this.traceHookPair( 'hash', + compilationSpan || spans.get(compiler), compilation.hooks.beforeHash, compilation.hooks.afterHash ) From 96095b69e396f5c55f5e89797008718699ad13ec Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Wed, 27 Jan 2021 23:36:50 -0800 Subject: [PATCH 04/13] Fix typo. --- packages/next/build/webpack/plugins/profiling-plugin.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index bf0adcfec2211..98bc7fb34005f 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -81,7 +81,7 @@ export class ProfilingPlugin { const reportedSpanName = `webpack-compilation-${spanName}` let span: Span | null = null startHook.tap(pluginName, () => { - if (span) { + if (!span) { tracer.withSpan(parentSpan, () => { span = tracer.startSpan(reportedSpanName) }) From e1ff565a510b62f94f8dbdd2e801bbb3049e32a4 Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Thu, 28 Jan 2021 22:40:50 -0800 Subject: [PATCH 05/13] Improve intrumentation-detection, move map into class. --- .../build/webpack/plugins/profiling-plugin.ts | 176 +++++++++++------- 1 file changed, 106 insertions(+), 70 deletions(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 98bc7fb34005f..7cca72434dc75 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -1,11 +1,13 @@ import { tracer } from '../../tracer' import { webpack, isWebpack5 } from 'next/dist/compiled/webpack/webpack' -import { Span } from '@opentelemetry/api' +import { + Span, + trace, + ProxyTracerProvider, + NoopTracerProvider, +} from '@opentelemetry/api' const pluginName = 'ProfilingPlugin' -const forceTrace = false - -export const spans = new WeakMap() function getNormalModuleLoaderHook(compilation: any) { if (isWebpack5) { @@ -16,148 +18,182 @@ function getNormalModuleLoaderHook(compilation: any) { return compilation.hooks.normalModuleLoader } +function tracingIsEnabled() { + const tracerProvider: any = trace.getTracerProvider() + if (Object.getPrototypeOf(tracerProvider) === ProxyTracerProvider) { + const proxyDelegate: any = tracerProvider.getDelegate() + return Object.getPrototypeOf(proxyDelegate) !== NoopTracerProvider + } + return false +} + export class ProfilingPlugin { + // Map should be defined on ProfilingPlugin instance to avoid collisions + // when multiple compilers are running concurrently. + spans: Map | undefined + apply(compiler: any) { - // Only enabled when instrumentation is loaded - const currentSpan = tracer.getCurrentSpan() - if (!currentSpan || (!currentSpan.isRecording() && !forceTrace)) { + // Only enable plugin when instrumentation is loaded + if (!tracingIsEnabled()) { return } - + this.spans = new Map() this.traceTopLevelHooks(compiler) this.traceCompilationHooks(compiler) } - traceTopLevelHooks(compiler: any) { - compiler.hooks.compile.tap(pluginName, () => { - const span = tracer.startSpan('webpack-compile', { - attributes: { name: compiler.name }, - }) - spans.set(compiler, span) - }) - compiler.hooks.done.tap(pluginName, () => { - spans.get(compiler).end() - }) - - compiler.hooks.watchRun.tap(pluginName, () => { - const span = tracer.startSpan('webpack-watchrun') - spans.set(compiler, span) - }) - compiler.hooks.watchClose.tap(pluginName, () => { - spans.get(compiler)?.end() - }) + traceWithParent(parentName: string, spanName: string, attrs?: any) { + if (!this.spans) { + return + } + const parentSpan = this.spans.get(parentName) + if (!parentSpan) { + return tracer.startSpan(spanName, attrs) + } - compiler.hooks.environment.tap(pluginName, () => { - const span = tracer.startSpan('webpack-prepare-env') - spans.set(compiler, span) - }) - compiler.hooks.afterEnvironment.tap(pluginName, () => { - spans.get(compiler)?.end() + let span: Span | undefined + tracer.withSpan(parentSpan, () => { + span = tracer.startSpan(spanName, attrs) + this.spans?.set?.(spanName, span) }) + return span } traceHookPair( spanName: string, - parentSpan: Span, + parentName: string | null, startHook: any, - stopHook: any + stopHook: any, + attrs?: any ) { - const reportedSpanName = `webpack-compilation-${spanName}` - let span: Span | null = null + let span: Span | undefined startHook.tap(pluginName, () => { - tracer.withSpan(parentSpan, () => { - span = tracer.startSpan(reportedSpanName) - }) + span = parentName + ? this.traceWithParent(parentName, spanName, attrs) + : tracer.startSpan(spanName, attrs) }) stopHook.tap(pluginName, () => span?.end?.()) } traceLoopedHook( spanName: string, - parentSpan: Span, + parentName: string, startHook: any, stopHook: any ) { - const reportedSpanName = `webpack-compilation-${spanName}` let span: Span | null = null startHook.tap(pluginName, () => { if (!span) { - tracer.withSpan(parentSpan, () => { - span = tracer.startSpan(reportedSpanName) - }) + this.traceWithParent(parentName, spanName) } }) stopHook.tap(pluginName, () => span?.end?.()) } - traceCompilationHooks(compiler: any) { - let compilationSpan: Span | null = null - compiler.hooks.compilation.intercept({ - tap() { - const parentSpan = spans.get(compiler) - tracer.withSpan(parentSpan, () => { - compilationSpan = tracer.startSpan('compile') - }) + traceHook( + spanName: string, + parentName: string, + hook: any, + onSet?: (span: Span | undefined) => void + ) { + let span: Span | undefined + hook.intercept({ + tap: () => { + span = this.traceWithParent(parentName, spanName) + onSet?.(span) }, - done() { - compilationSpan?.end?.() + done: () => { + span?.end?.() }, }) + } + + traceTopLevelHooks(compiler: any) { + this.traceHookPair( + 'webpack-compile', + null, + compiler.hooks.compile, + compiler.hooks.done, + { + attributes: { name: compiler.name }, + } + ) + this.traceHookPair( + 'webpack-watch-run', + 'webpack-compile', + compiler.hooks.watchRun, + compiler.hooks.watchClose + ) + + this.traceHookPair( + 'webpack-prepare-env', + 'webpack-compile', + compiler.hooks.environment, + compiler.hooks.afterEnvironment + ) + } + + traceCompilationHooks(compiler: any) { + this.traceHook('compilation', 'webpack-compile', compiler.hooks.compilation) compiler.hooks.compilation.tap(pluginName, (compilation: any) => { compilation.hooks.buildModule.tap(pluginName, (module: any) => { - tracer.withSpan(spans.get(compiler), () => { + const compilerSpan = this.spans?.get(compiler) + if (!compilerSpan) { + return + } + tracer.withSpan(compilerSpan, () => { const span = tracer.startSpan('build-module') span.setAttribute('name', module.userRequest) - spans.set(module, span) + this.spans?.set?.(module, span) }) }) getNormalModuleLoaderHook(compilation).tap( pluginName, (loaderContext: any, module: any) => { - const parentSpan = spans.get(module) + const parentSpan = this.spans?.get?.(module) loaderContext.currentTraceSpan = parentSpan } ) compilation.hooks.succeedModule.tap(pluginName, (module: any) => { - spans.get(module).end() + this.spans?.get?.(module)?.end() }) this.traceHookPair( - 'chunk-graph', - compilationSpan || spans.get(compiler), + 'webpack-compilation-chunk-graph', + 'compilation', compilation.hooks.beforeChunks, compilation.hooks.afterChunks ) this.traceHookPair( - 'optimize', - compilationSpan || spans.get(compiler), + 'webpack-compilation-optimize', + 'compilation', compilation.hooks.optimize, compilation.hooks.reviveModules ) this.traceLoopedHook( - 'optimize-modules', - compilationSpan || spans.get(compiler), + 'webpack-compilation-optimize-modules', + 'compilation', compilation.hooks.optimizeModules, compilation.hooks.afterOptimizeModules ) this.traceLoopedHook( - 'optimize-chunks', - compilationSpan || spans.get(compiler), + 'webpack-compilation-optimize-chunks', + 'compilation', compilation.hooks.optimizeChunks, compilation.hooks.afterOptimizeChunks ) this.traceHookPair( - 'optimize-tree', - compilationSpan || spans.get(compiler), + 'webpack-compilation-optimize-tree', + 'compilation', compilation.hooks.optimizeTree, compilation.hooks.afterOptimizeTree ) this.traceHookPair( - 'hash', - compilationSpan || spans.get(compiler), + 'webpack-compilation-hash', + 'compilation', compilation.hooks.beforeHash, compilation.hooks.afterHash ) From 4064ec718ae14340947997c31b7bcf12babd178f Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Thu, 28 Jan 2021 22:50:58 -0800 Subject: [PATCH 06/13] Make 'compile' span accessible via `spans` export. --- .../next/build/webpack/plugins/profiling-plugin.ts | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 7cca72434dc75..696dad186ef65 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -8,6 +8,7 @@ import { } from '@opentelemetry/api' const pluginName = 'ProfilingPlugin' +export const spans = new WeakMap() function getNormalModuleLoaderHook(compilation: any) { if (isWebpack5) { @@ -64,13 +65,15 @@ export class ProfilingPlugin { parentName: string | null, startHook: any, stopHook: any, - attrs?: any + attrs?: any, + onSetSpan?: (span: Span | undefined) => void ) { let span: Span | undefined startHook.tap(pluginName, () => { span = parentName ? this.traceWithParent(parentName, spanName, attrs) : tracer.startSpan(spanName, attrs) + onSetSpan?.(span) }) stopHook.tap(pluginName, () => span?.end?.()) } @@ -114,9 +117,8 @@ export class ProfilingPlugin { null, compiler.hooks.compile, compiler.hooks.done, - { - attributes: { name: compiler.name }, - } + { attributes: { name: compiler.name } }, + (span) => spans.set(compiler, span) ) this.traceHookPair( 'webpack-watch-run', From c6647750f81e6a55fd81059a572c3d64f62632e4 Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Thu, 28 Jan 2021 23:26:33 -0800 Subject: [PATCH 07/13] Fix instrumentation detection. --- packages/next/build/webpack/plugins/profiling-plugin.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 696dad186ef65..64ae331122a9f 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -21,9 +21,9 @@ function getNormalModuleLoaderHook(compilation: any) { function tracingIsEnabled() { const tracerProvider: any = trace.getTracerProvider() - if (Object.getPrototypeOf(tracerProvider) === ProxyTracerProvider) { + if (tracerProvider instanceof ProxyTracerProvider) { const proxyDelegate: any = tracerProvider.getDelegate() - return Object.getPrototypeOf(proxyDelegate) !== NoopTracerProvider + return !(proxyDelegate instanceof NoopTracerProvider) } return false } From 3b38a7d8f922b7f79361d848601d8d640837cd88 Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Thu, 28 Jan 2021 23:27:45 -0800 Subject: [PATCH 08/13] Re-parent telemetry events to 'webpack-compile'. --- .../build/webpack/plugins/profiling-plugin.ts | 29 ++++++++++++------- 1 file changed, 19 insertions(+), 10 deletions(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 64ae331122a9f..580a9b9723d94 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -31,7 +31,7 @@ function tracingIsEnabled() { export class ProfilingPlugin { // Map should be defined on ProfilingPlugin instance to avoid collisions // when multiple compilers are running concurrently. - spans: Map | undefined + spans: Map | undefined apply(compiler: any) { // Only enable plugin when instrumentation is loaded @@ -73,6 +73,7 @@ export class ProfilingPlugin { span = parentName ? this.traceWithParent(parentName, spanName, attrs) : tracer.startSpan(spanName, attrs) + this.spans?.set?.(spanName, span) onSetSpan?.(span) }) stopHook.tap(pluginName, () => span?.end?.()) @@ -84,10 +85,11 @@ export class ProfilingPlugin { startHook: any, stopHook: any ) { - let span: Span | null = null + let span: Span | undefined startHook.tap(pluginName, () => { if (!span) { this.traceWithParent(parentName, spanName) + this.spans?.set(spanName, span) } }) stopHook.tap(pluginName, () => span?.end?.()) @@ -103,6 +105,7 @@ export class ProfilingPlugin { hook.intercept({ tap: () => { span = this.traceWithParent(parentName, spanName) + this.spans?.set(spanName, span) onSet?.(span) }, done: () => { @@ -136,8 +139,6 @@ export class ProfilingPlugin { } traceCompilationHooks(compiler: any) { - this.traceHook('compilation', 'webpack-compile', compiler.hooks.compilation) - compiler.hooks.compilation.tap(pluginName, (compilation: any) => { compilation.hooks.buildModule.tap(pluginName, (module: any) => { const compilerSpan = this.spans?.get(compiler) @@ -162,40 +163,48 @@ export class ProfilingPlugin { compilation.hooks.succeedModule.tap(pluginName, (module: any) => { this.spans?.get?.(module)?.end() }) + if (isWebpack5) { + this.traceHookPair( + 'webpack-compilation', + 'webpack-compile', + compilation.hooks.beforeCompile, + compilation.hooks.afterCompile + ) + } this.traceHookPair( 'webpack-compilation-chunk-graph', - 'compilation', + 'webpack-compile', compilation.hooks.beforeChunks, compilation.hooks.afterChunks ) this.traceHookPair( 'webpack-compilation-optimize', - 'compilation', + 'webpack-compile', compilation.hooks.optimize, compilation.hooks.reviveModules ) this.traceLoopedHook( 'webpack-compilation-optimize-modules', - 'compilation', + 'webpack-compile', compilation.hooks.optimizeModules, compilation.hooks.afterOptimizeModules ) this.traceLoopedHook( 'webpack-compilation-optimize-chunks', - 'compilation', + 'webpack-compile', compilation.hooks.optimizeChunks, compilation.hooks.afterOptimizeChunks ) this.traceHookPair( 'webpack-compilation-optimize-tree', - 'compilation', + 'webpack-compile', compilation.hooks.optimizeTree, compilation.hooks.afterOptimizeTree ) this.traceHookPair( 'webpack-compilation-hash', - 'compilation', + 'webpack-compile', compilation.hooks.beforeHash, compilation.hooks.afterHash ) From 93becc2052948399239ffc44fb1dc42f2916adfa Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Thu, 28 Jan 2021 23:59:27 -0800 Subject: [PATCH 09/13] Use stack-based approach for associating spans. --- packages/next/build/tracer.ts | 43 ++++++++++ .../build/webpack/plugins/profiling-plugin.ts | 85 ++++--------------- 2 files changed, 59 insertions(+), 69 deletions(-) diff --git a/packages/next/build/tracer.ts b/packages/next/build/tracer.ts index 4be529ab8bcc8..2c8c16d47d83b 100644 --- a/packages/next/build/tracer.ts +++ b/packages/next/build/tracer.ts @@ -2,6 +2,49 @@ import api, { Span } from '@opentelemetry/api' export const tracer = api.trace.getTracer('next', process.env.__NEXT_VERSION) +const compilerStacks = new WeakMap() + +export function stackPush(compiler: any, spanName: string, attrs?: any): any { + let stack = compilerStacks.get(compiler) + let span + + if (!stack) { + compilerStacks.set(compiler, (stack = [])) + span = tracer.startSpan(spanName, attrs) + } else { + const parent = stack[stack.length - 1] + tracer.withSpan(parent, () => { + span = tracer.startSpan(spanName, attrs) + }) + } + + stack.push(span) + return span +} + +export function stackPop(compiler: any, span: any) { + span.end() + + let stack = compilerStacks.get(compiler) + if (!stack) { + console.warn( + 'Attempted to pop from non-existent stack. Compiler reference must be bad.' + ) + return + } + const poppedSpan = stack.pop() + if (poppedSpan !== span) { + stack.push(poppedSpan) + const spanIdx = stack.indexOf(span) + console.warn('Attempted to pop span that was not at top of stack.') + if (spanIdx !== -1) { + console.info( + `Span was found at index ${spanIdx} with stack size ${stack.length}` + ) + } + } +} + export function traceFn ReturnType>( span: Span, fn: T diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 580a9b9723d94..15a5a0a26ba40 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -1,4 +1,4 @@ -import { tracer } from '../../tracer' +import { tracer, stackPush, stackPop } from '../../tracer' import { webpack, isWebpack5 } from 'next/dist/compiled/webpack/webpack' import { Span, @@ -29,40 +29,20 @@ function tracingIsEnabled() { } export class ProfilingPlugin { - // Map should be defined on ProfilingPlugin instance to avoid collisions - // when multiple compilers are running concurrently. - spans: Map | undefined + compiler: any apply(compiler: any) { // Only enable plugin when instrumentation is loaded if (!tracingIsEnabled()) { return } - this.spans = new Map() this.traceTopLevelHooks(compiler) this.traceCompilationHooks(compiler) - } - - traceWithParent(parentName: string, spanName: string, attrs?: any) { - if (!this.spans) { - return - } - const parentSpan = this.spans.get(parentName) - if (!parentSpan) { - return tracer.startSpan(spanName, attrs) - } - - let span: Span | undefined - tracer.withSpan(parentSpan, () => { - span = tracer.startSpan(spanName, attrs) - this.spans?.set?.(spanName, span) - }) - return span + this.compiler = compiler } traceHookPair( spanName: string, - parentName: string | null, startHook: any, stopHook: any, attrs?: any, @@ -70,54 +50,29 @@ export class ProfilingPlugin { ) { let span: Span | undefined startHook.tap(pluginName, () => { - span = parentName - ? this.traceWithParent(parentName, spanName, attrs) - : tracer.startSpan(spanName, attrs) - this.spans?.set?.(spanName, span) + span = stackPush(this.compiler, spanName, attrs) onSetSpan?.(span) }) - stopHook.tap(pluginName, () => span?.end?.()) + stopHook.tap(pluginName, () => { + stackPop(this.compiler, span) + }) } - traceLoopedHook( - spanName: string, - parentName: string, - startHook: any, - stopHook: any - ) { + traceLoopedHook(spanName: string, startHook: any, stopHook: any) { let span: Span | undefined startHook.tap(pluginName, () => { if (!span) { - this.traceWithParent(parentName, spanName) - this.spans?.set(spanName, span) + span = stackPush(this.compiler, spanName) } }) - stopHook.tap(pluginName, () => span?.end?.()) - } - - traceHook( - spanName: string, - parentName: string, - hook: any, - onSet?: (span: Span | undefined) => void - ) { - let span: Span | undefined - hook.intercept({ - tap: () => { - span = this.traceWithParent(parentName, spanName) - this.spans?.set(spanName, span) - onSet?.(span) - }, - done: () => { - span?.end?.() - }, + stopHook.tap(pluginName, () => { + stackPop(this.compiler, span) }) } traceTopLevelHooks(compiler: any) { this.traceHookPair( 'webpack-compile', - null, compiler.hooks.compile, compiler.hooks.done, { attributes: { name: compiler.name } }, @@ -125,14 +80,12 @@ export class ProfilingPlugin { ) this.traceHookPair( 'webpack-watch-run', - 'webpack-compile', compiler.hooks.watchRun, compiler.hooks.watchClose ) this.traceHookPair( 'webpack-prepare-env', - 'webpack-compile', compiler.hooks.environment, compiler.hooks.afterEnvironment ) @@ -141,32 +94,32 @@ export class ProfilingPlugin { traceCompilationHooks(compiler: any) { compiler.hooks.compilation.tap(pluginName, (compilation: any) => { compilation.hooks.buildModule.tap(pluginName, (module: any) => { - const compilerSpan = this.spans?.get(compiler) + const compilerSpan = spans.get(compiler) if (!compilerSpan) { return } tracer.withSpan(compilerSpan, () => { const span = tracer.startSpan('build-module') span.setAttribute('name', module.userRequest) - this.spans?.set?.(module, span) + spans.set(module, span) }) }) getNormalModuleLoaderHook(compilation).tap( pluginName, (loaderContext: any, module: any) => { - const parentSpan = this.spans?.get?.(module) + const parentSpan = spans.get(module) loaderContext.currentTraceSpan = parentSpan } ) compilation.hooks.succeedModule.tap(pluginName, (module: any) => { - this.spans?.get?.(module)?.end() + spans.get(module).end() }) + if (isWebpack5) { this.traceHookPair( 'webpack-compilation', - 'webpack-compile', compilation.hooks.beforeCompile, compilation.hooks.afterCompile ) @@ -174,37 +127,31 @@ export class ProfilingPlugin { this.traceHookPair( 'webpack-compilation-chunk-graph', - 'webpack-compile', compilation.hooks.beforeChunks, compilation.hooks.afterChunks ) this.traceHookPair( 'webpack-compilation-optimize', - 'webpack-compile', compilation.hooks.optimize, compilation.hooks.reviveModules ) this.traceLoopedHook( 'webpack-compilation-optimize-modules', - 'webpack-compile', compilation.hooks.optimizeModules, compilation.hooks.afterOptimizeModules ) this.traceLoopedHook( 'webpack-compilation-optimize-chunks', - 'webpack-compile', compilation.hooks.optimizeChunks, compilation.hooks.afterOptimizeChunks ) this.traceHookPair( 'webpack-compilation-optimize-tree', - 'webpack-compile', compilation.hooks.optimizeTree, compilation.hooks.afterOptimizeTree ) this.traceHookPair( 'webpack-compilation-hash', - 'webpack-compile', compilation.hooks.beforeHash, compilation.hooks.afterHash ) From 31c6e1e0254c87d35cd790f83b2767a6308c2252 Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Fri, 29 Jan 2021 00:11:34 -0800 Subject: [PATCH 10/13] Remove extraneous hot-reloader noise. --- packages/next/server/hot-reloader.ts | 4 ---- 1 file changed, 4 deletions(-) diff --git a/packages/next/server/hot-reloader.ts b/packages/next/server/hot-reloader.ts index 2d6146fe2165a..5318057daf1fb 100644 --- a/packages/next/server/hot-reloader.ts +++ b/packages/next/server/hot-reloader.ts @@ -33,7 +33,6 @@ import { stringify } from 'querystring' import { Rewrite } from '../lib/load-custom-routes' import { difference } from '../build/utils' import { NextConfig } from '../next-server/server/config' -import { tracer } from '../build/tracer' import { Span } from '@opentelemetry/api' export async function renderScriptError( @@ -195,7 +194,6 @@ export default class HotReloader { res: ServerResponse, parsedUrl: UrlObject ): Promise<{ finished?: true }> { - this.span = tracer.startSpan('hot-reload') // Usually CORS support is not needed for the hot-reloader (this is dev only feature) // With when the app runs for multi-zones support behind a proxy, // the current page is trying to access this URL via assetPrefix. @@ -266,8 +264,6 @@ export default class HotReloader { }) } - this.span?.end?.() - return { finished } } From 11fc4b7acf2c52a5f9623bd3b59dda08d9ca9561 Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Fri, 29 Jan 2021 00:12:33 -0800 Subject: [PATCH 11/13] Clean up. --- packages/next/build/webpack/plugins/profiling-plugin.ts | 1 - packages/next/server/hot-reloader.ts | 3 --- 2 files changed, 4 deletions(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 15a5a0a26ba40..75378d8408fd5 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -83,7 +83,6 @@ export class ProfilingPlugin { compiler.hooks.watchRun, compiler.hooks.watchClose ) - this.traceHookPair( 'webpack-prepare-env', compiler.hooks.environment, diff --git a/packages/next/server/hot-reloader.ts b/packages/next/server/hot-reloader.ts index 5318057daf1fb..177a420fa2310 100644 --- a/packages/next/server/hot-reloader.ts +++ b/packages/next/server/hot-reloader.ts @@ -33,7 +33,6 @@ import { stringify } from 'querystring' import { Rewrite } from '../lib/load-custom-routes' import { difference } from '../build/utils' import { NextConfig } from '../next-server/server/config' -import { Span } from '@opentelemetry/api' export async function renderScriptError( res: ServerResponse, @@ -140,7 +139,6 @@ function erroredPages(compilation: webpack.compilation.Compilation) { } export default class HotReloader { - private span: Span | null private dir: string private buildId: string private middlewares: any[] @@ -182,7 +180,6 @@ export default class HotReloader { this.stats = null this.serverStats = null this.serverPrevDocumentHash = null - this.span = null this.config = config this.previewProps = previewProps From 24850bb2e70e506f7c7899464de7576d6f953f9a Mon Sep 17 00:00:00 2001 From: Dale Bustad Date: Fri, 29 Jan 2021 00:51:44 -0800 Subject: [PATCH 12/13] Use different hook for webpack hot-reload invalidation. --- .../next/build/webpack/plugins/profiling-plugin.ts | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 75378d8408fd5..77bf934f5df91 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -78,16 +78,16 @@ export class ProfilingPlugin { { attributes: { name: compiler.name } }, (span) => spans.set(compiler, span) ) - this.traceHookPair( - 'webpack-watch-run', - compiler.hooks.watchRun, - compiler.hooks.watchClose - ) this.traceHookPair( 'webpack-prepare-env', compiler.hooks.environment, compiler.hooks.afterEnvironment ) + this.traceHookPair( + 'webpack-invalidated', + compiler.hooks.invalid, + compiler.hooks.done + ) } traceCompilationHooks(compiler: any) { From b57819d513b0c9935a58eb0f7277dc3297c742b0 Mon Sep 17 00:00:00 2001 From: Tim Neutkens Date: Fri, 29 Jan 2021 10:46:12 +0100 Subject: [PATCH 13/13] Make sure attributes are generated at the correct time --- packages/next/build/tracer.ts | 4 ++-- packages/next/build/webpack/plugins/profiling-plugin.ts | 4 +++- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/packages/next/build/tracer.ts b/packages/next/build/tracer.ts index 2c8c16d47d83b..2c915822366d3 100644 --- a/packages/next/build/tracer.ts +++ b/packages/next/build/tracer.ts @@ -10,11 +10,11 @@ export function stackPush(compiler: any, spanName: string, attrs?: any): any { if (!stack) { compilerStacks.set(compiler, (stack = [])) - span = tracer.startSpan(spanName, attrs) + span = tracer.startSpan(spanName, attrs ? attrs() : undefined) } else { const parent = stack[stack.length - 1] tracer.withSpan(parent, () => { - span = tracer.startSpan(spanName, attrs) + span = tracer.startSpan(spanName, attrs ? attrs() : undefined) }) } diff --git a/packages/next/build/webpack/plugins/profiling-plugin.ts b/packages/next/build/webpack/plugins/profiling-plugin.ts index 77bf934f5df91..0371f6e0d0474 100644 --- a/packages/next/build/webpack/plugins/profiling-plugin.ts +++ b/packages/next/build/webpack/plugins/profiling-plugin.ts @@ -75,7 +75,9 @@ export class ProfilingPlugin { 'webpack-compile', compiler.hooks.compile, compiler.hooks.done, - { attributes: { name: compiler.name } }, + () => { + return { attributes: { name: compiler.name } } + }, (span) => spans.set(compiler, span) ) this.traceHookPair(