Merge pull request #21631 from Microsoft/joh/prof-startup

add --prof-startup flag

build/gulpfile.vscode.js

@@ -272,7 +272,8 @@ function packageTask(platform, arch, opts) {
 			.pipe(util.cleanNodeModule('native-keymap', ['binding.gyp', 'build/**', 'src/**', 'deps/**'], ['**/*.node']))
 			.pipe(util.cleanNodeModule('windows-foreground-love', ['binding.gyp', 'build/**', 'src/**'], ['**/*.node']))
 			.pipe(util.cleanNodeModule('gc-signals', ['binding.gyp', 'build/**', 'src/**', 'deps/**'], ['**/*.node', 'src/index.js']))
-			.pipe(util.cleanNodeModule('node-pty', ['binding.gyp', 'build/**', 'src/**', 'deps/**'], ['build/Release/**']));
+			.pipe(util.cleanNodeModule('v8-profiler', ['binding.gyp', 'build/**', 'src/**', 'deps/**'], ['**/*.node', 'src/index.js']))
+			.pipe(util.cleanNodeModule('node-pty', ['binding.gyp', 'build/**', 'src/**', 'tools/**'], ['build/Release/**']));
 
 		let all = es.merge(
 			packageJsonStream,

npm-shrinkwrap.json

@@ -399,6 +399,11 @@
       "from": "util-deprecate@>=1.0.1 <1.1.0",
       "resolved": "https://registry.npmjs.org/util-deprecate/-/util-deprecate-1.0.2.tgz"
     },
+    "v8-profiler": {
+      "version": "5.6.5",
+      "from": "v8-profiler@5.6.5",
+      "resolved": "git://github.com/jrieken/v8-profiler.git#bc0803a4d4b2150b8a1bbffa80270769007036c2"
+    },
     "vscode-debugprotocol": {
       "version": "1.17.0",
       "from": "vscode-debugprotocol@1.17.0",

package.json

@@ -33,6 +33,7 @@
     "native-keymap": "0.4.0",
     "node-pty": "0.6.2",
     "semver": "4.3.6",
+    "v8-profiler": "jrieken/v8-profiler#vscode",
     "vscode-debugprotocol": "1.17.0",
     "vscode-textmate": "^3.1.1",
     "winreg": "1.2.0",

src/main.js

@@ -5,6 +5,13 @@
 
 'use strict';
 
+if (process.argv.indexOf('--prof-startup') >= 0) {
+	var profiler = require('v8-profiler');
+	var prefix = require('crypto').randomBytes(2).toString('hex');
+	process.env.VSCODE_PROFILES_PREFIX = prefix;
+	profiler.startProfiling('main', true);
+}
+
 // Perf measurements
 global.perfStartTime = Date.now();
 

src/vs/base/node/profiler.ts

+/*---------------------------------------------------------------------------------------------
+ *  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 { TPromise } from 'vs/base/common/winjs.base';
+import { join, basename } from 'path';
+import { writeFile } from 'vs/base/node/pfs';
+
+export function startProfiling(name: string): TPromise<boolean> {
+	return lazyV8Profiler.value.then(profiler => {
+		profiler.startProfiling(name);
+		return true;
+	});
+}
+
+export function stopProfiling(dir: string, prefix: string, keepPaths: boolean = false): TPromise<string> {
+	return lazyV8Profiler.value.then(profiler => {
+		return profiler.stopProfiling();
+	}).then(profile => {
+		return new TPromise<any>((resolve, reject) => {
+
+			// remove pii paths
+			if (!keepPaths) {
+				removePiiPaths(profile);
+			}
+
+			profile.export(function (error, result) {
+				profile.delete();
+				if (error) {
+					reject(error);
+					return;
+				}
+				const filepath = join(dir, `${prefix}_${profile.title}.cpuprofile.txt`);
+				writeFile(filepath, result).then(() => resolve(filepath), reject);
+			});
+		});
+	});
+}
+
+function removePiiPaths(profile: Profile) {
+	const stack = [profile.head];
+	while (stack.length > 0) {
+		const element = stack.pop();
+		if (element.url) {
+			const shortUrl = basename(element.url);
+			if (element.url !== shortUrl) {
+				element.url = `pii_removed/${shortUrl}`;
+			}
+		}
+		if (element.children) {
+			stack.push(...element.children);
+		}
+	}
+}
+
+declare interface Profiler {
+	startProfiling(name: string);
+	stopProfiling(): Profile;
+}
+
+declare interface Profile {
+	title: string;
+	export(callback: (err, data) => void);
+	delete();
+	head: ProfileSample;
+}
+
+declare interface ProfileSample {
+	// bailoutReason:""
+	// callUID:2333
+	// children:Array[39]
+	// functionName:"(root)"
+	// hitCount:0
+	// id:1
+	// lineNumber:0
+	// scriptId:0
+	// url:""
+	url: string;
+	children: ProfileSample[];
+}
+
+const lazyV8Profiler = new class {
+	private _value: TPromise<Profiler>;
+	get value() {
+		if (!this._value) {
+			this._value = new TPromise((resolve, reject) => {
+				require(['v8-profiler'], resolve, reject);
+			});
+		}
+		return this._value;
+	}
+};

src/vs/code/electron-main/window.ts

@@ -8,6 +8,7 @@
 import * as path from 'path';
 import * as platform from 'vs/base/common/platform';
 import * as objects from 'vs/base/common/objects';
+import { stopProfiling } from 'vs/base/node/profiler';
 import nls = require('vs/nls');
 import { IStorageService } from 'vs/code/electron-main/storage';
 import { shell, screen, BrowserWindow, systemPreferences, app } from 'electron';
@@ -466,6 +467,13 @@ export class VSCodeWindow {
 				}
 			}, 10000);
 		}
+
+		// (--prof-startup) save profile to disk
+		const { profileStartup } = this.environmentService;
+		if (profileStartup) {
+			stopProfiling(profileStartup.dir, profileStartup.prefix)
+				.done(undefined, err => console.error(err));
+		}
 	}
 
 	public reload(cli?: ParsedArgs): void {

src/vs/platform/environment/common/environment.ts

@@ -22,6 +22,7 @@ export interface ParsedArgs {
 	locale?: string;
 	'user-data-dir'?: string;
 	performance?: boolean;
+	'prof-startup'?: string;
 	verbose?: boolean;
 	logExtensionHostCommunication?: boolean;
 	'disable-extensions'?: boolean;
@@ -75,6 +76,7 @@ export interface IEnvironmentService {
 	verbose: boolean;
 	wait: boolean;
 	performance: boolean;
+	profileStartup: { prefix: string, dir: string } | undefined;
 
 	mainIPCHandle: string;
 	sharedIPCHandle: string;

src/vs/platform/environment/node/argv.ts

@@ -34,6 +34,7 @@ const options: minimist.Opts = {
 		'unity-launch',
 		'reuse-window',
 		'performance',
+		'prof-startup',
 		'verbose',
 		'logExtensionHostCommunication',
 		'disable-extensions',
@@ -112,6 +113,7 @@ export const optionsHelp: { [name: string]: string; } = {
 	'--locale <locale>': localize('locale', "The locale to use (e.g. en-US or zh-TW)."),
 	'-n, --new-window': localize('newWindow', "Force a new instance of Code."),
 	'-p, --performance': localize('performance', "Start with the 'Developer: Startup Performance' command enabled."),
+	'--prof-startup': localize('prof-startup', "Run CPU profiler during startup"),
 	'-r, --reuse-window': localize('reuseWindow', "Force opening a file or folder in the last active window."),
 	'--user-data-dir <dir>': localize('userDataDir', "Specifies the directory that user data is kept in, useful when running as root."),
 	'--verbose': localize('verbose', "Print verbose output (implies --wait)."),

src/vs/platform/environment/node/environmentService.ts

@@ -109,9 +109,22 @@ export class EnvironmentService implements IEnvironmentService {
 	get isBuilt(): boolean { return !process.env['VSCODE_DEV']; }
 	get verbose(): boolean { return this._args.verbose; }
 	get wait(): boolean { return this._args.wait; }
-	get performance(): boolean { return this._args.performance; }
 	get logExtensionHostCommunication(): boolean { return this._args.logExtensionHostCommunication; }
 
+	get performance(): boolean { return this._args.performance; }
+
+	@memoize
+	get profileStartup(): { prefix: string, dir: string } | undefined {
+		if (this._args['prof-startup']) {
+			return {
+				prefix: process.env.VSCODE_PROFILES_PREFIX,
+				dir: os.homedir()
+			};
+		} else {
+			return undefined;
+		}
+	}
+
 	@memoize
 	get mainIPCHandle(): string { return getIPCHandle(this.userDataPath, 'main'); }
 

src/vs/platform/windows/common/windows.ts

@@ -37,6 +37,7 @@ export interface IWindowsService {
 	unmaximizeWindow(windowId: number): TPromise<void>;
 	setDocumentEdited(windowId: number, flag: boolean): TPromise<void>;
 	quit(): TPromise<void>;
+	relaunch(options: { addArgs?: string[], removeArgs?: string[] }): TPromise<void>;
 
 	// Global methods
 	openWindow(paths: string[], options?: { forceNewWindow?: boolean, forceReuseWindow?: boolean }): TPromise<void>;
@@ -95,4 +96,4 @@ export interface IWindowSettings {
 	autoDetectHighContrast: boolean;
 	menuBarVisibility: MenuBarVisibility;
 	newWindowDimensions: 'default' | 'inherit' | 'maximized' | 'fullscreen';
-}
\ No newline at end of file
+}

src/vs/platform/windows/common/windowsIpc.ts

@@ -80,6 +80,7 @@ export class WindowsChannel implements IWindowsChannel {
 			case 'showWindow': return this.service.showWindow(arg);
 			case 'getWindows': return this.service.getWindows();
 			case 'getWindowCount': return this.service.getWindowCount();
+			case 'relaunch': return this.service.relaunch(arg[0]);
 			case 'quit': return this.service.quit();
 			case 'log': return this.service.log(arg[0], arg[1]);
 			case 'closeExtensionHostWindow': return this.service.closeExtensionHostWindow(arg);
@@ -175,6 +176,10 @@ export class WindowsChannelClient implements IWindowsService {
 		return this.channel.call('quit');
 	}
 
+	relaunch(options: { addArgs?: string[], removeArgs?: string[] }): TPromise<void> {
+		return this.channel.call('relaunch', [options]);
+	}
+
 	openWindow(paths: string[], options?: { forceNewWindow?: boolean, forceReuseWindow?: boolean }): TPromise<void> {
 		return this.channel.call('openWindow', [paths, options]);
 	}

src/vs/platform/windows/electron-main/windowsService.ts

@@ -264,6 +264,24 @@ export class WindowsService implements IWindowsService, IDisposable {
 		return TPromise.as(null);
 	}
 
+	relaunch(options: { addArgs?: string[], removeArgs?: string[] }): TPromise<void> {
+		const args = process.argv.slice(1);
+		if (options.addArgs) {
+			args.push(...options.addArgs);
+		}
+		if (options.removeArgs) {
+			for (const a of options.removeArgs) {
+				const idx = args.indexOf(a);
+				if (idx >= 0) {
+					args.splice(idx, 1);
+				}
+			}
+		}
+		app.quit();
+		app.once('quit', () => app.relaunch({ args }));
+		return TPromise.as(null);
+	}
+
 	private openFileForURI(filePath: string): TPromise<void> {
 		const cli = assign(Object.create(null), this.environmentService.args, { goto: true });
 		const pathsToOpen = [filePath];

src/vs/workbench/electron-browser/actions.ts

@@ -738,9 +738,9 @@ export class ReportPerformanceIssueAction extends Action {
 		super(id, label);
 	}
 
-	public run(): TPromise<boolean> {
+	public run(appendix?: string): TPromise<boolean> {
 		return this.integrityService.isPure().then(res => {
-			const issueUrl = this.generatePerformanceIssueUrl(product.reportIssueUrl, pkg.name, pkg.version, product.commit, product.date, res.isPure);
+			const issueUrl = this.generatePerformanceIssueUrl(product.reportIssueUrl, pkg.name, pkg.version, product.commit, product.date, res.isPure, appendix);
 
 			window.open(issueUrl);
 
@@ -748,7 +748,15 @@ export class ReportPerformanceIssueAction extends Action {
 		});
 	}
 
-	private generatePerformanceIssueUrl(baseUrl: string, name: string, version: string, commit: string, date: string, isPure: boolean): string {
+	private generatePerformanceIssueUrl(baseUrl: string, name: string, version: string, commit: string, date: string, isPure: boolean, appendix?: string): string {
+
+		if (!appendix) {
+			appendix = `Additional Steps to Reproduce (if any):
+
+1.
+2.`;
+		}
+
 		let nodeModuleLoadTime: number;
 		if (this.environmentService.performance) {
 			nodeModuleLoadTime = this.computeNodeModulesLoadTime();
@@ -775,10 +783,7 @@ ${this.generatePerformanceTable(nodeModuleLoadTime)}
 
 ---
 
-Additional Steps to Reproduce (if any):
-
-1.
-2.`
+${appendix}`
 		);
 
 		return `${baseUrl}${queryStringPrefix}body=${body}`;
@@ -899,4 +904,4 @@ export class OpenIntroductoryVideosUrlAction extends Action {
 		window.open(OpenIntroductoryVideosUrlAction.URL);
 		return null;
 	}
-}
\ No newline at end of file
+}

src/vs/workbench/electron-browser/bootstrap/index.js

@@ -7,6 +7,11 @@
 
 'use strict';
 
+if (window.location.search.indexOf('prof-startup') >= 0) {
+	var profiler = require('v8-profiler');
+	profiler.startProfiling('renderer', true);
+}
+
 /*global window,document,define*/
 
 const path = require('path');

src/vs/workbench/electron-browser/shell.ts

@@ -16,6 +16,7 @@ import aria = require('vs/base/browser/ui/aria/aria');
 import { dispose, IDisposable, Disposables } from 'vs/base/common/lifecycle';
 import errors = require('vs/base/common/errors');
 import { toErrorMessage } from 'vs/base/common/errorMessage';
+import { stopProfiling } from 'vs/base/node/profiler';
 import product from 'vs/platform/node/product';
 import { SyncDescriptor } from 'vs/platform/instantiation/common/descriptors';
 import pkg from 'vs/platform/node/package';
@@ -86,7 +87,7 @@ import { URLChannelClient } from 'vs/platform/url/common/urlIpc';
 import { IURLService } from 'vs/platform/url/common/url';
 import { IBackupService } from 'vs/platform/backup/common/backup';
 import { BackupChannelClient } from 'vs/platform/backup/common/backupIpc';
-import { ReloadWindowAction } from 'vs/workbench/electron-browser/actions';
+import { ReloadWindowAction, ReportPerformanceIssueAction } from 'vs/workbench/electron-browser/actions';
 import { ExtensionHostProcessWorker } from 'vs/workbench/electron-browser/extensionHost';
 import { ITimerService } from 'vs/workbench/services/timer/common/timerService';
 import { remote } from 'electron';
@@ -95,6 +96,8 @@ import { MainProcessTextMateSyntax } from 'vs/editor/electron-browser/textMate/T
 import { BareFontInfo } from 'vs/editor/common/config/fontInfo';
 import { readFontInfo } from 'vs/editor/browser/config/configuration';
 import SCMPreview from 'vs/workbench/parts/scm/browser/scmPreview';
+import { readdir } from 'vs/base/node/pfs';
+import { join } from 'path';
 import 'vs/platform/opener/browser/opener.contribution';
 
 /**
@@ -123,6 +126,7 @@ export class WorkbenchShell {
 	private contextService: IWorkspaceContextService;
 	private telemetryService: ITelemetryService;
 	private extensionService: MainProcessExtensionService;
+	private windowsService: IWindowsService;
 	private windowIPCService: IWindowIPCService;
 	private timerService: ITimerService;
 
@@ -230,6 +234,40 @@ export class WorkbenchShell {
 		if ((platform.isLinux || platform.isMacintosh) && process.getuid() === 0) {
 			this.messageService.show(Severity.Warning, nls.localize('runningAsRoot', "It is recommended not to run Code as 'root'."));
 		}
+
+		// Profiler: startup cpu profile
+		const { profileStartup } = this.environmentService;
+		if (profileStartup) {
+
+			stopProfiling(profileStartup.dir, profileStartup.prefix).then(() => {
+
+				readdir(profileStartup.dir).then(files => {
+					return files.filter(value => value.indexOf(profileStartup.prefix) === 0);
+				}).then(files => {
+
+					const profileFiles = files.reduce((prev, cur) => `${prev}${join(profileStartup.dir, cur)}\n`, '\n');
+
+					const primaryButton = this.messageService.confirm({
+						type: 'info',
+						message: nls.localize('prof.message', "Successfully created profiles."),
+						detail: nls.localize('prof.detail', "Please create an issue and manually attach the following files:\n{0}", profileFiles),
+						primaryButton: nls.localize('prof.restartAndFileIssue', "Create Issue and Restart"),
+						secondaryButton: nls.localize('prof.restart', "Restart")
+					});
+
+					let createIssue = TPromise.as(undefined);
+					if (primaryButton) {
+						const action = this.workbench.getInstantiationService().createInstance(ReportPerformanceIssueAction, ReportPerformanceIssueAction.ID, ReportPerformanceIssueAction.LABEL);
+
+						createIssue = action.run(`:warning: Make sure to **attach** these files: :warning:\n${files.map(file => `-\`${join(profileStartup.dir, file)}\``).join('\n')}`).then(() => {
+							return this.windowsService.showItemInFolder(profileStartup.dir);
+						});
+					}
+					createIssue.then(() => this.windowsService.relaunch({ removeArgs: ['--prof-startup'] }));
+				});
+
+			}, err => console.error(err));
+		}
 	}
 
 	private initServiceCollection(container: HTMLElement): [IInstantiationService, ServiceCollection] {
@@ -251,7 +289,8 @@ export class WorkbenchShell {
 		disposables.add(mainProcessClient);
 
 		const windowsChannel = mainProcessClient.getChannel('windows');
-		serviceCollection.set(IWindowsService, new SyncDescriptor(WindowsChannelClient, windowsChannel));
+		this.windowsService = new WindowsChannelClient(windowsChannel);
+		serviceCollection.set(IWindowsService, this.windowsService);
 
 		serviceCollection.set(IWindowService, new SyncDescriptor(WindowService, this.windowIPCService.getWindowId()));
 

src/vs/workbench/parts/performance/electron-browser/performance.contribution.ts

@@ -5,15 +5,19 @@
 
 'use strict';
 
+import { localize } from 'vs/nls';
 import { assign } from 'vs/base/common/objects';
 import { join } from 'path';
 import { generateUuid } from 'vs/base/common/uuid';
+import { virtualMachineHint } from 'vs/base/node/id';
 import { TPromise } from 'vs/base/common/winjs.base';
 import { Registry } from 'vs/platform/platform';
 import { writeFile } from 'vs/base/node/pfs';
 import { IWindowsService } from 'vs/platform/windows/common/windows';
 import { IEnvironmentService } from 'vs/platform/environment/common/environment';
+import { IStorageService, StorageScope } from 'vs/platform/storage/common/storage';
 import { IExtensionService } from 'vs/platform/extensions/common/extensions';
+import { IMessageService } from 'vs/platform/message/common/message';
 import { ITimerService } from 'vs/workbench/services/timer/common/timerService';
 import { IWorkbenchContributionsRegistry, IWorkbenchContribution, Extensions } from 'vs/workbench/common/contributions';
 import product from 'vs/platform/node/product';
@@ -23,17 +27,25 @@ class PerformanceContribution implements IWorkbenchContribution {
 	constructor(
 		@IWindowsService private _windowsService: IWindowsService,
 		@ITimerService private _timerService: ITimerService,
-		@IEnvironmentService envService: IEnvironmentService,
-		@IExtensionService extensionService: IExtensionService
+		@IMessageService private _messageService: IMessageService,
+		@IEnvironmentService private _envService: IEnvironmentService,
+		@IStorageService private _storageService: IStorageService,
+		@IExtensionService extensionService: IExtensionService,
 	) {
 
-		const dumpFile = envService.args['prof-startup-timers'];
+		const dumpFile = _envService.args['prof-startup-timers'];
 		if (dumpFile) {
 			// wait for extensions being loaded
 			extensionService.onReady()
 				.then(() => TPromise.timeout(15000)) // time service isn't ready yet because it listens on the same event...
 				.then(() => this._dumpTimersAndQuit(dumpFile))
 				.done(undefined, err => console.error(err));
+
+		} else if (!_envService.args['prof-startup']) {
+			// notify user of slow start
+			setTimeout(() => {
+				this._checkTimersAndSuggestToProfile();
+			}, 5000);
 		}
 	}
 
@@ -48,6 +60,42 @@ class PerformanceContribution implements IWorkbenchContribution {
 		const raw = JSON.stringify(all);
 		return writeFile(join(folder, `timers-${id}.json`), raw).then(() => this._windowsService.quit());
 	}
+
+	private _checkTimersAndSuggestToProfile() {
+
+		const disabled = false;
+		if (disabled) {
+			return;
+		}
+		//TODO(joh) use better heuristics (70th percentile, not vm, etc)
+
+		const value = this._storageService.get(this.getId(), StorageScope.GLOBAL, undefined);
+		if (value !== undefined) {
+			return;
+		}
+
+		if (virtualMachineHint.value() >= .5) {
+			//
+			return;
+		}
+
+		const { ellapsed } = this._timerService.startupMetrics;
+		if (ellapsed > 5000 && Math.ceil(Math.random() * 10) % 3 === 0) {
+			const profile = this._messageService.confirm({
+				type: 'info',
+				message: localize('slow', "Slow startup detected"),
+				detail: localize('slow.detail', "Sorry that you just had a slow startup. Please restart '{0}' with profiling enabled, share the profiles with us, and we will work hard to make startup great again.", this._envService.appNameLong),
+				primaryButton: 'Restart and profile'
+			});
+
+			if (profile) {
+				this._storageService.store(this.getId(), 'didProfile', StorageScope.GLOBAL);
+				this._windowsService.relaunch({ addArgs: ['--prof-startup'] });
+			} else {
+				this._storageService.store(this.getId(), 'didReject', StorageScope.GLOBAL);
+			}
+		}
+	}
 }
 
 const registry = Registry.as<IWorkbenchContributionsRegistry>(Extensions.Workbench);

src/vs/workbench/test/workbenchTestServices.ts

@@ -917,6 +917,10 @@ export class TestWindowsService implements IWindowsService {
 		return TPromise.as(void 0);
 	}
 
+	relaunch(options: { addArgs?: string[], removeArgs?: string[] }): TPromise<void> {
+		return TPromise.as(void 0);
+	}
+
 	// Global methods
 	openWindow(paths: string[], options?: { forceNewWindow?: boolean, forceReuseWindow?: boolean }): TPromise<void> {
 		return TPromise.as(void 0);