From 5d60972ef452ef50fe4802c89489f9155ee821ba Mon Sep 17 00:00:00 2001 From: Andrew Casey Date: Thu, 6 Aug 2020 11:02:51 -0700 Subject: [PATCH 1/6] Trace key operations Produce output in Chrome's event tracing format so that it can be viewed in Chrome/Edge. --- src/compiler/binder.ts | 2 + src/compiler/checker.ts | 25 +++- src/compiler/commandLineParser.ts | 8 + src/compiler/diagnosticMessages.json | 4 + src/compiler/emitter.ts | 8 + src/compiler/parser.ts | 2 + src/compiler/program.ts | 10 +- src/compiler/sys.ts | 29 +++- src/compiler/tracing.ts | 140 ++++++++++++++++++ src/compiler/transformer.ts | 7 +- src/compiler/tsbuildPublic.ts | 1 + src/compiler/tsconfig.json | 1 + src/compiler/types.ts | 5 + src/compiler/utilities.ts | 2 +- src/executeCommandLine/executeCommandLine.ts | 41 ++++- src/harness/fakesHosts.ts | 12 +- src/harness/harnessLanguageService.ts | 6 +- src/harness/virtualFileSystemWithWatch.ts | 12 +- src/testRunner/unittests/tsserver/session.ts | 4 +- .../reference/api/tsserverlibrary.d.ts | 5 +- tests/baselines/reference/api/typescript.d.ts | 5 +- .../generateTrace/tsconfig.json | 5 + 22 files changed, 315 insertions(+), 19 deletions(-) create mode 100644 src/compiler/tracing.ts create mode 100644 tests/baselines/reference/showConfig/Shows tsconfig for single option/generateTrace/tsconfig.json diff --git a/src/compiler/binder.ts b/src/compiler/binder.ts index 1003b23b455ec..0451ab38f9124 100644 --- a/src/compiler/binder.ts +++ b/src/compiler/binder.ts @@ -174,12 +174,14 @@ namespace ts { const binder = createBinder(); export function bindSourceFile(file: SourceFile, options: CompilerOptions) { + tracing.begin(tracing.Phase.Bind, "bindSourceFile", { path: file.path }); performance.mark("beforeBind"); perfLogger.logStartBindFile("" + file.fileName); binder(file, options); perfLogger.logStopBindFile(); performance.mark("afterBind"); performance.measure("Bind", "beforeBind", "afterBind"); + tracing.end(); } function createBinder(): (file: SourceFile, options: CompilerOptions) => void { diff --git a/src/compiler/checker.ts b/src/compiler/checker.ts index a85281375e6b9..55bc2657a9f52 100644 --- a/src/compiler/checker.ts +++ b/src/compiler/checker.ts @@ -317,6 +317,8 @@ namespace ts { let constraintDepth = 0; let currentNode: Node | undefined; + const typeCatalog: Type[] = []; // NB: id is index + 1 + const emptySymbols = createSymbolTable(); const arrayVariances = [VarianceFlags.Covariant]; @@ -360,6 +362,7 @@ namespace ts { getNodeCount: () => sum(host.getSourceFiles(), "nodeCount"), getIdentifierCount: () => sum(host.getSourceFiles(), "identifierCount"), getSymbolCount: () => sum(host.getSourceFiles(), "symbolCount") + symbolCount, + getTypeCatalog: () => typeCatalog, getTypeCount: () => typeCount, getInstantiationCount: () => totalInstantiationCount, getRelationCacheSizes: () => ({ @@ -3661,6 +3664,7 @@ namespace ts { const result = new Type(checker, flags); typeCount++; result.id = typeCount; + typeCatalog.push(result); return result; } @@ -16031,6 +16035,7 @@ namespace ts { containingMessageChain?: () => DiagnosticMessageChain | undefined, errorOutputContainer?: { errors?: Diagnostic[], skipLogging?: boolean }, ): boolean { + let errorInfo: DiagnosticMessageChain | undefined; let relatedInfo: [DiagnosticRelatedInformation, ...DiagnosticRelatedInformation[]] | undefined; let maybeKeys: string[]; @@ -16093,6 +16098,8 @@ namespace ts { if (errorNode && errorOutputContainer && errorOutputContainer.skipLogging && result === Ternary.False) { Debug.assert(!!errorOutputContainer.errors, "missed opportunity to interact with error."); } + + return result !== Ternary.False; function resetErrorInfo(saved: ReturnType) { @@ -16811,6 +16818,13 @@ namespace ts { // equal and infinitely expanding. Fourth, if we have reached a depth of 100 nested comparisons, assume we have runaway recursion // and issue an error. Otherwise, actually compare the structure of the two types. function recursiveTypeRelatedTo(source: Type, target: Type, reportErrors: boolean, intersectionState: IntersectionState): Ternary { + tracing.begin(tracing.Phase.Check, "recursiveTypeRelatedTo", { sourceId: source.id, targetId: target.id }); + const result = recursiveTypeRelatedToWorker(source, target, reportErrors, intersectionState); + tracing.end(); + return result; + } + + function recursiveTypeRelatedToWorker(source: Type, target: Type, reportErrors: boolean, intersectionState: IntersectionState): Ternary { if (overflow) { return Ternary.False; } @@ -18082,6 +18096,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 }); // The emptyArray singleton is used to signal a recursive invocation. cache.variances = emptyArray; variances = []; @@ -18116,6 +18131,7 @@ namespace ts { variances.push(variance); } cache.variances = variances; + tracing.end(); } return variances; } @@ -19369,6 +19385,7 @@ namespace ts { inferFromTypes(originalSource, originalTarget); function inferFromTypes(source: Type, target: Type): void { + if (!couldContainTypeVariables(target)) { return; } @@ -30257,6 +30274,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 }); const saveCurrentNode = currentNode; currentNode = node; instantiationCount = 0; @@ -30266,6 +30284,7 @@ namespace ts { checkConstEnumAccess(node, type); } currentNode = saveCurrentNode; + tracing.end(); return type; } @@ -33032,8 +33051,10 @@ namespace ts { } function checkVariableDeclaration(node: VariableDeclaration) { + tracing.begin(tracing.Phase.Check, "checkVariableDeclaration", { kind: node.kind, pos: node.pos, end: node.end }); checkGrammarVariableDeclaration(node); - return checkVariableLikeDeclaration(node); + checkVariableLikeDeclaration(node); + tracing.end(); } function checkBindingElement(node: BindingElement) { @@ -36069,10 +36090,12 @@ namespace ts { } function checkSourceFile(node: SourceFile) { + tracing.begin(tracing.Phase.Check, "checkSourceFile", { path: node.path }); performance.mark("beforeCheck"); checkSourceFileWorker(node); performance.mark("afterCheck"); performance.measure("Check", "beforeCheck", "afterCheck"); + tracing.end(); } function unusedIsError(kind: UnusedKind, isAmbient: boolean): boolean { diff --git a/src/compiler/commandLineParser.ts b/src/compiler/commandLineParser.ts index 3095c9d7dc82e..e994be70d7377 100644 --- a/src/compiler/commandLineParser.ts +++ b/src/compiler/commandLineParser.ts @@ -197,6 +197,14 @@ namespace ts { category: Diagnostics.Advanced_Options, description: Diagnostics.Generates_a_CPU_profile }, + { + name: "generateTrace", + type: "string", + isFilePath: true, + paramType: Diagnostics.FILE_OR_DIRECTORY, + category: Diagnostics.Advanced_Options, + description: Diagnostics.Generates_an_event_trace_and_a_list_of_types + }, { name: "incremental", shortName: "i", diff --git a/src/compiler/diagnosticMessages.json b/src/compiler/diagnosticMessages.json index a5a7c2b3d3d12..a134d9afbc314 100644 --- a/src/compiler/diagnosticMessages.json +++ b/src/compiler/diagnosticMessages.json @@ -4486,6 +4486,10 @@ "category": "Error", "code": 6236 }, + "Generates an event trace and a list of types.": { + "category": "Message", + "code": 6237 + }, "Projects to reference": { "category": "Message", diff --git a/src/compiler/emitter.ts b/src/compiler/emitter.ts index e273a40511967..ce2f940acbb91 100644 --- a/src/compiler/emitter.ts +++ b/src/compiler/emitter.ts @@ -300,9 +300,17 @@ namespace ts { sourceFiles: sourceFileOrBundle.sourceFiles.map(file => relativeToBuildInfo(getNormalizedAbsolutePath(file.fileName, host.getCurrentDirectory()))) }; } + tracing.begin(tracing.Phase.Emit, "emitJsFileOrBundle", { jsFilePath }); emitJsFileOrBundle(sourceFileOrBundle, jsFilePath, sourceMapFilePath, relativeToBuildInfo); + tracing.end(); + + tracing.begin(tracing.Phase.Emit, "emitDeclarationFileOrBundle", { declarationFilePath }); emitDeclarationFileOrBundle(sourceFileOrBundle, declarationFilePath, declarationMapPath, relativeToBuildInfo); + tracing.end(); + + tracing.begin(tracing.Phase.Emit, "emitBuildInfo", { buildInfoPath }); emitBuildInfo(bundleBuildInfo, buildInfoPath); + tracing.end(); if (!emitSkipped && emittedFilesList) { if (!emitOnlyDtsFiles) { diff --git a/src/compiler/parser.ts b/src/compiler/parser.ts index d7655812e9b87..f5c8cfeceeb90 100644 --- a/src/compiler/parser.ts +++ b/src/compiler/parser.ts @@ -604,6 +604,7 @@ namespace ts { } export function createSourceFile(fileName: string, sourceText: string, languageVersion: ScriptTarget, setParentNodes = false, scriptKind?: ScriptKind): SourceFile { + tracing.begin(tracing.Phase.Parse, "createSourceFile", { path: fileName }); performance.mark("beforeParse"); let result: SourceFile; @@ -618,6 +619,7 @@ namespace ts { performance.mark("afterParse"); performance.measure("Parse", "beforeParse", "afterParse"); + tracing.end(); return result; } diff --git a/src/compiler/program.ts b/src/compiler/program.ts index 5703181e90a35..a8fe79d12c702 100644 --- a/src/compiler/program.ts +++ b/src/compiler/program.ts @@ -734,6 +734,7 @@ 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", {}); performance.mark("beforeProgram"); const host = createProgramOptions.host || createCompilerHost(options); @@ -948,6 +949,7 @@ namespace ts { getNodeCount: () => getDiagnosticsProducingTypeChecker().getNodeCount(), getIdentifierCount: () => getDiagnosticsProducingTypeChecker().getIdentifierCount(), getSymbolCount: () => getDiagnosticsProducingTypeChecker().getSymbolCount(), + getTypeCatalog: () => getDiagnosticsProducingTypeChecker().getTypeCatalog(), getTypeCount: () => getDiagnosticsProducingTypeChecker().getTypeCount(), getInstantiationCount: () => getDiagnosticsProducingTypeChecker().getInstantiationCount(), getRelationCacheSizes: () => getDiagnosticsProducingTypeChecker().getRelationCacheSizes(), @@ -982,6 +984,7 @@ namespace ts { verifyCompilerOptions(); performance.mark("afterProgram"); performance.measure("Program", "beforeProgram", "afterProgram"); + tracing.end(); return program; @@ -1505,6 +1508,7 @@ namespace ts { function emitBuildInfo(writeFileCallback?: WriteFileCallback): EmitResult { Debug.assert(!outFile(options)); + tracing.begin(tracing.Phase.Emit, "emitBuildInfo", {}); performance.mark("beforeEmit"); const emitResult = emitFiles( notImplementedResolver, @@ -1517,6 +1521,7 @@ namespace ts { performance.mark("afterEmit"); performance.measure("Emit", "beforeEmit", "afterEmit"); + tracing.end(); return emitResult; } @@ -1577,7 +1582,10 @@ namespace ts { } function emit(sourceFile?: SourceFile, writeFileCallback?: WriteFileCallback, cancellationToken?: CancellationToken, emitOnlyDtsFiles?: boolean, transformers?: CustomTransformers, forceDtsEmit?: boolean): EmitResult { - return runWithCancellationToken(() => emitWorker(program, sourceFile, writeFileCallback, cancellationToken, emitOnlyDtsFiles, transformers, forceDtsEmit)); + tracing.begin(tracing.Phase.Emit, "emit", { path: sourceFile?.path }); + const result = runWithCancellationToken(() => emitWorker(program, sourceFile, writeFileCallback, cancellationToken, emitOnlyDtsFiles, transformers, forceDtsEmit)); + tracing.end(); + return result; } function isEmitBlocked(emitFileName: string): boolean { diff --git a/src/compiler/sys.ts b/src/compiler/sys.ts index efa51678f4da0..3f877666a0d6b 100644 --- a/src/compiler/sys.ts +++ b/src/compiler/sys.ts @@ -1047,11 +1047,13 @@ namespace ts { args: string[]; newLine: string; useCaseSensitiveFileNames: boolean; - write(s: string): void; + write(s: string, fd?: number): void; writeOutputIsTTY?(): boolean; readFile(path: string, encoding?: string): string | undefined; getFileSize?(path: string): number; writeFile(path: string, data: string, writeByteOrderMark?: boolean): void; + openFile(path: string, mode: "w"): number | undefined; + closeFile(fd: number): void; /** * @pollingInterval - this parameter is used in polling-based watchers and ignored in watchers that @@ -1183,12 +1185,33 @@ namespace ts { args: process.argv.slice(2), newLine: _os.EOL, useCaseSensitiveFileNames, - write(s: string): void { - process.stdout.write(s); + write(s: string, fd?: number): void { + if (fd) { + _fs.writeSync(fd, s); + } + else { + process.stdout.write(s); + } }, writeOutputIsTTY() { return process.stdout.isTTY; }, + openFile: (path, mode) => { + try { + return _fs.openSync(path, mode); + } + catch { + return undefined; + } + }, + closeFile: (fd) => { + try { + _fs.closeSync(fd); + } + catch { + // ignore + } + }, readFile, writeFile, watchFile, diff --git a/src/compiler/tracing.ts b/src/compiler/tracing.ts new file mode 100644 index 0000000000000..5391ecafd0540 --- /dev/null +++ b/src/compiler/tracing.ts @@ -0,0 +1,140 @@ +/*@internal*/ +/** Tracing events for the compiler. */ +namespace ts.tracing { + type WriteFn = (data: string) => void; + + let write: WriteFn | undefined; + + /** Enables (and resets) tracing events for the compiler. */ + export function startTracing(w: WriteFn) { + write = w; + write(`[\n`); + } + + /** Disables tracing events for the compiler. */ + export function stopTracing() { + // This both indicates that the trace is untruncated and conveniently + // ensures that the last array element won't have a trailing comma. + write?.(`{"pid":1,"tid":1,"ph":"i","ts":${1000 * timestamp()},"name":"done","s":"g"}\n`); + write?.(`]\n`); + write = undefined; + } + + export function isTracing() { + return !!write; + } + + export const enum Phase { + Parse = "parse", + Program = "program", + Bind = "bind", + Check = "check", + Emit = "emit", + } + + export function begin(phase: Phase, name: string, args: object) { + performance.mark("beginTracing"); + write?.(`{"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"); + } + + export function end() { + performance.mark("beginTracing"); + write?.(`{"pid":1,"tid":1,"ph":"E","ts":${1000 * timestamp()}},\n`); + performance.mark("endTracing"); + performance.measure("Tracing", "beginTracing", "endTracing"); + } + + function indexFromOne(lc: LineAndCharacter): LineAndCharacter { + return { + line: lc.line + 1, + character: lc.character + 1, + }; + } + + export function dumpTypes(types: readonly Type[], write: WriteFn) { + performance.mark("beginDumpTypes"); + + const numTypes = types.length; + + // Cleverness: no line break hear so that the type ID will match the line number + write("["); + for (let i = 0; i < numTypes; i++) { + const type = types[i]; + const objectFlags = (type as any).objectFlags; + const symbol = type.aliasSymbol ?? type.symbol; + const firstDeclaration = symbol?.declarations?.[0]; + const firstFile = firstDeclaration && getSourceFileOfNode(firstDeclaration); + + // It's slow to compute the display text, so skip it unless it's really valuable (or cheap) + let display: string | undefined; + if ((objectFlags & ObjectFlags.Anonymous) | (type.flags & TypeFlags.Literal)) { + try { + display = type.checker?.typeToString(type); + } + catch { + display = undefined; + } + } + + let indexedAccessProperties: object = {}; + if (type.flags & TypeFlags.IndexedAccess) { + const indexedAccessType = type as IndexedAccessType; + indexedAccessProperties = { + indexedAccessObjectType: indexedAccessType.objectType?.id, + indexedAccessIndexType: indexedAccessType.indexType?.id, + }; + } + + let referenceProperties: object = {}; + if (objectFlags & ObjectFlags.Reference) { + const referenceType = type as TypeReference; + referenceProperties = { + instantiatedType: referenceType.target?.id, + typeArguments: referenceType.resolvedTypeArguments?.map(t => t.id), + }; + } + + let conditionalProperties: object = {}; + if (type.flags & TypeFlags.Conditional) { + const conditionalType = type as ConditionalType; + conditionalProperties = { + conditionalCheckType: conditionalType.checkType?.id, + conditionalExtendsType: conditionalType.extendsType?.id, + conditionalTrueType: conditionalType.resolvedTrueType?.id ?? -1, + conditionalFalseType: conditionalType.resolvedFalseType?.id ?? -1, + }; + } + + const descriptor = { + id: type.id, + intrinsicName: (type as any).intrinsicName, + symbolName: symbol?.escapedName && unescapeLeadingUnderscores(symbol.escapedName), + unionTypes: (type.flags & TypeFlags.Union) ? (type as UnionType).types?.map(t => t.id) : undefined, + intersectionTypes: (type.flags & TypeFlags.Intersection) ? (type as IntersectionType).types.map(t => t.id) : undefined, + aliasTypeArguments: type.aliasTypeArguments?.map(t => t.id), + keyofType: (type.flags & TypeFlags.Index) ? (type as IndexType).type?.id : undefined, + ...indexedAccessProperties, + ...referenceProperties, + ...conditionalProperties, + firstDeclaration: firstDeclaration && { + path: firstFile.path, + start: indexFromOne(getLineAndCharacterOfPosition(firstFile, firstDeclaration.pos)), + end: indexFromOne(getLineAndCharacterOfPosition(getSourceFileOfNode(firstDeclaration), firstDeclaration.end)), + }, + flags: Debug.formatTypeFlags(type.flags).split("|"), + display, + }; + + write(JSON.stringify(descriptor)); + if (i < numTypes - 1) { + write(",\n"); + } + } + write("]\n"); + + performance.mark("endDumpTypes"); + performance.measure("Dump types", "beginDumpTypes", "endDumpTypes"); + } +} diff --git a/src/compiler/transformer.ts b/src/compiler/transformer.ts index 2ed0e6ad93162..2172d152412df 100644 --- a/src/compiler/transformer.ts +++ b/src/compiler/transformer.ts @@ -222,7 +222,12 @@ namespace ts { state = TransformationState.Initialized; // Transform each node. - const transformed = map(nodes, allowDtsFiles ? transformation : transformRoot); + 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 }); + transformed.push((allowDtsFiles ? transformation : transformRoot)(node)); + tracing.end(); + } // prevent modification of the lexical environment. state = TransformationState.Completed; diff --git a/src/compiler/tsbuildPublic.ts b/src/compiler/tsbuildPublic.ts index a9e2c9a4a95e1..8d1c59fb3fd80 100644 --- a/src/compiler/tsbuildPublic.ts +++ b/src/compiler/tsbuildPublic.ts @@ -23,6 +23,7 @@ namespace ts { /* @internal */ extendedDiagnostics?: boolean; /* @internal */ locale?: string; /* @internal */ generateCpuProfile?: string; + /* @internal */ generateTrace?: string; [option: string]: CompilerOptionsValue | undefined; } diff --git a/src/compiler/tsconfig.json b/src/compiler/tsconfig.json index 8213e019b340e..1edb2bbd63da3 100644 --- a/src/compiler/tsconfig.json +++ b/src/compiler/tsconfig.json @@ -17,6 +17,7 @@ "performance.ts", "perfLogger.ts", "semver.ts", + "tracing.ts", "types.ts", "sys.ts", diff --git a/src/compiler/types.ts b/src/compiler/types.ts index 40f43b3ad6bbc..5e8ba2786a536 100644 --- a/src/compiler/types.ts +++ b/src/compiler/types.ts @@ -3729,6 +3729,8 @@ namespace ts { /* @internal */ getClassifiableNames(): Set<__String>; + getTypeCatalog(): readonly Type[]; + getNodeCount(): number; getIdentifierCount(): number; getSymbolCount(): number; @@ -4063,6 +4065,8 @@ namespace ts { /* @internal */ getGlobalDiagnostics(): Diagnostic[]; /* @internal */ getEmitResolver(sourceFile?: SourceFile, cancellationToken?: CancellationToken): EmitResolver; + /* @internal */ getTypeCatalog(): readonly Type[]; + /* @internal */ getNodeCount(): number; /* @internal */ getIdentifierCount(): number; /* @internal */ getSymbolCount(): number; @@ -5675,6 +5679,7 @@ namespace ts { experimentalDecorators?: boolean; forceConsistentCasingInFileNames?: boolean; /*@internal*/generateCpuProfile?: string; + /*@internal*/generateTrace?: string; /*@internal*/help?: boolean; importHelpers?: boolean; importsNotUsedAsValues?: ImportsNotUsedAsValues; diff --git a/src/compiler/utilities.ts b/src/compiler/utilities.ts index 6b58a9aafd6d3..17b45554cff4f 100644 --- a/src/compiler/utilities.ts +++ b/src/compiler/utilities.ts @@ -5520,7 +5520,7 @@ namespace ts { function Type(this: Type, checker: TypeChecker, flags: TypeFlags) { this.flags = flags; - if (Debug.isDebugging) { + if (Debug.isDebugging || tracing.isTracing()) { this.checker = checker; } } diff --git a/src/executeCommandLine/executeCommandLine.ts b/src/executeCommandLine/executeCommandLine.ts index 9d1ecc7c66621..ebe27c25593b6 100644 --- a/src/executeCommandLine/executeCommandLine.ts +++ b/src/executeCommandLine/executeCommandLine.ts @@ -476,7 +476,7 @@ namespace ts { const currentDirectory = host.getCurrentDirectory(); const getCanonicalFileName = createGetCanonicalFileName(host.useCaseSensitiveFileNames()); changeCompilerHostLikeToUseCache(host, fileName => toPath(fileName, currentDirectory, getCanonicalFileName)); - enableStatistics(sys, options); + enableStatisticsAndTracing(sys, options); const programOptions: CreateProgramOptions = { rootNames: fileNames, @@ -504,7 +504,7 @@ namespace ts { config: ParsedCommandLine ) { const { options, fileNames, projectReferences } = config; - enableStatistics(sys, options); + enableStatisticsAndTracing(sys, options); const host = createIncrementalCompilerHost(options, sys); const exitStatus = ts.performIncrementalCompilation({ host, @@ -541,7 +541,7 @@ namespace ts { host.createProgram = (rootNames, options, host, oldProgram, configFileParsingDiagnostics, projectReferences) => { Debug.assert(rootNames !== undefined || (options === undefined && !!oldProgram)); if (options !== undefined) { - enableStatistics(sys, options); + enableStatisticsAndTracing(sys, options); } return compileUsingBuilder(rootNames, options, host, oldProgram, configFileParsingDiagnostics, projectReferences); }; @@ -610,15 +610,44 @@ namespace ts { return system === sys && (compilerOptions.diagnostics || compilerOptions.extendedDiagnostics); } - function enableStatistics(sys: System, compilerOptions: CompilerOptions) { - if (canReportDiagnostics(sys, compilerOptions)) { + let traceCount = 0; + let tracingFd: number | undefined; + + function enableStatisticsAndTracing(system: System, compilerOptions: CompilerOptions) { + if (canReportDiagnostics(system, compilerOptions)) { performance.enable(); } + + Debug.assert(!tracingFd, "Tracing already started"); + if (system === sys) { + const tracePath = compilerOptions.generateTrace; + if (tracePath) { + const extension = getAnyExtensionFromPath(tracePath); + tracingFd = sys.openFile(changeAnyExtension(tracePath, `${++traceCount}${extension}`), "w"); + if (tracingFd) { + tracing.startTracing(event => sys.write(event, tracingFd)); + } + } + } } function reportStatistics(sys: System, program: Program) { - let statistics: Statistic[]; const compilerOptions = program.getCompilerOptions(); + + if (tracingFd) { + tracing.stopTracing(); + sys.closeFile(tracingFd); + tracingFd = undefined; + + const typesPath = changeAnyExtension(compilerOptions.generateTrace!, `${traceCount}.types.json`); + const typesFd = sys.openFile(typesPath, "w"); + if (typesFd) { + tracing.dumpTypes(program.getTypeCatalog(), type => sys.write(type, typesFd)); + sys.closeFile(typesFd); + } + } + + let statistics: Statistic[]; if (canReportDiagnostics(sys, compilerOptions)) { statistics = []; const memoryUsed = sys.getMemoryUsage ? sys.getMemoryUsage() : -1; diff --git a/src/harness/fakesHosts.ts b/src/harness/fakesHosts.ts index 8d7db1d333cb3..d6b4f1d5599c9 100644 --- a/src/harness/fakesHosts.ts +++ b/src/harness/fakesHosts.ts @@ -37,7 +37,8 @@ namespace fakes { return true; } - public write(message: string) { + public write(message: string, fd?: number) { + assert.isUndefined(fd); this.output.push(message); } @@ -60,6 +61,15 @@ namespace fakes { this.vfs.unlinkSync(path); } + public openFile(_path: string, _mode: "w"): number | undefined { + assert.fail("NYI"); + return undefined; + } + + public closeFile(_fd: number): void{ + assert.fail("NYI"); + } + public fileExists(path: string) { const stats = this._getStats(path); return stats ? stats.isFile() : false; diff --git a/src/harness/harnessLanguageService.ts b/src/harness/harnessLanguageService.ts index 69d7238cbec15..0993438c2f001 100644 --- a/src/harness/harnessLanguageService.ts +++ b/src/harness/harnessLanguageService.ts @@ -724,7 +724,8 @@ namespace Harness.LanguageService { onMessage = ts.noop; writeMessage = ts.noop; // overridden - write(message: string): void { + write(message: string, fd?: number): void { + assert.isUndefined(fd); this.writeMessage(message); } @@ -744,6 +745,9 @@ namespace Harness.LanguageService { writeFile = ts.noop; + openFile = ts.returnUndefined; + closeFile = ts.noop; + resolvePath(path: string): string { return path; } diff --git a/src/harness/virtualFileSystemWithWatch.ts b/src/harness/virtualFileSystemWithWatch.ts index c0e66430e9a06..6036b74187a61 100644 --- a/src/harness/virtualFileSystemWithWatch.ts +++ b/src/harness/virtualFileSystemWithWatch.ts @@ -1011,11 +1011,21 @@ interface Array { length: number; [n: number]: T; }` } } + openFile(_path: string, _mode: "w"): number | undefined { + assert.fail("NYI"); + return undefined; + } + + closeFile(_fd: number): void { + assert.fail("NYI"); + } + appendFile(path: string, content: string, options?: Partial): void { this.modifyFile(path, this.readFile(path) + content, options); } - write(message: string) { + write(message: string, fd?: number) { + assert.isUndefined(fd); this.output.push(message); } diff --git a/src/testRunner/unittests/tsserver/session.ts b/src/testRunner/unittests/tsserver/session.ts index 8084b79056b30..646b435407a03 100644 --- a/src/testRunner/unittests/tsserver/session.ts +++ b/src/testRunner/unittests/tsserver/session.ts @@ -7,9 +7,11 @@ namespace ts.server { args: [], newLine: "\n", useCaseSensitiveFileNames: true, - write(s): void { lastWrittenToHost = s; }, + write(s, _fd: number): void { lastWrittenToHost = s; }, readFile: returnUndefined, writeFile: noop, + openFile: returnUndefined, + closeFile: noop, resolvePath(): string { return undefined!; }, // TODO: GH#18217 fileExists: () => false, directoryExists: () => false, diff --git a/tests/baselines/reference/api/tsserverlibrary.d.ts b/tests/baselines/reference/api/tsserverlibrary.d.ts index 142dc3a9e7d29..58341d0e9f135 100644 --- a/tests/baselines/reference/api/tsserverlibrary.d.ts +++ b/tests/baselines/reference/api/tsserverlibrary.d.ts @@ -2053,6 +2053,7 @@ declare namespace ts { * Gets a type checker that can be used to semantically analyze source files in the program. */ getTypeChecker(): TypeChecker; + getTypeCatalog(): readonly Type[]; getNodeCount(): number; getIdentifierCount(): number; getSymbolCount(): number; @@ -3840,11 +3841,13 @@ declare namespace ts { args: string[]; newLine: string; useCaseSensitiveFileNames: boolean; - write(s: string): void; + write(s: string, fd?: number): void; writeOutputIsTTY?(): boolean; readFile(path: string, encoding?: string): string | undefined; getFileSize?(path: string): number; writeFile(path: string, data: string, writeByteOrderMark?: boolean): void; + openFile(path: string, mode: "w"): number | undefined; + closeFile(fd: number): void; /** * @pollingInterval - this parameter is used in polling-based watchers and ignored in watchers that * use native OS file watching diff --git a/tests/baselines/reference/api/typescript.d.ts b/tests/baselines/reference/api/typescript.d.ts index 86432ff0efad4..34301d0e5cb14 100644 --- a/tests/baselines/reference/api/typescript.d.ts +++ b/tests/baselines/reference/api/typescript.d.ts @@ -2053,6 +2053,7 @@ declare namespace ts { * Gets a type checker that can be used to semantically analyze source files in the program. */ getTypeChecker(): TypeChecker; + getTypeCatalog(): readonly Type[]; getNodeCount(): number; getIdentifierCount(): number; getSymbolCount(): number; @@ -3840,11 +3841,13 @@ declare namespace ts { args: string[]; newLine: string; useCaseSensitiveFileNames: boolean; - write(s: string): void; + write(s: string, fd?: number): void; writeOutputIsTTY?(): boolean; readFile(path: string, encoding?: string): string | undefined; getFileSize?(path: string): number; writeFile(path: string, data: string, writeByteOrderMark?: boolean): void; + openFile(path: string, mode: "w"): number | undefined; + closeFile(fd: number): void; /** * @pollingInterval - this parameter is used in polling-based watchers and ignored in watchers that * use native OS file watching diff --git a/tests/baselines/reference/showConfig/Shows tsconfig for single option/generateTrace/tsconfig.json b/tests/baselines/reference/showConfig/Shows tsconfig for single option/generateTrace/tsconfig.json new file mode 100644 index 0000000000000..d02fdafbf84db --- /dev/null +++ b/tests/baselines/reference/showConfig/Shows tsconfig for single option/generateTrace/tsconfig.json @@ -0,0 +1,5 @@ +{ + "compilerOptions": { + "generateTrace": "./someString" + } +} From a0479da1e51da0f79aa188b4d39f1dd4628b428b Mon Sep 17 00:00:00 2001 From: Andrew Casey Date: Thu, 20 Aug 2020 18:04:38 -0700 Subject: [PATCH 2/6] Revert System changes and consume fs directly --- src/compiler/commandLineParser.ts | 3 +- src/compiler/sys.ts | 29 +--- src/compiler/tracing.ts | 131 +++++++++++++++--- src/executeCommandLine/executeCommandLine.ts | 39 ++---- src/harness/fakesHosts.ts | 12 +- src/harness/harnessLanguageService.ts | 6 +- src/harness/virtualFileSystemWithWatch.ts | 12 +- src/testRunner/unittests/tsserver/session.ts | 4 +- .../reference/api/tsserverlibrary.d.ts | 4 +- tests/baselines/reference/api/typescript.d.ts | 4 +- 10 files changed, 133 insertions(+), 111 deletions(-) diff --git a/src/compiler/commandLineParser.ts b/src/compiler/commandLineParser.ts index e994be70d7377..fd0c64fb515f9 100644 --- a/src/compiler/commandLineParser.ts +++ b/src/compiler/commandLineParser.ts @@ -201,7 +201,8 @@ namespace ts { name: "generateTrace", type: "string", isFilePath: true, - paramType: Diagnostics.FILE_OR_DIRECTORY, + isCommandLineOnly: true, + paramType: Diagnostics.DIRECTORY, category: Diagnostics.Advanced_Options, description: Diagnostics.Generates_an_event_trace_and_a_list_of_types }, diff --git a/src/compiler/sys.ts b/src/compiler/sys.ts index 3f877666a0d6b..efa51678f4da0 100644 --- a/src/compiler/sys.ts +++ b/src/compiler/sys.ts @@ -1047,13 +1047,11 @@ namespace ts { args: string[]; newLine: string; useCaseSensitiveFileNames: boolean; - write(s: string, fd?: number): void; + write(s: string): void; writeOutputIsTTY?(): boolean; readFile(path: string, encoding?: string): string | undefined; getFileSize?(path: string): number; writeFile(path: string, data: string, writeByteOrderMark?: boolean): void; - openFile(path: string, mode: "w"): number | undefined; - closeFile(fd: number): void; /** * @pollingInterval - this parameter is used in polling-based watchers and ignored in watchers that @@ -1185,33 +1183,12 @@ namespace ts { args: process.argv.slice(2), newLine: _os.EOL, useCaseSensitiveFileNames, - write(s: string, fd?: number): void { - if (fd) { - _fs.writeSync(fd, s); - } - else { - process.stdout.write(s); - } + write(s: string): void { + process.stdout.write(s); }, writeOutputIsTTY() { return process.stdout.isTTY; }, - openFile: (path, mode) => { - try { - return _fs.openSync(path, mode); - } - catch { - return undefined; - } - }, - closeFile: (fd) => { - try { - _fs.closeSync(fd); - } - catch { - // ignore - } - }, readFile, writeFile, watchFile, diff --git a/src/compiler/tracing.ts b/src/compiler/tracing.ts index 5391ecafd0540..c7f2add068a64 100644 --- a/src/compiler/tracing.ts +++ b/src/compiler/tracing.ts @@ -1,27 +1,83 @@ /*@internal*/ /** Tracing events for the compiler. */ namespace ts.tracing { - type WriteFn = (data: string) => void; + let fs: typeof import("fs") | false | undefined; - let write: WriteFn | undefined; + let traceCount = 0; + let traceFd: number | undefined; - /** Enables (and resets) tracing events for the compiler. */ - export function startTracing(w: WriteFn) { - write = w; - write(`[\n`); + let legendPath: string | undefined; + const legend: TraceRecord[] = []; + + /** Starts tracing for the given project (unless the `fs` module is unavailable). */ + export function startTracing(configFilePath: string | undefined, traceDir: string, isBuildMode: boolean) { + Debug.assert(!traceFd, "Tracing already started"); + + if (fs === undefined) { + try { + fs = require("fs"); + } + catch { + fs = false; + } + } + + if (!fs) { + return; + } + + if (legendPath === undefined) { + legendPath = combinePaths(traceDir, "legend.json"); + } + + // Note that writing will fail later on if it exists and is not a directory + if (!fs.existsSync(traceDir)) { + fs.mkdirSync(traceDir, { recursive: true }); + } + + const countPart = isBuildMode ? `.${++traceCount}` : ``; + const tracePath = combinePaths(traceDir, `trace${countPart}.json`); + const typesPath = combinePaths(traceDir, `types${countPart}.json`); + + legend.push({ + configFilePath, + tracePath, + typesPath, + }); + + traceFd = fs.openSync(tracePath, "w"); + fs.writeSync(traceFd, `[\n`); } - /** Disables tracing events for the compiler. */ - export function stopTracing() { + /** Stops tracing for the in-progress project and dumps the type catalog (unless the `fs` module is unavailable). */ + export function stopTracing(typeCatalog: readonly Type[]) { + if (!traceFd) { + Debug.assert(!fs, "Tracing is not in progress"); + return; + } + + 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. - write?.(`{"pid":1,"tid":1,"ph":"i","ts":${1000 * timestamp()},"name":"done","s":"g"}\n`); - write?.(`]\n`); - write = undefined; + fs.writeSync(traceFd, `{"pid":1,"tid":1,"ph":"i","ts":${1000 * timestamp()},"name":"done","s":"g"}\n`); + fs.writeSync(traceFd, `]\n`); + + fs.closeSync(traceFd); + traceFd = undefined; + + if (typeCatalog) { + dumpTypes(typeCatalog); + } + else { + // We pre-computed this path for convenience, but clear it + // now that the file won't be created. + legend[legend.length - 1].typesPath = undefined; + } } export function isTracing() { - return !!write; + return !!traceFd; } export const enum Phase { @@ -33,15 +89,25 @@ namespace ts.tracing { } export function begin(phase: Phase, name: string, args: object) { + if (!traceFd) { + return; + } + Debug.assert(fs); + performance.mark("beginTracing"); - write?.(`{"pid":1,"tid":1,"ph":"B","cat":"${phase}","ts":${1000 * timestamp()},"name":"${name}","args":{ "ts": ${JSON.stringify(args)} }},\n`); + 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"); } export function end() { + if (!traceFd) { + return; + } + Debug.assert(fs); + performance.mark("beginTracing"); - write?.(`{"pid":1,"tid":1,"ph":"E","ts":${1000 * timestamp()}},\n`); + fs.writeSync(traceFd, `{"pid":1,"tid":1,"ph":"E","ts":${1000 * timestamp()}},\n`); performance.mark("endTracing"); performance.measure("Tracing", "beginTracing", "endTracing"); } @@ -53,13 +119,18 @@ namespace ts.tracing { }; } - export function dumpTypes(types: readonly Type[], write: WriteFn) { + function dumpTypes(types: readonly Type[]) { + Debug.assert(fs); + performance.mark("beginDumpTypes"); - const numTypes = types.length; + const typesPath = legend[legend.length - 1].typesPath!; + const typesFd = fs.openSync(typesPath, "w"); + + // Cleverness: no line break here so that the type ID will match the line number + fs.writeSync(typesFd, "["); - // Cleverness: no line break hear so that the type ID will match the line number - write("["); + const numTypes = types.length; for (let i = 0; i < numTypes; i++) { const type = types[i]; const objectFlags = (type as any).objectFlags; @@ -127,14 +198,32 @@ namespace ts.tracing { display, }; - write(JSON.stringify(descriptor)); + fs.writeSync(typesFd, JSON.stringify(descriptor)); if (i < numTypes - 1) { - write(",\n"); + fs.writeSync(typesFd, ",\n"); } } - write("]\n"); + + fs.writeSync(typesFd, "]\n"); + + fs.closeSync(typesFd); performance.mark("endDumpTypes"); performance.measure("Dump types", "beginDumpTypes", "endDumpTypes"); } + + export function dumpLegend() { + if (!legendPath) { + return; + } + Debug.assert(fs); + + fs.writeFileSync(legendPath, JSON.stringify(legend)); + } + + interface TraceRecord { + configFilePath?: string; + tracePath: string; + typesPath?: string; + } } diff --git a/src/executeCommandLine/executeCommandLine.ts b/src/executeCommandLine/executeCommandLine.ts index ebe27c25593b6..ce469755daf06 100644 --- a/src/executeCommandLine/executeCommandLine.ts +++ b/src/executeCommandLine/executeCommandLine.ts @@ -456,6 +456,7 @@ namespace ts { updateSolutionBuilderHost(sys, cb, buildHost); const builder = createSolutionBuilder(buildHost, projects, buildOptions); const exitStatus = buildOptions.clean ? builder.clean() : builder.build(); + tracing.dumpLegend(); return sys.exit(exitStatus); } @@ -476,7 +477,7 @@ namespace ts { const currentDirectory = host.getCurrentDirectory(); const getCanonicalFileName = createGetCanonicalFileName(host.useCaseSensitiveFileNames()); changeCompilerHostLikeToUseCache(host, fileName => toPath(fileName, currentDirectory, getCanonicalFileName)); - enableStatisticsAndTracing(sys, options); + enableStatisticsAndTracing(sys, options, /*isBuildMode*/ false); const programOptions: CreateProgramOptions = { rootNames: fileNames, @@ -504,7 +505,7 @@ namespace ts { config: ParsedCommandLine ) { const { options, fileNames, projectReferences } = config; - enableStatisticsAndTracing(sys, options); + enableStatisticsAndTracing(sys, options, /*isBuildMode*/ false); const host = createIncrementalCompilerHost(options, sys); const exitStatus = ts.performIncrementalCompilation({ host, @@ -541,7 +542,7 @@ namespace ts { host.createProgram = (rootNames, options, host, oldProgram, configFileParsingDiagnostics, projectReferences) => { Debug.assert(rootNames !== undefined || (options === undefined && !!oldProgram)); if (options !== undefined) { - enableStatisticsAndTracing(sys, options); + enableStatisticsAndTracing(sys, options, /*isBuildMode*/ true); } return compileUsingBuilder(rootNames, options, host, oldProgram, configFileParsingDiagnostics, projectReferences); }; @@ -610,41 +611,25 @@ namespace ts { return system === sys && (compilerOptions.diagnostics || compilerOptions.extendedDiagnostics); } - let traceCount = 0; - let tracingFd: number | undefined; + function canTrace(system: System, compilerOptions: CompilerOptions) { + return system === sys && compilerOptions.generateTrace; + } - function enableStatisticsAndTracing(system: System, compilerOptions: CompilerOptions) { + function enableStatisticsAndTracing(system: System, compilerOptions: CompilerOptions, isBuildMode: boolean) { if (canReportDiagnostics(system, compilerOptions)) { performance.enable(); } - Debug.assert(!tracingFd, "Tracing already started"); - if (system === sys) { - const tracePath = compilerOptions.generateTrace; - if (tracePath) { - const extension = getAnyExtensionFromPath(tracePath); - tracingFd = sys.openFile(changeAnyExtension(tracePath, `${++traceCount}${extension}`), "w"); - if (tracingFd) { - tracing.startTracing(event => sys.write(event, tracingFd)); - } - } + if (canTrace(system, compilerOptions)) { + tracing.startTracing(compilerOptions.configFilePath, compilerOptions.generateTrace!, isBuildMode); } } function reportStatistics(sys: System, program: Program) { const compilerOptions = program.getCompilerOptions(); - if (tracingFd) { - tracing.stopTracing(); - sys.closeFile(tracingFd); - tracingFd = undefined; - - const typesPath = changeAnyExtension(compilerOptions.generateTrace!, `${traceCount}.types.json`); - const typesFd = sys.openFile(typesPath, "w"); - if (typesFd) { - tracing.dumpTypes(program.getTypeCatalog(), type => sys.write(type, typesFd)); - sys.closeFile(typesFd); - } + if (canTrace(sys, compilerOptions)) { + tracing.stopTracing(program.getTypeCatalog()); } let statistics: Statistic[]; diff --git a/src/harness/fakesHosts.ts b/src/harness/fakesHosts.ts index d6b4f1d5599c9..8d7db1d333cb3 100644 --- a/src/harness/fakesHosts.ts +++ b/src/harness/fakesHosts.ts @@ -37,8 +37,7 @@ namespace fakes { return true; } - public write(message: string, fd?: number) { - assert.isUndefined(fd); + public write(message: string) { this.output.push(message); } @@ -61,15 +60,6 @@ namespace fakes { this.vfs.unlinkSync(path); } - public openFile(_path: string, _mode: "w"): number | undefined { - assert.fail("NYI"); - return undefined; - } - - public closeFile(_fd: number): void{ - assert.fail("NYI"); - } - public fileExists(path: string) { const stats = this._getStats(path); return stats ? stats.isFile() : false; diff --git a/src/harness/harnessLanguageService.ts b/src/harness/harnessLanguageService.ts index 0993438c2f001..69d7238cbec15 100644 --- a/src/harness/harnessLanguageService.ts +++ b/src/harness/harnessLanguageService.ts @@ -724,8 +724,7 @@ namespace Harness.LanguageService { onMessage = ts.noop; writeMessage = ts.noop; // overridden - write(message: string, fd?: number): void { - assert.isUndefined(fd); + write(message: string): void { this.writeMessage(message); } @@ -745,9 +744,6 @@ namespace Harness.LanguageService { writeFile = ts.noop; - openFile = ts.returnUndefined; - closeFile = ts.noop; - resolvePath(path: string): string { return path; } diff --git a/src/harness/virtualFileSystemWithWatch.ts b/src/harness/virtualFileSystemWithWatch.ts index 6036b74187a61..c0e66430e9a06 100644 --- a/src/harness/virtualFileSystemWithWatch.ts +++ b/src/harness/virtualFileSystemWithWatch.ts @@ -1011,21 +1011,11 @@ interface Array { length: number; [n: number]: T; }` } } - openFile(_path: string, _mode: "w"): number | undefined { - assert.fail("NYI"); - return undefined; - } - - closeFile(_fd: number): void { - assert.fail("NYI"); - } - appendFile(path: string, content: string, options?: Partial): void { this.modifyFile(path, this.readFile(path) + content, options); } - write(message: string, fd?: number) { - assert.isUndefined(fd); + write(message: string) { this.output.push(message); } diff --git a/src/testRunner/unittests/tsserver/session.ts b/src/testRunner/unittests/tsserver/session.ts index 646b435407a03..8084b79056b30 100644 --- a/src/testRunner/unittests/tsserver/session.ts +++ b/src/testRunner/unittests/tsserver/session.ts @@ -7,11 +7,9 @@ namespace ts.server { args: [], newLine: "\n", useCaseSensitiveFileNames: true, - write(s, _fd: number): void { lastWrittenToHost = s; }, + write(s): void { lastWrittenToHost = s; }, readFile: returnUndefined, writeFile: noop, - openFile: returnUndefined, - closeFile: noop, resolvePath(): string { return undefined!; }, // TODO: GH#18217 fileExists: () => false, directoryExists: () => false, diff --git a/tests/baselines/reference/api/tsserverlibrary.d.ts b/tests/baselines/reference/api/tsserverlibrary.d.ts index 58341d0e9f135..0bca465cc6064 100644 --- a/tests/baselines/reference/api/tsserverlibrary.d.ts +++ b/tests/baselines/reference/api/tsserverlibrary.d.ts @@ -3841,13 +3841,11 @@ declare namespace ts { args: string[]; newLine: string; useCaseSensitiveFileNames: boolean; - write(s: string, fd?: number): void; + write(s: string): void; writeOutputIsTTY?(): boolean; readFile(path: string, encoding?: string): string | undefined; getFileSize?(path: string): number; writeFile(path: string, data: string, writeByteOrderMark?: boolean): void; - openFile(path: string, mode: "w"): number | undefined; - closeFile(fd: number): void; /** * @pollingInterval - this parameter is used in polling-based watchers and ignored in watchers that * use native OS file watching diff --git a/tests/baselines/reference/api/typescript.d.ts b/tests/baselines/reference/api/typescript.d.ts index 34301d0e5cb14..ecbbcd23c770b 100644 --- a/tests/baselines/reference/api/typescript.d.ts +++ b/tests/baselines/reference/api/typescript.d.ts @@ -3841,13 +3841,11 @@ declare namespace ts { args: string[]; newLine: string; useCaseSensitiveFileNames: boolean; - write(s: string, fd?: number): void; + write(s: string): void; writeOutputIsTTY?(): boolean; readFile(path: string, encoding?: string): string | undefined; getFileSize?(path: string): number; writeFile(path: string, data: string, writeByteOrderMark?: boolean): void; - openFile(path: string, mode: "w"): number | undefined; - closeFile(fd: number): void; /** * @pollingInterval - this parameter is used in polling-based watchers and ignored in watchers that * use native OS file watching From 00804d8aa69081c040637273fa6cfe63255712f3 Mon Sep 17 00:00:00 2001 From: Andrew Casey Date: Fri, 21 Aug 2020 17:06:00 -0700 Subject: [PATCH 3/6] Trace structuredTypeRelatedTo, rather than recursiveTypeRelatedTo --- src/compiler/checker.ts | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/src/compiler/checker.ts b/src/compiler/checker.ts index 55bc2657a9f52..45ad4e1f2e5a4 100644 --- a/src/compiler/checker.ts +++ b/src/compiler/checker.ts @@ -16818,13 +16818,6 @@ namespace ts { // equal and infinitely expanding. Fourth, if we have reached a depth of 100 nested comparisons, assume we have runaway recursion // and issue an error. Otherwise, actually compare the structure of the two types. function recursiveTypeRelatedTo(source: Type, target: Type, reportErrors: boolean, intersectionState: IntersectionState): Ternary { - tracing.begin(tracing.Phase.Check, "recursiveTypeRelatedTo", { sourceId: source.id, targetId: target.id }); - const result = recursiveTypeRelatedToWorker(source, target, reportErrors, intersectionState); - tracing.end(); - return result; - } - - function recursiveTypeRelatedToWorker(source: Type, target: Type, reportErrors: boolean, intersectionState: IntersectionState): Ternary { if (overflow) { return Ternary.False; } @@ -16909,6 +16902,13 @@ 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 }); + const result = structuredTypeRelatedToWorker(source, target, reportErrors, intersectionState); + tracing.end(); + return result; + } + + function structuredTypeRelatedToWorker(source: Type, target: Type, reportErrors: boolean, intersectionState: IntersectionState): Ternary { if (intersectionState & IntersectionState.PropertyCheck) { return propertiesRelatedTo(source, target, reportErrors, /*excludedProperties*/ undefined, IntersectionState.None); } From 7b40895b2943c9e93647869da2fc4f62bf6eaed9 Mon Sep 17 00:00:00 2001 From: Andrew Casey Date: Fri, 21 Aug 2020 17:39:03 -0700 Subject: [PATCH 4/6] Record the recursion ID of each type, if available --- src/compiler/checker.ts | 1 + src/compiler/tracing.ts | 15 +++++++++++++++ src/compiler/types.ts | 1 + 3 files changed, 17 insertions(+) diff --git a/src/compiler/checker.ts b/src/compiler/checker.ts index 45ad4e1f2e5a4..ff7e456cb6c7e 100644 --- a/src/compiler/checker.ts +++ b/src/compiler/checker.ts @@ -377,6 +377,7 @@ namespace ts { getMergedSymbol, getDiagnostics, getGlobalDiagnostics, + getRecursionIdentity, getTypeOfSymbolAtLocation: (symbol, locationIn) => { const location = getParseTreeNode(locationIn); return location ? getTypeOfSymbolAtLocation(symbol, location) : errorType; diff --git a/src/compiler/tracing.ts b/src/compiler/tracing.ts index c7f2add068a64..cabbb6c810c7d 100644 --- a/src/compiler/tracing.ts +++ b/src/compiler/tracing.ts @@ -127,6 +127,8 @@ namespace ts.tracing { const typesPath = legend[legend.length - 1].typesPath!; const typesFd = fs.openSync(typesPath, "w"); + const recursionIdentityMap = new Map(); + // Cleverness: no line break here so that the type ID will match the line number fs.writeSync(typesFd, "["); @@ -178,10 +180,23 @@ namespace ts.tracing { }; } + // We can't print out an arbitrary object, so just assign each one a unique number. + // Don't call it an "id" so people don't treat it as a type id. + let recursionToken: number | undefined; + const recursionIdentity = type.checker.getRecursionIdentity(type); + if (recursionIdentity) { + recursionToken = recursionIdentityMap.get(recursionIdentity); + if (!recursionToken) { + recursionToken = recursionIdentityMap.size; + recursionIdentityMap.set(recursionIdentity, recursionToken); + } + } + const descriptor = { id: type.id, intrinsicName: (type as any).intrinsicName, symbolName: symbol?.escapedName && unescapeLeadingUnderscores(symbol.escapedName), + recursionId: recursionToken, unionTypes: (type.flags & TypeFlags.Union) ? (type as UnionType).types?.map(t => t.id) : undefined, intersectionTypes: (type.flags & TypeFlags.Intersection) ? (type as IntersectionType).types.map(t => t.id) : undefined, aliasTypeArguments: type.aliasTypeArguments?.map(t => t.id), diff --git a/src/compiler/types.ts b/src/compiler/types.ts index 5e8ba2786a536..2bfc8e5a5cf1d 100644 --- a/src/compiler/types.ts +++ b/src/compiler/types.ts @@ -4073,6 +4073,7 @@ namespace ts { /* @internal */ getTypeCount(): number; /* @internal */ getInstantiationCount(): number; /* @internal */ getRelationCacheSizes(): { assignable: number, identity: number, subtype: number, strictSubtype: number }; + /* @internal */ getRecursionIdentity(type: Type): object | undefined; /* @internal */ isArrayType(type: Type): boolean; /* @internal */ isTupleType(type: Type): boolean; From 36489ff5c676c3b9a85b53fc8cd0d30a79ea18ee Mon Sep 17 00:00:00 2001 From: Andrew Casey Date: Fri, 28 Aug 2020 15:51:52 -0700 Subject: [PATCH 5/6] Add instantaneous events when depth limits are hit --- src/compiler/checker.ts | 11 ++++++++++- src/compiler/tracing.ts | 12 ++++++++++++ 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/src/compiler/checker.ts b/src/compiler/checker.ts index ff7e456cb6c7e..ee5b7e9119649 100644 --- a/src/compiler/checker.ts +++ b/src/compiler/checker.ts @@ -10804,6 +10804,7 @@ namespace ts { // very high likelihood we're dealing with an infinite generic type that perpetually generates // new type identities as we descend into it. We stop the recursion here and mark this type // and the outer types as having circular constraints. + tracing.instant(tracing.Phase.Check, "getImmediateBaseConstraint_DepthLimit", { typeId: t.id, originalTypeId: type.id, depth: constraintDepth }); error(currentNode, Diagnostics.Type_instantiation_is_excessively_deep_and_possibly_infinite); nonTerminating = true; return t.immediateBaseConstraint = noConstraintType; @@ -12878,6 +12879,7 @@ namespace ts { // caps union types at 5000 unique literal types and 1000 unique object types. const estimatedCount = (count / (len - i)) * len; if (estimatedCount > (primitivesOnly ? 25000000 : 1000000)) { + tracing.instant(tracing.Phase.Check, "removeSubtypes_DepthLimit", { typeIds: types.map(t => t.id) }); error(currentNode, Diagnostics.Expression_produces_a_union_type_that_is_too_complex_to_represent); return false; } @@ -14940,6 +14942,7 @@ namespace ts { // We have reached 50 recursive type instantiations and there is a very high likelyhood we're dealing // with a combination of infinite generic types that perpetually generate new type identities. We stop // the recursion here by yielding the error type. + tracing.instant(tracing.Phase.Check, "instantiateType_DepthLimit", { typeId: type.id, instantiationDepth, instantiationCount }); error(currentNode, Diagnostics.Type_instantiation_is_excessively_deep_and_possibly_infinite); return errorType; } @@ -16058,6 +16061,7 @@ namespace ts { reportIncompatibleStack(); } if (overflow) { + tracing.instant(tracing.Phase.Check, "checkTypeRelatedTo_DepthLimit", { sourceId: source.id, targetId: target.id, depth }); const diag = error(errorNode || currentNode, Diagnostics.Excessive_stack_depth_comparing_types_0_and_1, typeToString(source), typeToString(target)); if (errorOutputContainer) { (errorOutputContainer.errors || (errorOutputContainer.errors = [])).push(diag); @@ -17358,6 +17362,7 @@ namespace ts { numCombinations *= countTypes(getTypeOfSymbol(sourceProperty)); if (numCombinations > 25) { // We've reached the complexity limit. + tracing.instant(tracing.Phase.Check, "typeRelatedToDiscriminatedType_DepthLimit", { sourceId: source.id, targetId: target.id, numCombinations }); return Ternary.False; } } @@ -18281,7 +18286,10 @@ namespace ts { for (let i = 0; i < depth; i++) { if (getRecursionIdentity(stack[i]) === identity) { count++; - if (count >= 5) return true; + if (count >= 5) { + tracing.instant(tracing.Phase.Check, "isDeeplyNestedType_DepthLimit", { typeId: type.id, typeIdStack: stack.map(t => t.id), depth, count }); + return true; + } } } } @@ -21089,6 +21097,7 @@ namespace ts { if (flowDepth === 2000) { // We have made 2000 recursive invocations. To avoid overflowing the call stack we report an error // and disable further control flow analysis in the containing function or module body. + tracing.instant(tracing.Phase.Check, "getTypeAtFlowNode_DepthLimit", { flowId: flow.id }); flowAnalysisDisabled = true; reportFlowControlError(reference); return errorType; diff --git a/src/compiler/tracing.ts b/src/compiler/tracing.ts index cabbb6c810c7d..30b90a2b0d1a2 100644 --- a/src/compiler/tracing.ts +++ b/src/compiler/tracing.ts @@ -112,6 +112,18 @@ namespace ts.tracing { performance.measure("Tracing", "beginTracing", "endTracing"); } + export function instant(phase: Phase, name: string, args: object) { + 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`); + performance.mark("endTracing"); + performance.measure("Tracing", "beginTracing", "endTracing"); + } + function indexFromOne(lc: LineAndCharacter): LineAndCharacter { return { line: lc.line + 1, From ef1481c8a4777b3bfd242be7b717533b3ca5d149 Mon Sep 17 00:00:00 2001 From: Andrew Casey Date: Tue, 1 Sep 2020 16:46:07 -0700 Subject: [PATCH 6/6] Correct bottoming-out tracing for recursiveTypeRelatedTo --- src/compiler/checker.ts | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/src/compiler/checker.ts b/src/compiler/checker.ts index ee5b7e9119649..65b6eea3f71f8 100644 --- a/src/compiler/checker.ts +++ b/src/compiler/checker.ts @@ -16882,6 +16882,17 @@ namespace ts { return originalHandler!(onlyUnreliable); }; } + + if (expandingFlags === ExpandingFlags.Both) { + tracing.instant(tracing.Phase.Check, "recursiveTypeRelatedTo_DepthLimit", { + sourceId: source.id, + sourceIdStack: sourceStack.map(t => t.id), + targetId: target.id, + targetIdStack: targetStack.map(t => t.id), + depth, + }); + } + const result = expandingFlags !== ExpandingFlags.Both ? structuredTypeRelatedTo(source, target, reportErrors, intersectionState) : Ternary.Maybe; if (outofbandVarianceMarkerHandler) { outofbandVarianceMarkerHandler = originalHandler; @@ -18287,7 +18298,6 @@ namespace ts { if (getRecursionIdentity(stack[i]) === identity) { count++; if (count >= 5) { - tracing.instant(tracing.Phase.Check, "isDeeplyNestedType_DepthLimit", { typeId: type.id, typeIdStack: stack.map(t => t.id), depth, count }); return true; } }