microsoft/TypeScript
1
0
Fork 0
mirror of https://github.com/microsoft/TypeScript.git synced 2026-02-06 20:14:01 -06:00
Code Issues Packages Projects Releases 212 Wiki Activity

More logging for performance

Browse Source
This commit is contained in:
Sheetal Nandi 2020-01-24 12:36:19 -08:00
parent d10eedea4f
commit fd7ed33253
6 changed files with 153 additions and 104 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

125
src/compiler/utilities.ts
View File

@ -6240,4 +6240,129 @@ namespace ts {
const heritageClause = tryCast(node.parent.parent, isHeritageClause) ?? tryCast(node.parent.parent?.parent, isHeritageClause);
return heritageClause?.token === SyntaxKind.ImplementsKeyword || heritageClause?.parent.kind === SyntaxKind.InterfaceDeclaration;
}
interface Statistic {
name: string;
value: string;
}
function countLines(program: Program): number {
let count = 0;
forEach(program.getSourceFiles(), file => {
count += getLineStarts(file).length;
});
return count;
}
function padLeft(s: string, length: number) {
while (s.length < length) {
s = " " + s;
}
return s;
}
function padRight(s: string, length: number) {
while (s.length < length) {
s = s + " ";
}
return s;
}
export interface StatisticsHost {
getMemoryUsage?(): number;
write(s: string): void;
newLine: string;
system: System;
}
export function enableStatistics(host: StatisticsHost | System, compilerOptions: CompilerOptions) {
if (canReportDiagnostics(host, compilerOptions)) {
performance.enable();
}
}
export function reportStatistics(host: StatisticsHost | System, program: Program) {
let statistics: Statistic[];
const compilerOptions = program.getCompilerOptions();
if (canReportDiagnostics(host, compilerOptions)) {
statistics = [];
const memoryUsed = host.getMemoryUsage ? host.getMemoryUsage() : -1;
reportCountStatistic("Files", program.getSourceFiles().length);
reportCountStatistic("Lines", countLines(program));
reportCountStatistic("Nodes", program.getNodeCount());
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");
}
const programTime = performance.getDuration("Program");
const bindTime = performance.getDuration("Bind");
const checkTime = performance.getDuration("Check");
const emitTime = performance.getDuration("Emit");
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);
performance.forEachMeasure((name, duration) => reportTimeStatistic(`${name} time`, duration));
}
else {
// Individual component times.
// Note: To match the behavior of previous versions of the compiler, the reported parse time includes
// I/O read time and processing time for triple-slash references and module imports, and the reported
// emit time includes I/O write time. We preserve this behavior so we can accurately compare times.
reportTimeStatistic("I/O read", performance.getDuration("I/O Read"));
reportTimeStatistic("I/O write", performance.getDuration("I/O Write"));
reportTimeStatistic("Parse time", programTime);
reportTimeStatistic("Bind time", bindTime);
reportTimeStatistic("Check time", checkTime);
reportTimeStatistic("Emit time", emitTime);
}
reportTimeStatistic("Total time", programTime + bindTime + checkTime + emitTime);
reportStatistics();
performance.disable();
}
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) {
host.write(padRight(name + ":", nameSize + 2) + padLeft(value.toString(), valueSize) + host.newLine);
}
}
function reportStatisticalValue(name: string, value: string) {
statistics.push({ name, value });
}
function reportCountStatistic(name: string, count: number) {
reportStatisticalValue(name, "" + count);
}
function reportTimeStatistic(name: string, time: number) {
reportStatisticalValue(name, (time / 1000).toFixed(2) + "s");
}
}
function canReportDiagnostics(host: StatisticsHost | System, compilerOptions: CompilerOptions) {
return (host === sys || (host as StatisticsHost).system === sys) &&
(compilerOptions.diagnostics || compilerOptions.extendedDiagnostics);
}
}

102
src/executeCommandLine/executeCommandLine.ts
View File

