Skip to content

Commit 01e1b1b

Browse files
amcaseyamcasey
authored
Merge pull request microsoft#32612 from mrcrane/etw-logger
Use optional module "@microsoft/typescript-etw" for ETW logging
2 parents 269c3d3 + 47e77c9 commit 01e1b1b

File tree

12 files changed

+105
-6
lines changed

12 files changed

+105
-6
lines changed

‎package.json

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,7 @@
4242
"@types/gulp-sourcemaps": "0.0.32",
4343
"@types/jake": "latest",
4444
"@types/merge2": "latest",
45+
"@types/microsoft__typescript-etw": "latest",
4546
"@types/minimatch": "latest",
4647
"@types/minimist": "latest",
4748
"@types/mkdirp": "latest",
@@ -109,7 +110,8 @@
109110
"browser": {
110111
"fs": false,
111112
"os": false,
112-
"path": false
113+
"path": false,
114+
"@microsoft/typescript-etw": false
113115
},
114116
"dependencies": {}
115117
}

‎src/compiler/binder.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -106,7 +106,9 @@ namespace ts {
106106

107107
export function bindSourceFile(file: SourceFile, options: CompilerOptions) {
108108
performance.mark("beforeBind");
109+
perfLogger.logStartBindFile("" + file.fileName);
109110
binder(file, options);
111+
perfLogger.logStopBindFile();
110112
performance.mark("afterBind");
111113
performance.measure("Bind", "beforeBind", "afterBind");
112114
}

‎src/compiler/moduleNameResolver.ts

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -665,6 +665,7 @@ namespace ts {
665665
}
666666
}
667667

