From 90f85da2de72f320653e6292968f70c87876bada Mon Sep 17 00:00:00 2001 From: Zach Arend Date: Fri, 19 Mar 2021 07:56:13 -0700 Subject: [PATCH] feat(language-service): add perf tracing to LanguageService (#41319) Adds perf tracing for the public methods in LanguageService. If the log level is verbose or higher, trace performance results to the tsServer logger. This logger is implemented on the extension side in angular/vscode-ng-language-service. PR Close #41319 --- .../compiler-cli/src/ngtsc/perf/src/api.ts | 34 ++ .../language-service/ivy/language_service.ts | 318 ++++++++++-------- .../ivy/test/diagnostic_spec.ts | 22 ++ .../ivy/testing/src/project.ts | 4 + 4 files changed, 240 insertions(+), 138 deletions(-) diff --git a/packages/compiler-cli/src/ngtsc/perf/src/api.ts b/packages/compiler-cli/src/ngtsc/perf/src/api.ts index 851ada1ba7..39e2a44bc0 100644 --- a/packages/compiler-cli/src/ngtsc/perf/src/api.ts +++ b/packages/compiler-cli/src/ngtsc/perf/src/api.ts @@ -110,6 +110,40 @@ export enum PerfPhase { */ LsReferencesAndRenames, + /** + * Time spent by the Angular Language Service calculating a "quick info" operation. + */ + LsQuickInfo, + + /** + * Time spent by the Angular Language Service calculating a "get type definition" or "get + * definition" operation. + */ + LsDefinition, + + /** + * Time spent by the Angular Language Service calculating a "get completions" (AKA autocomplete) + * operation. + */ + LsCompletions, + + /** + * Time spent by the Angular Language Service calculating a "view template typecheck block" + * operation. + */ + LsTcb, + + /** + * Time spent by the Angular Language Service calculating diagnostics. + */ + LsDiagnostics, + + /** + * Time spent by the Angular Language Service calculating a "get component locations for template" + * operation. + */ + LsComponentLocations, + /** * Tracks the number of `PerfPhase`s, and must appear at the end of the list. */ diff --git a/packages/language-service/ivy/language_service.ts b/packages/language-service/ivy/language_service.ts index 7167dbeb75..cbbff8d462 100644 --- a/packages/language-service/ivy/language_service.ts +++ b/packages/language-service/ivy/language_service.ts @@ -11,6 +11,7 @@ import {CompilerOptions, ConfigurationHost, readConfiguration} from '@angular/co import {NgCompiler} from '@angular/compiler-cli/src/ngtsc/core'; import {ErrorCode, ngErrorCode} from '@angular/compiler-cli/src/ngtsc/diagnostics'; import {absoluteFrom, absoluteFromSourceFile, AbsoluteFsPath} from '@angular/compiler-cli/src/ngtsc/file_system'; +import {PerfPhase} from '@angular/compiler-cli/src/ngtsc/perf'; import {isNamedClassDeclaration} from '@angular/compiler-cli/src/ngtsc/reflection'; import {TypeCheckShimGenerator} from '@angular/compiler-cli/src/ngtsc/typecheck'; import {OptimizeFor, TypeCheckingProgramStrategy} from '@angular/compiler-cli/src/ngtsc/typecheck/api'; @@ -63,51 +64,54 @@ export class LanguageService { } getSemanticDiagnostics(fileName: string): ts.Diagnostic[] { - const compiler = this.compilerFactory.getOrCreate(); - const ttc = compiler.getTemplateTypeChecker(); - const diagnostics: ts.Diagnostic[] = []; - if (isTypeScriptFile(fileName)) { - const program = compiler.getNextProgram(); - const sourceFile = program.getSourceFile(fileName); - if (sourceFile) { - const ngDiagnostics = compiler.getDiagnosticsForFile(sourceFile, OptimizeFor.SingleFile); - // There are several kinds of diagnostics returned by `NgCompiler` for a source file: - // - // 1. Angular-related non-template diagnostics from decorated classes within that file. - // 2. Template diagnostics for components with direct inline templates (a string literal). - // 3. Template diagnostics for components with indirect inline templates (templates computed - // by expression). - // 4. Template diagnostics for components with external templates. - // - // When showing diagnostics for a TS source file, we want to only include kinds 1 and 2 - - // those diagnostics which are reported at a location within the TS file itself. Diagnostics - // for external templates will be shown when editing that template file (the `else` block) - // below. - // - // Currently, indirect inline template diagnostics (kind 3) are not shown at all by the - // Language Service, because there is no sensible location in the user's code for them. Such - // templates are an edge case, though, and should not be common. - // - // TODO(alxhub): figure out a good user experience for indirect template diagnostics and - // show them from within the Language Service. - diagnostics.push(...ngDiagnostics.filter( - diag => diag.file !== undefined && diag.file.fileName === sourceFile.fileName)); - } - } else { - const components = compiler.getComponentsWithTemplateFile(fileName); - for (const component of components) { - if (ts.isClassDeclaration(component)) { - diagnostics.push(...ttc.getDiagnosticsForComponent(component)); + return this.withCompilerAndPerfTracing(PerfPhase.LsDiagnostics, (compiler) => { + const ttc = compiler.getTemplateTypeChecker(); + const diagnostics: ts.Diagnostic[] = []; + if (isTypeScriptFile(fileName)) { + const program = compiler.getNextProgram(); + const sourceFile = program.getSourceFile(fileName); + if (sourceFile) { + const ngDiagnostics = compiler.getDiagnosticsForFile(sourceFile, OptimizeFor.SingleFile); + // There are several kinds of diagnostics returned by `NgCompiler` for a source file: + // + // 1. Angular-related non-template diagnostics from decorated classes within that + // file. + // 2. Template diagnostics for components with direct inline templates (a string + // literal). + // 3. Template diagnostics for components with indirect inline templates (templates + // computed + // by expression). + // 4. Template diagnostics for components with external templates. + // + // When showing diagnostics for a TS source file, we want to only include kinds 1 and + // 2 - those diagnostics which are reported at a location within the TS file itself. + // Diagnostics for external templates will be shown when editing that template file + // (the `else` block) below. + // + // Currently, indirect inline template diagnostics (kind 3) are not shown at all by + // the Language Service, because there is no sensible location in the user's code for + // them. Such templates are an edge case, though, and should not be common. + // + // TODO(alxhub): figure out a good user experience for indirect template diagnostics + // and show them from within the Language Service. + diagnostics.push(...ngDiagnostics.filter( + diag => diag.file !== undefined && diag.file.fileName === sourceFile.fileName)); + } + } else { + const components = compiler.getComponentsWithTemplateFile(fileName); + for (const component of components) { + if (ts.isClassDeclaration(component)) { + diagnostics.push(...ttc.getDiagnosticsForComponent(component)); + } } } - } - this.compilerFactory.registerLastKnownProgram(); - return diagnostics; + return diagnostics; + }); } getDefinitionAndBoundSpan(fileName: string, position: number): ts.DefinitionInfoAndBoundSpan |undefined { - return this.withCompiler((compiler) => { + return this.withCompilerAndPerfTracing(PerfPhase.LsDefinition, (compiler) => { if (!isInAngularContext(compiler.getNextProgram(), fileName, position)) { return undefined; } @@ -118,7 +122,7 @@ export class LanguageService { getTypeDefinitionAtPosition(fileName: string, position: number): readonly ts.DefinitionInfo[]|undefined { - return this.withCompiler((compiler) => { + return this.withCompilerAndPerfTracing(PerfPhase.LsDefinition, (compiler) => { if (!isTemplateContext(compiler.getNextProgram(), fileName, position)) { return undefined; } @@ -128,64 +132,70 @@ export class LanguageService { } getQuickInfoAtPosition(fileName: string, position: number): ts.QuickInfo|undefined { - return this.withCompiler((compiler) => { - if (!isTemplateContext(compiler.getNextProgram(), fileName, position)) { - return undefined; - } - - const templateInfo = getTemplateInfoAtPosition(fileName, position, compiler); - if (templateInfo === undefined) { - return undefined; - } - const positionDetails = getTargetAtPosition(templateInfo.template, position); - if (positionDetails === null) { - return undefined; - } - - // Because we can only show 1 quick info, just use the bound attribute if the target is a two - // way binding. We may consider concatenating additional display parts from the other target - // nodes or representing the two way binding in some other manner in the future. - const node = positionDetails.context.kind === TargetNodeKind.TwoWayBindingContext ? - positionDetails.context.nodes[0] : - positionDetails.context.node; - return new QuickInfoBuilder(this.tsLS, compiler, templateInfo.component, node).get(); + return this.withCompilerAndPerfTracing(PerfPhase.LsQuickInfo, (compiler) => { + return this.getQuickInfoAtPositionImpl(fileName, position, compiler); }); } + private getQuickInfoAtPositionImpl( + fileName: string, + position: number, + compiler: NgCompiler, + ): ts.QuickInfo|undefined { + if (!isTemplateContext(compiler.getNextProgram(), fileName, position)) { + return undefined; + } + + const templateInfo = getTemplateInfoAtPosition(fileName, position, compiler); + if (templateInfo === undefined) { + return undefined; + } + const positionDetails = getTargetAtPosition(templateInfo.template, position); + if (positionDetails === null) { + return undefined; + } + + // Because we can only show 1 quick info, just use the bound attribute if the target is a two + // way binding. We may consider concatenating additional display parts from the other target + // nodes or representing the two way binding in some other manner in the future. + const node = positionDetails.context.kind === TargetNodeKind.TwoWayBindingContext ? + positionDetails.context.nodes[0] : + positionDetails.context.node; + return new QuickInfoBuilder(this.tsLS, compiler, templateInfo.component, node).get(); + } + getReferencesAtPosition(fileName: string, position: number): ts.ReferenceEntry[]|undefined { - const compiler = this.compilerFactory.getOrCreate(); - const results = new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler) - .getReferencesAtPosition(fileName, position); - this.compilerFactory.registerLastKnownProgram(); - return results; + return this.withCompilerAndPerfTracing(PerfPhase.LsReferencesAndRenames, (compiler) => { + return new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler) + .getReferencesAtPosition(fileName, position); + }); } getRenameInfo(fileName: string, position: number): ts.RenameInfo { - const compiler = this.compilerFactory.getOrCreate(); - const renameInfo = new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler) - .getRenameInfo(absoluteFrom(fileName), position); - if (!renameInfo.canRename) { - return renameInfo; - } + return this.withCompilerAndPerfTracing(PerfPhase.LsReferencesAndRenames, (compiler) => { + const renameInfo = new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler) + .getRenameInfo(absoluteFrom(fileName), position); + if (!renameInfo.canRename) { + return renameInfo; + } - const quickInfo = this.getQuickInfoAtPosition(fileName, position) ?? - this.tsLS.getQuickInfoAtPosition(fileName, position); - const kind = quickInfo?.kind ?? ts.ScriptElementKind.unknown; - const kindModifiers = quickInfo?.kindModifiers ?? ts.ScriptElementKind.unknown; - return {...renameInfo, kind, kindModifiers}; + const quickInfo = this.getQuickInfoAtPositionImpl(fileName, position, compiler) ?? + this.tsLS.getQuickInfoAtPosition(fileName, position); + const kind = quickInfo?.kind ?? ts.ScriptElementKind.unknown; + const kindModifiers = quickInfo?.kindModifiers ?? ts.ScriptElementKind.unknown; + return {...renameInfo, kind, kindModifiers}; + }); } findRenameLocations(fileName: string, position: number): readonly ts.RenameLocation[]|undefined { - const compiler = this.compilerFactory.getOrCreate(); - const results = new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler) - .findRenameLocations(fileName, position); - this.compilerFactory.registerLastKnownProgram(); - return results; + return this.withCompilerAndPerfTracing(PerfPhase.LsReferencesAndRenames, (compiler) => { + return new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler) + .findRenameLocations(fileName, position); + }); } - private getCompletionBuilder(fileName: string, position: number): + private getCompletionBuilder(fileName: string, position: number, compiler: NgCompiler): CompletionBuilder|null { - const compiler = this.compilerFactory.getOrCreate(); const templateInfo = getTemplateInfoAtPosition(fileName, position, compiler); if (templateInfo === undefined) { return null; @@ -208,29 +218,35 @@ export class LanguageService { getCompletionsAtPosition( fileName: string, position: number, options: ts.GetCompletionsAtPositionOptions|undefined): ts.WithMetadata|undefined { - return this.withCompiler((compiler) => { - if (!isTemplateContext(compiler.getNextProgram(), fileName, position)) { - return undefined; - } - - const builder = this.getCompletionBuilder(fileName, position); - if (builder === null) { - return undefined; - } - return builder.getCompletionsAtPosition(options); + return this.withCompilerAndPerfTracing(PerfPhase.LsCompletions, (compiler) => { + return this.getCompletionsAtPositionImpl(fileName, position, options, compiler); }); } + private getCompletionsAtPositionImpl( + fileName: string, position: number, options: ts.GetCompletionsAtPositionOptions|undefined, + compiler: NgCompiler): ts.WithMetadata|undefined { + if (!isTemplateContext(compiler.getNextProgram(), fileName, position)) { + return undefined; + } + + const builder = this.getCompletionBuilder(fileName, position, compiler); + if (builder === null) { + return undefined; + } + return builder.getCompletionsAtPosition(options); + } + getCompletionEntryDetails( fileName: string, position: number, entryName: string, formatOptions: ts.FormatCodeOptions|ts.FormatCodeSettings|undefined, preferences: ts.UserPreferences|undefined): ts.CompletionEntryDetails|undefined { - return this.withCompiler((compiler) => { + return this.withCompilerAndPerfTracing(PerfPhase.LsCompletions, (compiler) => { if (!isTemplateContext(compiler.getNextProgram(), fileName, position)) { return undefined; } - const builder = this.getCompletionBuilder(fileName, position); + const builder = this.getCompletionBuilder(fileName, position, compiler); if (builder === null) { return undefined; } @@ -240,12 +256,12 @@ export class LanguageService { getCompletionEntrySymbol(fileName: string, position: number, entryName: string): ts.Symbol |undefined { - return this.withCompiler((compiler) => { + return this.withCompilerAndPerfTracing(PerfPhase.LsCompletions, (compiler) => { if (!isTemplateContext(compiler.getNextProgram(), fileName, position)) { return undefined; } - const builder = this.getCompletionBuilder(fileName, position); + const builder = this.getCompletionBuilder(fileName, position, compiler); if (builder === null) { return undefined; } @@ -256,30 +272,31 @@ export class LanguageService { } getComponentLocationsForTemplate(fileName: string): GetComponentLocationsForTemplateResponse { - return this.withCompiler((compiler) => { - const components = compiler.getComponentsWithTemplateFile(fileName); - const componentDeclarationLocations: ts.DocumentSpan[] = - Array.from(components.values()).map(c => { - let contextSpan: ts.TextSpan|undefined = undefined; - let textSpan: ts.TextSpan; - if (isNamedClassDeclaration(c)) { - textSpan = ts.createTextSpanFromBounds(c.name.getStart(), c.name.getEnd()); - contextSpan = ts.createTextSpanFromBounds(c.getStart(), c.getEnd()); - } else { - textSpan = ts.createTextSpanFromBounds(c.getStart(), c.getEnd()); - } - return { - fileName: c.getSourceFile().fileName, - textSpan, - contextSpan, - }; - }); - return componentDeclarationLocations; - }); + return this.withCompilerAndPerfTracing( + PerfPhase.LsComponentLocations, (compiler) => { + const components = compiler.getComponentsWithTemplateFile(fileName); + const componentDeclarationLocations: ts.DocumentSpan[] = + Array.from(components.values()).map(c => { + let contextSpan: ts.TextSpan|undefined = undefined; + let textSpan: ts.TextSpan; + if (isNamedClassDeclaration(c)) { + textSpan = ts.createTextSpanFromBounds(c.name.getStart(), c.name.getEnd()); + contextSpan = ts.createTextSpanFromBounds(c.getStart(), c.getEnd()); + } else { + textSpan = ts.createTextSpanFromBounds(c.getStart(), c.getEnd()); + } + return { + fileName: c.getSourceFile().fileName, + textSpan, + contextSpan, + }; + }); + return componentDeclarationLocations; + }); } getTcb(fileName: string, position: number): GetTcbResponse|undefined { - return this.withCompiler(compiler => { + return this.withCompilerAndPerfTracing(PerfPhase.LsTcb, compiler => { const templateInfo = getTemplateInfoAtPosition(fileName, position, compiler); if (templateInfo === undefined) { return undefined; @@ -323,10 +340,34 @@ export class LanguageService { }); } - private withCompiler(p: (compiler: NgCompiler) => T): T { + /** + * Provides an instance of the `NgCompiler` and traces perf results. Perf results are logged only + * if the log level is verbose or higher. This method is intended to be called once per public + * method call. + * + * Here is an example of the log output. + * + * Perf 245 [16:16:39.353] LanguageService#getQuickInfoAtPosition(): {"events":{},"phases":{ + * "Unaccounted":379,"TtcSymbol":4},"memory":{}} + * + * Passing name of caller instead of using `arguments.caller` because 'caller', 'callee', and + * 'arguments' properties may not be accessed in strict mode. + * + * @param phase the `PerfPhase` to execute the `p` callback in + * @param p callback to be run synchronously with an instance of the `NgCompiler` as argument + * @return the result of running the `p` callback + */ + private withCompilerAndPerfTracing(phase: PerfPhase, p: (compiler: NgCompiler) => T): T { const compiler = this.compilerFactory.getOrCreate(); - const result = p(compiler); + const result = compiler.perfRecorder.inPhase(phase, () => p(compiler)); this.compilerFactory.registerLastKnownProgram(); + + const logger = this.project.projectService.logger; + if (logger.hasLevel(ts.server.LogLevel.verbose)) { + logger.perftrc(`LanguageService#${PerfPhase[phase]}: ${ + JSON.stringify(compiler.perfRecorder.finalize())}`); + } + return result; } @@ -336,26 +377,27 @@ export class LanguageService { return []; } - const diagnostics: ts.Diagnostic[] = []; - const configSourceFile = ts.readJsonConfigFile( - project.getConfigFilePath(), (path: string) => project.readFile(path)); + return this.withCompilerAndPerfTracing(PerfPhase.LsDiagnostics, (compiler) => { + const diagnostics: ts.Diagnostic[] = []; + const configSourceFile = ts.readJsonConfigFile( + project.getConfigFilePath(), (path: string) => project.readFile(path)); - if (!this.options.strictTemplates && !this.options.fullTemplateTypeCheck) { - diagnostics.push({ - messageText: 'Some language features are not available. ' + - 'To access all features, enable `strictTemplates` in `angularCompilerOptions`.', - category: ts.DiagnosticCategory.Suggestion, - code: ngErrorCode(ErrorCode.SUGGEST_STRICT_TEMPLATES), - file: configSourceFile, - start: undefined, - length: undefined, - }); - } + if (!this.options.strictTemplates && !this.options.fullTemplateTypeCheck) { + diagnostics.push({ + messageText: 'Some language features are not available. ' + + 'To access all features, enable `strictTemplates` in `angularCompilerOptions`.', + category: ts.DiagnosticCategory.Suggestion, + code: ngErrorCode(ErrorCode.SUGGEST_STRICT_TEMPLATES), + file: configSourceFile, + start: undefined, + length: undefined, + }); + } - const compiler = this.compilerFactory.getOrCreate(); - diagnostics.push(...compiler.getOptionDiagnostics()); + diagnostics.push(...compiler.getOptionDiagnostics()); - return diagnostics; + return diagnostics; + }); } private watchConfigFile(project: ts.server.Project) { diff --git a/packages/language-service/ivy/test/diagnostic_spec.ts b/packages/language-service/ivy/test/diagnostic_spec.ts index d1264db207..3fadd8f966 100644 --- a/packages/language-service/ivy/test/diagnostic_spec.ts +++ b/packages/language-service/ivy/test/diagnostic_spec.ts @@ -275,6 +275,28 @@ describe('getSemanticDiagnostics', () => { expect(diag.category).toBe(ts.DiagnosticCategory.Suggestion); expect(getTextOfDiagnostic(diag)).toBe('user'); }); + + it('logs perf tracing', () => { + const files = { + 'app.ts': ` + import {Component} from '@angular/core'; + @Component({ template: '' }) + export class MyComponent {} + ` + }; + + const project = createModuleAndProjectWithDeclarations(env, 'test', files); + + const logger = project.getLogger(); + spyOn(logger, 'hasLevel').and.returnValue(true); + spyOn(logger, 'perftrc').and.callFake(() => {}); + + const diags = project.getDiagnosticsForFile('app.ts'); + expect(diags.length).toEqual(0); + expect(logger.perftrc) + .toHaveBeenCalledWith(jasmine.stringMatching( + /LanguageService\#LsDiagnostics\:.*\"LsDiagnostics\":\s*\d+.*/g)); + }); }); function getTextOfDiagnostic(diag: ts.Diagnostic): string { diff --git a/packages/language-service/ivy/testing/src/project.ts b/packages/language-service/ivy/testing/src/project.ts index 5577f7c705..37ae237eda 100644 --- a/packages/language-service/ivy/testing/src/project.ts +++ b/packages/language-service/ivy/testing/src/project.ts @@ -179,6 +179,10 @@ export class Project { getTemplateTypeChecker(): TemplateTypeChecker { return this.ngLS.compilerFactory.getOrCreate().getTemplateTypeChecker(); } + + getLogger(): ts.server.Logger { + return this.tsProject.projectService.logger; + } } function getClassOrError(sf: ts.SourceFile, name: string): ts.ClassDeclaration {