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

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.
    */

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,7 +64,7 @@ export class LanguageService {
   }
 
   getSemanticDiagnostics(fileName: string): ts.Diagnostic[] {
-    const compiler = this.compilerFactory.getOrCreate();
+    return this.withCompilerAndPerfTracing(PerfPhase.LsDiagnostics, (compiler) => {
       const ttc = compiler.getTemplateTypeChecker();
       const diagnostics: ts.Diagnostic[] = [];
       if (isTypeScriptFile(fileName)) {
@@ -73,23 +74,26 @@ export class LanguageService {
           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.
+          // 1. Angular-related non-template diagnostics from decorated classes within that
-        // 2. Template diagnostics for components with direct inline templates (a string literal).
+          // file.
-        // 3. Template diagnostics for components with indirect inline templates (templates computed
+          // 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 -
+          // When showing diagnostics for a TS source file, we want to only include kinds 1 and
-        // those diagnostics which are reported at a location within the TS file itself. Diagnostics
+          // 2 - those diagnostics which are reported at a location within the TS file itself.
-        // for external templates will be shown when editing that template file (the `else` block)
+          // Diagnostics for external templates will be shown when editing that template file
-        // below.
+          // (the `else` block) below.
           //
-        // Currently, indirect inline template diagnostics (kind 3) are not shown at all by the
+          // Currently, indirect inline template diagnostics (kind 3) are not shown at all by
-        // Language Service, because there is no sensible location in the user's code for them. Such
+          // the Language Service, because there is no sensible location in the user's code for
-        // templates are an edge case, though, and should not be common.
+          // 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
+          // TODO(alxhub): figure out a good user experience for indirect template diagnostics
-        // show them from within the Language Service.
+          // and show them from within the Language Service.
           diagnostics.push(...ngDiagnostics.filter(
               diag => diag.file !== undefined && diag.file.fileName === sourceFile.fileName));
         }
@@ -101,13 +105,13 @@ export class LanguageService {
           }
         }
       }
-    this.compilerFactory.registerLastKnownProgram();
       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,7 +132,16 @@ export class LanguageService {
   }
 
   getQuickInfoAtPosition(fileName: string, position: number): ts.QuickInfo|undefined {
-    return this.withCompiler((compiler) => {
+    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;
     }
@@ -149,43 +162,40 @@ export class LanguageService {
         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();
+    return this.withCompilerAndPerfTracing(PerfPhase.LsReferencesAndRenames, (compiler) => {
-    const results = new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler)
+      return new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler)
           .getReferencesAtPosition(fileName, position);
-    this.compilerFactory.registerLastKnownProgram();
+    });
-    return results;
   }
 
   getRenameInfo(fileName: string, position: number): ts.RenameInfo {
-    const compiler = this.compilerFactory.getOrCreate();
+    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) ??
+      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();
+    return this.withCompilerAndPerfTracing(PerfPhase.LsReferencesAndRenames, (compiler) => {
-    const results = new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler)
+      return new ReferencesAndRenameBuilder(this.strategy, this.tsLS, compiler)
           .findRenameLocations(fileName, position);
-    this.compilerFactory.registerLastKnownProgram();
+    });
-    return results;
   }
 
-  private getCompletionBuilder(fileName: string, position: number):
+  private getCompletionBuilder(fileName: string, position: number, compiler: NgCompiler):
       CompletionBuilder<TmplAstNode|AST>|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<ts.CompletionInfo>|undefined {
-    return this.withCompiler((compiler) => {
+    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<ts.CompletionInfo>|undefined {
     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;
     }
     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,7 +272,8 @@ export class LanguageService {
   }
 
   getComponentLocationsForTemplate(fileName: string): GetComponentLocationsForTemplateResponse {
-    return this.withCompiler<GetComponentLocationsForTemplateResponse>((compiler) => {
+    return this.withCompilerAndPerfTracing<GetComponentLocationsForTemplateResponse>(
+        PerfPhase.LsComponentLocations, (compiler) => {
           const components = compiler.getComponentsWithTemplateFile(fileName);
           const componentDeclarationLocations: ts.DocumentSpan[] =
               Array.from(components.values()).map(c => {
@@ -279,7 +296,7 @@ export class LanguageService {
   }
 
   getTcb(fileName: string, position: number): GetTcbResponse|undefined {
-    return this.withCompiler<GetTcbResponse|undefined>(compiler => {
+    return this.withCompilerAndPerfTracing<GetTcbResponse|undefined>(PerfPhase.LsTcb, compiler => {
       const templateInfo = getTemplateInfoAtPosition(fileName, position, compiler);
       if (templateInfo === undefined) {
         return undefined;
@@ -323,10 +340,34 @@ export class LanguageService {
     });
   }
 
-  private withCompiler<T>(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<T>(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,6 +377,7 @@ export class LanguageService {
       return [];
     }
 
+    return this.withCompilerAndPerfTracing(PerfPhase.LsDiagnostics, (compiler) => {
       const diagnostics: ts.Diagnostic[] = [];
       const configSourceFile = ts.readJsonConfigFile(
           project.getConfigFilePath(), (path: string) => project.readFile(path));
@@ -352,10 +394,10 @@ export class LanguageService {
         });
       }
 
-    const compiler = this.compilerFactory.getOrCreate();
       diagnostics.push(...compiler.getOptionDiagnostics());
 
       return diagnostics;
+    });
   }
 
   private watchConfigFile(project: ts.server.Project) {

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 {

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 {