microsoft/TypeScript
1
0
Fork 0
mirror of https://github.com/microsoft/TypeScript.git synced 2026-06-25 02:50:59 -05:00
Code Issues Packages Projects Releases 212 Wiki Activity

Tracing work

Browse Source 
* Fix: `E` events need to have the same information that is on the
  corresponding `B` events.  (Superseded below.)

* Use `I` (not `i`) for instant events, so they show in devtools
  too.  (Though they don't go through the flame chart as they do in
  `about://tracing`, so they're not nearly as useful.)

* Abstract the code that writes the records in a single `writeEvent`
  local function.

* Make `args` optional, and default to `undefined` (which will not add
  them) at all.

* Drop the `{ "ts": ... }` wrapper around the `args`, after verifying
  that having arguments with names like `begin`, `end`, `pos`, `id`
  doesn't interfere with either UIs.

* Add `tracing.push`/`tracing.pop` for complete events, change a few
  `.begin`/`.end` to use these.  (The caveat is that until there's an exit
  handler to dump unterminated events, these won't show in the dump.  When
  that's done the push/pop variant can be used everywhere.)

* Add meta lines to name the process and the thread, and a line that
  avoids the warning when opening in devtools.
This commit is contained in:
Eli Barzilay
2020-09-17 14:25:28 -04:00
parent 5d021b401a
commit fe7ec1ee2e
7 changed files with 77 additions and 59 deletions
Download Patch File Download Diff File Expand all files Collapse all files

5
src/compiler/binder.ts
View File

@@ -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 {

21
src/compiler/checker.ts
View File

@@ -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<TCache extends { variances?: VarianceFlags[] }>(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 {

12
src/compiler/emitter.ts
View File

@@ -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) {

5
src/compiler/parser.ts
View File

@@ -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;
}

15
src/compiler/program.ts
View File

@@ -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<string, boolean>();
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;
}

74
src/compiler/tracing.ts
View File

@@ -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);
performance.mark("beginTracing");
fs.writeSync(traceFd, `{"pid":1,"tid":1,"ph":"E","ts":${1000 * timestamp()}},\n`);
performance.mark("endTracing");
performance.measure("Tracing", "beginTracing", "endTracing");
export function instant(phase: Phase, name: string, args?: object) {
writeEvent("I", phase, name, args, `"s":"g"`);
}
export function instant(phase: Phase, name: string, args: object) {
if (!traceFd) {
return;
}
Debug.assert(fs);
// 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);
}
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");
}

4
src/compiler/transformer.ts
View File

@@ -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.