Added metrics for printing

This commit is contained in:
Ron Buckton 2016-05-24 10:36:23 -07:00
parent b5dec0b8ab
commit 96ba0f2696
7 changed files with 143 additions and 112 deletions

View file

@ -96,8 +96,7 @@ namespace ts {
export function bindSourceFile(file: SourceFile, options: CompilerOptions) {
performance.mark("bindStart");
binder(file, options);
performance.mark("bindEnd");
performance.measure("bindTime", "bindStart", "bindEnd");
performance.measure("bindTime", "bindStart");
}
function createBinder(): (file: SourceFile, options: CompilerOptions) => void {

View file

@ -16068,8 +16068,7 @@ namespace ts {
checkSourceFileWorker(node);
performance.mark("checkEnd");
performance.measure("checkTime", "checkStart", "checkEnd");
performance.measure("checkTime", "checkStart");
}
// Fully type check a source file and collect the relevant diagnostics.

View file

@ -7,7 +7,6 @@ namespace ts {
setSourceFile(sourceFile: SourceFile): void;
getLeadingComments(range: TextRange): CommentRange[];
getLeadingComments(range: TextRange, contextNode: Node, ignoreNodeCallback: (contextNode: Node) => boolean, getTextRangeCallback: (contextNode: Node) => TextRange): CommentRange[];
getLeadingCommentsOfPosition(pos: number): CommentRange[];
getTrailingComments(range: TextRange): CommentRange[];
getTrailingComments(range: TextRange, contextNode: Node, ignoreNodeCallback: (contextNode: Node) => boolean, getTextRangeCallback: (contextNode: Node) => TextRange): CommentRange[];
getTrailingCommentsOfPosition(pos: number): CommentRange[];
@ -32,9 +31,9 @@ namespace ts {
// This maps start->end for a comment range. See `hasConsumedCommentRange` and
// `consumeCommentRange` for usage.
let consumedCommentRanges: number[];
let leadingCommentRangePositions: boolean[];
let trailingCommentRangePositions: boolean[];
let consumedCommentRanges: Map<number>;
let leadingCommentRangePositions: Map<boolean>;
let trailingCommentRangePositions: Map<boolean>;
return compilerOptions.removeComments
? createCommentRemovingWriter()
@ -45,7 +44,6 @@ namespace ts {
reset,
setSourceFile,
getLeadingComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean, getTextRangeCallback?: (contextNode: Node) => TextRange): CommentRange[] { return undefined; },
getLeadingCommentsOfPosition(pos: number): CommentRange[] { return undefined; },
getTrailingComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean, getTextRangeCallback?: (contextNode: Node) => TextRange): CommentRange[] { return undefined; },
getTrailingCommentsOfPosition(pos: number): CommentRange[] { return undefined; },
emitLeadingComments(range: TextRange, comments: CommentRange[], contextNode?: Node, getTextRangeCallback?: (contextNode: Node) => TextRange): void { },
@ -69,7 +67,6 @@ namespace ts {
reset,
setSourceFile,
getLeadingComments,
getLeadingCommentsOfPosition,
getTrailingComments,
getTrailingCommentsOfPosition,
emitLeadingComments,
@ -81,9 +78,14 @@ namespace ts {
function getLeadingComments(range: TextRange): CommentRange[];
function getLeadingComments(range: TextRange, contextNode: Node, ignoreNodeCallback: (contextNode: Node) => boolean, getTextRangeCallback: (contextNode: Node) => TextRange): CommentRange[];
function getLeadingComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean, getTextRangeCallback?: (contextNode: Node) => TextRange) {
performance.mark("commentStart");
let comments: CommentRange[] = [];
let ignored = false;
if (contextNode) {
range = getTextRangeCallback(contextNode) || range;
if (ignoreNodeCallback(contextNode)) {
ignored = true;
// If the node will not be emitted in JS, remove all the comments (normal,
// pinned and `///`) associated with the node, unless it is a triple slash
// comment at the top of the file.
@ -97,15 +99,17 @@ namespace ts {
// The first `///` will NOT be removed while the second one will be removed
// even though both nodes will not be emitted.
if (range.pos === 0) {
return filter(getLeadingCommentsOfPosition(0), isTripleSlashComment);
comments = filter(getLeadingCommentsOfPosition(0), isTripleSlashComment);
}
return undefined;
}
}
if (!ignored) {
comments = getLeadingCommentsOfPosition(range.pos);
}
return getLeadingCommentsOfPosition(range.pos);
performance.measure("commentTime", "commentStart");
return comments;
}
/**
@ -127,15 +131,25 @@ namespace ts {
function getTrailingComments(range: TextRange): CommentRange[];
function getTrailingComments(range: TextRange, contextNode: Node, ignoreNodeCallback: (contextNode: Node) => boolean, getTextRangeCallback: (contextNode: Node) => TextRange): CommentRange[];
function getTrailingComments(range: TextRange, contextNode?: Node, ignoreNodeCallback?: (contextNode: Node) => boolean, getTextRangeCallback?: (contextNode: Node) => TextRange) {
performance.mark("commentStart");
let ignored = false;
if (contextNode) {
if (ignoreNodeCallback(contextNode)) {
return undefined;
ignored = true;
}
else {
range = getTextRangeCallback(contextNode) || range;
}
range = getTextRangeCallback(contextNode) || range;
}
return getTrailingCommentsOfPosition(range.end);
let comments: CommentRange[];
if (!ignored) {
comments = getTrailingCommentsOfPositionWorker(range.end);
}
performance.measure("commentTime", "commentStart");
return comments;
}
function getLeadingCommentsOfPosition(pos: number) {
@ -151,6 +165,13 @@ namespace ts {
}
function getTrailingCommentsOfPosition(pos: number) {
performance.mark("commentStart");
const comments = getTrailingCommentsOfPositionWorker(pos);
performance.measure("commentTime", "commentStart");
return comments;
}
function getTrailingCommentsOfPositionWorker(pos: number) {
if (positionIsSynthesized(pos) || trailingCommentRangePositions[pos]) {
return undefined;
}
@ -163,6 +184,7 @@ namespace ts {
function emitLeadingComments(range: TextRange, comments: CommentRange[]): void;
function emitLeadingComments(range: TextRange, comments: CommentRange[], contextNode: Node, getTextRangeCallback: (contextNode: Node) => TextRange): void;
function emitLeadingComments(range: TextRange, comments: CommentRange[], contextNode?: Node, getTextRangeCallback?: (contextNode: Node) => TextRange) {
performance.mark("commentStart");
if (comments && comments.length > 0) {
if (contextNode) {
range = getTextRangeCallback(contextNode) || range;
@ -173,11 +195,14 @@ namespace ts {
// Leading comments are emitted at /*leading comment1 */space/*leading comment*/space
emitComments(currentText, currentLineMap, writer, comments, /*leadingSeparator*/ false, /*trailingSeparator*/ true, newLine, writeComment);
}
performance.measure("commentTime", "commentStart");
}
function emitTrailingComments(range: TextRange, comments: CommentRange[]) {
// trailing comments are emitted at space/*trailing comment1 */space/*trailing comment*/
performance.mark("commentStart");
emitComments(currentText, currentLineMap, writer, comments, /*leadingSeparator*/ true, /*trailingSeparator*/ false, newLine, writeComment);
performance.measure("commentTime", "commentStart");
}
function emitLeadingDetachedComments(range: TextRange): void;
@ -187,7 +212,9 @@ namespace ts {
return;
}
performance.mark("commentStart");
emitDetachedCommentsAndUpdateCommentsInfo(range, /*removeComments*/ false);
performance.measure("commentTime", "commentStart");
}
function emitTrailingDetachedComments(range: TextRange): void;
@ -264,9 +291,9 @@ namespace ts {
currentText = sourceFile.text;
currentLineMap = getLineStarts(sourceFile);
detachedCommentsInfo = undefined;
consumedCommentRanges = [];
leadingCommentRangePositions = [];
trailingCommentRangePositions = [];
consumedCommentRanges = {};
leadingCommentRangePositions = {};
trailingCommentRangePositions = {};
}
function hasDetachedComments(pos: number) {

View file

@ -1157,15 +1157,15 @@ namespace ts {
duration: number;
}
const marks: MarkData[] = [];
const measures: MeasureData[] = [];
const markTimestamps: Map<number> = {};
const markCounts: Map<number> = {};
const measureDurations: Map<number> = {};
let start = now();
let enabled = false;
/** Gets the current timer for performance measurements. */
export function now() {
// TODO(rbuckton): Determine if there is a higher-resolution timer we can use.
return Date.now();
}
@ -1176,103 +1176,110 @@ namespace ts {
*/
export function mark(markName: string) {
if (enabled) {
marks.push({ markName, timestamp: now() });
markTimestamps[markName] = now();
markCounts[markName] = getCount(markName) + 1;
}
}
/**
* Gets the number of marks with the specified name.
*
* @param markName The name of the marks that should be counted.
*/
export function getCount(markName: string) {
if (enabled) {
return getProperty(markCounts, markName) || 0;
}
return 0;
}
/**
* Gets the most recent timestamp for the marks with the specified name.
*
* @param markName The name of the mark.
*/
export function getTimestamp(markName: string) {
if (enabled) {
return getProperty(markTimestamps, markName) || 0;
}
return 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) {
markTimestamps[markName] = 0;
markCounts[markName] = 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.
* 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.
* If provided, the most recent time value of the end mark is used.
* If not specified, the current time is used.
*/
export function measure(measureName: string, startMarkName?: string, endMarkName?: string) {
if (enabled) {
measures.push({
measureName,
startMarkName,
endMarkName,
timestamp: now(),
marksOffset: marks.length
});
const startTime = startMarkName ? getTimestamp(startMarkName) : start;
const endTime = endMarkName ? getTimestamp(endMarkName) : now();
const duration = endTime - startTime;
measureDurations[measureName] = getDuration(measureName) + duration;
}
}
/**
* Gets an array of performance measures.
* Gets the total duration of all measurements with the supplied name.
*
* @param measureName The name of the measure.
* If provided, only measures with the provided name are returned.
* If not specified, all measures are returned since the last time the
* performance service was reset.
* @param measureName The name of the measure whose durations should be accumulated.
*/
export function getMeasures(measureName?: string) {
const result: Measure[] = [];
for (const measure of measures) {
if (measureName !== undefined && measureName !== measure.measureName) {
continue;
}
let startOffset = 0;
let startTime = start;
if (measure.startMarkName) {
const startMarkIndex = getMarkOffset(measure.startMarkName, 0, measure.marksOffset);
if (startMarkIndex >= 0) {
startOffset = startMarkIndex;
startTime = marks[startMarkIndex].timestamp;
}
}
let endTime = measure.timestamp;
if (measure.endMarkName) {
const endMarkIndex = getMarkOffset(measure.endMarkName, startOffset, measure.marksOffset);
if (endMarkIndex >= 0) {
endTime = marks[endMarkIndex].timestamp;
}
}
const duration = endTime - startTime;
result.push({
name: measure.measureName,
startTime,
duration
});
}
return result;
export function getDuration(measureName: string) {
return getProperty(measureDurations, measureName) || 0;
}
function getMarkOffset(markName: string, markStart: number, markEnd: number) {
if (markName === undefined) {
return -1;
/**
* 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);
}
if (markStart < 0) {
markStart = 0;
else {
clearMeasure(measureName);
}
}
for (let i = markEnd - 1; i >= markStart; i--) {
const mark = marks[i];
if (mark.markName === markName) {
return i;
}
}
return -1;
function clearMeasure(measureName: string) {
measureDurations[measureName] = 0;
}
/**
* Resets all marks and measurements in the performance service.
*/
export function reset() {
marks.length = 0;
measures.length = 0;
clearMarks();
clearMeasures();
start = now();
}

View file

@ -276,7 +276,9 @@ const _super = (function (geti, seti) {
currentFileIdentifiers = node.identifiers;
sourceMap.setSourceFile(node);
comments.setSourceFile(node);
performance.mark("printStart");
emitNodeWithNotificationOption(node, emitWorker);
performance.measure("printTime", "printStart");
return node;
}

View file

@ -778,8 +778,7 @@ namespace ts {
try {
performance.mark("ioReadStart");
text = sys.readFile(fileName, options.charset);
performance.mark("ioReadEnd");
performance.measure("ioReadTime", "ioReadStart", "ioReadEnd");
performance.measure("ioReadTime", "ioReadStart");
}
catch (e) {
if (onError) {
@ -856,8 +855,7 @@ namespace ts {
sys.writeFile(fileName, data, writeByteOrderMark);
}
performance.mark("ioWriteEnd");
performance.measure("ioWriteTime", "ioWriteStart", "ioWriteEnd");
performance.measure("ioWriteTime", "ioWriteStart");
}
catch (e) {
if (onError) {
@ -1052,8 +1050,7 @@ namespace ts {
verifyCompilerOptions();
performance.mark("programEnd");
performance.measure("programTime", "programStart", "programEnd");
performance.measure("programTime", "programStart");
return program;
@ -1300,8 +1297,7 @@ namespace ts {
getEmitHost(writeFileCallback),
sourceFile);
performance.mark("emitEnd");
performance.measure("emitTime", "emitStart", "emitEnd");
performance.measure("emitTime", "emitStart");
return emitResult;
}

View file

@ -238,7 +238,7 @@ namespace ts {
}
function reportStatisticalValue(name: string, value: string) {
sys.write(padRight(name + ":", 12) + padLeft(value.toString(), 10) + sys.newLine);
sys.write(padRight(name + ":", 20) + padLeft(value.toString(), 10) + sys.newLine);
}
function reportCountStatistic(name: string, count: number) {
@ -559,15 +559,6 @@ namespace ts {
}
if (compilerOptions.diagnostics) {
const ioReadTime = reduceLeft(performance.getMeasures("ioReadTime"), (aggregate, measure) => aggregate + measure.duration, 0);
const ioWriteTime = reduceLeft(performance.getMeasures("ioWriteTime"), (aggregate, measure) => aggregate + measure.duration, 0);
const programTime = reduceLeft(performance.getMeasures("programTime"), (aggregate, measure) => aggregate + measure.duration, 0);
const bindTime = reduceLeft(performance.getMeasures("bindTime"), (aggregate, measure) => aggregate + measure.duration, 0);
const checkTime = reduceLeft(performance.getMeasures("checkTime"), (aggregate, measure) => aggregate + measure.duration, 0);
const emitTime = reduceLeft(performance.getMeasures("emitTime"), (aggregate, measure) => aggregate + measure.duration, 0);
performance.disable();
performance.reset();
const memoryUsed = sys.getMemoryUsage ? sys.getMemoryUsage() : -1;
reportCountStatistic("Files", program.getSourceFiles().length);
reportCountStatistic("Lines", countLines(program));
@ -584,13 +575,23 @@ namespace ts {
// 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", ioReadTime);
reportTimeStatistic("I/O write", ioWriteTime);
reportTimeStatistic("I/O read", performance.getDuration("ioReadTime"));
reportTimeStatistic("I/O write", performance.getDuration("ioWriteTime"));
reportTimeStatistic("Print time", performance.getDuration("printTime"));
reportTimeStatistic("Comment time", performance.getDuration("commentTime"));
reportTimeStatistic("Sourcemap time", performance.getDuration("sourcemapTime"));
const programTime = performance.getDuration("programTime");
const bindTime = performance.getDuration("bindTime");
const checkTime = performance.getDuration("checkTime");
const emitTime = performance.getDuration("emitTime");
reportTimeStatistic("Parse time", programTime);
reportTimeStatistic("Bind time", bindTime);
reportTimeStatistic("Check time", checkTime);
reportTimeStatistic("Emit time", emitTime);
reportTimeStatistic("Total time", programTime + bindTime + checkTime + emitTime);
performance.disable();
performance.reset();
}
return { program, exitStatus };