From 9a45160ab64da5d1121aa806a8fb49fe01e3eb05 Mon Sep 17 00:00:00 2001 From: steveluc Date: Sat, 7 Mar 2015 17:13:52 -0800 Subject: [PATCH] Changed TypeScript server logging to use an environment variable TSS_LOG as follows. If TSS_LOG is not set, no logging will occur. If TSS_LOG is set to any value, logging will occur as before this change (log file will be in directory of tsserver.js with name .logPID where PID is the process id of the server process; log will contain the pre-change messages). If TSS_LOG is set to a string that has the form "-file fileName", the log file will be in the tsserver.js directory with name 'fileName'. If TSS_LOG is set to a string that has the form "-level levelName", then the level of logging will be set to 'levelName'. Currently the two levels are 'normal' and 'verbose'. The TSS_LOG string can contain zero, one or both of its options as in "-file LOG -level verbose". At the verbose level, the server will log every request, response and event, and will also give elapsed time for message processing. --- src/server/editorServices.ts | 2 ++ src/server/server.ts | 64 +++++++++++++++++++++++++++++++++--- src/server/session.ts | 17 +++++++++- 3 files changed, 78 insertions(+), 5 deletions(-) diff --git a/src/server/editorServices.ts b/src/server/editorServices.ts index 5ca4cb4d00f..3cb66fed297 100644 --- a/src/server/editorServices.ts +++ b/src/server/editorServices.ts @@ -5,6 +5,8 @@ module ts.server { export interface Logger { close(): void; + verbose(): boolean; + enabled(): boolean; perftrc(s: string): void; info(s: string): void; startGroup(): void; diff --git a/src/server/server.ts b/src/server/server.ts index c48ba951347..e5cc0fd398d 100644 --- a/src/server/server.ts +++ b/src/server/server.ts @@ -19,7 +19,7 @@ module ts.server { inGroup = false; firstInGroup = true; - constructor(public logFilename: string) { + constructor(public logFilename: string, public level: string) { } static padStringRight(str: string, padding: string) { @@ -51,9 +51,20 @@ module ts.server { this.firstInGroup = true; } + enabled() { + return !!this.logFilename; + } + + verbose() { + return this.enabled() && (this.level == "verbose"); + } + + msg(s: string, type = "Err") { if (this.fd < 0) { - this.fd = fs.openSync(this.logFilename, "w"); + if (this.logFilename) { + this.fd = fs.openSync(this.logFilename, "w"); + } } if (this.fd >= 0) { s = s + "\n"; @@ -173,17 +184,62 @@ module ts.server { }); rl.on('close',() => { - this.projectService.closeLog(); this.projectService.log("Exiting..."); + this.projectService.closeLog(); process.exit(0); }); } } + interface LogEnv { + file?: string; + level?: string; + } + + function parseLogEnv(logEnvStr: string): LogEnv { + var logEnv: LogEnv = {}; + var args = logEnvStr.split(' '); + for (var i = 0, len = args.length; i < len; i++) { + var option = args[i]; + var value = args[i + 1]; + if (option && value) { + switch (option) { + case "-file": + logEnv.file = value; + break; + case "-level": + logEnv.level = value; + break; + } + } + } + return logEnv; + } + + // TSS_LOG "{ level: "normal | verbose | terse", file?: string}" + function createLoggerFromEnv() { + var fileName: string = undefined; + var level = "normal"; + var logEnvStr = process.env["TSS_LOG"]; + if (logEnvStr) { + var logEnv = parseLogEnv(logEnvStr); + if (logEnv.file) { + fileName = logEnv.file; + } + else { + fileName = __dirname + "/.log" + process.pid.toString(); + } + if (logEnv.level) { + level = logEnv.level; + } + } + var logger = new Logger(fileName, level); + return logger; + } // This places log file in the directory containing editorServices.js // TODO: check that this location is writable - var logger = new Logger(__dirname + "/.log" + process.pid.toString()); + var logger = createLoggerFromEnv(); // REVIEW: for now this implementation uses polling. // The advantage of polling is that it works reliably diff --git a/src/server/session.ts b/src/server/session.ts index 5a91bcc08a1..59a049a18e9 100644 --- a/src/server/session.ts +++ b/src/server/session.ts @@ -145,6 +145,9 @@ module ts.server { send(msg: NodeJS._debugger.Message) { var json = JSON.stringify(msg); + if (this.logger.verbose()) { + this.logger.info(msg.type+": " + json); + } this.sendLineToClient('Content-Length: ' + (1 + Buffer.byteLength(json, 'utf8')) + '\r\n\r\n' + json); } @@ -717,6 +720,10 @@ module ts.server { } onMessage(message: string) { + if (this.logger.verbose()) { + this.logger.info("request: " + message); + var start = process.hrtime(); + } try { var request = JSON.parse(message); var response: any; @@ -822,13 +829,21 @@ module ts.server { } } + if (this.logger.verbose()) { + var elapsed = process.hrtime(start); + var elapsedms = ((1e9 * elapsed[0]) + elapsed[1])/1000000.0; + var leader = "Elapsed time (in milliseconds)"; + if (!responseRequired) { + leader = "Async elapsed time (in milliseconds)"; + } + this.logger.msg(leader+": " + elapsedms.toFixed(4).toString(), "Perf"); + } if (response) { this.output(response, request.command, request.seq); } else if (responseRequired) { this.output(undefined, request.command, request.seq, "No content available."); } - } catch (err) { if (err instanceof OperationCanceledException) { // Handle cancellation exceptions