maxmustermann/TypeScript
1
0
Fork 0
Code Issues Pull requests Projects Releases Wiki Activity

Use optional module "@microsoft/typescript-etw" for ETW logging

Browse source
This commit is contained in:
Bill Ticehurst 2018-10-26 11:22:25 -07:00 committed by Michael Crane
parent dbe9e3d237
commit 996e7e50d5
11 changed files with 183 additions and 89 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

1
package.json
View file

@ -42,6 +42,7 @@
"@types/gulp-sourcemaps": "0.0.32",
"@types/jake": "latest",
"@types/merge2": "latest",
"@types/microsoft__typescript-etw": "latest",
"@types/minimatch": "latest",
"@types/minimist": "latest",
"@types/mkdirp": "latest",

13
src/compiler/binder.ts
View file

@ -105,10 +105,15 @@ namespace ts {
const binder = createBinder();
export function bindSourceFile(file: SourceFile, options: CompilerOptions) {
performance.mark("beforeBind");
binder(file, options);
performance.mark("afterBind");
performance.measure("Bind", "beforeBind", "afterBind");
try {
performance.mark("beforeBind");
if (etwLogger) etwLogger.logStartBindFile("" + file.fileName);
binder(file, options);
} finally {
if (etwLogger) etwLogger.logStopBindFile();
performance.mark("afterBind");
performance.measure("Bind", "beforeBind", "afterBind");
}
}
function createBinder(): (file: SourceFile, options: CompilerOptions) => void {

18
src/compiler/core.ts
View file

@ -4,6 +4,24 @@ namespace ts {
export const versionMajorMinor = "3.6";
/** The version of the TypeScript compiler release */
export const version = `${versionMajorMinor}.0-dev`;
// Load optional module to enable Event Tracing for Windows
// See https://github.com/microsoft/typescript-etw for more information
let etwModule;
try {
// tslint:disable-next-line:no-implicit-dependencies
etwModule = require("@microsoft/typescript-etw");
}
catch (e) {
// Optional module not installed
etwModule = undefined;
}
/* @internal */
// tslint:disable-next-line:no-implicit-dependencies
export const etwLogger: typeof import("@microsoft/typescript-etw") | undefined = etwModule;
if (etwLogger) etwLogger.logInfoEvent(`Starting TypeScript v${versionMajorMinor} with command line: ${JSON.stringify(process.argv)}`);
}
namespace ts {

25
src/compiler/moduleNameResolver.ts
View file

@ -665,16 +665,23 @@ namespace ts {
}
}
switch (moduleResolution) {
case ModuleResolutionKind.NodeJs:
result = nodeModuleNameResolver(moduleName, containingFile, compilerOptions, host, cache, redirectedReference);
break;
case ModuleResolutionKind.Classic:
result = classicNameResolver(moduleName, containingFile, compilerOptions, host, cache, redirectedReference);
break;
default:
return Debug.fail(`Unexpected moduleResolution: ${moduleResolution}`);
try {
if (etwLogger) etwLogger.logStartResolveModule(moduleName /* , containingFile, ModuleResolutionKind[moduleResolution]*/);
switch (moduleResolution) {
case ModuleResolutionKind.NodeJs:
result = nodeModuleNameResolver(moduleName, containingFile, compilerOptions, host, cache, redirectedReference);
break;
case ModuleResolutionKind.Classic:
result = classicNameResolver(moduleName, containingFile, compilerOptions, host, cache, redirectedReference);
break;
default:
return Debug.fail(`Unexpected moduleResolution: ${moduleResolution}`);
}
}
finally {
if (etwLogger && result && result.resolvedModule) etwLogger.logInfoEvent(`Module "${moduleName}" resolved to "${result.resolvedModule.resolvedFileName}"`);
if (etwLogger) etwLogger.logStopResolveModule((result && result.resolvedModule) ? "" + result.resolvedModule.resolvedFileName : "null");
}
if (perFolderCache) {
perFolderCache.set(moduleName, result);

15
src/compiler/parser.ts
View file

@ -512,12 +512,19 @@ namespace ts {
export function createSourceFile(fileName: string, sourceText: string, languageVersion: ScriptTarget, setParentNodes = false, scriptKind?: ScriptKind): SourceFile {
performance.mark("beforeParse");
let result: SourceFile;
if (languageVersion === ScriptTarget.JSON) {
result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, ScriptKind.JSON);
try {
if (etwLogger) etwLogger.logStartParseSourceFile(fileName);
if (languageVersion === ScriptTarget.JSON) {
result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, ScriptKind.JSON);
}
else {
result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, scriptKind);
}
}
else {
result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, scriptKind);
finally {
if (etwLogger) etwLogger.logStopParseSourceFile();
}
performance.mark("afterParse");
performance.measure("Parse", "beforeParse", "afterParse");
return result;

56
src/compiler/sys.ts
View file

@ -1087,35 +1087,41 @@ namespace ts {
}
function readFile(fileName: string, _encoding?: string): string | undefined {
if (!fileExists(fileName)) {
return undefined;
}
const buffer = _fs.readFileSync(fileName);
let len = buffer.length;
if (len >= 2 && buffer[0] === 0xFE && buffer[1] === 0xFF) {
// Big endian UTF-16 byte order mark detected. Since big endian is not supported by node.js,
// flip all byte pairs and treat as little endian.
len &= ~1; // Round down to a multiple of 2
for (let i = 0; i < len; i += 2) {
const temp = buffer[i];
buffer[i] = buffer[i + 1];
buffer[i + 1] = temp;
try {
if (etwLogger) etwLogger.logStartReadFile(fileName);
if (!fileExists(fileName)) {
return undefined;
}
return buffer.toString("utf16le", 2);
const buffer = _fs.readFileSync(fileName);
let len = buffer.length;
if (len >= 2 && buffer[0] === 0xFE && buffer[1] === 0xFF) {
// Big endian UTF-16 byte order mark detected. Since big endian is not supported by node.js,
// flip all byte pairs and treat as little endian.
len &= ~1; // Round down to a multiple of 2
for (let i = 0; i < len; i += 2) {
const temp = buffer[i];
buffer[i] = buffer[i + 1];
buffer[i + 1] = temp;
}
return buffer.toString("utf16le", 2);
}
if (len >= 2 && buffer[0] === 0xFF && buffer[1] === 0xFE) {
// Little endian UTF-16 byte order mark detected
return buffer.toString("utf16le", 2);
}
if (len >= 3 && buffer[0] === 0xEF && buffer[1] === 0xBB && buffer[2] === 0xBF) {
// UTF-8 byte order mark detected
return buffer.toString("utf8", 3);
}
// Default is UTF-8 with no byte order mark
return buffer.toString("utf8");
} finally {
if (etwLogger) etwLogger.logStopReadFile();
}
if (len >= 2 && buffer[0] === 0xFF && buffer[1] === 0xFE) {
// Little endian UTF-16 byte order mark detected
return buffer.toString("utf16le", 2);
}
if (len >= 3 && buffer[0] === 0xEF && buffer[1] === 0xBB && buffer[2] === 0xBF) {
// UTF-8 byte order mark detected
return buffer.toString("utf8", 3);
}
// Default is UTF-8 with no byte order mark
return buffer.toString("utf8");
}
function writeFile(fileName: string, data: string, writeByteOrderMark?: boolean): void {
if (etwLogger) etwLogger.logEvent("WriteFile: " + fileName);
// If a BOM is required, emit one
if (writeByteOrderMark) {
data = byteOrderMarkIndicator + data;
@ -1135,6 +1141,7 @@ namespace ts {
}
function getAccessibleFileSystemEntries(path: string): FileSystemEntries {
if (etwLogger) etwLogger.logEvent("ReadDir: " + (path || "."));
try {
const entries = _fs.readdirSync(path || ".").sort();
const files: string[] = [];
@ -1196,6 +1203,7 @@ namespace ts {
}
function getDirectories(path: string): string[] {
if (etwLogger) etwLogger.logEvent("ReadDir: " + path);
return filter<string>(_fs.readdirSync(path), dir => fileSystemEntryExists(combinePaths(path, dir), FileSystemEntryKind.Directory));
}

23
src/compiler/watch.ts
View file

@ -1003,14 +1003,21 @@ namespace ts {
timerToUpdateProgram = undefined;
reportWatchDiagnostic(Diagnostics.File_change_detected_Starting_incremental_compilation);
switch (reloadLevel) {
case ConfigFileProgramReloadLevel.Partial:
return reloadFileNamesFromConfigFile();
case ConfigFileProgramReloadLevel.Full:
return reloadConfigFile();
default:
synchronizeProgram();
return;
try {
switch (reloadLevel) {
case ConfigFileProgramReloadLevel.Partial:
if (etwLogger) etwLogger.logStartUpdateProgram("PartialConfigReload");
return reloadFileNamesFromConfigFile();
case ConfigFileProgramReloadLevel.Full:
if (etwLogger) etwLogger.logStartUpdateProgram("FullConfigReload");
return reloadConfigFile();
default:
if (etwLogger) etwLogger.logStartUpdateProgram("SynchronizeProgram");
synchronizeProgram();
return;
}
} finally {
if (etwLogger) etwLogger.logStopUpdateProgram("Done");
}
}

63
src/server/project.ts
View file

@ -851,42 +851,47 @@ namespace ts.server {
* @returns: true if set of files in the project stays the same and false - otherwise.
*/
updateGraph(): boolean {
this.resolutionCache.startRecordingFilesWithChangedResolutions();
if (etwLogger) etwLogger.logStartUpdateGraph();
try {
this.resolutionCache.startRecordingFilesWithChangedResolutions();
const hasNewProgram = this.updateGraphWorker();
const hasAddedorRemovedFiles = this.hasAddedorRemovedFiles;
this.hasAddedorRemovedFiles = false;
const hasNewProgram = this.updateGraphWorker();
const hasAddedorRemovedFiles = this.hasAddedorRemovedFiles;
this.hasAddedorRemovedFiles = false;
const changedFiles: ReadonlyArray<Path> = this.resolutionCache.finishRecordingFilesWithChangedResolutions() || emptyArray;
const changedFiles: ReadonlyArray<Path> = this.resolutionCache.finishRecordingFilesWithChangedResolutions() || emptyArray;
for (const file of changedFiles) {
// delete cached information for changed files
this.cachedUnresolvedImportsPerFile.delete(file);
}
// update builder only if language service is enabled
// otherwise tell it to drop its internal state
if (this.languageServiceEnabled) {
// 1. no changes in structure, no changes in unresolved imports - do nothing
// 2. no changes in structure, unresolved imports were changed - collect unresolved imports for all files
// (can reuse cached imports for files that were not changed)
// 3. new files were added/removed, but compilation settings stays the same - collect unresolved imports for all new/modified files
// (can reuse cached imports for files that were not changed)
// 4. compilation settings were changed in the way that might affect module resolution - drop all caches and collect all data from the scratch
if (hasNewProgram || changedFiles.length) {
this.lastCachedUnresolvedImportsList = getUnresolvedImports(this.program!, this.cachedUnresolvedImportsPerFile);
for (const file of changedFiles) {
// delete cached information for changed files
this.cachedUnresolvedImportsPerFile.delete(file);
}
this.projectService.typingsCache.enqueueInstallTypingsForProject(this, this.lastCachedUnresolvedImportsList, hasAddedorRemovedFiles);
}
else {
this.lastCachedUnresolvedImportsList = undefined;
}
// update builder only if language service is enabled
// otherwise tell it to drop its internal state
if (this.languageServiceEnabled) {
// 1. no changes in structure, no changes in unresolved imports - do nothing
// 2. no changes in structure, unresolved imports were changed - collect unresolved imports for all files
// (can reuse cached imports for files that were not changed)
// 3. new files were added/removed, but compilation settings stays the same - collect unresolved imports for all new/modified files
// (can reuse cached imports for files that were not changed)
// 4. compilation settings were changed in the way that might affect module resolution - drop all caches and collect all data from the scratch
if (hasNewProgram || changedFiles.length) {
this.lastCachedUnresolvedImportsList = getUnresolvedImports(this.program!, this.cachedUnresolvedImportsPerFile);
}
if (hasNewProgram) {
this.projectProgramVersion++;
this.projectService.typingsCache.enqueueInstallTypingsForProject(this, this.lastCachedUnresolvedImportsList, hasAddedorRemovedFiles);
}
else {
this.lastCachedUnresolvedImportsList = undefined;
}
if (hasNewProgram) {
this.projectProgramVersion++;
}
return !hasNewProgram;
} finally {
if (etwLogger) etwLogger.logStopUpdateGraph();
}
return !hasNewProgram;
}
/*@internal*/

15
src/server/session.ts
View file

@ -731,7 +731,9 @@ namespace ts.server {
}
return;
}
this.host.write(formatMessage(msg, this.logger, this.byteLength, this.host.newLine));
const msgText = formatMessage(msg, this.logger, this.byteLength, this.host.newLine);
if (etwLogger) etwLogger.logEvent(`Response message size: ${msgText.length}`);
this.host.write(msgText);
}
public event<T extends object>(body: T, eventName: string): void {
@ -2506,9 +2508,12 @@ namespace ts.server {
let request: protocol.Request | undefined;
let relevantFile: protocol.FileRequestArgs | undefined;
let commandSucceeded = false;
try {
request = <protocol.Request>JSON.parse(message);
relevantFile = request.arguments && (request as protocol.FileRequest).arguments.file ? (request as protocol.FileRequest).arguments : undefined;
if (etwLogger) etwLogger.logStartCommand("" + request.command, message.substring(0, 100));
const { response, responseRequired } = this.executeCommand(request);
if (this.logger.hasLevel(LogLevel.requestTime)) {
@ -2521,6 +2526,10 @@ namespace ts.server {
}
}
// Note: Log before writing the response, else the editor can complete its activity before the server does
// Set 'commandSucceded' flag to ensure logStopCommand doesn't get called twice (e.g. if doOutput throws)
commandSucceeded = true;
if (etwLogger) etwLogger.logStopCommand("" + request.command, "Success");
if (response) {
this.doOutput(response, request.command, request.seq, /*success*/ true);
}
@ -2531,10 +2540,14 @@ namespace ts.server {
catch (err) {
if (err instanceof OperationCanceledException) {
// Handle cancellation exceptions
if (etwLogger && !commandSucceeded) etwLogger.logStopCommand("" + (request && request.command), "Canceled: " + err);
this.doOutput({ canceled: true }, request!.command, request!.seq, /*success*/ true);
return;
}
this.logErrorWorker(err, message, relevantFile);
if (etwLogger && !commandSucceeded) etwLogger.logStopCommand("" + (request && request.command), "Error: " + err);
this.doOutput(
/*info*/ undefined,
request ? request.command : CommandNames.Unknown,

30
src/server/utilities.ts
View file

@ -150,11 +150,16 @@ namespace ts.server {
}
private static run(self: ThrottledOperations, operationId: string, cb: () => void) {
self.pendingTimeouts.delete(operationId);
if (self.logger) {
self.logger.info(`Running: ${operationId}`);
try {
if (etwLogger) etwLogger.logStartScheduledOperation(operationId);
self.pendingTimeouts.delete(operationId);
if (self.logger) {
self.logger.info(`Running: ${operationId}`);
}
cb();
} finally {
if (etwLogger) etwLogger.logStopScheduledOperation();
}
cb();
}
}
@ -174,13 +179,18 @@ namespace ts.server {
private static run(self: GcTimer) {
self.timerId = undefined;
const log = self.logger.hasLevel(LogLevel.requestTime);
const before = log && self.host.getMemoryUsage!(); // TODO: GH#18217
try {
if (etwLogger) etwLogger.logStartScheduledOperation("GC collect");
const log = self.logger.hasLevel(LogLevel.requestTime);
const before = log && self.host.getMemoryUsage!(); // TODO: GH#18217
self.host.gc!(); // TODO: GH#18217
if (log) {
const after = self.host.getMemoryUsage!(); // TODO: GH#18217
self.logger.perftrc(`GC::before ${before}, after ${after}`);
self.host.gc!(); // TODO: GH#18217
if (log) {
const after = self.host.getMemoryUsage!(); // TODO: GH#18217
self.logger.perftrc(`GC::before ${before}, after ${after}`);
}
} finally {
if (etwLogger) etwLogger.logStopScheduledOperation();
}
}
}

13
src/tsserver/server.ts
View file

@ -180,6 +180,19 @@ namespace ts.server {
}
msg(s: string, type: Msg = Msg.Err) {
if (etwLogger) {
switch (type) {
case Msg.Info:
etwLogger.logInfoEvent(s);
break;
case Msg.Perf:
etwLogger.logPerfEvent(s);
break;
default: // Msg.Err
etwLogger.logErrEvent(s);
break;
}
}
if (!this.canWrite) return;
s = `[${nowString()}] ${s}\n`;