668+
perfLogger.logStartResolveModule(moduleName /* , containingFile, ModuleResolutionKind[moduleResolution]*/);
668669
switch (moduleResolution) {
669670
case ModuleResolutionKind.NodeJs:
670671
result = nodeModuleNameResolver(moduleName, containingFile, compilerOptions, host, cache, redirectedReference);
@@ -675,6 +676,8 @@ namespace ts {
675676
default:
676677
return Debug.fail(`Unexpected moduleResolution: ${moduleResolution}`);
677678
}
679+
if (result && result.resolvedModule) perfLogger.logInfoEvent(`Module "${moduleName}" resolved to "${result.resolvedModule.resolvedFileName}"`);
680+
perfLogger.logStopResolveModule((result && result.resolvedModule) ? "" + result.resolvedModule.resolvedFileName : "null");
678681

679682
if (perFolderCache) {
680683
perFolderCache.set(moduleName, result);

‎src/compiler/parser.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -512,12 +512,16 @@ namespace ts {
512512
export function createSourceFile(fileName: string, sourceText: string, languageVersion: ScriptTarget, setParentNodes = false, scriptKind?: ScriptKind): SourceFile {
513513
performance.mark("beforeParse");
514514
let result: SourceFile;
515+
516+
perfLogger.logStartParseSourceFile(fileName);
515517
if (languageVersion === ScriptTarget.JSON) {
516518
result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, ScriptKind.JSON);
517519
}
518520
else {
519521
result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, scriptKind);
520522
}
523+
perfLogger.logStopParseSourceFile();
524+
521525
performance.mark("afterParse");
522526
performance.measure("Parse", "beforeParse", "afterParse");
523527
return result;

‎src/compiler/perfLogger.ts

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,43 @@
1+
/* @internal */
2+
namespace ts {
3+
type PerfLogger = typeof import("@microsoft/typescript-etw"); // tslint:disable-line:no-implicit-dependencies
4+
const nullLogger: PerfLogger = {
5+
logEvent: noop,
6+
logErrEvent: noop,
7+
logPerfEvent: noop,
8+
logInfoEvent: noop,
9+
logStartCommand: noop,
10+
logStopCommand: noop,
11+
logStartUpdateProgram: noop,
12+
logStopUpdateProgram: noop,
13+
logStartUpdateGraph: noop,
14+
logStopUpdateGraph: noop,
15+
logStartResolveModule: noop,
16+
logStopResolveModule: noop,
17+
logStartParseSourceFile: noop,
18+
logStopParseSourceFile: noop,
19+
logStartReadFile: noop,
20+
logStopReadFile: noop,
21+
logStartBindFile: noop,
22+
logStopBindFile: noop,
23+
logStartScheduledOperation: noop,
24+
logStopScheduledOperation: noop,
25+
};
26+
27+
// Load optional module to enable Event Tracing for Windows
28+
// See https://github.com/microsoft/typescript-etw for more information
29+
let etwModule;
30+
try {
31+
// require() will throw an exception if the module is not installed
32+
// It may also return undefined if not installed properly
33+
etwModule = require("@microsoft/typescript-etw"); // tslint:disable-line:no-implicit-dependencies
34+
}
35+
catch (e) {
36+
etwModule = undefined;
37+
}
38+
39+
/** Performance logger that will generate ETW events if possible */
40+
export const perfLogger: PerfLogger = etwModule ? etwModule : nullLogger;
41+
42+
perfLogger.logInfoEvent(`Starting TypeScript v${versionMajorMinor} with command line: ${JSON.stringify(process.argv)}`);
43+
}

‎src/compiler/sys.ts

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1134,7 +1134,7 @@ namespace ts {
11341134
return (directoryName, callback) => fsWatchFile(directoryName, () => callback(directoryName), PollingInterval.Medium);
11351135
}
11361136

1137-
function readFile(fileName: string, _encoding?: string): string | undefined {
1137+
function readFileWorker(fileName: string, _encoding?: string): string | undefined {
11381138
if (!fileExists(fileName)) {
11391139
return undefined;
11401140
}
@@ -1163,7 +1163,15 @@ namespace ts {
11631163
return buffer.toString("utf8");
11641164
}
11651165

1166+
function readFile(fileName: string, _encoding?: string): string | undefined {
1167+
perfLogger.logStartReadFile(fileName);
1168+
const file = readFileWorker(fileName, _encoding);
1169+
perfLogger.logStopReadFile();
1170+
return file;
1171+
}
1172+
11661173
function writeFile(fileName: string, data: string, writeByteOrderMark?: boolean): void {
1174+
perfLogger.logEvent("WriteFile: " + fileName);
11671175
// If a BOM is required, emit one
11681176
if (writeByteOrderMark) {
11691177
data = byteOrderMarkIndicator + data;
@@ -1183,6 +1191,7 @@ namespace ts {
11831191
}
11841192

11851193
function getAccessibleFileSystemEntries(path: string): FileSystemEntries {
1194+
perfLogger.logEvent("ReadDir: " + (path || "."));
11861195
try {
11871196
const entries = _fs.readdirSync(path || ".").sort();
11881197
const files: string[] = [];
@@ -1244,6 +1253,7 @@ namespace ts {
12441253
}
12451254

12461255
function getDirectories(path: string): string[] {
1256+
perfLogger.logEvent("ReadDir: " + path);
12471257
return filter<string>(_fs.readdirSync(path), dir => fileSystemEntryExists(combinePaths(path, dir), FileSystemEntryKind.Directory));
12481258
}
12491259

‎src/compiler/tsconfig.json

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010
"core.ts",
1111
"debug.ts",
1212
"performance.ts",
13+
"perfLogger.ts",
1314
"semver.ts",
1415

1516
"types.ts",

‎src/compiler/watch.ts

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1005,13 +1005,19 @@ namespace ts {
10051005

10061006
switch (reloadLevel) {
10071007
case ConfigFileProgramReloadLevel.Partial:
1008-
return reloadFileNamesFromConfigFile();
1008+
perfLogger.logStartUpdateProgram("PartialConfigReload");
1009+
reloadFileNamesFromConfigFile();
1010+
break;
10091011
case ConfigFileProgramReloadLevel.Full:
1010-
return reloadConfigFile();
1012+
perfLogger.logStartUpdateProgram("FullConfigReload");
1013+
reloadConfigFile();
1014+
break;
10111015
default:
1016+
perfLogger.logStartUpdateProgram("SynchronizeProgram");
10121017
synchronizeProgram();
1013-
return;
1018+
break;
10141019
}
1020+
perfLogger.logStopUpdateProgram("Done");
10151021
}
10161022

10171023
function reloadFileNamesFromConfigFile() {

‎src/server/project.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -851,6 +851,7 @@ namespace ts.server {
851851
* @returns: true if set of files in the project stays the same and false - otherwise.
852852
*/
853853
updateGraph(): boolean {
854+
perfLogger.logStartUpdateGraph();
854855
this.resolutionCache.startRecordingFilesWithChangedResolutions();
855856

856857
const hasNewProgram = this.updateGraphWorker();
@@ -886,6 +887,7 @@ namespace ts.server {
886887
if (hasNewProgram) {
887888
this.projectProgramVersion++;
888889
}
890+
perfLogger.logStopUpdateGraph();
889891
return !hasNewProgram;
890892
}
891893

‎src/server/session.ts

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -731,7 +731,9 @@ namespace ts.server {
731731
}
732732
return;
733733
}
734-
this.host.write(formatMessage(msg, this.logger, this.byteLength, this.host.newLine));
734+
const msgText = formatMessage(msg, this.logger, this.byteLength, this.host.newLine);
735+
perfLogger.logEvent(`Response message size: ${msgText.length}`);
736+
this.host.write(msgText);
735737
}
736738

737739
public event<T extends object>(body: T, eventName: string): void {
@@ -2509,6 +2511,8 @@ namespace ts.server {
25092511
try {
25102512
request = <protocol.Request>JSON.parse(message);
25112513
relevantFile = request.arguments && (request as protocol.FileRequest).arguments.file ? (request as protocol.FileRequest).arguments : undefined;
2514+
2515+
perfLogger.logStartCommand("" + request.command, message.substring(0, 100));
25122516
const { response, responseRequired } = this.executeCommand(request);
25132517

25142518
if (this.logger.hasLevel(LogLevel.requestTime)) {
@@ -2521,6 +2525,8 @@ namespace ts.server {
25212525
}
25222526
}
25232527

2528+
// Note: Log before writing the response, else the editor can complete its activity before the server does
2529+
perfLogger.logStopCommand("" + request.command, "Success");
25242530
if (response) {
25252531
this.doOutput(response, request.command, request.seq, /*success*/ true);
25262532
}
@@ -2531,10 +2537,14 @@ namespace ts.server {
25312537
catch (err) {
25322538
if (err instanceof OperationCanceledException) {
25332539
// Handle cancellation exceptions
2540+
perfLogger.logStopCommand("" + (request && request.command), "Canceled: " + err);
25342541
this.doOutput({ canceled: true }, request!.command, request!.seq, /*success*/ true);
25352542
return;
25362543
}
2544+
25372545
this.logErrorWorker(err, message, relevantFile);
2546+
perfLogger.logStopCommand("" + (request && request.command), "Error: " + err);
2547+
25382548
this.doOutput(
25392549
/*info*/ undefined,
25402550
request ? request.command : CommandNames.Unknown,

0 commit comments

Comments
 (0)