diff --git a/src/compiler/binder.ts b/src/compiler/binder.ts index 5e7695ffef366..faab9a6dfe5f1 100644 --- a/src/compiler/binder.ts +++ b/src/compiler/binder.ts @@ -174,14 +174,15 @@ namespace ts { const binder = createBinder(); export function bindSourceFile(file: SourceFile, options: CompilerOptions) { - tracing.begin(tracing.Phase.Bind, "bindSourceFile", { path: file.path }); + const tracingData: tracing.EventData = [tracing.Phase.Bind, "bindSourceFile", { path: file.path }]; + tracing.begin(...tracingData); performance.mark("beforeBind"); perfLogger.logStartBindFile("" + file.fileName); binder(file, options); perfLogger.logStopBindFile(); performance.mark("afterBind"); performance.measure("Bind", "beforeBind", "afterBind"); - tracing.end(); + tracing.end(...tracingData); } function createBinder(): (file: SourceFile, options: CompilerOptions) => void { diff --git a/src/compiler/checker.ts b/src/compiler/checker.ts index 019527f430380..9dea26c42df38 100644 --- a/src/compiler/checker.ts +++ b/src/compiler/checker.ts @@ -17272,9 +17272,9 @@ namespace ts { } function structuredTypeRelatedTo(source: Type, target: Type, reportErrors: boolean, intersectionState: IntersectionState): Ternary { - tracing.begin(tracing.Phase.Check, "structuredTypeRelatedTo", { sourceId: source.id, targetId: target.id }); + tracing.push(tracing.Phase.Check, "structuredTypeRelatedTo", { sourceId: source.id, targetId: target.id }); const result = structuredTypeRelatedToWorker(source, target, reportErrors, intersectionState); - tracing.end(); + tracing.pop(); return result; } @@ -18529,7 +18529,7 @@ namespace ts { function getVariancesWorker(typeParameters: readonly TypeParameter[] = emptyArray, cache: TCache, createMarkerType: (input: TCache, param: TypeParameter, marker: Type) => Type): VarianceFlags[] { let variances = cache.variances; if (!variances) { - tracing.begin(tracing.Phase.Check, "getVariancesWorker", { arity: typeParameters.length, id: (cache as any).id ?? (cache as any).declaredType?.id ?? -1 }); + tracing.push(tracing.Phase.Check, "getVariancesWorker", { arity: typeParameters.length, id: (cache as any).id ?? (cache as any).declaredType?.id ?? -1 }); // The emptyArray singleton is used to signal a recursive invocation. cache.variances = emptyArray; variances = []; @@ -18564,7 +18564,7 @@ namespace ts { variances.push(variance); } cache.variances = variances; - tracing.end(); + tracing.pop(); } return variances; } @@ -30979,7 +30979,7 @@ namespace ts { } function checkExpression(node: Expression | QualifiedName, checkMode?: CheckMode, forceTuple?: boolean): Type { - tracing.begin(tracing.Phase.Check, "checkExpression", { kind: node.kind, pos: node.pos, end: node.end }); + tracing.push(tracing.Phase.Check, "checkExpression", { kind: node.kind, pos: node.pos, end: node.end }); const saveCurrentNode = currentNode; currentNode = node; instantiationCount = 0; @@ -30989,7 +30989,7 @@ namespace ts { checkConstEnumAccess(node, type); } currentNode = saveCurrentNode; - tracing.end(); + tracing.pop(); return type; } @@ -33780,10 +33780,10 @@ namespace ts { } function checkVariableDeclaration(node: VariableDeclaration) { - tracing.begin(tracing.Phase.Check, "checkVariableDeclaration", { kind: node.kind, pos: node.pos, end: node.end }); + tracing.push(tracing.Phase.Check, "checkVariableDeclaration", { kind: node.kind, pos: node.pos, end: node.end }); checkGrammarVariableDeclaration(node); checkVariableLikeDeclaration(node); - tracing.end(); + tracing.pop(); } function checkBindingElement(node: BindingElement) { @@ -36854,12 +36854,13 @@ namespace ts { } function checkSourceFile(node: SourceFile) { - tracing.begin(tracing.Phase.Check, "checkSourceFile", { path: node.path }); + const tracingData: tracing.EventData = [tracing.Phase.Check, "checkSourceFile", { path: node.path }]; + tracing.begin(...tracingData); performance.mark("beforeCheck"); checkSourceFileWorker(node); performance.mark("afterCheck"); performance.measure("Check", "beforeCheck", "afterCheck"); - tracing.end(); + tracing.end(...tracingData); } function unusedIsError(kind: UnusedKind, isAmbient: boolean): boolean { diff --git a/src/compiler/emitter.ts b/src/compiler/emitter.ts index ee2d1b9c576c8..dbbb4a1b65fe5 100644 --- a/src/compiler/emitter.ts +++ b/src/compiler/emitter.ts @@ -300,17 +300,17 @@ namespace ts { sourceFiles: sourceFileOrBundle.sourceFiles.map(file => relativeToBuildInfo(getNormalizedAbsolutePath(file.fileName, host.getCurrentDirectory()))) }; } - tracing.begin(tracing.Phase.Emit, "emitJsFileOrBundle", { jsFilePath }); + tracing.push(tracing.Phase.Emit, "emitJsFileOrBundle", { jsFilePath }); emitJsFileOrBundle(sourceFileOrBundle, jsFilePath, sourceMapFilePath, relativeToBuildInfo); - tracing.end(); + tracing.pop(); - tracing.begin(tracing.Phase.Emit, "emitDeclarationFileOrBundle", { declarationFilePath }); + tracing.push(tracing.Phase.Emit, "emitDeclarationFileOrBundle", { declarationFilePath }); emitDeclarationFileOrBundle(sourceFileOrBundle, declarationFilePath, declarationMapPath, relativeToBuildInfo); - tracing.end(); + tracing.pop(); - tracing.begin(tracing.Phase.Emit, "emitBuildInfo", { buildInfoPath }); + tracing.push(tracing.Phase.Emit, "emitBuildInfo", { buildInfoPath }); emitBuildInfo(bundleBuildInfo, buildInfoPath); - tracing.end(); + tracing.pop(); if (!emitSkipped && emittedFilesList) { if (!emitOnlyDtsFiles) { diff --git a/src/compiler/parser.ts b/src/compiler/parser.ts index a815a12db9a53..722604bb3e2f6 100644 --- a/src/compiler/parser.ts +++ b/src/compiler/parser.ts @@ -614,7 +614,8 @@ namespace ts { } export function createSourceFile(fileName: string, sourceText: string, languageVersion: ScriptTarget, setParentNodes = false, scriptKind?: ScriptKind): SourceFile { - tracing.begin(tracing.Phase.Parse, "createSourceFile", { path: fileName }); + const tracingData: tracing.EventData = [tracing.Phase.Parse, "createSourceFile", { path: fileName }]; + tracing.begin(...tracingData); performance.mark("beforeParse"); let result: SourceFile; @@ -629,7 +630,7 @@ namespace ts { performance.mark("afterParse"); performance.measure("Parse", "beforeParse", "afterParse"); - tracing.end(); + tracing.end(...tracingData); return result; } diff --git a/src/compiler/program.ts b/src/compiler/program.ts index 2c8a2709fb712..5095c055e23e6 100644 --- a/src/compiler/program.ts +++ b/src/compiler/program.ts @@ -780,7 +780,8 @@ namespace ts { // Track source files that are source files found by searching under node_modules, as these shouldn't be compiled. const sourceFilesFoundSearchingNodeModules = new Map(); - tracing.begin(tracing.Phase.Program, "createProgram", {}); + const tracingData: tracing.EventData = [tracing.Phase.Program, "createProgram"]; + tracing.begin(...tracingData); performance.mark("beforeProgram"); const host = createProgramOptions.host || createCompilerHost(options); @@ -1032,7 +1033,7 @@ namespace ts { verifyCompilerOptions(); performance.mark("afterProgram"); performance.measure("Program", "beforeProgram", "afterProgram"); - tracing.end(); + tracing.end(...tracingData); return program; @@ -1590,7 +1591,8 @@ namespace ts { function emitBuildInfo(writeFileCallback?: WriteFileCallback): EmitResult { Debug.assert(!outFile(options)); - tracing.begin(tracing.Phase.Emit, "emitBuildInfo", {}); + const tracingData: tracing.EventData = [tracing.Phase.Emit, "emitBuildInfo"]; + tracing.begin(...tracingData); performance.mark("beforeEmit"); const emitResult = emitFiles( notImplementedResolver, @@ -1603,7 +1605,7 @@ namespace ts { performance.mark("afterEmit"); performance.measure("Emit", "beforeEmit", "afterEmit"); - tracing.end(); + tracing.end(...tracingData); return emitResult; } @@ -1664,9 +1666,10 @@ namespace ts { } function emit(sourceFile?: SourceFile, writeFileCallback?: WriteFileCallback, cancellationToken?: CancellationToken, emitOnlyDtsFiles?: boolean, transformers?: CustomTransformers, forceDtsEmit?: boolean): EmitResult { - tracing.begin(tracing.Phase.Emit, "emit", { path: sourceFile?.path }); + const tracingData: tracing.EventData = [tracing.Phase.Emit, "emit", { path: sourceFile?.path }]; + tracing.begin(...tracingData); const result = runWithCancellationToken(() => emitWorker(program, sourceFile, writeFileCallback, cancellationToken, emitOnlyDtsFiles, transformers, forceDtsEmit)); - tracing.end(); + tracing.end(...tracingData); return result; } diff --git a/src/compiler/tracing.ts b/src/compiler/tracing.ts index 30b90a2b0d1a2..9498928f13873 100644 --- a/src/compiler/tracing.ts +++ b/src/compiler/tracing.ts @@ -46,7 +46,15 @@ namespace ts.tracing { }); traceFd = fs.openSync(tracePath, "w"); - fs.writeSync(traceFd, `[\n`); + + // Start with a prefix that contains some metadata that the devtools profiler expects (also avoids a warning on import) + const meta = { cat: "__metadata", ph: "M", ts: 1000 * timestamp(), pid: 1, tid: 1 }; + fs.writeSync(traceFd, + "[\n" + + [{ name: "process_name", args: { name: "tsc" }, ...meta }, + { name: "thread_name", args: { name: "Main" }, ...meta }, + { name: "TracingStartedInBrowser", ...meta, cat: "disabled-by-default-devtools.timeline" }] + .map(v => JSON.stringify(v)).join(",\n")); } /** Stops tracing for the in-progress project and dumps the type catalog (unless the `fs` module is unavailable). */ @@ -58,11 +66,7 @@ namespace ts.tracing { Debug.assert(fs); - // This both indicates that the trace is untruncated and conveniently - // ensures that the last array element won't have a trailing comma. - fs.writeSync(traceFd, `{"pid":1,"tid":1,"ph":"i","ts":${1000 * timestamp()},"name":"done","s":"g"}\n`); - fs.writeSync(traceFd, `]\n`); - + fs.writeSync(traceFd, `\n]\n`); fs.closeSync(traceFd); traceFd = undefined; @@ -88,38 +92,46 @@ namespace ts.tracing { Emit = "emit", } - export function begin(phase: Phase, name: string, args: object) { - if (!traceFd) { - return; - } - Debug.assert(fs); + export type EventData = [phase: Phase, name: string, args?: object]; - performance.mark("beginTracing"); - fs.writeSync(traceFd, `{"pid":1,"tid":1,"ph":"B","cat":"${phase}","ts":${1000 * timestamp()},"name":"${name}","args":{ "ts": ${JSON.stringify(args)} }},\n`); - performance.mark("endTracing"); - performance.measure("Tracing", "beginTracing", "endTracing"); + /** Note: `push`/`pop` should be used by default. + * `begin`/`end` are for special cases where we need the data point even if the event never + * terminates (typically for reducing a scenario too big to trace to one that can be completed). + * In the future we might implement an exit handler to dump unfinished events which would + * deprecate these operations. + */ + export function begin(phase: Phase, name: string, args?: object) { + writeEvent("B", phase, name, args); + } + export function end(phase: Phase, name: string, args?: object) { + writeEvent("E", phase, name, args); } - export function end() { - if (!traceFd) { - return; - } - Debug.assert(fs); + export function instant(phase: Phase, name: string, args?: object) { + writeEvent("I", phase, name, args, `"s":"g"`); + } - performance.mark("beginTracing"); - fs.writeSync(traceFd, `{"pid":1,"tid":1,"ph":"E","ts":${1000 * timestamp()}},\n`); - performance.mark("endTracing"); - performance.measure("Tracing", "beginTracing", "endTracing"); + // Used for "Complete" (ph:"X") events + const completeEvents: { phase: Phase, name: string, args?: object, time: number }[] = []; + export function push(phase: Phase, name: string, args?: object) { + completeEvents.push({ phase, name, args, time: 1000 * timestamp() }); + } + export function pop() { + Debug.assert(completeEvents.length > 0); + const { phase, name, args, time } = completeEvents.pop()!; + const dur = 1000 * timestamp() - time; + writeEvent("X", phase, name, args, `"dur":${dur}`, time); } - export function instant(phase: Phase, name: string, args: object) { - if (!traceFd) { - return; - } + function writeEvent(eventType: string, phase: Phase, name: string, args: object | undefined, extras?: string, + time: number = 1000 * timestamp()) { + if (!traceFd) return; Debug.assert(fs); - performance.mark("beginTracing"); - fs.writeSync(traceFd, `{"pid":1,"tid":1,"ph":"i","cat":"${phase}","ts":${1000 * timestamp()},"name":"${name}","s":"g","args":{ "ts": ${JSON.stringify(args)} }},\n`); + fs.writeSync(traceFd, `,\n{"pid":1,"tid":1,"ph":"${eventType}","cat":"${phase}","ts":${time},"name":"${name}"`); + if (extras) fs.writeSync(traceFd, `,${extras}`); + if (args) fs.writeSync(traceFd, `,"args":${JSON.stringify(args)}`); + fs.writeSync(traceFd, `}`); performance.mark("endTracing"); performance.measure("Tracing", "beginTracing", "endTracing"); } diff --git a/src/compiler/transformer.ts b/src/compiler/transformer.ts index f76652df95eb6..efca6f7f187d3 100644 --- a/src/compiler/transformer.ts +++ b/src/compiler/transformer.ts @@ -223,9 +223,9 @@ namespace ts { // Transform each node. const transformed: T[] = []; for (const node of nodes) { - tracing.begin(tracing.Phase.Emit, "transformNodes", node.kind === SyntaxKind.SourceFile ? { path: (node as any as SourceFile).path } : { kind: node.kind, pos: node.pos, end: node.end }); + tracing.push(tracing.Phase.Emit, "transformNodes", node.kind === SyntaxKind.SourceFile ? { path: (node as any as SourceFile).path } : { kind: node.kind, pos: node.pos, end: node.end }); transformed.push((allowDtsFiles ? transformation : transformRoot)(node)); - tracing.end(); + tracing.pop(); } // prevent modification of the lexical environment.