From 996e7e50d5cae2ac7226ad9396794d4160a27a0f Mon Sep 17 00:00:00 2001 From: Bill Ticehurst Date: Fri, 26 Oct 2018 11:22:25 -0700 Subject: [PATCH 1/8] Use optional module "@microsoft/typescript-etw" for ETW logging --- package.json | 1 + src/compiler/binder.ts | 13 ++++-- src/compiler/core.ts | 18 +++++++++ src/compiler/moduleNameResolver.ts | 25 +++++++----- src/compiler/parser.ts | 15 +++++-- src/compiler/sys.ts | 56 ++++++++++++++------------ src/compiler/watch.ts | 23 +++++++---- src/server/project.ts | 63 ++++++++++++++++-------------- src/server/session.ts | 15 ++++++- src/server/utilities.ts | 30 +++++++++----- src/tsserver/server.ts | 13 ++++++ 11 files changed, 183 insertions(+), 89 deletions(-) diff --git a/package.json b/package.json index 2f1b44cbb0..333240b0e7 100644 --- a/package.json +++ b/package.json @@ -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", diff --git a/src/compiler/binder.ts b/src/compiler/binder.ts index d18ab45a34..89602facbb 100644 --- a/src/compiler/binder.ts +++ b/src/compiler/binder.ts @@ -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 { diff --git a/src/compiler/core.ts b/src/compiler/core.ts index e0e70c7294..30e04f8983 100644 --- a/src/compiler/core.ts +++ b/src/compiler/core.ts @@ -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 { diff --git a/src/compiler/moduleNameResolver.ts b/src/compiler/moduleNameResolver.ts index 94f835caff..f36ff5c7d4 100644 --- a/src/compiler/moduleNameResolver.ts +++ b/src/compiler/moduleNameResolver.ts @@ -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); diff --git a/src/compiler/parser.ts b/src/compiler/parser.ts index 254be93000..9e66504a12 100644 --- a/src/compiler/parser.ts +++ b/src/compiler/parser.ts @@ -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; diff --git a/src/compiler/sys.ts b/src/compiler/sys.ts index 7049821c90..5e40476891 100644 --- a/src/compiler/sys.ts +++ b/src/compiler/sys.ts @@ -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(_fs.readdirSync(path), dir => fileSystemEntryExists(combinePaths(path, dir), FileSystemEntryKind.Directory)); } diff --git a/src/compiler/watch.ts b/src/compiler/watch.ts index 6963a4df64..4b1ce6b71f 100644 --- a/src/compiler/watch.ts +++ b/src/compiler/watch.ts @@ -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"); } } diff --git a/src/server/project.ts b/src/server/project.ts index 889e97b24c..6e9973b9e9 100644 --- a/src/server/project.ts +++ b/src/server/project.ts @@ -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 = this.resolutionCache.finishRecordingFilesWithChangedResolutions() || emptyArray; + const changedFiles: ReadonlyArray = 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*/ diff --git a/src/server/session.ts b/src/server/session.ts index d663ca0924..4dea24c8df 100644 --- a/src/server/session.ts +++ b/src/server/session.ts @@ -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(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 = 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, diff --git a/src/server/utilities.ts b/src/server/utilities.ts index fd38c6a432..a11d13f589 100644 --- a/src/server/utilities.ts +++ b/src/server/utilities.ts @@ -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(); } } } diff --git a/src/tsserver/server.ts b/src/tsserver/server.ts index a9fbf2f3b6..7cbe53682b 100644 --- a/src/tsserver/server.ts +++ b/src/tsserver/server.ts @@ -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`; From fa3e9c86db8a1f4497be33d283b6fa5d7cc7f122 Mon Sep 17 00:00:00 2001 From: Michael Crane Date: Thu, 1 Aug 2019 12:46:33 -0700 Subject: [PATCH 2/8] Add PerfLogger and NullLogger to simplify conditional logic --- src/compiler/binder.ts | 4 +- src/compiler/core.ts | 18 +------ src/compiler/moduleNameResolver.ts | 6 +-- src/compiler/parser.ts | 4 +- src/compiler/perfLogger.ts | 81 ++++++++++++++++++++++++++++++ src/compiler/sys.ts | 10 ++-- src/compiler/tsconfig.json | 1 + src/compiler/watch.ts | 8 +-- src/server/project.ts | 4 +- src/server/session.ts | 10 ++-- src/server/utilities.ts | 8 +-- src/tsserver/server.ts | 23 ++++----- 12 files changed, 121 insertions(+), 56 deletions(-) create mode 100644 src/compiler/perfLogger.ts diff --git a/src/compiler/binder.ts b/src/compiler/binder.ts index 89602facbb..8de145d4b7 100644 --- a/src/compiler/binder.ts +++ b/src/compiler/binder.ts @@ -107,10 +107,10 @@ namespace ts { export function bindSourceFile(file: SourceFile, options: CompilerOptions) { try { performance.mark("beforeBind"); - if (etwLogger) etwLogger.logStartBindFile("" + file.fileName); + perfLogger.logStartBindFile("" + file.fileName); binder(file, options); } finally { - if (etwLogger) etwLogger.logStopBindFile(); + perfLogger.logStopBindFile(); performance.mark("afterBind"); performance.measure("Bind", "beforeBind", "afterBind"); } diff --git a/src/compiler/core.ts b/src/compiler/core.ts index 30e04f8983..37506e53cf 100644 --- a/src/compiler/core.ts +++ b/src/compiler/core.ts @@ -5,23 +5,7 @@ namespace ts { /** 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)}`); + perfLogger.logInfoEvent(`Starting TypeScript v${versionMajorMinor} with command line: ${JSON.stringify(process.argv)}`); } namespace ts { diff --git a/src/compiler/moduleNameResolver.ts b/src/compiler/moduleNameResolver.ts index f36ff5c7d4..23d39dee52 100644 --- a/src/compiler/moduleNameResolver.ts +++ b/src/compiler/moduleNameResolver.ts @@ -666,7 +666,7 @@ namespace ts { } try { - if (etwLogger) etwLogger.logStartResolveModule(moduleName /* , containingFile, ModuleResolutionKind[moduleResolution]*/); + perfLogger.logStartResolveModule(moduleName /* , containingFile, ModuleResolutionKind[moduleResolution]*/); switch (moduleResolution) { case ModuleResolutionKind.NodeJs: result = nodeModuleNameResolver(moduleName, containingFile, compilerOptions, host, cache, redirectedReference); @@ -679,8 +679,8 @@ namespace ts { } } 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 (result && result.resolvedModule) perfLogger.logInfoEvent(`Module "${moduleName}" resolved to "${result.resolvedModule.resolvedFileName}"`); + perfLogger.logStopResolveModule((result && result.resolvedModule) ? "" + result.resolvedModule.resolvedFileName : "null"); } if (perFolderCache) { diff --git a/src/compiler/parser.ts b/src/compiler/parser.ts index 9e66504a12..a90f556afd 100644 --- a/src/compiler/parser.ts +++ b/src/compiler/parser.ts @@ -513,7 +513,7 @@ namespace ts { performance.mark("beforeParse"); let result: SourceFile; try { - if (etwLogger) etwLogger.logStartParseSourceFile(fileName); + perfLogger.logStartParseSourceFile(fileName); if (languageVersion === ScriptTarget.JSON) { result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, ScriptKind.JSON); } @@ -522,7 +522,7 @@ namespace ts { } } finally { - if (etwLogger) etwLogger.logStopParseSourceFile(); + perfLogger.logStopParseSourceFile(); } performance.mark("afterParse"); diff --git a/src/compiler/perfLogger.ts b/src/compiler/perfLogger.ts new file mode 100644 index 0000000000..4f6d277dac --- /dev/null +++ b/src/compiler/perfLogger.ts @@ -0,0 +1,81 @@ +/* @internal */ +namespace ts { + export type PerfLogger = typeof import("@microsoft/typescript-etw"); // tslint:disable-line:no-implicit-dependencies + + export class NullLogger implements PerfLogger { + logEvent(_msg: string): void { + return; + } + logErrEvent(_msg: string): void { + return; + } + logPerfEvent(_msg: string): void { + return; + } + logInfoEvent(_msg: string): void { + return; + } + logStartCommand(_command: string, _msg: string): void { + return; + } + logStopCommand(_command: string, _msg: string): void { + return; + } + logStartUpdateProgram(_msg: string): void { + return; + } + logStopUpdateProgram(_msg: string): void { + return; + } + logStartUpdateGraph(): void { + return; + } + logStopUpdateGraph(): void { + return; + } + logStartResolveModule(_name: string): void { + return; + } + logStopResolveModule(_success: string): void { + return; + } + logStartParseSourceFile(_filename: string): void { + return; + } + logStopParseSourceFile(): void { + return; + } + logStartReadFile(_filename: string): void { + return; + } + logStopReadFile(): void { + return; + } + logStartBindFile(_filename: string): void { + return; + } + logStopBindFile(): void { + return; + } + logStartScheduledOperation(_operationId: string): void { + return; + } + logStopScheduledOperation(): void { + return; + } + } + + // Load optional module to enable Event Tracing for Windows + // See https://github.com/microsoft/typescript-etw for more information + let etwModule; + try { + // require() will throw an exception if the module is not installed + // It may also return undefined if not installed properly + etwModule = require("@microsoft/typescript-etw"); // tslint:disable-line:no-implicit-dependencies + } + catch (e) { + etwModule = undefined; + } + + export const perfLogger: PerfLogger = etwModule ? etwModule : new NullLogger(); +} \ No newline at end of file diff --git a/src/compiler/sys.ts b/src/compiler/sys.ts index 5e40476891..95f9531ea9 100644 --- a/src/compiler/sys.ts +++ b/src/compiler/sys.ts @@ -1088,7 +1088,7 @@ namespace ts { function readFile(fileName: string, _encoding?: string): string | undefined { try { - if (etwLogger) etwLogger.logStartReadFile(fileName); + perfLogger.logStartReadFile(fileName); if (!fileExists(fileName)) { return undefined; } @@ -1116,12 +1116,12 @@ namespace ts { // Default is UTF-8 with no byte order mark return buffer.toString("utf8"); } finally { - if (etwLogger) etwLogger.logStopReadFile(); + perfLogger.logStopReadFile(); } } function writeFile(fileName: string, data: string, writeByteOrderMark?: boolean): void { - if (etwLogger) etwLogger.logEvent("WriteFile: " + fileName); + perfLogger.logEvent("WriteFile: " + fileName); // If a BOM is required, emit one if (writeByteOrderMark) { data = byteOrderMarkIndicator + data; @@ -1141,7 +1141,7 @@ namespace ts { } function getAccessibleFileSystemEntries(path: string): FileSystemEntries { - if (etwLogger) etwLogger.logEvent("ReadDir: " + (path || ".")); + perfLogger.logEvent("ReadDir: " + (path || ".")); try { const entries = _fs.readdirSync(path || ".").sort(); const files: string[] = []; @@ -1203,7 +1203,7 @@ namespace ts { } function getDirectories(path: string): string[] { - if (etwLogger) etwLogger.logEvent("ReadDir: " + path); + perfLogger.logEvent("ReadDir: " + path); return filter(_fs.readdirSync(path), dir => fileSystemEntryExists(combinePaths(path, dir), FileSystemEntryKind.Directory)); } diff --git a/src/compiler/tsconfig.json b/src/compiler/tsconfig.json index f5e16b0d12..e9a8f7fda5 100644 --- a/src/compiler/tsconfig.json +++ b/src/compiler/tsconfig.json @@ -7,6 +7,7 @@ "references": [], "files": [ + "perfLogger.ts", "core.ts", "debug.ts", "performance.ts", diff --git a/src/compiler/watch.ts b/src/compiler/watch.ts index 4b1ce6b71f..abefe1ab32 100644 --- a/src/compiler/watch.ts +++ b/src/compiler/watch.ts @@ -1006,18 +1006,18 @@ namespace ts { try { switch (reloadLevel) { case ConfigFileProgramReloadLevel.Partial: - if (etwLogger) etwLogger.logStartUpdateProgram("PartialConfigReload"); + perfLogger.logStartUpdateProgram("PartialConfigReload"); return reloadFileNamesFromConfigFile(); case ConfigFileProgramReloadLevel.Full: - if (etwLogger) etwLogger.logStartUpdateProgram("FullConfigReload"); + perfLogger.logStartUpdateProgram("FullConfigReload"); return reloadConfigFile(); default: - if (etwLogger) etwLogger.logStartUpdateProgram("SynchronizeProgram"); + perfLogger.logStartUpdateProgram("SynchronizeProgram"); synchronizeProgram(); return; } } finally { - if (etwLogger) etwLogger.logStopUpdateProgram("Done"); + perfLogger.logStopUpdateProgram("Done"); } } diff --git a/src/server/project.ts b/src/server/project.ts index 6e9973b9e9..d65c20f397 100644 --- a/src/server/project.ts +++ b/src/server/project.ts @@ -851,7 +851,7 @@ namespace ts.server { * @returns: true if set of files in the project stays the same and false - otherwise. */ updateGraph(): boolean { - if (etwLogger) etwLogger.logStartUpdateGraph(); + perfLogger.logStartUpdateGraph(); try { this.resolutionCache.startRecordingFilesWithChangedResolutions(); @@ -890,7 +890,7 @@ namespace ts.server { } return !hasNewProgram; } finally { - if (etwLogger) etwLogger.logStopUpdateGraph(); + perfLogger.logStopUpdateGraph(); } } diff --git a/src/server/session.ts b/src/server/session.ts index 4dea24c8df..8be592a81b 100644 --- a/src/server/session.ts +++ b/src/server/session.ts @@ -732,7 +732,7 @@ namespace ts.server { return; } const msgText = formatMessage(msg, this.logger, this.byteLength, this.host.newLine); - if (etwLogger) etwLogger.logEvent(`Response message size: ${msgText.length}`); + perfLogger.logEvent(`Response message size: ${msgText.length}`); this.host.write(msgText); } @@ -2513,7 +2513,7 @@ namespace ts.server { 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)); + perfLogger.logStartCommand("" + request.command, message.substring(0, 100)); const { response, responseRequired } = this.executeCommand(request); if (this.logger.hasLevel(LogLevel.requestTime)) { @@ -2529,7 +2529,7 @@ 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"); + perfLogger.logStopCommand("" + request.command, "Success"); if (response) { this.doOutput(response, request.command, request.seq, /*success*/ true); } @@ -2540,13 +2540,13 @@ namespace ts.server { catch (err) { if (err instanceof OperationCanceledException) { // Handle cancellation exceptions - if (etwLogger && !commandSucceeded) etwLogger.logStopCommand("" + (request && request.command), "Canceled: " + err); + if (!commandSucceeded) perfLogger.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); + if (!commandSucceeded) perfLogger.logStopCommand("" + (request && request.command), "Error: " + err); this.doOutput( /*info*/ undefined, diff --git a/src/server/utilities.ts b/src/server/utilities.ts index a11d13f589..a080ea38ac 100644 --- a/src/server/utilities.ts +++ b/src/server/utilities.ts @@ -151,14 +151,14 @@ namespace ts.server { private static run(self: ThrottledOperations, operationId: string, cb: () => void) { try { - if (etwLogger) etwLogger.logStartScheduledOperation(operationId); + perfLogger.logStartScheduledOperation(operationId); self.pendingTimeouts.delete(operationId); if (self.logger) { self.logger.info(`Running: ${operationId}`); } cb(); } finally { - if (etwLogger) etwLogger.logStopScheduledOperation(); + perfLogger.logStopScheduledOperation(); } } } @@ -180,7 +180,7 @@ namespace ts.server { self.timerId = undefined; try { - if (etwLogger) etwLogger.logStartScheduledOperation("GC collect"); + perfLogger.logStartScheduledOperation("GC collect"); const log = self.logger.hasLevel(LogLevel.requestTime); const before = log && self.host.getMemoryUsage!(); // TODO: GH#18217 @@ -190,7 +190,7 @@ namespace ts.server { self.logger.perftrc(`GC::before ${before}, after ${after}`); } } finally { - if (etwLogger) etwLogger.logStopScheduledOperation(); + perfLogger.logStopScheduledOperation(); } } } diff --git a/src/tsserver/server.ts b/src/tsserver/server.ts index 7cbe53682b..13bba67664 100644 --- a/src/tsserver/server.ts +++ b/src/tsserver/server.ts @@ -180,19 +180,18 @@ 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; - } + switch (type) { + case Msg.Info: + perfLogger.logInfoEvent(s); + break; + case Msg.Perf: + perfLogger.logPerfEvent(s); + break; + default: // Msg.Err + perfLogger.logErrEvent(s); + break; } + if (!this.canWrite) return; s = `[${nowString()}] ${s}\n`; From d34cf525766d29b7182cdc19cabd784d311ba081 Mon Sep 17 00:00:00 2001 From: Michael Crane Date: Fri, 2 Aug 2019 10:20:17 -0700 Subject: [PATCH 3/8] Use 'noop' for NullLogger --- src/compiler/core.ts | 2 - src/compiler/perfLogger.ts | 94 ++++++++++++-------------------------- src/compiler/tsconfig.json | 2 +- 3 files changed, 29 insertions(+), 69 deletions(-) diff --git a/src/compiler/core.ts b/src/compiler/core.ts index 37506e53cf..e0e70c7294 100644 --- a/src/compiler/core.ts +++ b/src/compiler/core.ts @@ -4,8 +4,6 @@ namespace ts { export const versionMajorMinor = "3.6"; /** The version of the TypeScript compiler release */ export const version = `${versionMajorMinor}.0-dev`; - - perfLogger.logInfoEvent(`Starting TypeScript v${versionMajorMinor} with command line: ${JSON.stringify(process.argv)}`); } namespace ts { diff --git a/src/compiler/perfLogger.ts b/src/compiler/perfLogger.ts index 4f6d277dac..974e231d15 100644 --- a/src/compiler/perfLogger.ts +++ b/src/compiler/perfLogger.ts @@ -1,69 +1,28 @@ /* @internal */ namespace ts { - export type PerfLogger = typeof import("@microsoft/typescript-etw"); // tslint:disable-line:no-implicit-dependencies - - export class NullLogger implements PerfLogger { - logEvent(_msg: string): void { - return; - } - logErrEvent(_msg: string): void { - return; - } - logPerfEvent(_msg: string): void { - return; - } - logInfoEvent(_msg: string): void { - return; - } - logStartCommand(_command: string, _msg: string): void { - return; - } - logStopCommand(_command: string, _msg: string): void { - return; - } - logStartUpdateProgram(_msg: string): void { - return; - } - logStopUpdateProgram(_msg: string): void { - return; - } - logStartUpdateGraph(): void { - return; - } - logStopUpdateGraph(): void { - return; - } - logStartResolveModule(_name: string): void { - return; - } - logStopResolveModule(_success: string): void { - return; - } - logStartParseSourceFile(_filename: string): void { - return; - } - logStopParseSourceFile(): void { - return; - } - logStartReadFile(_filename: string): void { - return; - } - logStopReadFile(): void { - return; - } - logStartBindFile(_filename: string): void { - return; - } - logStopBindFile(): void { - return; - } - logStartScheduledOperation(_operationId: string): void { - return; - } - logStopScheduledOperation(): void { - return; - } - } + type PerfLogger = typeof import("@microsoft/typescript-etw"); // tslint:disable-line:no-implicit-dependencies + const nullLogger: PerfLogger = { + logEvent: noop, + logErrEvent: noop, + logPerfEvent: noop, + logInfoEvent: noop, + logStartCommand: noop, + logStopCommand: noop, + logStartUpdateProgram: noop, + logStopUpdateProgram: noop, + logStartUpdateGraph: noop, + logStopUpdateGraph: noop, + logStartResolveModule: noop, + logStopResolveModule: noop, + logStartParseSourceFile: noop, + logStopParseSourceFile: noop, + logStartReadFile: noop, + logStopReadFile: noop, + logStartBindFile: noop, + logStopBindFile: noop, + logStartScheduledOperation: noop, + logStopScheduledOperation: noop, + }; // Load optional module to enable Event Tracing for Windows // See https://github.com/microsoft/typescript-etw for more information @@ -77,5 +36,8 @@ namespace ts { etwModule = undefined; } - export const perfLogger: PerfLogger = etwModule ? etwModule : new NullLogger(); -} \ No newline at end of file + /** Performance logger that will generate ETW events if possible */ + export const perfLogger: PerfLogger = etwModule ? etwModule : nullLogger; + + perfLogger.logInfoEvent(`Starting TypeScript v${versionMajorMinor} with command line: ${JSON.stringify(process.argv)}`); +} diff --git a/src/compiler/tsconfig.json b/src/compiler/tsconfig.json index e9a8f7fda5..c90c6f35b3 100644 --- a/src/compiler/tsconfig.json +++ b/src/compiler/tsconfig.json @@ -7,10 +7,10 @@ "references": [], "files": [ - "perfLogger.ts", "core.ts", "debug.ts", "performance.ts", + "perfLogger.ts", "semver.ts", "types.ts", From 5e197539796a040611d60c76f038e7be7634c6d3 Mon Sep 17 00:00:00 2001 From: Michael Crane Date: Fri, 2 Aug 2019 10:50:49 -0700 Subject: [PATCH 4/8] Update browser table --- package.json | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/package.json b/package.json index 333240b0e7..a90be2f813 100644 --- a/package.json +++ b/package.json @@ -110,7 +110,8 @@ "browser": { "fs": false, "os": false, - "path": false + "path": false, + "@microsoft/typescript-etw": false }, "dependencies": {} } From 7d44a4592e49d5c6b3685e43c062ad158853a59b Mon Sep 17 00:00:00 2001 From: Michael Crane Date: Fri, 2 Aug 2019 16:39:33 -0700 Subject: [PATCH 5/8] Remove try-finally blocks --- src/compiler/binder.ts | 15 +++----- src/compiler/moduleNameResolver.ts | 28 ++++++-------- src/compiler/parser.ts | 17 ++++----- src/compiler/sys.ts | 61 +++++++++++++++--------------- src/compiler/watch.ts | 29 +++++++------- 5 files changed, 70 insertions(+), 80 deletions(-) diff --git a/src/compiler/binder.ts b/src/compiler/binder.ts index 8de145d4b7..e69f94498b 100644 --- a/src/compiler/binder.ts +++ b/src/compiler/binder.ts @@ -105,15 +105,12 @@ namespace ts { const binder = createBinder(); export function bindSourceFile(file: SourceFile, options: CompilerOptions) { - try { - performance.mark("beforeBind"); - perfLogger.logStartBindFile("" + file.fileName); - binder(file, options); - } finally { - perfLogger.logStopBindFile(); - performance.mark("afterBind"); - performance.measure("Bind", "beforeBind", "afterBind"); - } + performance.mark("beforeBind"); + perfLogger.logStartBindFile("" + file.fileName); + binder(file, options); + perfLogger.logStopBindFile(); + performance.mark("afterBind"); + performance.measure("Bind", "beforeBind", "afterBind"); } function createBinder(): (file: SourceFile, options: CompilerOptions) => void { diff --git a/src/compiler/moduleNameResolver.ts b/src/compiler/moduleNameResolver.ts index 23d39dee52..98e82a6843 100644 --- a/src/compiler/moduleNameResolver.ts +++ b/src/compiler/moduleNameResolver.ts @@ -665,23 +665,19 @@ namespace ts { } } - try { - perfLogger.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}`); - } + perfLogger.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 (result && result.resolvedModule) perfLogger.logInfoEvent(`Module "${moduleName}" resolved to "${result.resolvedModule.resolvedFileName}"`); - perfLogger.logStopResolveModule((result && result.resolvedModule) ? "" + result.resolvedModule.resolvedFileName : "null"); - } + if (result && result.resolvedModule) perfLogger.logInfoEvent(`Module "${moduleName}" resolved to "${result.resolvedModule.resolvedFileName}"`); + perfLogger.logStopResolveModule((result && result.resolvedModule) ? "" + result.resolvedModule.resolvedFileName : "null"); if (perFolderCache) { perFolderCache.set(moduleName, result); diff --git a/src/compiler/parser.ts b/src/compiler/parser.ts index a90f556afd..ae3b4fac87 100644 --- a/src/compiler/parser.ts +++ b/src/compiler/parser.ts @@ -512,18 +512,15 @@ namespace ts { export function createSourceFile(fileName: string, sourceText: string, languageVersion: ScriptTarget, setParentNodes = false, scriptKind?: ScriptKind): SourceFile { performance.mark("beforeParse"); let result: SourceFile; - try { - perfLogger.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); - } + + perfLogger.logStartParseSourceFile(fileName); + if (languageVersion === ScriptTarget.JSON) { + result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, ScriptKind.JSON); } - finally { - perfLogger.logStopParseSourceFile(); + else { + result = Parser.parseSourceFile(fileName, sourceText, languageVersion, /*syntaxCursor*/ undefined, setParentNodes, scriptKind); } + perfLogger.logStopParseSourceFile(); performance.mark("afterParse"); performance.measure("Parse", "beforeParse", "afterParse"); diff --git a/src/compiler/sys.ts b/src/compiler/sys.ts index 95f9531ea9..f2f14c581e 100644 --- a/src/compiler/sys.ts +++ b/src/compiler/sys.ts @@ -1087,37 +1087,38 @@ namespace ts { } function readFile(fileName: string, _encoding?: string): string | undefined { - try { - perfLogger.logStartReadFile(fileName); - 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; - } - 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 { - perfLogger.logStopReadFile(); + perfLogger.logStartReadFile(fileName); + if (!fileExists(fileName)) { + return undefined; } + const buffer = _fs.readFileSync(fileName); + let len = buffer.length; + let result: string; + 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; + } + result = buffer.toString("utf16le", 2); + } + else if (len >= 2 && buffer[0] === 0xFF && buffer[1] === 0xFE) { + // Little endian UTF-16 byte order mark detected + result = buffer.toString("utf16le", 2); + } + else if (len >= 3 && buffer[0] === 0xEF && buffer[1] === 0xBB && buffer[2] === 0xBF) { + // UTF-8 byte order mark detected + result = buffer.toString("utf8", 3); + } + else { + // Default is UTF-8 with no byte order mark + result = buffer.toString("utf8"); + } + perfLogger.logStopReadFile(); + return result; } function writeFile(fileName: string, data: string, writeByteOrderMark?: boolean): void { diff --git a/src/compiler/watch.ts b/src/compiler/watch.ts index abefe1ab32..5e2c004d42 100644 --- a/src/compiler/watch.ts +++ b/src/compiler/watch.ts @@ -1003,22 +1003,21 @@ namespace ts { timerToUpdateProgram = undefined; reportWatchDiagnostic(Diagnostics.File_change_detected_Starting_incremental_compilation); - try { - switch (reloadLevel) { - case ConfigFileProgramReloadLevel.Partial: - perfLogger.logStartUpdateProgram("PartialConfigReload"); - return reloadFileNamesFromConfigFile(); - case ConfigFileProgramReloadLevel.Full: - perfLogger.logStartUpdateProgram("FullConfigReload"); - return reloadConfigFile(); - default: - perfLogger.logStartUpdateProgram("SynchronizeProgram"); - synchronizeProgram(); - return; - } - } finally { - perfLogger.logStopUpdateProgram("Done"); + switch (reloadLevel) { + case ConfigFileProgramReloadLevel.Partial: + perfLogger.logStartUpdateProgram("PartialConfigReload"); + reloadFileNamesFromConfigFile(); + break; + case ConfigFileProgramReloadLevel.Full: + perfLogger.logStartUpdateProgram("FullConfigReload"); + reloadConfigFile(); + break; + default: + perfLogger.logStartUpdateProgram("SynchronizeProgram"); + synchronizeProgram(); + break; } + perfLogger.logStopUpdateProgram("Done"); } function reloadFileNamesFromConfigFile() { From cca32f079cdb105333e6a29b5525c3a01db0eef2 Mon Sep 17 00:00:00 2001 From: Michael Crane Date: Fri, 2 Aug 2019 16:46:19 -0700 Subject: [PATCH 6/8] Remove more try-finally blocks --- src/server/project.ts | 69 ++++++++++++++++++++--------------------- src/server/utilities.ts | 34 +++++++++----------- 2 files changed, 47 insertions(+), 56 deletions(-) diff --git a/src/server/project.ts b/src/server/project.ts index d65c20f397..f63b3e8cb0 100644 --- a/src/server/project.ts +++ b/src/server/project.ts @@ -852,46 +852,43 @@ namespace ts.server { */ updateGraph(): boolean { perfLogger.logStartUpdateGraph(); - try { - this.resolutionCache.startRecordingFilesWithChangedResolutions(); + 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 = this.resolutionCache.finishRecordingFilesWithChangedResolutions() || emptyArray; + const changedFiles: ReadonlyArray = 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); - } - - this.projectService.typingsCache.enqueueInstallTypingsForProject(this, this.lastCachedUnresolvedImportsList, hasAddedorRemovedFiles); - } - else { - this.lastCachedUnresolvedImportsList = undefined; - } - - if (hasNewProgram) { - this.projectProgramVersion++; - } - return !hasNewProgram; - } finally { - perfLogger.logStopUpdateGraph(); + 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); + } + + this.projectService.typingsCache.enqueueInstallTypingsForProject(this, this.lastCachedUnresolvedImportsList, hasAddedorRemovedFiles); + } + else { + this.lastCachedUnresolvedImportsList = undefined; + } + + if (hasNewProgram) { + this.projectProgramVersion++; + } + perfLogger.logStopUpdateGraph(); + return !hasNewProgram; } /*@internal*/ diff --git a/src/server/utilities.ts b/src/server/utilities.ts index a080ea38ac..d5e17520ce 100644 --- a/src/server/utilities.ts +++ b/src/server/utilities.ts @@ -150,16 +150,13 @@ namespace ts.server { } private static run(self: ThrottledOperations, operationId: string, cb: () => void) { - try { - perfLogger.logStartScheduledOperation(operationId); - self.pendingTimeouts.delete(operationId); - if (self.logger) { - self.logger.info(`Running: ${operationId}`); - } - cb(); - } finally { - perfLogger.logStopScheduledOperation(); + perfLogger.logStartScheduledOperation(operationId); + self.pendingTimeouts.delete(operationId); + if (self.logger) { + self.logger.info(`Running: ${operationId}`); } + cb(); + perfLogger.logStopScheduledOperation(); } } @@ -179,19 +176,16 @@ namespace ts.server { private static run(self: GcTimer) { self.timerId = undefined; - try { - perfLogger.logStartScheduledOperation("GC collect"); - const log = self.logger.hasLevel(LogLevel.requestTime); - const before = log && self.host.getMemoryUsage!(); // TODO: GH#18217 + perfLogger.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}`); - } - } finally { - perfLogger.logStopScheduledOperation(); + self.host.gc!(); // TODO: GH#18217 + if (log) { + const after = self.host.getMemoryUsage!(); // TODO: GH#18217 + self.logger.perftrc(`GC::before ${before}, after ${after}`); } + perfLogger.logStopScheduledOperation(); } } From f6fb1305309daff8f5c8f0e2e6641e15afce3875 Mon Sep 17 00:00:00 2001 From: Michael Crane Date: Mon, 5 Aug 2019 15:19:25 -0700 Subject: [PATCH 7/8] Add 'readFileWorker' instead of modifying 'readFile' --- src/compiler/sys.ts | 27 ++++++++++++++------------- 1 file changed, 14 insertions(+), 13 deletions(-) diff --git a/src/compiler/sys.ts b/src/compiler/sys.ts index f2f14c581e..300086b72e 100644 --- a/src/compiler/sys.ts +++ b/src/compiler/sys.ts @@ -1086,14 +1086,12 @@ namespace ts { return (directoryName, callback) => fsWatchFile(directoryName, () => callback(directoryName), PollingInterval.Medium); } - function readFile(fileName: string, _encoding?: string): string | undefined { - perfLogger.logStartReadFile(fileName); + function readFileWorker(fileName: string, _encoding?: string): string | undefined { if (!fileExists(fileName)) { return undefined; } const buffer = _fs.readFileSync(fileName); let len = buffer.length; - let result: string; 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. @@ -1103,22 +1101,25 @@ namespace ts { buffer[i] = buffer[i + 1]; buffer[i + 1] = temp; } - result = buffer.toString("utf16le", 2); + return buffer.toString("utf16le", 2); } - else if (len >= 2 && buffer[0] === 0xFF && buffer[1] === 0xFE) { + if (len >= 2 && buffer[0] === 0xFF && buffer[1] === 0xFE) { // Little endian UTF-16 byte order mark detected - result = buffer.toString("utf16le", 2); + return buffer.toString("utf16le", 2); } - else if (len >= 3 && buffer[0] === 0xEF && buffer[1] === 0xBB && buffer[2] === 0xBF) { + if (len >= 3 && buffer[0] === 0xEF && buffer[1] === 0xBB && buffer[2] === 0xBF) { // UTF-8 byte order mark detected - result = buffer.toString("utf8", 3); - } - else { - // Default is UTF-8 with no byte order mark - result = buffer.toString("utf8"); + return buffer.toString("utf8", 3); } + // Default is UTF-8 with no byte order mark + return buffer.toString("utf8"); + } + + function readFile(fileName: string, _encoding?: string): string | undefined { + perfLogger.logStartReadFile(fileName); + const file = readFileWorker(fileName, _encoding); perfLogger.logStopReadFile(); - return result; + return file; } function writeFile(fileName: string, data: string, writeByteOrderMark?: boolean): void { From 47e77c976b6d94a7b5fca4ba05a7f4de6ee26506 Mon Sep 17 00:00:00 2001 From: Michael Crane Date: Tue, 6 Aug 2019 11:48:31 -0700 Subject: [PATCH 8/8] Remove unnecessary 'commandSucceeded' variable --- src/server/session.ts | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/src/server/session.ts b/src/server/session.ts index 8be592a81b..4ae5282a74 100644 --- a/src/server/session.ts +++ b/src/server/session.ts @@ -2508,7 +2508,6 @@ namespace ts.server { let request: protocol.Request | undefined; let relevantFile: protocol.FileRequestArgs | undefined; - let commandSucceeded = false; try { request = JSON.parse(message); relevantFile = request.arguments && (request as protocol.FileRequest).arguments.file ? (request as protocol.FileRequest).arguments : undefined; @@ -2527,8 +2526,6 @@ 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; perfLogger.logStopCommand("" + request.command, "Success"); if (response) { this.doOutput(response, request.command, request.seq, /*success*/ true); @@ -2540,13 +2537,13 @@ namespace ts.server { catch (err) { if (err instanceof OperationCanceledException) { // Handle cancellation exceptions - if (!commandSucceeded) perfLogger.logStopCommand("" + (request && request.command), "Canceled: " + err); + perfLogger.logStopCommand("" + (request && request.command), "Canceled: " + err); this.doOutput({ canceled: true }, request!.command, request!.seq, /*success*/ true); return; } this.logErrorWorker(err, message, relevantFile); - if (!commandSucceeded) perfLogger.logStopCommand("" + (request && request.command), "Error: " + err); + perfLogger.logStopCommand("" + (request && request.command), "Error: " + err); this.doOutput( /*info*/ undefined,