From 405d8e91978708a613fe8cb631a83b13c430a808 Mon Sep 17 00:00:00 2001 From: Sheetal Nandi Date: Fri, 27 May 2022 13:42:28 -0700 Subject: [PATCH] Report aggregate statistics for solution as well as some solution perf numbers --- src/compiler/performance.ts | 270 ++++++++++--------- src/compiler/sourcemap.ts | 4 +- src/compiler/tsbuildPublic.ts | 132 ++++++--- src/executeCommandLine/executeCommandLine.ts | 199 ++++++++++---- 4 files changed, 390 insertions(+), 215 deletions(-) diff --git a/src/compiler/performance.ts b/src/compiler/performance.ts index 3f6c23f2b07..2dbdb390b40 100644 --- a/src/compiler/performance.ts +++ b/src/compiler/performance.ts @@ -1,146 +1,162 @@ /*@internal*/ /** Performance measurements for the compiler. */ -namespace ts.performance { - let perfHooks: PerformanceHooks | undefined; - // when set, indicates the implementation of `Performance` to use for user timing. - // when unset, indicates user timing is unavailable or disabled. - let performanceImpl: Performance | undefined; - - export interface Timer { +namespace ts { + interface Timer { enter(): void; exit(): void; } - export function createTimerIf(condition: boolean, measureName: string, startMarkName: string, endMarkName: string) { - return condition ? createTimer(measureName, startMarkName, endMarkName) : nullTimer; - } + const nullTimer: Timer = { enter: noop, exit: noop }; + export const performance = createPerformanceTracker(); + export const solutionPerformance = createPerformanceTracker(); + + function createPerformanceTracker() { + let perfHooks: PerformanceHooks | undefined; + // when set, indicates the implementation of `Performance` to use for user timing. + // when unset, indicates user timing is unavailable or disabled. + let performanceImpl: Performance | undefined; + let enabled = false; + let timeorigin = timestamp(); + const marks = new Map(); + const counts = new Map(); + const durations = new Map(); - export function createTimer(measureName: string, startMarkName: string, endMarkName: string): Timer { - let enterCount = 0; return { - enter, - exit + createTimerIf, + createTimer, + mark, + measure, + getCount, + getDuration, + forEachMeasure, + isEnabled, + enable, + disable, }; - function enter() { - if (++enterCount === 1) { - mark(startMarkName); + function createTimerIf(condition: boolean, measureName: string, startMarkName: string, endMarkName: string) { + return condition ? createTimer(measureName, startMarkName, endMarkName) : nullTimer; + } + + function createTimer(measureName: string, startMarkName: string, endMarkName: string): Timer { + let enterCount = 0; + return { + enter, + exit + }; + + function enter() { + if (++enterCount === 1) { + mark(startMarkName); + } } - } - function exit() { - if (--enterCount === 0) { - mark(endMarkName); - measure(measureName, startMarkName, endMarkName); - } - else if (enterCount < 0) { - Debug.fail("enter/exit count does not match."); - } - } - } - - export const nullTimer: Timer = { enter: noop, exit: noop }; - - let enabled = false; - let timeorigin = timestamp(); - const marks = new Map(); - const counts = new Map(); - const durations = new Map(); - - /** - * Marks a performance event. - * - * @param markName The name of the mark. - */ - export function mark(markName: string) { - if (enabled) { - const count = counts.get(markName) ?? 0; - counts.set(markName, count + 1); - marks.set(markName, timestamp()); - performanceImpl?.mark(markName); - } - } - - /** - * Adds a performance measurement with the specified name. - * - * @param measureName The name of the performance measurement. - * @param startMarkName The name of the starting mark. If not supplied, the point at which the - * profiler was enabled is used. - * @param endMarkName The name of the ending mark. If not supplied, the current timestamp is - * used. - */ - export function measure(measureName: string, startMarkName?: string, endMarkName?: string) { - if (enabled) { - const end = (endMarkName !== undefined ? marks.get(endMarkName) : undefined) ?? timestamp(); - const start = (startMarkName !== undefined ? marks.get(startMarkName) : undefined) ?? timeorigin; - const previousDuration = durations.get(measureName) || 0; - durations.set(measureName, previousDuration + (end - start)); - performanceImpl?.measure(measureName, startMarkName, endMarkName); - } - } - - /** - * Gets the number of times a marker was encountered. - * - * @param markName The name of the mark. - */ - export function getCount(markName: string) { - return counts.get(markName) || 0; - } - - /** - * Gets the total duration of all measurements with the supplied name. - * - * @param measureName The name of the measure whose durations should be accumulated. - */ - export function getDuration(measureName: string) { - return durations.get(measureName) || 0; - } - - /** - * Iterate over each measure, performing some action - * - * @param cb The action to perform for each measure - */ - export function forEachMeasure(cb: (measureName: string, duration: number) => void) { - durations.forEach((duration, measureName) => cb(measureName, duration)); - } - - /** - * Indicates whether the performance API is enabled. - */ - export function isEnabled() { - return enabled; - } - - /** Enables (and resets) performance measurements for the compiler. */ - export function enable(system: System = sys) { - if (!enabled) { - enabled = true; - perfHooks ||= tryGetNativePerformanceHooks(); - if (perfHooks) { - timeorigin = perfHooks.performance.timeOrigin; - // NodeJS's Web Performance API is currently slower than expected, but we'd still like - // to be able to leverage native trace events when node is run with either `--cpu-prof` - // or `--prof`, if we're running with our own `--generateCpuProfile` flag, or when - // running in debug mode (since its possible to generate a cpu profile while debugging). - if (perfHooks.shouldWriteNativeEvents || system?.cpuProfilingEnabled?.() || system?.debugMode) { - performanceImpl = perfHooks.performance; + function exit() { + if (--enterCount === 0) { + mark(endMarkName); + measure(measureName, startMarkName, endMarkName); + } + else if (enterCount < 0) { + Debug.fail("enter/exit count does not match."); } } } - return true; - } - /** Disables performance measurements for the compiler. */ - export function disable() { - if (enabled) { - marks.clear(); - counts.clear(); - durations.clear(); - performanceImpl = undefined; - enabled = false; + /** + * Marks a performance event. + * + * @param markName The name of the mark. + */ + function mark(markName: string) { + if (enabled) { + const count = counts.get(markName) ?? 0; + counts.set(markName, count + 1); + marks.set(markName, timestamp()); + performanceImpl?.mark(markName); + } + } + + /** + * Adds a performance measurement with the specified name. + * + * @param measureName The name of the performance measurement. + * @param startMarkName The name of the starting mark. If not supplied, the point at which the + * profiler was enabled is used. + * @param endMarkName The name of the ending mark. If not supplied, the current timestamp is + * used. + */ + function measure(measureName: string, startMarkName: string, endMarkName: string) { + if (enabled) { + const end = marks.get(endMarkName) ?? timestamp(); + const start = marks.get(startMarkName) ?? timeorigin; + const previousDuration = durations.get(measureName) || 0; + durations.set(measureName, previousDuration + (end - start)); + performanceImpl?.measure(measureName, startMarkName, endMarkName); + } + } + + /** + * Gets the number of times a marker was encountered. + * + * @param markName The name of the mark. + */ + function getCount(markName: string) { + return counts.get(markName) || 0; + } + + /** + * Gets the total duration of all measurements with the supplied name. + * + * @param measureName The name of the measure whose durations should be accumulated. + */ + function getDuration(measureName: string) { + return durations.get(measureName) || 0; + } + + /** + * Iterate over each measure, performing some action + * + * @param cb The action to perform for each measure + */ + function forEachMeasure(cb: (measureName: string, duration: number) => void) { + durations.forEach((duration, measureName) => cb(measureName, duration)); + } + + /** + * Indicates whether the performance API is enabled. + */ + function isEnabled() { + return enabled; + } + + /** Enables (and resets) performance measurements for the compiler. */ + function enable(system: System = sys) { + if (!enabled) { + enabled = true; + perfHooks ||= tryGetNativePerformanceHooks(); + if (perfHooks) { + timeorigin = perfHooks.performance.timeOrigin; + // NodeJS's Web Performance API is currently slower than expected, but we'd still like + // to be able to leverage native trace events when node is run with either `--cpu-prof` + // or `--prof`, if we're running with our own `--generateCpuProfile` flag, or when + // running in debug mode (since its possible to generate a cpu profile while debugging). + if (perfHooks.shouldWriteNativeEvents || system?.cpuProfilingEnabled?.() || system?.debugMode) { + performanceImpl = perfHooks.performance; + } + } + } + return true; + } + + /** Disables performance measurements for the compiler. */ + function disable() { + if (enabled) { + marks.clear(); + counts.clear(); + durations.clear(); + performanceImpl = undefined; + enabled = false; + } } } } diff --git a/src/compiler/sourcemap.ts b/src/compiler/sourcemap.ts index e3aebc849b6..22bb9e92424 100644 --- a/src/compiler/sourcemap.ts +++ b/src/compiler/sourcemap.ts @@ -5,9 +5,7 @@ namespace ts { } export function createSourceMapGenerator(host: EmitHost, file: string, sourceRoot: string, sourcesDirectoryPath: string, generatorOptions: SourceMapGeneratorOptions): SourceMapGenerator { - const { enter, exit } = generatorOptions.extendedDiagnostics - ? performance.createTimer("Source Map", "beforeSourcemap", "afterSourcemap") - : performance.nullTimer; + const { enter, exit } = performance.createTimerIf(!!generatorOptions.extendedDiagnostics, "Source Map", "beforeSourcemap", "afterSourcemap"); // Current source map file and its index in the sources list const rawSources: string[] = []; diff --git a/src/compiler/tsbuildPublic.ts b/src/compiler/tsbuildPublic.ts index 6de356151ef..632333b9bea 100644 --- a/src/compiler/tsbuildPublic.ts +++ b/src/compiler/tsbuildPublic.ts @@ -398,7 +398,7 @@ namespace ts { if (value) { return isParsedCommandLine(value) ? value : undefined; } - + solutionPerformance.mark("beforeParseConfigFile"); let diagnostic: Diagnostic | undefined; const { parseConfigFileHost, baseCompilerOptions, baseWatchOptions, extendedConfigCache, host } = state; let parsed: ParsedCommandLine | undefined; @@ -412,6 +412,8 @@ namespace ts { parseConfigFileHost.onUnRecoverableConfigFileDiagnostic = noop; } configFileCache.set(configFilePath, parsed || diagnostic!); + solutionPerformance.mark("afterParseConfigFile"); + solutionPerformance.measure("ParseConfigFile", "beforeParseConfigFile", "afterParseConfigFile"); return parsed; } @@ -471,6 +473,7 @@ namespace ts { } function createStateBuildOrder(state: SolutionBuilderState) { + solutionPerformance.mark("beforeCreateBuildOrder"); const buildOrder = createBuildOrder(state, state.rootNames.map(f => resolveProjectName(state, f))); // Clear all to ResolvedConfigFilePaths cache to start fresh @@ -528,6 +531,8 @@ namespace ts { { onDeleteValue: existingMap => existingMap.forEach(closeFileWatcher) } ); } + solutionPerformance.mark("afterCreateBuildOrder"); + solutionPerformance.measure("CreateBuildOrder", "beforeCreateBuildOrder", "afterCreateBuildOrder"); return state.buildOrder = buildOrder; } @@ -729,6 +734,7 @@ namespace ts { if (updateOutputFileStampsPending) { updateOutputTimestamps(state, config, projectPath); } + solutionPerformance.mark("timestampUpdated"); return doneInvalidatedProject(state, projectPath); } }; @@ -842,6 +848,8 @@ namespace ts { function done(cancellationToken?: CancellationToken, writeFile?: WriteFileCallback, customTransformers?: CustomTransformers) { executeSteps(BuildStep.Done, cancellationToken, writeFile, customTransformers); + if (kind === InvalidatedProjectKind.Build) solutionPerformance.mark("projectsBuilt"); + else solutionPerformance.mark("bundlesUpdated"); return doneInvalidatedProject(state, projectPath); } @@ -985,6 +993,7 @@ namespace ts { const isIncremental = isIncrementalCompilation(options); let outputTimeStampMap: ESMap | undefined; let now: Date | undefined; + solutionPerformance.mark("beforeOutputFilesWrite"); outputFiles.forEach(({ name, text, writeByteOrderMark, buildInfo }) => { const path = toPath(state, name); emittedOutputs.set(toPath(state, name), name); @@ -999,6 +1008,8 @@ namespace ts { (outputTimeStampMap ||= getOutputTimeStampMap(state, projectPath)!).set(path, now ||= getCurrentTime(state.host)); } }); + solutionPerformance.mark("afterOutputFilesWrite"); + solutionPerformance.measure("OutputFilesWrite", "beforeOutputFilesWrite", "afterOutputFilesWrite"); finishEmit( emitterDiagnostics, @@ -1202,6 +1213,18 @@ namespace ts { state: SolutionBuilderState, buildOrder: AnyBuildOrder, reportQueue: boolean + ): InvalidateProjectCreateInfo | undefined { + solutionPerformance.mark("beforeGetNextInvalidatedProjectCreateInfo"); + const result = getNextInvalidatedProjectCreateInfoWorker(state, buildOrder, reportQueue); + solutionPerformance.mark("afterGetNextInvalidatedProjectCreateInfo"); + solutionPerformance.measure("GetNextInvalidatedProjectCreateInfo", "beforeGetNextInvalidatedProjectCreateInfo", "afterGetNextInvalidatedProjectCreateInfo"); + return result; + } + + function getNextInvalidatedProjectCreateInfoWorker( + state: SolutionBuilderState, + buildOrder: AnyBuildOrder, + reportQueue: boolean ): InvalidateProjectCreateInfo | undefined { if (!state.projectPendingBuild.size) return undefined; if (isCircularBuildOrder(buildOrder)) return undefined; @@ -1338,8 +1361,7 @@ namespace ts { reportQueue: boolean ): InvalidatedProject | undefined { const info = getNextInvalidatedProjectCreateInfo(state, buildOrder, reportQueue); - if (!info) return info; - return createInvalidatedProjectWithInfo(state, info, buildOrder); + return info && createInvalidatedProjectWithInfo(state, info, buildOrder); } function listEmittedFile({ write }: SolutionBuilderState, proj: ParsedCommandLine, file: string) { @@ -1348,11 +1370,15 @@ namespace ts { } } - function getOldProgram({ options, builderPrograms, compilerHost }: SolutionBuilderState, proj: ResolvedConfigFilePath, parsed: ParsedCommandLine) { - if (options.force) return undefined; - const value = builderPrograms.get(proj); + function getOldProgram(state: SolutionBuilderState, proj: ResolvedConfigFilePath, parsed: ParsedCommandLine) { + if (state.options.force) return undefined; + const value = state.builderPrograms.get(proj); if (value) return value; - return readBuilderProgram(parsed.options, compilerHost) as any as T; + solutionPerformance.mark("beforeReadBuilderProgram"); + const program = readBuilderProgram(parsed.options, state.compilerHost) as any as T; + solutionPerformance.mark("afterReadBuilderProgram"); + solutionPerformance.measure("ReadBuilderProgram", "beforeReadBuilderProgram", "afterReadBuilderProgram"); + return program; } function afterProgramDone( @@ -1479,10 +1505,16 @@ namespace ts { if (existing !== undefined && existing.path === path) { return existing.buildInfo || undefined; } + solutionPerformance.mark("beforeGetBuildInfo"); + solutionPerformance.mark("beforeBuildInfoRead"); const value = state.readFileWithCache(buildInfoPath); + solutionPerformance.mark("afterBuildInfoRead"); + solutionPerformance.measure("BuildInfoRead", "beforeBuildInfoRead", "afterBuildInfoRead"); const buildInfo = value ? ts.getBuildInfo(value) : undefined; Debug.assert(modifiedTime || !buildInfo); state.buildInfoCache.set(resolvedConfigPath, { path, buildInfo: buildInfo || false, modifiedTime: modifiedTime || missingFileModifiedTime }); + solutionPerformance.mark("afterGetBuildInfo"); + solutionPerformance.measure("GetBuildInfo", "beforeGetBuildInfo", "afterGetBuildInfo"); return buildInfo; } @@ -1784,7 +1816,10 @@ namespace ts { return prior; } + solutionPerformance.mark("beforeGetUpToDateStatus"); const actual = getUpToDateStatusWorker(state, project, resolvedPath); + solutionPerformance.mark("afterGetUpToDateStatus"); + solutionPerformance.measure("GetUpToDateStatus", "beforeGetUpToDateStatus", "afterGetUpToDateStatus"); state.projectStatus.set(resolvedPath, actual); return actual; } @@ -1798,6 +1833,7 @@ namespace ts { ) { if (proj.options.noEmit) return; let now: Date | undefined; + solutionPerformance.mark("beforeUpdateOutputTimestamps"); const buildInfoPath = getTsBuildInfoEmitOutputFilePath(proj.options); if (buildInfoPath) { if (!skipOutputs?.has(toPath(state, buildInfoPath))) { @@ -1806,34 +1842,36 @@ namespace ts { getBuildInfoCacheEntry(state, buildInfoPath, projectPath)!.modifiedTime = now; } state.outputTimeStamps.delete(projectPath); - return; } - - const { host } = state; - const outputs = getAllProjectOutputs(proj, !host.useCaseSensitiveFileNames()); - const outputTimeStampMap = getOutputTimeStampMap(state, projectPath); - const modifiedOutputs = outputTimeStampMap ? new Set() : undefined; - if (!skipOutputs || outputs.length !== skipOutputs.size) { - let reportVerbose = !!state.options.verbose; - for (const file of outputs) { - const path = toPath(state, file); - if (skipOutputs?.has(path)) continue; - if (reportVerbose) { - reportVerbose = false; - reportStatus(state, verboseMessage, proj.options.configFilePath!); - } - host.setModifiedTime(file, now ||= getCurrentTime(state.host)); - if (outputTimeStampMap) { - outputTimeStampMap.set(path, now); - modifiedOutputs!.add(path); + else { + const { host } = state; + const outputs = getAllProjectOutputs(proj, !host.useCaseSensitiveFileNames()); + const outputTimeStampMap = getOutputTimeStampMap(state, projectPath); + const modifiedOutputs = outputTimeStampMap ? new Set() : undefined; + if (!skipOutputs || outputs.length !== skipOutputs.size) { + let reportVerbose = !!state.options.verbose; + for (const file of outputs) { + const path = toPath(state, file); + if (skipOutputs?.has(path)) continue; + if (reportVerbose) { + reportVerbose = false; + reportStatus(state, verboseMessage, proj.options.configFilePath!); + } + host.setModifiedTime(file, now ||= getCurrentTime(state.host)); + if (outputTimeStampMap) { + outputTimeStampMap.set(path, now); + modifiedOutputs!.add(path); + } } } - } - // Clear out timestamps not in output list any more - outputTimeStampMap?.forEach((_value, key) => { - if (!skipOutputs?.has(key) && !modifiedOutputs!.has(key)) outputTimeStampMap.delete(key); - }); + // Clear out timestamps not in output list any more + outputTimeStampMap?.forEach((_value, key) => { + if (!skipOutputs?.has(key) && !modifiedOutputs!.has(key)) outputTimeStampMap.delete(key); + }); + } + solutionPerformance.mark("afterUpdateOutputTimestamps"); + solutionPerformance.measure("UpdateOutputTimestamps", "beforeUpdateOutputTimestamps", "afterUpdateOutputTimestamps"); } function getDtsChangeTime(state: SolutionBuilderState, options: CompilerOptions, resolvedConfigPath: ResolvedConfigFilePath) { @@ -1899,7 +1937,7 @@ namespace ts { } break; } - // falls through + // falls through case UpToDateStatusType.UpToDateWithInputFileText: case UpToDateStatusType.UpToDateWithUpstreamTypes: @@ -1927,6 +1965,14 @@ namespace ts { } function build(state: SolutionBuilderState, project?: string, cancellationToken?: CancellationToken, writeFile?: WriteFileCallback, getCustomTransformers?: (project: string) => CustomTransformers, onlyReferences?: boolean): ExitStatus { + solutionPerformance.mark("beforeBuild"); + const result = buildWorker(state, project, cancellationToken, writeFile, getCustomTransformers, onlyReferences); + solutionPerformance.mark("afterBuild"); + solutionPerformance.measure("Build", "beforeBuild", "afterBuild"); + return result; + } + + function buildWorker(state: SolutionBuilderState, project?: string, cancellationToken?: CancellationToken, writeFile?: WriteFileCallback, getCustomTransformers?: (project: string) => CustomTransformers, onlyReferences?: boolean): ExitStatus { const buildOrder = getBuildOrderFor(state, project, onlyReferences); if (!buildOrder) return ExitStatus.InvalidProject_OutputsSkipped; @@ -1938,7 +1984,10 @@ namespace ts { const invalidatedProject = getNextInvalidatedProject(state, buildOrder, reportQueue); if (!invalidatedProject) break; reportQueue = false; + solutionPerformance.mark("beforeInvalidatedProjectBuild"); invalidatedProject.done(cancellationToken, writeFile, getCustomTransformers?.(invalidatedProject.project)); + solutionPerformance.mark("afterInvalidatedProjectBuild"); + solutionPerformance.measure("InvalidatedProjectBuild", "beforeInvalidatedProjectBuild", "afterInvalidatedProjectBuild"); if (!state.diagnostics.has(invalidatedProject.projectPath)) successfulProjects++; } @@ -2032,6 +2081,14 @@ namespace ts { } function buildNextInvalidatedProject(state: SolutionBuilderState, changeDetected: boolean) { + solutionPerformance.mark("beforeBuild"); + const buildOrder = buildNextInvalidatedProjectWorker(state, changeDetected); + solutionPerformance.mark("afterBuild"); + solutionPerformance.measure("Build", "beforeBuild", "afterBuild"); + if (buildOrder) reportErrorSummary(state, buildOrder); + } + + function buildNextInvalidatedProjectWorker(state: SolutionBuilderState, changeDetected: boolean) { state.timerToBuildInvalidatedProject = undefined; if (state.reportFileChangeDetected) { state.reportFileChangeDetected = false; @@ -2042,7 +2099,10 @@ namespace ts { const buildOrder = getBuildOrder(state); const invalidatedProject = getNextInvalidatedProject(state, buildOrder, /*reportQueue*/ false); if (invalidatedProject) { + solutionPerformance.mark("beforeInvalidatedProjectBuild"); invalidatedProject.done(); + solutionPerformance.mark("afterInvalidatedProjectBuild"); + solutionPerformance.measure("InvalidatedProjectBuild", "beforeInvalidatedProjectBuild", "afterInvalidatedProjectBuild"); projectsBuilt++; while (state.projectPendingBuild.size) { // If already scheduled, skip @@ -2056,12 +2116,15 @@ namespace ts { return; } const project = createInvalidatedProjectWithInfo(state, info, buildOrder); + solutionPerformance.mark("beforeInvalidatedProjectBuild"); project.done(); + solutionPerformance.mark("afterInvalidatedProjectBuild"); + solutionPerformance.measure("InvalidatedProjectBuild", "beforeInvalidatedProjectBuild", "afterInvalidatedProjectBuild"); if (info.kind !== InvalidatedProjectKind.UpdateOutputFileStamps) projectsBuilt++; } } disableCache(state); - reportErrorSummary(state, buildOrder); + return buildOrder; } function watchConfigFile(state: SolutionBuilderState, resolved: ResolvedConfigFileName, resolvedPath: ResolvedConfigFilePath, parsed: ParsedCommandLine | undefined) { @@ -2168,6 +2231,7 @@ namespace ts { function startWatching(state: SolutionBuilderState, buildOrder: AnyBuildOrder) { if (!state.watchAllProjectsPending) return; + solutionPerformance.mark("beforeStartWatching"); state.watchAllProjectsPending = false; for (const resolved of getBuildOrderFromAnyBuildOrder(buildOrder)) { const resolvedPath = toResolvedConfigFilePath(state, resolved); @@ -2186,6 +2250,8 @@ namespace ts { watchPackageJsonFiles(state, resolved, resolvedPath, cfg); } } + solutionPerformance.mark("afterStartWatching"); + solutionPerformance.measure("StartWatching", "beforeStartWatching", "afterStartWatching"); } function stopWatching(state: SolutionBuilderState) { diff --git a/src/executeCommandLine/executeCommandLine.ts b/src/executeCommandLine/executeCommandLine.ts index 68d2e51e9d4..08d758da78d 100644 --- a/src/executeCommandLine/executeCommandLine.ts +++ b/src/executeCommandLine/executeCommandLine.ts @@ -1,7 +1,18 @@ namespace ts { - interface Statistic { + export interface Statistic { name: string; - value: string; + value: number; + type: StatisticType + } + + export enum StatisticType { + time, + count, + memory, + } + + export interface SolutionBuilderHostBase extends ProgramHost { + statistics?: Statistic[][]; } function countLines(program: Program): Map { @@ -751,9 +762,22 @@ namespace ts { createBuilderStatusReporter(sys, shouldBePretty(sys, buildOptions)), createWatchStatusReporter(sys, buildOptions) ); + const onWatchStatusChange = buildHost.onWatchStatusChange; + let reportWatchStatistics = false; + buildHost.onWatchStatusChange = (d, newLine, options, errorCount) => { + onWatchStatusChange?.(d, newLine, options, errorCount); + if (!reportWatchStatistics) return; + if (d.code === Diagnostics.Found_0_errors_Watching_for_file_changes.code || + d.code === Diagnostics.Found_1_error_Watching_for_file_changes.code) { + reportSolutionBuilderTimes(sys, builder, buildHost); + } + }; updateSolutionBuilderHost(sys, cb, buildHost); + enableSolutionPerformance(sys, buildOptions); const builder = createSolutionBuilderWithWatch(buildHost, projects, buildOptions, watchOptions); builder.build(); + reportSolutionBuilderTimes(sys, builder, buildHost); + reportWatchStatistics = true; return builder; } @@ -765,12 +789,55 @@ namespace ts { createReportErrorSummary(sys, buildOptions) ); updateSolutionBuilderHost(sys, cb, buildHost); + enableSolutionPerformance(sys, buildOptions); const builder = createSolutionBuilder(buildHost, projects, buildOptions); const exitStatus = buildOptions.clean ? builder.clean() : builder.build(); + reportSolutionBuilderTimes(sys, builder, buildHost); dumpTracingLegend(); // Will no-op if there hasn't been any tracing return sys.exit(exitStatus); } + function enableSolutionPerformance(system: System, options: BuildOptions) { + if (system === sys && (options.diagnostics || options.extendedDiagnostics)) solutionPerformance.enable(); + } + + function reportSolutionBuilderTimes(system: System, builder: SolutionBuilder, buildHost: SolutionBuilderHost) { + if (system !== sys) return; + + if (solutionPerformance.isEnabled()) { + const solutionStatistics: Statistic[] = []; + solutionPerformance.forEachMeasure((name, duration) => solutionStatistics.push({ name: `${name} time`, value: duration, type: StatisticType.time })); + solutionStatistics.push( + { name: "projectsBuilt", value: solutionPerformance.getCount("projectsBuilt"), type: StatisticType.count }, + { name: "timestampUpdated", value: solutionPerformance.getCount("timestampUpdated"), type: StatisticType.count }, + { name: "bundlesUpdated", value: solutionPerformance.getCount("bundlesUpdated"), type: StatisticType.count }, + { name: "projects", value: getBuildOrderFromAnyBuildOrder(builder.getBuildOrder()).length, type: StatisticType.count }, + ); + buildHost.statistics = append(buildHost.statistics, solutionStatistics); + solutionPerformance.disable(); + solutionPerformance.enable(); + } + + if (!buildHost.statistics) return; + const statistics: Statistic[] = []; + const map: Map = new Map(); + for (const statistic of buildHost.statistics) { + for (const s of statistic) { + const existing = map.get(s.name); + if (existing) { + if (existing.type === StatisticType.memory) existing.value = Math.max(existing.value, s.value); + else existing.value += s.value; + } + else { + map.set(s.name, s); + statistics.push(s); + } + } + } + buildHost.statistics = undefined; + reportAllStatistics(system, statistics); + } + function createReportErrorSummary(sys: System, options: CompilerOptions | BuildOptions): ReportEmitErrorSummary | undefined { return shouldBePretty(sys, options) ? (errorCount, filesInError) => sys.write(getErrorSummaryText(errorCount, filesInError, sys.newLine, sys)) : @@ -842,10 +909,13 @@ namespace ts { ) { updateCreateProgram(sys, buildHost); buildHost.afterProgramEmitAndDiagnostics = program => { - reportStatistics(sys, program.getProgram()); + buildHost.statistics = append(buildHost.statistics, reportStatistics(sys, program.getProgram())); cb(program); }; - buildHost.afterEmitBundle = cb; + buildHost.afterEmitBundle = config => { + buildHost.statistics = append(buildHost.statistics, reportStatistics(sys, config)); + cb(config); + }; } function updateCreateProgram(sys: System, host: { createProgram: CreateProgram; }) { @@ -939,8 +1009,13 @@ namespace ts { } } - function reportStatistics(sys: System, program: Program) { - const compilerOptions = program.getCompilerOptions(); + function isProgram(programOrConfig: Program | ParsedCommandLine): programOrConfig is Program { + return !!(programOrConfig as Program).getCompilerOptions; + } + function reportStatistics(sys: System, programOrConfig: Program | ParsedCommandLine): Statistic[] | undefined { + const program = isProgram(programOrConfig) ? programOrConfig : undefined; + const config = !isProgram(programOrConfig) ? programOrConfig : undefined; + const compilerOptions = program?.getCompilerOptions() || config?.options!; if (canTrace(sys, compilerOptions)) { tracing?.stopTracing(); @@ -950,30 +1025,32 @@ namespace ts { if (canReportDiagnostics(sys, compilerOptions)) { statistics = []; const memoryUsed = sys.getMemoryUsage ? sys.getMemoryUsage() : -1; - reportCountStatistic("Files", program.getSourceFiles().length); + if (program) { + reportCountStatistic("Files", program.getSourceFiles().length); - const lineCounts = countLines(program); - const nodeCounts = countNodes(program); - if (compilerOptions.extendedDiagnostics) { - for (const key of arrayFrom(lineCounts.keys())) { - reportCountStatistic("Lines of " + key, lineCounts.get(key)!); + const lineCounts = countLines(program); + const nodeCounts = countNodes(program); + if (compilerOptions.extendedDiagnostics) { + for (const key of arrayFrom(lineCounts.keys())) { + reportCountStatistic("Lines of " + key, lineCounts.get(key)!); + } + for (const key of arrayFrom(nodeCounts.keys())) { + reportCountStatistic("Nodes of " + key, nodeCounts.get(key)!); + } } - for (const key of arrayFrom(nodeCounts.keys())) { - reportCountStatistic("Nodes of " + key, nodeCounts.get(key)!); + else { + reportCountStatistic("Lines", reduceLeftIterator(lineCounts.values(), (sum, count) => sum + count, 0)); + reportCountStatistic("Nodes", reduceLeftIterator(nodeCounts.values(), (sum, count) => sum + count, 0)); } - } - else { - reportCountStatistic("Lines", reduceLeftIterator(lineCounts.values(), (sum, count) => sum + count, 0)); - reportCountStatistic("Nodes", reduceLeftIterator(nodeCounts.values(), (sum, count) => sum + count, 0)); - } - reportCountStatistic("Identifiers", program.getIdentifierCount()); - reportCountStatistic("Symbols", program.getSymbolCount()); - reportCountStatistic("Types", program.getTypeCount()); - reportCountStatistic("Instantiations", program.getInstantiationCount()); + reportCountStatistic("Identifiers", program.getIdentifierCount()); + reportCountStatistic("Symbols", program.getSymbolCount()); + reportCountStatistic("Types", program.getTypeCount()); + reportCountStatistic("Instantiations", program.getInstantiationCount()); + } if (memoryUsed >= 0) { - reportStatisticalValue("Memory used", Math.round(memoryUsed / 1000) + "K"); + reportMemoryStatistic("Memory used", memoryUsed); } const isPerformanceEnabled = performance.isEnabled(); @@ -982,11 +1059,13 @@ namespace ts { const checkTime = isPerformanceEnabled ? performance.getDuration("Check") : 0; const emitTime = isPerformanceEnabled ? performance.getDuration("Emit") : 0; if (compilerOptions.extendedDiagnostics) { - const caches = program.getRelationCacheSizes(); - reportCountStatistic("Assignability cache size", caches.assignable); - reportCountStatistic("Identity cache size", caches.identity); - reportCountStatistic("Subtype cache size", caches.subtype); - reportCountStatistic("Strict subtype cache size", caches.strictSubtype); + if (program) { + const caches = program.getRelationCacheSizes(); + reportCountStatistic("Assignability cache size", caches.assignable); + reportCountStatistic("Identity cache size", caches.identity); + reportCountStatistic("Subtype cache size", caches.subtype); + reportCountStatistic("Strict subtype cache size", caches.strictSubtype); + } if (isPerformanceEnabled) { performance.forEachMeasure((name, duration) => reportTimeStatistic(`${name} time`, duration)); } @@ -1006,43 +1085,59 @@ namespace ts { if (isPerformanceEnabled) { reportTimeStatistic("Total time", programTime + bindTime + checkTime + emitTime); } - reportStatistics(); + reportAllStatistics(sys, statistics); if (!isPerformanceEnabled) { sys.write(Diagnostics.Performance_timings_for_diagnostics_or_extendedDiagnostics_are_not_available_in_this_session_A_native_implementation_of_the_Web_Performance_API_could_not_be_found.message + "\n"); } else { performance.disable(); } + return statistics; } - function reportStatistics() { - let nameSize = 0; - let valueSize = 0; - for (const { name, value } of statistics) { - if (name.length > nameSize) { - nameSize = name.length; - } - - if (value.length > valueSize) { - valueSize = value.length; - } - } - - for (const { name, value } of statistics) { - sys.write(padRight(name + ":", nameSize + 2) + padLeft(value.toString(), valueSize) + sys.newLine); - } - } - - function reportStatisticalValue(name: string, value: string) { - statistics.push({ name, value }); + function reportMemoryStatistic(name: string, memoryUsed: number) { + statistics.push({ name, value: memoryUsed, type: StatisticType.memory }); } function reportCountStatistic(name: string, count: number) { - reportStatisticalValue(name, "" + count); + statistics.push({ name, value: count, type: StatisticType.count }); } function reportTimeStatistic(name: string, time: number) { - reportStatisticalValue(name, (time / 1000).toFixed(2) + "s"); + statistics.push({ name, value: time, type: StatisticType.time }); + } + } + + function reportAllStatistics(sys: System, statistics: Statistic[]) { + let nameSize = 0; + let valueSize = 0; + for (const s of statistics) { + if (s.name.length > nameSize) { + nameSize = s.name.length; + } + + const valueString = statisticValue(s); + if (valueString.length > valueSize) { + valueSize = valueString.length; + } + } + + for (const s of statistics) { + sys.write(padRight(s.name + ":", nameSize + 2) + padLeft(statisticValue(s).toString(), valueSize) + sys.newLine); + } + } + + function statisticValue(s: Statistic) { + switch (s.type) { + case StatisticType.count: + return "" + s.value; + case StatisticType.time: + return (s.value / 1000).toFixed(2) + "s"; + case StatisticType.memory: + return Math.round(s.value / 1000) + "K"; + break; + default: + Debug.assertNever(s.type); } }