From 3c6ceaf85e4516db1b06ad59da71a5d55624d957 Mon Sep 17 00:00:00 2001 From: Ron Buckton Date: Thu, 26 May 2016 18:25:11 -0700 Subject: [PATCH] Simplified performance timers --- src/compiler/binder.ts | 4 +- src/compiler/checker.ts | 4 +- src/compiler/comments.ts | 28 ++++---- src/compiler/core.ts | 132 ++++++-------------------------------- src/compiler/printer.ts | 4 +- src/compiler/program.ts | 16 ++--- src/compiler/sourcemap.ts | 20 +++--- src/compiler/tsc.ts | 27 ++------ 8 files changed, 63 insertions(+), 172 deletions(-) diff --git a/src/compiler/binder.ts b/src/compiler/binder.ts index 707a7567d7..fe225d9225 100644 --- a/src/compiler/binder.ts +++ b/src/compiler/binder.ts @@ -94,9 +94,9 @@ namespace ts { const binder = createBinder(); export function bindSourceFile(file: SourceFile, options: CompilerOptions) { - performance.mark("bindStart"); + const bindStart = performance.mark(); binder(file, options); - performance.measure("bindTime", "bindStart"); + performance.measure("bindTime", bindStart); } function createBinder(): (file: SourceFile, options: CompilerOptions) => void { diff --git a/src/compiler/checker.ts b/src/compiler/checker.ts index 71e099bbf8..c03c5a163c 100644 --- a/src/compiler/checker.ts +++ b/src/compiler/checker.ts @@ -16064,11 +16064,11 @@ namespace ts { } function checkSourceFile(node: SourceFile) { - performance.mark("checkStart"); + const checkStart = performance.mark(); checkSourceFileWorker(node); - performance.measure("checkTime", "checkStart"); + performance.measure("checkTime", checkStart); } // Fully type check a source file and collect the relevant diagnostics. diff --git a/src/compiler/comments.ts b/src/compiler/comments.ts index 79bb795efe..a7c7c34ab4 100644 --- a/src/compiler/comments.ts +++ b/src/compiler/comments.ts @@ -272,42 +272,42 @@ namespace ts { reset, setSourceFile, getLeadingComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean, getTextRangeCallback?: (contextNode: Node) => TextRange): CommentRange[] { - performance.mark("commentStart"); + const commentStart = performance.mark(); const comments = getLeadingComments(range, contextNode, ignoreNodeCallback, getTextRangeCallback); - performance.measure("commentTime", "commentStart"); + performance.measure("commentTime", commentStart); return comments; }, getTrailingComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean, getTextRangeCallback?: (contextNode: Node) => TextRange): CommentRange[] { - performance.mark("commentStart"); + const commentStart = performance.mark(); const comments = getTrailingComments(range, contextNode, ignoreNodeCallback, getTextRangeCallback); - performance.measure("commentTime", "commentStart"); + performance.measure("commentTime", commentStart); return comments; }, getTrailingCommentsOfPosition(pos: number): CommentRange[] { - performance.mark("commentStart"); + const commentStart = performance.mark(); const comments = getTrailingCommentsOfPosition(pos); - performance.measure("commentTime", "commentStart"); + performance.measure("commentTime", commentStart); return comments; }, emitLeadingComments(range: TextRange, comments: CommentRange[], contextNode?: Node, getTextRangeCallback?: (contextNode: Node) => TextRange): void { - performance.mark("commentStart"); + const commentStart = performance.mark(); emitLeadingComments(range, comments, contextNode, getTextRangeCallback); - performance.measure("commentTime", "commentStart"); + performance.measure("commentTime", commentStart); }, emitTrailingComments(range: TextRange, comments: CommentRange[]): void { - performance.mark("commentStart"); + const commentStart = performance.mark(); emitLeadingComments(range, comments); - performance.measure("commentTime", "commentStart"); + performance.measure("commentTime", commentStart); }, emitLeadingDetachedComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean): void { - performance.mark("commentStart"); + const commentStart = performance.mark(); emitLeadingDetachedComments(range, contextNode, ignoreNodeCallback); - performance.measure("commentTime", "commentStart"); + performance.measure("commentTime", commentStart); }, emitTrailingDetachedComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean): void { - performance.mark("commentStart"); + const commentStart = performance.mark(); emitTrailingDetachedComments(range, contextNode, ignoreNodeCallback); - performance.measure("commentTime", "commentStart"); + performance.measure("commentTime", commentStart); } }; } diff --git a/src/compiler/core.ts b/src/compiler/core.ts index aada521c2e..1980cf9ad9 100644 --- a/src/compiler/core.ts +++ b/src/compiler/core.ts @@ -1139,158 +1139,64 @@ namespace ts { /** Performance measurements for the compiler. */ /*@internal*/ export namespace performance { - interface MarkData { - markName: string; - timestamp: number; - } - - interface MeasureData { - measureName: string; - startMarkName: string; - endMarkName: string; - timestamp: number; - marksOffset: number; - } - - export interface Measure { - name: string; - startTime: number; - duration: number; - } - - const markTimestamps: Map = {}; - const markCounts: Map = {}; - const measureDurations: Map = {}; - - let start = now(); + let counters: Map = {}; + let measures: Map = {}; let enabled = false; - /** Gets the current timer for performance measurements. */ - export function now() { - return Date.now(); - } - /** - * Adds a performance mark with the specified name. + * Increments a counter with the specified name. * - * @param markName The name of the performance mark. + * @param counterName The name of the counter. */ - export function mark(markName: string) { + export function increment(counterName: string) { if (enabled) { - markTimestamps[markName] = now(); - markCounts[markName] = getCount(markName) + 1; + counters[counterName] = (getProperty(counters, counterName) || 0) + 1; } } /** - * Gets the names of all marks. - */ - export function getMarkNames() { - return getKeys(markCounts); - } - - /** - * Gets the number of marks with the specified name. + * Gets the value of the counter with the specified name. * - * @param markName The name of the marks that should be counted. + * @param counterName The name of the counter. */ - export function getCount(markName: string) { - return enabled && getProperty(markCounts, markName) || 0; + export function getCount(counterName: string) { + return enabled && getProperty(counters, counterName) || 0; } /** - * Gets the most recent timestamp for the marks with the specified name. - * - * @param markName The name of the mark. + * Marks the start of a performance measurement. */ - export function getTimestamp(markName: string) { - return enabled && getProperty(markTimestamps, markName) || 0; - } - - /** - * Clears performance marks. - * - * @param markName The name of the mark whose time values should be cleared. If not - * specified, all marks will be cleared. - */ - export function clearMarks(markName?: string) { - if (markName === undefined) { - forEachKey(markTimestamps, clearMark); - } - else { - clearMark(markName); - } - } - - function clearMark(markName: string) { - if (delete markTimestamps[markName]) { - delete markCounts[markName]; - } + export function mark() { + return enabled ? Date.now() : 0; } /** * 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 provided, the most recent time value of the start mark is used. - * If not specified, the value is the time that the performance service was - * initialized or the last time it was reset. - * @param endMarkName The name of the ending mark. - * If provided, the most recent time value of the end mark is used. - * If not specified, the current time is used. + * @param marker The timestamp of the starting mark. */ - export function measure(measureName: string, startMarkName?: string, endMarkName?: string) { + export function measure(measureName: string, marker: number) { if (enabled) { - const startTime = startMarkName ? getTimestamp(startMarkName) : start; - const endTime = endMarkName ? getTimestamp(endMarkName) : now(); - const duration = endTime - startTime; - measureDurations[measureName] = getDuration(measureName) + duration; + measures[measureName] = (getProperty(measures, measureName) || 0) + (mark() - marker); } } - /** - * Gets the names of all recorded measures. - */ - export function getMeasureNames() { - return getKeys(measureDurations); - } - /** * 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 enabled && getProperty(measureDurations, measureName) || 0; - } - - /** - * Clears performance measures. - * - * @param measureName The name of the measure whose durations should be cleared. If not - * specified, all measures will be cleared. - */ - export function clearMeasures(measureName?: string) { - if (measureName === undefined) { - forEachKey(measureDurations, clearMeasure); - } - else { - clearMeasure(measureName); - } - } - - function clearMeasure(measureName: string) { - delete measureDurations[measureName]; + return enabled && getProperty(measures, measureName) || 0; } /** * Resets all marks and measurements in the performance service. */ export function reset() { - clearMarks(); - clearMeasures(); - start = now(); + counters = {}; + measures = {}; } /** Enables performance measurements for the compiler. */ diff --git a/src/compiler/printer.ts b/src/compiler/printer.ts index 12d399b04d..c577f7999f 100644 --- a/src/compiler/printer.ts +++ b/src/compiler/printer.ts @@ -281,9 +281,9 @@ const _super = (function (geti, seti) { } function printSourceFileWithExtendedDiagnostics(node: SourceFile) { - performance.mark("printStart"); + const printStart = performance.mark(); printSourceFile(node); - performance.measure("printTime", "printStart"); + performance.measure("printTime", printStart); return node; } diff --git a/src/compiler/program.ts b/src/compiler/program.ts index 5559f9d374..03db19ed44 100644 --- a/src/compiler/program.ts +++ b/src/compiler/program.ts @@ -776,9 +776,9 @@ namespace ts { function getSourceFile(fileName: string, languageVersion: ScriptTarget, onError?: (message: string) => void): SourceFile { let text: string; try { - performance.mark("ioReadStart"); + const ioReadStart = performance.mark(); text = sys.readFile(fileName, options.charset); - performance.measure("ioReadTime", "ioReadStart"); + performance.measure("ioReadTime", ioReadStart); } catch (e) { if (onError) { @@ -845,7 +845,7 @@ namespace ts { function writeFile(fileName: string, data: string, writeByteOrderMark: boolean, onError?: (message: string) => void) { try { - performance.mark("ioWriteStart"); + const ioWriteStart = performance.mark(); ensureDirectoriesExist(getDirectoryPath(normalizePath(fileName))); if (isWatchSet(options) && sys.createHash && sys.getModifiedTime) { @@ -855,7 +855,7 @@ namespace ts { sys.writeFile(fileName, data, writeByteOrderMark); } - performance.measure("ioWriteTime", "ioWriteStart"); + performance.measure("ioWriteTime", ioWriteStart); } catch (e) { if (onError) { @@ -957,7 +957,7 @@ namespace ts { let resolvedTypeReferenceDirectives: Map = {}; let fileProcessingDiagnostics = createDiagnosticCollection(); - performance.mark("programStart"); + const programStart = performance.mark(); host = host || createCompilerHost(options); @@ -1050,7 +1050,7 @@ namespace ts { verifyCompilerOptions(); - performance.measure("programTime", "programStart"); + performance.measure("programTime", programStart); return program; @@ -1283,7 +1283,7 @@ namespace ts { // checked is to not pass the file to getEmitResolver. const emitResolver = getDiagnosticsProducingTypeChecker().getEmitResolver((options.outFile || options.out) ? undefined : sourceFile); - performance.mark("emitStart"); + const emitStart = performance.mark(); // TODO(rbuckton): remove USE_TRANSFORMS condition when we switch to transforms permanently. let useLegacyEmitter = options.useLegacyEmitter; @@ -1297,7 +1297,7 @@ namespace ts { getEmitHost(writeFileCallback), sourceFile); - performance.measure("emitTime", "emitStart"); + performance.measure("emitTime", emitStart); return emitResult; } diff --git a/src/compiler/sourcemap.ts b/src/compiler/sourcemap.ts index 8e7cc3b1d4..de056196bd 100644 --- a/src/compiler/sourcemap.ts +++ b/src/compiler/sourcemap.ts @@ -782,30 +782,30 @@ namespace ts { getSourceMapData, setSourceFile, emitPos(pos: number): void { - performance.mark("sourcemapStart"); + const sourcemapStart = performance.mark(); emitPos(pos); - performance.measure("sourcemapTime", "sourcemapStart"); + performance.measure("sourceMapTime", sourcemapStart); }, emitStart(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (node: Node) => boolean, ignoreChildrenCallback?: (node: Node) => boolean, getTextRangeCallback?: (node: Node) => TextRange): void { - performance.mark("sourcemapStart"); + const sourcemapStart = performance.mark(); emitStart(range, contextNode, ignoreNodeCallback, ignoreChildrenCallback, getTextRangeCallback); - performance.measure("sourcemapTime", "sourcemapStart"); + performance.measure("sourceMapTime", sourcemapStart); }, emitEnd(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (node: Node) => boolean, ignoreChildrenCallback?: (node: Node) => boolean, getTextRangeCallback?: (node: Node) => TextRange): void { - performance.mark("sourcemapStart"); + const sourcemapStart = performance.mark(); emitEnd(range, contextNode, ignoreNodeCallback, ignoreChildrenCallback, getTextRangeCallback); - performance.measure("sourcemapTime", "sourcemapStart"); + performance.measure("sourceMapTime", sourcemapStart); }, emitTokenStart(token: SyntaxKind, tokenStartPos: number, contextNode?: Node, ignoreTokenCallback?: (node: Node) => boolean, getTokenTextRangeCallback?: (node: Node, token: SyntaxKind) => TextRange): number { - performance.mark("sourcemapStart"); + const sourcemapStart = performance.mark(); tokenStartPos = emitTokenStart(token, tokenStartPos, contextNode, ignoreTokenCallback, getTokenTextRangeCallback); - performance.measure("sourcemapTime", "sourcemapStart"); + performance.measure("sourceMapTime", sourcemapStart); return tokenStartPos; }, emitTokenEnd(token: SyntaxKind, tokenEndPos: number, contextNode?: Node, ignoreTokenCallback?: (node: Node) => boolean, getTokenTextRangeCallback?: (node: Node, token: SyntaxKind) => TextRange): number { - performance.mark("sourcemapStart"); + const sourcemapStart = performance.mark(); tokenEndPos = emitTokenEnd(token, tokenEndPos, contextNode, ignoreTokenCallback, getTokenTextRangeCallback); - performance.measure("sourcemapTime", "sourcemapStart"); + performance.measure("sourceMapTime", sourcemapStart); return tokenEndPos; }, changeEmitSourcePos, diff --git a/src/compiler/tsc.ts b/src/compiler/tsc.ts index 9d521c17f2..f7bb2f5d4d 100644 --- a/src/compiler/tsc.ts +++ b/src/compiler/tsc.ts @@ -571,6 +571,12 @@ namespace ts { reportStatisticalValue("Memory used", Math.round(memoryUsed / 1000) + "K"); } + if (compilerOptions.extendedDiagnostics) { + reportTimeStatistic("Print time", performance.getDuration("printTime")); + reportTimeStatistic("Comment time", performance.getDuration("commentTime")); + reportTimeStatistic("SourceMap time", performance.getDuration("sourceMapTime")); + } + // 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 @@ -587,27 +593,6 @@ namespace ts { reportTimeStatistic("Emit time", emitTime); reportTimeStatistic("Total time", programTime + bindTime + checkTime + emitTime); - if (compilerOptions.extendedDiagnostics) { - sys.write("Extended Diagnostics:" + sys.newLine); - sys.write("Marks:" + sys.newLine); - for (const markName of performance.getMarkNames()) { - if (/^(ioReadStart|ioWriteStart|programStart|bindStart|checkStart|emitStart)$/.test(markName)) { - continue; - } - - reportCountStatistic(" " + markName, performance.getCount(markName)); - } - - sys.write("Measures:" + sys.newLine); - for (const measureName of performance.getMeasureNames()) { - if (/^(ioReadTime|ioWriteTime|programTime|bindTime|checkTime|emitTime)$/.test(measureName)) { - continue; - } - - reportTimeStatistic(" " + measureName, performance.getDuration(measureName)); - } - } - performance.disable(); performance.reset(); }