diff --git a/src/bootstrap.js b/src/bootstrap.js index dad68bf5c80421b4f2ffd180bf35db50c61457de..af713da7509a5ad8234e4b82a960809d9a659e54 100644 --- a/src/bootstrap.js +++ b/src/bootstrap.js @@ -14,10 +14,11 @@ process.noAsar = true; if (!!process.send && process.env.PIPE_LOGGING === 'true') { var MAX_LENGTH = 100000; - // Prevent circular stringify - function safeStringify(args) { + // Prevent circular stringify and convert arguments to real array + function safeToArray(args) { var seen = []; var res; + var argsArray = []; // Massage some arguments with special treatment if (args.length) { @@ -40,11 +41,20 @@ if (!!process.send && process.env.PIPE_LOGGING === 'true') { args[i] = errorObj.toString(); } } + + argsArray.push(args[i]); } } + // Add the stack trace as payload if we are told so. We remove the message and the 2 top frames + // to start the stacktrace where the console message was being written + if (process.env.VSCODE_LOG_STACK === 'true') { + const stack = new Error().stack; + argsArray.push({ __$stack: stack.split('\n').slice(3).join('\n') }); + } + try { - res = JSON.stringify(args, function (key, value) { + res = JSON.stringify(argsArray, function (key, value) { // Objects get special treatment to prevent circles if (value && Object.prototype.toString.call(value) === '[object Object]') { @@ -78,16 +88,16 @@ if (!!process.send && process.env.PIPE_LOGGING === 'true') { // Pass console logging to the outside so that we have it in the main side if told so if (process.env.VERBOSE_LOGGING === 'true') { - console.log = function () { safeSend({ type: '__$console', severity: 'log', arguments: safeStringify(arguments) }); }; - console.info = function () { safeSend({ type: '__$console', severity: 'log', arguments: safeStringify(arguments) }); }; - console.warn = function () { safeSend({ type: '__$console', severity: 'warn', arguments: safeStringify(arguments) }); }; + console.log = function () { safeSend({ type: '__$console', severity: 'log', arguments: safeToArray(arguments) }); }; + console.info = function () { safeSend({ type: '__$console', severity: 'log', arguments: safeToArray(arguments) }); }; + console.warn = function () { safeSend({ type: '__$console', severity: 'warn', arguments: safeToArray(arguments) }); }; } else { console.log = function () { /* ignore */ }; console.warn = function () { /* ignore */ }; console.info = function () { /* ignore */ }; } - console.error = function () { safeSend({ type: '__$console', severity: 'error', arguments: safeStringify(arguments) }); }; + console.error = function () { safeSend({ type: '__$console', severity: 'error', arguments: safeToArray(arguments) }); }; } if (!process.env['VSCODE_ALLOW_IO']) { diff --git a/src/vs/base/node/console.ts b/src/vs/base/node/console.ts new file mode 100644 index 0000000000000000000000000000000000000000..fc3cf3baeabd2e2a3a9774e8ca322aab1f02876d --- /dev/null +++ b/src/vs/base/node/console.ts @@ -0,0 +1,125 @@ +/*--------------------------------------------------------------------------------------------- + * Copyright (c) Microsoft Corporation. All rights reserved. + * Licensed under the MIT License. See License.txt in the project root for license information. + *--------------------------------------------------------------------------------------------*/ + +'use strict'; + +import URI from 'vs/base/common/uri'; + +export interface IRemoteConsoleLog { + type: string; + severity: string; + arguments: string; +} + +interface IStackArgument { + __$stack: string; +} + +export interface IStackFrame { + uri: URI; + line: number; + column: number; +} + +export function isRemoteConsoleLog(obj: any): obj is IRemoteConsoleLog { + const entry = obj as IRemoteConsoleLog; + + return entry && typeof entry.type === 'string' && typeof entry.severity === 'string'; +} + +export function parse(entry: IRemoteConsoleLog): { args: any[], stack?: string } { + const args: any[] = []; + let stack: string; + + // Parse Entry + try { + const parsedArguments: any[] = JSON.parse(entry.arguments); + + // Check for special stack entry as last entry + const stackArgument = parsedArguments[parsedArguments.length - 1] as IStackArgument; + if (stackArgument && stackArgument.__$stack) { + parsedArguments.pop(); // stack is handled specially + stack = stackArgument.__$stack; + } + + args.push(...parsedArguments); + } catch (error) { + args.push('Unable to log remote console arguments', entry.arguments); + } + + return { args, stack }; +} + +export function getFirstFrame(entry: IRemoteConsoleLog): IStackFrame; +export function getFirstFrame(stack: string): IStackFrame; +export function getFirstFrame(arg0: IRemoteConsoleLog | string): IStackFrame { + if (typeof arg0 !== 'string') { + return getFirstFrame(parse(arg0).stack); + } + + // Parse a source information out of the stack if we have one. Format: + // at vscode.commands.registerCommand (/Users/someone/Desktop/test-ts/out/src/extension.js:18:17) + const stack = arg0; + if (stack) { + const matches = /.+\((.+):(\d+):(\d+)\)/.exec(stack); + if (matches.length === 4) { + return { + uri: URI.file(matches[1]), + line: Number(matches[2]), + column: Number(matches[3]) + } as IStackFrame; + } + } + + return void 0; +} + +export function log(entry: IRemoteConsoleLog, label: string): void { + const { args, stack } = parse(entry); + + // Determine suffix based on severity of log entry if we have a stack + let suffixColor = 'blue'; + let suffix = ''; + if (stack) { + switch (entry.severity) { + case 'warn': + suffixColor = 'goldenrod'; + suffix = ' WARNING:'; + break; + case 'error': + suffixColor = 'darkred'; + suffix = ' ERROR:'; + break; + } + } + + let consoleArgs = []; + + // First arg is a string + if (typeof args[0] === 'string') { + consoleArgs = [`%c[${label}]%c${suffix} %c${args[0]}`, color('blue'), color(suffixColor), color('black'), ...args.slice(1)]; + } + + // First arg is something else, just apply all + else { + consoleArgs = [`%c[${label}]%c${suffix}`, color('blue'), color(suffixColor), ...args]; + } + + // Stack: use console group + if (stack) { + console.groupCollapsed.apply(console, consoleArgs); + console.log(stack); + console.groupEnd(); + } + + // No stack: just log message + else { + console[entry.severity].apply(console, consoleArgs); + } +} + +function color(color: string): string { + return `color: ${color}; font-weight: normal;`; +} \ No newline at end of file diff --git a/src/vs/base/parts/ipc/node/ipc.cp.ts b/src/vs/base/parts/ipc/node/ipc.cp.ts index 45d401724c4c793fd8ec0a5b3f324590567a9cc1..cb73fe6f93790ca8c52230cd9985407e21e955fe 100644 --- a/src/vs/base/parts/ipc/node/ipc.cp.ts +++ b/src/vs/base/parts/ipc/node/ipc.cp.ts @@ -12,6 +12,7 @@ import { Emitter } from 'vs/base/common/event'; import { fromEventEmitter } from 'vs/base/node/event'; import { createQueuedSender } from 'vs/base/node/processes'; import { ChannelServer as IPCServer, ChannelClient as IPCClient, IChannelClient, IChannel } from 'vs/base/parts/ipc/common/ipc'; +import { isRemoteConsoleLog, log } from 'vs/base/node/console'; export class Server extends IPCServer { constructor() { @@ -151,24 +152,15 @@ export class Client implements IChannelClient, IDisposable { const onRawMessage = fromEventEmitter(this.child, 'message', msg => msg); onRawMessage(msg => { - // Handle console logs specially - if (msg && msg.type === '__$console') { - let args = ['%c[IPC Library: ' + this.options.serverName + ']', 'color: darkgreen']; - try { - const parsed = JSON.parse(msg.arguments); - args = args.concat(Object.getOwnPropertyNames(parsed).map(o => parsed[o])); - } catch (error) { - args.push(msg.arguments); - } - - console[msg.severity].apply(console, args); + + // Handle remote console logs specially + if (isRemoteConsoleLog(msg)) { + log(msg, `IPC Library: ${this.options.serverName}`); return null; } // Anything else goes to the outside - else { - onMessageEmitter.fire(msg); - } + onMessageEmitter.fire(msg); }); const sender = this.options.useQueue ? createQueuedSender(this.child) : this.child; diff --git a/src/vs/platform/extensions/common/extensionHost.ts b/src/vs/platform/extensions/common/extensionHost.ts index 3466201a1997c061c9bccbfa3098e8bbc7d4d25b..dd2d2ca92d2026b29a42c2d195d82e50d08a0d80 100644 --- a/src/vs/platform/extensions/common/extensionHost.ts +++ b/src/vs/platform/extensions/common/extensionHost.ts @@ -11,10 +11,4 @@ export const EXTENSION_LOG_BROADCAST_CHANNEL = 'vscode:extensionLog'; export const EXTENSION_ATTACH_BROADCAST_CHANNEL = 'vscode:extensionAttach'; export const EXTENSION_TERMINATE_BROADCAST_CHANNEL = 'vscode:extensionTerminate'; export const EXTENSION_RELOAD_BROADCAST_CHANNEL = 'vscode:extensionReload'; -export const EXTENSION_CLOSE_EXTHOST_BROADCAST_CHANNEL = 'vscode:extensionCloseExtensionHost'; - -export interface ILogEntry { - type: string; - severity: string; - arguments: any; -} \ No newline at end of file +export const EXTENSION_CLOSE_EXTHOST_BROADCAST_CHANNEL = 'vscode:extensionCloseExtensionHost'; \ No newline at end of file diff --git a/src/vs/workbench/parts/debug/electron-browser/debugService.ts b/src/vs/workbench/parts/debug/electron-browser/debugService.ts index d25b506caa796ae61e85c92e7e6f6be26f884805..a3d44d3cc0aca2698225a7ee24e7a9307df4a68f 100644 --- a/src/vs/workbench/parts/debug/electron-browser/debugService.ts +++ b/src/vs/workbench/parts/debug/electron-browser/debugService.ts @@ -49,8 +49,9 @@ import { ITextFileService } from 'vs/workbench/services/textfile/common/textfile import { IConfigurationService } from 'vs/platform/configuration/common/configuration'; import { IWorkspaceContextService, WorkbenchState, IWorkspaceFolder } from 'vs/platform/workspace/common/workspace'; import { IWorkbenchEditorService } from 'vs/workbench/services/editor/common/editorService'; -import { ILogEntry, EXTENSION_LOG_BROADCAST_CHANNEL, EXTENSION_ATTACH_BROADCAST_CHANNEL, EXTENSION_TERMINATE_BROADCAST_CHANNEL, EXTENSION_CLOSE_EXTHOST_BROADCAST_CHANNEL, EXTENSION_RELOAD_BROADCAST_CHANNEL } from 'vs/platform/extensions/common/extensionHost'; +import { EXTENSION_LOG_BROADCAST_CHANNEL, EXTENSION_ATTACH_BROADCAST_CHANNEL, EXTENSION_TERMINATE_BROADCAST_CHANNEL, EXTENSION_CLOSE_EXTHOST_BROADCAST_CHANNEL, EXTENSION_RELOAD_BROADCAST_CHANNEL } from 'vs/platform/extensions/common/extensionHost'; import { IBroadcastService, IBroadcast } from 'vs/platform/broadcast/electron-browser/broadcastService'; +import { IRemoteConsoleLog, parse } from 'vs/base/node/console'; const DEBUG_BREAKPOINTS_KEY = 'debug.breakpoint'; const DEBUG_BREAKPOINTS_ACTIVATED_KEY = 'debug.breakpointactivated'; @@ -163,16 +164,10 @@ export class DebugService implements debug.IDebugService { // an extension logged output, show it inside the REPL if (broadcast.channel === EXTENSION_LOG_BROADCAST_CHANNEL) { - let extensionOutput: ILogEntry = broadcast.payload.logEntry; + let extensionOutput: IRemoteConsoleLog = broadcast.payload.logEntry; let sev = extensionOutput.severity === 'warn' ? severity.Warning : extensionOutput.severity === 'error' ? severity.Error : severity.Info; - let args: any[] = []; - try { - let parsed = JSON.parse(extensionOutput.arguments); - args.push(...Object.getOwnPropertyNames(parsed).map(o => parsed[o])); - } catch (error) { - args.push(extensionOutput.arguments); - } + const { args } = parse(extensionOutput); // add output for each argument logged let simpleVals: any[] = []; diff --git a/src/vs/workbench/services/extensions/electron-browser/extensionHost.ts b/src/vs/workbench/services/extensions/electron-browser/extensionHost.ts index cee692ce0e6946e6a8e50e8c6b0fe9d7a8c7872d..d4b17a7fbc3f5906f1d525dd73ba09375cbdf993 100644 --- a/src/vs/workbench/services/extensions/electron-browser/extensionHost.ts +++ b/src/vs/workbench/services/extensions/electron-browser/extensionHost.ts @@ -33,8 +33,9 @@ import { IWorkspaceConfigurationService } from 'vs/workbench/services/configurat import { ICrashReporterService } from 'vs/workbench/services/crashReporter/common/crashReporterService'; import { IBroadcastService, IBroadcast } from 'vs/platform/broadcast/electron-browser/broadcastService'; import { isEqual } from 'vs/base/common/paths'; -import { EXTENSION_CLOSE_EXTHOST_BROADCAST_CHANNEL, EXTENSION_RELOAD_BROADCAST_CHANNEL, ILogEntry, EXTENSION_ATTACH_BROADCAST_CHANNEL, EXTENSION_LOG_BROADCAST_CHANNEL, EXTENSION_TERMINATE_BROADCAST_CHANNEL } from 'vs/platform/extensions/common/extensionHost'; +import { EXTENSION_CLOSE_EXTHOST_BROADCAST_CHANNEL, EXTENSION_RELOAD_BROADCAST_CHANNEL, EXTENSION_ATTACH_BROADCAST_CHANNEL, EXTENSION_LOG_BROADCAST_CHANNEL, EXTENSION_TERMINATE_BROADCAST_CHANNEL } from 'vs/platform/extensions/common/extensionHost'; import { IDisposable, dispose } from 'vs/base/common/lifecycle'; +import { IRemoteConsoleLog, log, parse } from 'vs/base/node/console'; export class ExtensionHostProcessWorker { @@ -142,7 +143,8 @@ export class ExtensionHostProcessWorker { VSCODE_WINDOW_ID: String(this._windowService.getCurrentWindowId()), VSCODE_IPC_HOOK_EXTHOST: pipeName, VSCODE_HANDLES_UNCAUGHT_ERRORS: true, - ELECTRON_NO_ASAR: '1' + ELECTRON_NO_ASAR: '1', + VSCODE_LOG_STACK: !this._isExtensionDevTestFromCli && (this._isExtensionDevHost || !this._environmentService.isBuilt || product.quality !== 'stable' || this._environmentService.verbose) }), // We only detach the extension host on windows. Linux and Mac orphan by default // and detach under Linux and Mac create another process group. @@ -195,8 +197,8 @@ export class ExtensionHostProcessWorker { // Support logging from extension host this._extensionHostProcess.on('message', msg => { - if (msg && (msg).type === '__$console') { - this._logExtensionHostMessage(msg); + if (msg && (msg).type === '__$console') { + this._logExtensionHostMessage(msg); } }); @@ -365,33 +367,16 @@ export class ExtensionHostProcessWorker { }); } - private _logExtensionHostMessage(logEntry: ILogEntry) { - let args = []; - try { - let parsed = JSON.parse(logEntry.arguments); - args.push(...Object.getOwnPropertyNames(parsed).map(o => parsed[o])); - } catch (error) { - args.push(logEntry.arguments); - } - - // If the first argument is a string, check for % which indicates that the message - // uses substitution for variables. In this case, we cannot just inject our colored - // [Extension Host] to the front because it breaks substitution. - let consoleArgs = []; - if (typeof args[0] === 'string' && args[0].indexOf('%') >= 0) { - consoleArgs = [`%c[Extension Host]%c ${args[0]}`, 'color: blue', 'color: black', ...args.slice(1)]; - } else { - consoleArgs = ['%c[Extension Host]', 'color: blue', ...args]; - } + private _logExtensionHostMessage(entry: IRemoteConsoleLog) { // Send to local console unless we run tests from cli if (!this._isExtensionDevTestFromCli) { - console[logEntry.severity].apply(console, consoleArgs); + log(entry, 'Extension Host'); } // Log on main side if running tests from cli if (this._isExtensionDevTestFromCli) { - this._windowsService.log(logEntry.severity, ...args); + this._windowsService.log(entry.severity, ...parse(entry).args); } // Broadcast to other windows if we are in development mode @@ -399,7 +384,7 @@ export class ExtensionHostProcessWorker { this._broadcastService.broadcast({ channel: EXTENSION_LOG_BROADCAST_CHANNEL, payload: { - logEntry, + logEntry: entry, debugId: this._environmentService.debugExtensionHost.debugId } });