Simplified performance timers

This commit is contained in:
Ron Buckton 2016-05-26 18:25:11 -07:00
parent 3bf4f2a6f5
commit 3c6ceaf85e
8 changed files with 63 additions and 172 deletions

View file

@ -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 {

View file

@ -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.

View file

@ -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);
}
};
}

View file

@ -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<number> = {};
const markCounts: Map<number> = {};
const measureDurations: Map<number> = {};
let start = now();
let counters: Map<number> = {};
let measures: Map<number> = {};
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. */

View file

@ -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;
}

View file

@ -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<ResolvedTypeReferenceDirective> = {};
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;
}

View file

@ -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,

View file

@ -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();
}