@ -1,17 +1,4 @@
namespace ts {
interface Statistic {
name: string;
value: string;
}
function countLines(program: Program): number {
let count = 0;
forEach(program.getSourceFiles(), file => {
count += getLineStarts(file).length;
});
return count;
}
function updateReportDiagnostic(
sys: System,
existing: DiagnosticReporter,
@ -617,95 +604,6 @@ namespace ts {
return createWatchProgram(watchCompilerHost);
}
function canReportDiagnostics(system: System, compilerOptions: CompilerOptions) {
return system === sys && (compilerOptions.diagnostics || compilerOptions.extendedDiagnostics);
}
function enableStatistics(sys: System, compilerOptions: CompilerOptions) {
if (canReportDiagnostics(sys, compilerOptions)) {
performance.enable();
}
}
function reportStatistics(sys: System, program: Program) {
let statistics: Statistic[];
const compilerOptions = program.getCompilerOptions();
if (canReportDiagnostics(sys, compilerOptions)) {
statistics = [];
const memoryUsed = sys.getMemoryUsage ? sys.getMemoryUsage() : -1;
reportCountStatistic("Files", program.getSourceFiles().length);
reportCountStatistic("Lines", countLines(program));
reportCountStatistic("Nodes", program.getNodeCount());
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");
}
const programTime = performance.getDuration("Program");
const bindTime = performance.getDuration("Bind");
const checkTime = performance.getDuration("Check");
const emitTime = performance.getDuration("Emit");
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);
performance.forEachMeasure((name, duration) => reportTimeStatistic(`${name} time`, duration));
}
else {
// Individual component times.
// Note: To match the behavior of previous versions of the compiler, the reported parse time includes
// I/O read time and processing time for triple-slash references and module imports, and the reported
// emit time includes I/O write time. We preserve this behavior so we can accurately compare times.
reportTimeStatistic("I/O read", performance.getDuration("I/O Read"));
reportTimeStatistic("I/O write", performance.getDuration("I/O Write"));
reportTimeStatistic("Parse time", programTime);
reportTimeStatistic("Bind time", bindTime);
reportTimeStatistic("Check time", checkTime);
reportTimeStatistic("Emit time", emitTime);
}
reportTimeStatistic("Total time", programTime + bindTime + checkTime + emitTime);
reportStatistics();
performance.disable();
}
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 reportCountStatistic(name: string, count: number) {
reportStatisticalValue(name, "" + count);
}
function reportTimeStatistic(name: string, time: number) {
reportStatisticalValue(name, (time / 1000).toFixed(2) + "s");
}
}
function writeConfigFile(
sys: System,
reportDiagnostic: DiagnosticReporter,

4
src/server/editorServices.ts
View File

@ -668,11 +668,11 @@ namespace ts.server {
extraFileExtensions: [],
};
this.documentRegistry = createDocumentRegistryInternal(this.host.useCaseSensitiveFileNames, this.currentDirectory, this);
const watchLogLevel = this.logger.hasLevel(LogLevel.verbose) ? WatchLogLevel.Verbose :
this.logger.loggingEnabled() ? WatchLogLevel.TriggerOnly : WatchLogLevel.None;
const log: (s: string) => void = watchLogLevel !== WatchLogLevel.None ? (s => this.logger.info(s)) : noop;
this.watchFactory = getWatchFactory(watchLogLevel, log, getDetailWatchInfo);
this.documentRegistry = createDocumentRegistryInternal(this.host.useCaseSensitiveFileNames, this.currentDirectory, this);
}
toPath(fileName: string) {
@ -1397,6 +1397,7 @@ namespace ts.server {
}
private deleteScriptInfo(info: ScriptInfo) {
this.logger.info(`Deleting script info: ${info.path}`);
this.filenameToScriptInfo.delete(info.path);
this.filenameToScriptInfoVersion.set(info.path, info.getVersion());
const realpath = info.getRealpathIfDifferent();
@ -2404,6 +2405,7 @@ namespace ts.server {
return;
}
info = new ScriptInfo(this.host, fileName, scriptKind!, !!hasMixedContent, path, this.filenameToScriptInfoVersion.get(path)); // TODO: GH#18217
this.logger.info(`Created script info: ${info.path}`);
this.filenameToScriptInfo.set(info.path, info);
this.filenameToScriptInfoVersion.delete(info.path);
if (!openedByClient) {

15
src/server/project.ts
View File

@ -247,6 +247,8 @@ namespace ts.server {
/*@internal*/
private symlinks: ReadonlyMap<string> | undefined;
private readonly statisticsHost: StatisticsHost;
/*@internal*/
constructor(
/*@internal*/ readonly projectName: string,
@ -275,6 +277,7 @@ namespace ts.server {
// If files are listed explicitly or allowJs is specified, allow all extensions
this.compilerOptions.allowNonTsExtensions = true;
}
this.compilerOptions.extendedDiagnostics = true;
this.languageServiceEnabled = !projectService.syntaxOnly;
@ -291,6 +294,13 @@ namespace ts.server {
this.realpath = customRealpath || (path => host.realpath!(path));
}
this.statisticsHost = {
newLine: "",
getMemoryUsage: maybeBind(host, host.getMemoryUsage),
write: s => this.writeLog(s),
system: host
};
// Use the current directory as resolution root only if the project created using current directory string
this.resolutionCache = createResolutionCache(this, currentDirectory && this.currentDirectory, /*logChangesWhenResolvingModule*/ true);
this.languageService = createLanguageService(this, this.documentRegistry, projectService.syntaxOnly);
@ -987,6 +997,7 @@ namespace ts.server {
const oldProgram = this.program;
Debug.assert(!this.isClosed(), "Called update graph worker of closed project");
this.writeLog(`Starting updateGraphWorker: Project: ${this.getProjectName()}`);
enableStatistics(this.statisticsHost, this.getCompilationSettings());
const start = timestamp();
this.hasInvalidatedResolution = this.resolutionCache.createHasInvalidatedResolution();
this.resolutionCache.startCachingPerDirectoryResolution();
@ -1110,6 +1121,9 @@ namespace ts.server {
else if (this.program !== oldProgram) {
this.writeLog(`Different program with same set of files:: oldProgram.structureIsReused:: ${oldProgram && oldProgram.structureIsReused}`);
}
if (this.program) {
reportStatistics(this.statisticsHost, this.program);
}
return hasNewProgram;
}
@ -1303,6 +1317,7 @@ namespace ts.server {
this.lastCachedUnresolvedImportsList = undefined;
this.resolutionCache.clear();
}
this.compilerOptions.extendedDiagnostics = true;
this.markAsDirty();
}
}

2
src/server/session.ts
View File

@ -2623,9 +2623,11 @@ namespace ts.server {
public executeWithRequestId<T>(requestId: number, f: () => T) {
try {
this.setCurrentRequest(requestId);
this.logger.info(`Starting request: ${requestId}`);
return f();
}
finally {
this.logger.info(`Finished request: ${requestId}`);
this.resetCurrentRequest(requestId);
}
}

9
src/services/documentRegistry.ts
View File

@ -115,7 +115,7 @@ namespace ts {
}
/*@internal*/
export function createDocumentRegistryInternal(useCaseSensitiveFileNames?: boolean, currentDirectory = "", externalCache?: ExternalDocumentCache): DocumentRegistry {
export function createDocumentRegistryInternal(useCaseSensitiveFileNames?: boolean, currentDirectory = "", externalCache?: ExternalDocumentCache, log: (s: string) => void = noop): DocumentRegistry {
// Maps from compiler setting target (ES3, ES5, etc.) to all the cached documents we have
// for those settings.
const buckets = createMap<Map<DocumentRegistryEntry>>();
@ -170,10 +170,12 @@ namespace ts {
acquiring: boolean,
scriptKind?: ScriptKind): SourceFile {
const start = timestamp();
const bucket = getOrUpdate<Map<DocumentRegistryEntry>>(buckets, key, createMap);
let entry = bucket.get(path);
const scriptTarget = scriptKind === ScriptKind.JSON ? ScriptTarget.JSON : compilationSettings.target || ScriptTarget.ES5;
if (!entry && externalCache) {
log(`Creating document ${path}`);
const sourceFile = externalCache.getDocument(key, path);
if (sourceFile) {
Debug.assert(acquiring);
@ -217,9 +219,12 @@ namespace ts {
if (acquiring) {
entry.languageServiceRefCount++;
}
log(`${acquiring ? "acquiring" : "updating"} document ${path}`);
}
Debug.assert(entry.languageServiceRefCount !== 0);
const elapsed = timestamp() - start;
log(`${acquiring ? "acquiring" : "updating"} document ${path} elapsed: ${elapsed}ms`);
return entry.sourceFile;
}
@ -233,9 +238,11 @@ namespace ts {
const bucket = Debug.checkDefined(buckets.get(key));
const entry = bucket.get(path)!;
entry.languageServiceRefCount--;
log(`Releasing document: ${path}`);
Debug.assert(entry.languageServiceRefCount >= 0);
if (entry.languageServiceRefCount === 0) {
log(`Deleting document: ${path}`);
bucket.delete(path);
}
}