feat: refact non-cached duration logic according to code review

Author: chengcyber

common/reviews/api/rush-lib.api.md

@@ -371,8 +371,8 @@ export interface _INpmOptionsJson extends IPackageManagerOptionsJsonBase {
 
 // @alpha
 export interface IOperationExecutionResult {
-    readonly durationInSecondsWithoutCache: number | undefined;
     readonly error: Error | undefined;
+    readonly nonCachedDurationMs: number | undefined;
     readonly status: OperationStatus;
     readonly stdioSummarizer: StdioSummarizer;
     readonly stopwatch: IStopwatchResult;
@@ -400,8 +400,12 @@ export interface IOperationRunner {
 export interface IOperationRunnerContext {
     collatedWriter: CollatedWriter;
     debugMode: boolean;
+    // Warning: (ae-forgotten-export) The symbol "OperationStateFile" needs to be exported by the entry point index.d.ts
+    operationStateFile?: OperationStateFile;
     quietMode: boolean;
     stdioSummarizer: StdioSummarizer;
+    // Warning: (ae-forgotten-export) The symbol "Stopwatch" needs to be exported by the entry point index.d.ts
+    stopwatch: Stopwatch;
 }
 
 // @public
@@ -508,8 +512,8 @@ export interface ITelemetryMachineInfo {
 // @beta (undocumented)
 export interface ITelemetryOperationResult {
     dependencies: string[];
-    durationInSecondsWithoutCache?: number;
     endTimestampMs?: number;
+    nonCachedDurationMs?: number;
     result: string;
     startTimestampMs?: number;
 }

libraries/rush-lib/src/cli/scriptActions/PhasedScriptAction.ts

@@ -578,7 +578,7 @@ export class PhasedScriptAction extends BaseScriptAction<IPhasedCommandConfig> {
           operationResults[operation.name!] = {
             startTimestampMs: startTime,
             endTimestampMs: endTime,
-            durationInSecondsWithoutCache: operationResult.durationInSecondsWithoutCache,
+            nonCachedDurationMs: operationResult.nonCachedDurationMs,
             result: operationResult.status,
             dependencies: Array.from(getNonSilentDependencies(operation)).sort()
           };

libraries/rush-lib/src/logic/Telemetry.ts

@@ -68,7 +68,7 @@ export interface ITelemetryOperationResult {
   endTimestampMs?: number;
 
   /**
-   * Duration in seconds when the operation does not hit cache
+   * Duration in milliseconds when the operation does not hit cache
    */
   nonCachedDurationMs?: number;
 }

libraries/rush-lib/src/logic/buildCache/ProjectBuildCache.ts

@@ -3,7 +3,7 @@
 
 import * as path from 'path';
 import * as crypto from 'crypto';
-import { FileSystem, Path, ITerminal, FolderItem, InternalError } from '@rushstack/node-core-library';
+import { FileSystem, Path, ITerminal, FolderItem, InternalError, Async } from '@rushstack/node-core-library';
 
 import { RushConfigurationProject } from '../../api/RushConfigurationProject';
 import { ProjectChangeAnalyzer } from '../ProjectChangeAnalyzer';
@@ -19,6 +19,7 @@ export interface IProjectBuildCacheOptions {
   buildCacheConfiguration: BuildCacheConfiguration;
   projectConfiguration: RushProjectConfiguration;
   projectOutputFolderNames: ReadonlyArray<string>;
+  additionalProjectOutputFilePaths?: ReadonlyArray<string>;
   command: string;
   trackedProjectFiles: string[] | undefined;
   projectChangeAnalyzer: ProjectChangeAnalyzer;
@@ -44,18 +45,23 @@ export class ProjectBuildCache {
   private readonly _buildCacheEnabled: boolean;
   private readonly _cacheWriteEnabled: boolean;
   private readonly _projectOutputFolderNames: ReadonlyArray<string>;
-  private readonly _additionalOutputFilePaths: string[];
+  private readonly _additionalProjectOutputFilePaths: ReadonlyArray<string>;
   private _cacheId: string | undefined;
 
   private constructor(cacheId: string | undefined, options: IProjectBuildCacheOptions) {
-    const { buildCacheConfiguration, projectConfiguration, projectOutputFolderNames } = options;
+    const {
+      buildCacheConfiguration,
+      projectConfiguration,
+      projectOutputFolderNames,
+      additionalProjectOutputFilePaths
+    } = options;
     this._project = projectConfiguration.project;
     this._localBuildCacheProvider = buildCacheConfiguration.localCacheProvider;
     this._cloudBuildCacheProvider = buildCacheConfiguration.cloudCacheProvider;
     this._buildCacheEnabled = buildCacheConfiguration.buildCacheEnabled;
     this._cacheWriteEnabled = buildCacheConfiguration.cacheWriteEnabled;
     this._projectOutputFolderNames = projectOutputFolderNames || [];
-    this._additionalOutputFilePaths = [];
+    this._additionalProjectOutputFilePaths = additionalProjectOutputFilePaths || [];
     this._cacheId = cacheId;
   }
 
@@ -118,22 +124,14 @@ export class ProjectBuildCache {
     if (inputOutputFiles.length > 0) {
       terminal.writeWarningLine(
         'Unable to use build cache. The following files are used to calculate project state ' +
-          `and are considered project output: ${inputOutputFiles.join(', ')}`
+        `and are considered project output: ${inputOutputFiles.join(', ')}`
       );
       return false;
     } else {
       return true;
     }
   }
 
-  public get additionalOutputFilePaths(): string[] {
-    return this._additionalOutputFilePaths;
-  }
-
-  public addAdditionalOutputFilePaths(outputFilePath: string): void {
-    this._additionalOutputFilePaths.push(outputFilePath);
-  }
-
   public async tryRestoreFromCacheAsync(terminal: ITerminal): Promise<boolean> {
     const cacheId: string | undefined = this._cacheId;
     if (!cacheId) {
@@ -261,14 +259,14 @@ export class ProjectBuildCache {
       } else {
         terminal.writeWarningLine(
           `"tar" exited with code ${tarExitCode} while attempting to create the cache entry. ` +
-            `See "${logFilePath}" for logs from the tar process.`
+          `See "${logFilePath}" for logs from the tar process.`
         );
         return false;
       }
     } else {
       terminal.writeWarningLine(
         `Unable to locate "tar". Please ensure that "tar" is on your PATH environment variable, or set the ` +
-          `${EnvironmentVariableNames.RUSH_TAR_BINARY_PATH} environment variable to the full path to the "tar" binary.`
+        `${EnvironmentVariableNames.RUSH_TAR_BINARY_PATH} environment variable to the full path to the "tar" binary.`
       );
       return false;
     }
@@ -370,13 +368,17 @@ export class ProjectBuildCache {
     }
 
     // Add additional output file paths
-    await Async.foreEachAsync(this._additionalOutputFilePaths, async (additionalOutputFilePath) => {
-      const fullPath: string = `${projectFolderPath}/${addAdditionalOutputFilePath}`;
-      const pathExists: boolean = await FileSystem.existsAsync(fullPath);
-      if (pathExists) {
-        outputFilePaths.push(addAdditionalOutputFilePath);
-      }
-    }, { concurrency: 10 });
+    await Async.forEachAsync(
+      this._additionalProjectOutputFilePaths,
+      async (additionalProjectOutputFilePath) => {
+        const fullPath: string = `${projectFolderPath}/${additionalProjectOutputFilePath}`;
+        const pathExists: boolean = await FileSystem.existsAsync(fullPath);
+        if (pathExists) {
+          outputFilePaths.push(additionalProjectOutputFilePath);
+        }
+      },
+      { concurrency: 10 }
+    );
 
     // Ensure stable output path order.
     outputFilePaths.sort();

libraries/rush-lib/src/logic/operations/IOperationExecutionResult.ts

@@ -33,7 +33,6 @@ export interface IOperationExecutionResult {
   readonly stdioSummarizer: StdioSummarizer;
   /**
    * The value indicates the duration of the same operation without cache hit.
-   * It is specified if current operation hits cache
    */
   readonly nonCachedDurationMs: number | undefined;
 }

libraries/rush-lib/src/logic/operations/IOperationRunner.ts

@@ -5,6 +5,8 @@ import type { StdioSummarizer } from '@rushstack/terminal';
 import type { CollatedWriter } from '@rushstack/stream-collator';
 
 import type { OperationStatus } from './OperationStatus';
+import type { OperationStateFile } from './OperationStateFile';
+import type { Stopwatch } from '../../utilities/Stopwatch';
 
 /**
  * Information passed to the executing `IOperationRunner`
@@ -28,6 +30,14 @@ export interface IOperationRunnerContext {
    * Object used to report a summary at the end of the Rush invocation.
    */
   stdioSummarizer: StdioSummarizer;
+  /**
+   * Object used to record state of the operation.
+   */
+  operationStateFile?: OperationStateFile;
+  /**
+   * Object used to track elapsed time.
+   */
+  stopwatch: Stopwatch;
 }
 
 /**

libraries/rush-lib/src/logic/operations/OperationExecutionRecord.ts

@@ -87,8 +87,6 @@ export class OperationExecutionRecord implements IOperationRunnerContext {
 
   private _collatedWriter: CollatedWriter | undefined = undefined;
 
-  public nonCachedDurationMs: number | undefined = undefined;
-
   public constructor(operation: Operation, context: IOperationExecutionRecordContext) {
     const { runner } = operation;
 
@@ -129,6 +127,11 @@ export class OperationExecutionRecord implements IOperationRunnerContext {
     return this._collatedWriter;
   }
 
+  public get nonCachedDurationMs(): number | undefined {
+    // Lazy calculated because the state file is created/restored later on
+    return this.operationStateFile?.state?.nonCachedDurationMs;
+  }
+
   public async executeAsync(onResult: (record: OperationExecutionRecord) => void): Promise<void> {
     this.status = OperationStatus.Executing;
     this.stopwatch.start();

libraries/rush-lib/src/logic/operations/OperationStateFile.ts

@@ -1,7 +1,6 @@
 // Copyright (c) Microsoft Corporation. All rights reserved. Licensed under the MIT license.
 // See LICENSE in the project root for license information.
 
-import * as path from 'path';
 import { FileSystem, InternalError, JsonFile } from '@rushstack/node-core-library';
 import { RushConstants } from '../RushConstants';
 
@@ -17,21 +16,32 @@ export interface IOperationStateJson {
   nonCachedDurationMs: number;
 }
 
+/**
+ * A helper class for managing the state file of a operation.
+ *
+ * @internal
+ */
 export class OperationStateFile {
   private readonly _rushProject: RushConfigurationProject;
   private readonly _filename: string;
+  private _state: IOperationStateJson | undefined;
 
   public constructor(options: IOperationStateFileOptions) {
     const { rushProject, phase } = options;
     this._rushProject = rushProject;
-    this._filename = OperationStateFile.getFilename(phase, rushProject);
+    this._filename = OperationStateFile._getFilename(phase, rushProject);
   }
 
-  public static getFilename(phase: IPhase, project: RushConfigurationProject): string {
+  private static _getFilename(phase: IPhase, project: RushConfigurationProject): string {
     const relativeFilename: string = OperationStateFile.getFilenameRelativeToProjectRoot(phase);
     return `${project.projectFolder}/${relativeFilename}`;
   }
 
+  /**
+   * ProjectBuildCache expects the relative path for better logging
+   *
+   * @internal
+   */
   public static getFilenameRelativeToProjectRoot(phase: IPhase): string {
     const identifier: string = `${phase.logFilenameIdentifier}`;
     return `${RushConstants.projectRushFolderName}/${RushConstants.rushTempFolderName}/operation/${identifier}/state.json`;
@@ -44,20 +54,26 @@ export class OperationStateFile {
     return this._filename;
   }
 
+  public get state(): IOperationStateJson | undefined {
+    return this._state;
+  }
+
   public async writeAsync(json: IOperationStateJson): Promise<void> {
     await JsonFile.saveAsync(json, this._filename, { ensureFolderExists: true, updateExistingFile: true });
+    this._state = json;
   }
 
-  public async tryReadAsync(): Promise<IOperationStateJson | undefined> {
+  public async tryRestoreAsync(): Promise<IOperationStateJson | undefined> {
     try {
-      return await JsonFile.loadAsync(this._filename);
+      this._state = await JsonFile.loadAsync(this._filename);
     } catch (error) {
       if (FileSystem.isNotExistError(error as Error)) {
-        return undefined;
+        this._state = undefined;
       } else {
         // This should not happen
         throw new InternalError(error);
       }
     }
+    return this._state;
   }
 }

libraries/rush-lib/src/logic/operations/ShellOperationRunner.ts

@@ -34,7 +34,6 @@ import { CollatedTerminalProvider } from '../../utilities/CollatedTerminalProvid
 import { RushConstants } from '../RushConstants';
 import { EnvironmentConfiguration } from '../../api/EnvironmentConfiguration';
 import { OperationStateFile } from './OperationStateFile';
-import { OperationExecutionRecord } from './OperationExecutionRecord';
 
 import type { RushConfiguration } from '../../api/RushConfiguration';
 import type { RushConfigurationProject } from '../../api/RushConfigurationProject';
@@ -275,11 +274,8 @@ export class ShellOperationRunner implements IOperationRunner {
           await projectBuildCache?.tryRestoreFromCacheAsync(terminal);
 
         if (restoreFromCacheSuccess) {
-          // Restore the original state of the operation without cache if hit cache
-          if (context instanceof OperationExecutionRecord) {
-            context.durationInSecondsWithoutCache =
-              context.operationStateFile?.tryRead()?.durationInSecondsWithoutCache;
-          }
+          // Restore the original state of the operation without cache
+          await context.operationStateFile?.tryRestoreAsync();
           return OperationStatus.FromCache;
         }
       }
@@ -378,16 +374,10 @@ export class ShellOperationRunner implements IOperationRunner {
         });
 
         // If the operation without cache was successful, we can save the state to disk
-        if (context instanceof OperationExecutionRecord) {
-          if (context.operationStateFile) {
-            const { duration } = context.stopwatch;
-            if (duration) {
-              context.operationStateFile.write({
-                durationInSecondsWithoutCache: duration
-              });
-            }
-          }
-        }
+        const { duration: durationInSeconds } = context.stopwatch;
+        await context.operationStateFile?.writeAsync({
+          nonCachedDurationMs: durationInSeconds * 1000
+        });
 
         // If the command is successful, we can calculate project hash, and no dependencies were skipped,
         // write a new cache entry.
@@ -451,19 +441,20 @@ export class ShellOperationRunner implements IOperationRunner {
             } else {
               const projectOutputFolderNames: ReadonlyArray<string> =
                 operationSettings.outputFolderNames || [];
+              const additionalProjectOutputFilePaths: ReadonlyArray<string> = [
+                OperationStateFile.getFilenameRelativeToProjectRoot(this._phase)
+              ];
               this._projectBuildCache = await ProjectBuildCache.tryGetProjectBuildCache({
                 projectConfiguration,
                 projectOutputFolderNames,
+                additionalProjectOutputFilePaths,
                 buildCacheConfiguration: this._buildCacheConfiguration,
                 terminal,
                 command: this._commandToRun,
                 trackedProjectFiles: trackedProjectFiles,
                 projectChangeAnalyzer: this._projectChangeAnalyzer,
                 phaseName: this._phase.name
               });
-              this._projectBuildCache?.addAdditionalOutputFilePaths(
-                OperationStateFile.getFilenameRelativeToProjectRoot(this._phase)
-              );
             }
           }
         } else {