rename startupTimer to performance, support mark and measure, drop promise support, add more marks to slowly phase out old timers

build/gulpfile.vscode.js

@@ -68,7 +68,7 @@ const vscodeResources = [
 	'out-build/bootstrap-amd.js',
 	'out-build/paths.js',
 	'out-build/vs/**/*.{svg,png,cur,html}',
-	'out-build/vs/base/node/startupTimers.js',
+	'out-build/vs/base/common/performance.js',
 	'out-build/vs/base/node/{stdForkStart.js,terminateProcess.sh}',
 	'out-build/vs/base/browser/ui/octiconLabel/octicons/**',
 	'out-build/vs/workbench/browser/media/*-theme.css',

src/main.js

@@ -12,6 +12,9 @@ if (process.argv.indexOf('--prof-startup') >= 0) {
 	profiler.startProfiling('main', true);
 }
 
+var perf = require('./vs/base/common/performance');
+perf.mark('main:started');
+
 // Perf measurements
 global.perfStartTime = Date.now();
 
@@ -218,6 +221,7 @@ var nodeCachedDataDir = getNodeCachedDataDir().then(function (value) {
 
 // Load our code once ready
 app.once('ready', function () {
+	perf.mark('main:appReady');
 	global.perfAppReady = Date.now();
 	var nlsConfig = getNLSConfiguration();
 	process.env['VSCODE_NLS_CONFIG'] = JSON.stringify(nlsConfig);

src/vs/base/common/performance.d.ts

@@ -0,0 +1,17 @@
+/*---------------------------------------------------------------------------------------------
+ *  Copyright (c) Microsoft Corporation. All rights reserved.
+ *  Licensed under the MIT License. See License.txt in the project root for license information.
+ *--------------------------------------------------------------------------------------------*/
+
+export interface PerformanceEntry {
+	readonly type: 'mark' | 'measure';
+	readonly name: string;
+	readonly startTime: number;
+	readonly duration: number;
+}
+
+export function mark(name: string): void;
+export function measure(name: string, from?: string, to?: string): void;
+export function time(name: string): { stop(): void };
+export function getEntries(type?: 'mark' | 'measure'): PerformanceEntry[];
+export function importEntries(entries: PerformanceEntry[]): void;

src/vs/base/common/performance.js

@@ -0,0 +1,106 @@
+/*---------------------------------------------------------------------------------------------
+ *  Copyright (c) Microsoft Corporation. All rights reserved.
+ *  Licensed under the MIT License. See License.txt in the project root for license information.
+ *--------------------------------------------------------------------------------------------*/
+
+'use strict';
+
+/*global define*/
+
+// This module can be loaded in an amd and commonjs-context.
+// Because we want both instances to use the same perf-data
+// we store them globally
+global._performanceEntries = global._performanceEntries || [];
+
+if (typeof define !== "function" && typeof module === "object" && typeof module.exports === "object") {
+	// this is commonjs, fake amd
+	global.define = function (dep, callback) {
+		module.exports = callback();
+		global.define = undefined;
+	};
+}
+
+define([], function () {
+
+	// const _now = global.performance && performance.now ? performance.now : Date.now
+	const _now = Date.now;
+
+	class PerformanceEntry {
+		constructor(type, name, startTime, duration) {
+			this.type = type;
+			this.name = name;
+			this.startTime = startTime;
+			this.duration = duration;
+		}
+	}
+
+	function _getEntry(type, name) {
+		for (let i = global._performanceEntries.length - 1; i >= 0; i--) {
+			if (
+				(type === undefined || global._performanceEntries[i].type === type) &&
+				(name === undefined || global._performanceEntries[i].name === name)
+			) {
+				return global._performanceEntries[i];
+			}
+		}
+	}
+
+	function importEntries(entries) {
+		global._performanceEntries.splice(0, 0, ...entries);
+	}
+
+	function getEntries(type, name) {
+		return global._performanceEntries.filter(entry => {
+			return (type === undefined || entry.type === type) &&
+				(name === undefined || entry.name === name);
+		}).sort((a, b) => {
+			return a.startTime - b.startTime;
+		});
+	}
+
+	function mark(name) {
+		const entry = new PerformanceEntry('mark', name, _now(), 0);
+		global._performanceEntries.push(entry);
+		if (typeof console.timeStamp === 'function') {
+			console.timeStamp(name);
+		}
+	}
+
+	function time(name) {
+		let from = `${name}/start`;
+		mark(from);
+		return { stop() { measure(name, from); } };
+	}
+
+	function measure(name, from, to) {
+
+		let startTime;
+		let duration;
+		let now = _now();
+
+		if (!from) {
+			startTime = now;
+		} else {
+			startTime = _getEntry(undefined, from).startTime;
+		}
+
+		if (!to) {
+			duration = now - startTime;
+		} else {
+			duration = _getEntry(undefined, to).startTime - startTime;
+		}
+
+		const entry = new PerformanceEntry('measure', name, startTime, duration);
+		global._performanceEntries.push(entry);
+	}
+
+	var exports = {
+		mark: mark,
+		measure: measure,
+		time: time,
+		getEntries: getEntries,
+		importEntries: importEntries
+	};
+
+	return exports;
+});

src/vs/base/node/startupTimers.d.ts

@@ -1,39 +0,0 @@
-/*---------------------------------------------------------------------------------------------
- *  Copyright (c) Microsoft Corporation. All rights reserved.
- *  Licensed under the MIT License. See License.txt in the project root for license information.
- *--------------------------------------------------------------------------------------------*/
-
-import { Profile } from './profiler';
-
-declare interface TickStart {
-	name: string;
-	started: number;
-}
-
-export declare class Tick {
-
-	readonly duration: number;
-	readonly name: string;
-	readonly started: number;
-	readonly stopped: number;
-	readonly profile: Profile;
-
-	static compareByStart(a: Tick, b: Tick): number;
-}
-
-declare interface TickController {
-	while<T extends Thenable<any>>(t: T): T;
-	stop(stopped?: number): void;
-}
-
-export function startTimer(name: string): TickController;
-
-export function stopTimer(name: string): void;
-
-export function ticks(): Tick[];
-
-export function tick(name: string): Tick;
-
-export function setProfileList(names: string[]): void;
-
-export function disable(): void;

src/vs/base/node/startupTimers.js

@@ -1,128 +0,0 @@
-/*---------------------------------------------------------------------------------------------
- *  Copyright (c) Microsoft Corporation. All rights reserved.
- *  Licensed under the MIT License. See License.txt in the project root for license information.
- *--------------------------------------------------------------------------------------------*/
-
-'use strict';
-
-/*global define*/
-
-var requireProfiler;
-
-if (typeof define !== "function" && typeof module === "object" && typeof module.exports === "object") {
-	// this is commonjs, fake amd
-	global.define = function (dep, callback) {
-		module.exports = callback();
-		global.define = undefined;
-	};
-	requireProfiler = function () {
-		return require('v8-profiler');
-	};
-} else {
-	// this is amd
-	requireProfiler = function () {
-		return require.__$__nodeRequire('v8-profiler');
-	};
-}
-
-define([], function () {
-
-	function Tick(name, started, stopped, profile) {
-		this.name = name;
-		this.started = Math.round((started[0] * 1e9 + started[1]) / 1e6);
-		this.stopped = Math.round((stopped[0] * 1e9 + stopped[1]) / 1e6);
-		this.duration = Math.round(((stopped[0] * 1.e9 + stopped[1]) - (started[0] * 1e9 + started[1])) / 1.e6);
-		this.profile = profile;
-	}
-	Tick.compareByStart = function (a, b) {
-		if (a.started < b.started) {
-			return -1;
-		} else if (a.started > b.started) {
-			return 1;
-		} else {
-			return 0;
-		}
-	};
-
-	// This module can be loaded in an amd and commonjs-context.
-	// Because we want both instances to use the same tick-data
-	// we store them globally
-	global._perfStarts = global._perfStarts || new Map();
-	global._perfTicks = global._perfTicks || new Map();
-	global._perfToBeProfiled = global._perfToBeProfiled || new Set();
-
-	var _starts = global._perfStarts;
-	var _ticks = global._perfTicks;
-	var _toBeProfiled = global._perfToBeProfiled;
-
-	function startTimer(name) {
-		if (_starts.has(name)) {
-			throw new Error("${name}" + " already exists");
-		}
-		if (_toBeProfiled.has(name)) {
-			requireProfiler().startProfiling(name, true);
-		}
-		_starts.set(name, { name: name, started: process.hrtime() });
-		var stop = stopTimer.bind(undefined, name);
-		return {
-			stop: stop,
-			while: function (thenable) {
-				thenable.then(function () { stop(); }, function () { stop(); });
-				return thenable;
-			}
-		};
-	}
-
-	function stopTimer(name) {
-		var profile = _toBeProfiled.has(name) ? requireProfiler().stopProfiling(name) : undefined;
-		var start = _starts.get(name);
-		if (start !== undefined) {
-			var tick = new Tick(start.name, start.started, process.hrtime(), profile);
-			_ticks.set(name, tick);
-			_starts.delete(name);
-		}
-	}
-
-	function ticks() {
-		var ret = [];
-		_ticks.forEach(function (value) { ret.push(value); });
-		return ret.sort((a, b) => a.started - b.started);
-	}
-
-	function tick(name) {
-		var ret = _ticks.get(name);
-		if (!ret) {
-			var now = Date.now();
-			ret = new Tick(name, now, now);
-		}
-		return ret;
-	}
-
-	function setProfileList(names) {
-		_toBeProfiled.clear();
-		names.forEach(function (name) { _toBeProfiled.add(name); });
-	}
-
-	var exports = {
-		Tick: Tick,
-		startTimer: startTimer,
-		stopTimer: stopTimer,
-		ticks: ticks,
-		tick: tick,
-		setProfileList: setProfileList,
-		disable: disable,
-	};
-
-	function disable() {
-		var emptyController = Object.freeze({ while: function (t) { return t; }, stop: function () { } });
-		var emptyTicks = Object.create([]);
-		exports.startTimer = function () { return emptyController; };
-		exports.stopTimer = function () { };
-		exports.ticks = function () { return emptyTicks; };
-
-		delete global._perfStarts;
-		delete global._perfTicks;
-	}
-
-	return exports;
-});

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

@@ -26,6 +26,7 @@ import { ICodeWindow } from 'vs/platform/windows/electron-main/windows';
 import { IWorkspaceIdentifier, IWorkspacesMainService } from 'vs/platform/workspaces/common/workspaces';
 import { IBackupMainService } from 'vs/platform/backup/common/backup';
 import { ICommandAction } from 'vs/platform/actions/common/actions';
+import { mark, getEntries } from 'vs/base/common/performance';
 
 export interface IWindowState {
 	width?: number;
@@ -507,6 +508,7 @@ export class CodeWindow implements ICodeWindow {
 		}
 
 		// Load URL
+		mark('main:loadWindow');
 		this._win.loadURL(this.getUrl(config));
 
 		// Make window visible if it did not open in N seconds because this indicates an error
@@ -578,6 +580,7 @@ export class CodeWindow implements ICodeWindow {
 		windowConfiguration.backgroundColor = this.getBackgroundColor();
 
 		// Perf Counters
+		windowConfiguration.perfEntries = getEntries();
 		windowConfiguration.perfStartTime = global.perfStartTime;
 		windowConfiguration.perfAppReady = global.perfAppReady;
 		windowConfiguration.perfWindowLoadTime = Date.now();
@@ -971,4 +974,4 @@ export class CodeWindow implements ICodeWindow {
 
 		this._win = null; // Important to dereference the window object to allow for GC
 	}
-}
+}

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

@@ -14,6 +14,7 @@ import { ParsedArgs } from 'vs/platform/environment/common/environment';
 import { IWorkspaceIdentifier, IWorkspaceFolderCreationData } from 'vs/platform/workspaces/common/workspaces';
 import { IRecentlyOpened } from 'vs/platform/history/common/history';
 import { ICommandAction } from 'vs/platform/actions/common/actions';
+import { PerformanceEntry } from 'vs/base/common/performance';
 
 export const IWindowsService = createDecorator<IWindowsService>('windowsService');
 
@@ -255,6 +256,7 @@ export interface IWindowConfiguration extends ParsedArgs, IOpenFileRequest {
 	backgroundColor?: string;
 	accessibilitySupport?: boolean;
 
+	perfEntries: PerformanceEntry[];
 	perfStartTime?: number;
 	perfAppReady?: number;
 	perfWindowLoadTime?: number;
@@ -263,4 +265,4 @@ export interface IWindowConfiguration extends ParsedArgs, IOpenFileRequest {
 export interface IRunActionInWindowRequest {
 	id: string;
 	from: 'menu' | 'touchbar' | 'mouse';
-}
+}

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

@@ -45,7 +45,7 @@ import { IWorkspaceIdentifier, getWorkspaceLabel, ISingleFolderWorkspaceIdentifi
 import { FileKind } from 'vs/platform/files/common/files';
 import { IInstantiationService } from 'vs/platform/instantiation/common/instantiation';
 import { IExtensionService } from 'vs/platform/extensions/common/extensions';
-import { ticks } from 'vs/base/node/startupTimers';
+import { getEntries } from 'vs/base/common/performance';
 
 // --- actions
 
@@ -367,9 +367,10 @@ export class ShowStartupPerformance extends Action {
 
 			(<any>console).group('Raw Startup Timers (CSV)');
 			let value = `Name\tStart\tDuration\n`;
-			let offset = ticks()[0].started;
-			for (const tick of ticks()) {
-				value += `${tick.name}\t${tick.started - offset}\t${tick.duration}\n`;
+			const entries = getEntries('measure');
+			let offset = entries[0].startTime;
+			for (const entry of entries) {
+				value += `${entry.name}\t${entry.startTime - offset}\t${entry.duration}\n`;
 			}
 			console.log(value);
 			(<any>console).groupEnd();

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

@@ -14,7 +14,9 @@ if (window.location.search.indexOf('prof-startup') >= 0) {
 
 /*global window,document,define,Monaco_Loader_Init*/
 
-const startTimer = require('../../../base/node/startupTimers').startTimer;
+const perf = require('../../../base/common/performance');
+perf.mark('renderer/started');
+
 const path = require('path');
 const electron = require('electron');
 const remote = electron.remote;
@@ -124,6 +126,7 @@ function main() {
 
 	// Correctly inherit the parent's environment
 	assign(process.env, configuration.userEnv);
+	perf.importEntries(configuration.perfEntries);
 
 	// Get the nls configuration into the process.env as early as possible.
 	var nlsConfig = { availableLanguages: {} };
@@ -161,7 +164,6 @@ function main() {
 		window.nodeRequire = require.__$__nodeRequire;
 
 		define('fs', ['original-fs'], function (originalFS) { return originalFS; }); // replace the patched electron fs with the original node fs for all AMD code
-		loaderTimer.stop();
 
 		window.MonacoEnvironment = {};
 
@@ -191,13 +193,13 @@ function main() {
 			beforeLoadWorkbenchMain: Date.now()
 		};
 
-		const workbenchMainTimer = startTimer('load:workbench.main');
+		const workbenchMainClock = perf.time('loadWorkbenchMain');
 		require([
 			'vs/workbench/workbench.main',
 			'vs/nls!vs/workbench/workbench.main',
 			'vs/css!vs/workbench/workbench.main'
 		], function () {
-			workbenchMainTimer.stop();
+			workbenchMainClock.stop();
 			timers.afterLoadWorkbenchMain = Date.now();
 
 			process.lazyEnv.then(function () {
@@ -213,8 +215,6 @@ function main() {
 	}
 
 	// In the bundled version the nls plugin is packaged with the loader so the NLS Plugins
-	// loads as soon as the loader loads. To be able to have pseudo translation
-	const loaderTimer = startTimer('load:loader');
 	if (typeof Monaco_Loader_Init === 'function') {
 		const loader = Monaco_Loader_Init();
 		//eslint-disable-next-line no-global-assign

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

@@ -16,7 +16,7 @@ import { Builder, $ } from 'vs/base/browser/builder';
 import { Delayer, RunOnceScheduler } from 'vs/base/common/async';
 import * as browser from 'vs/base/browser/browser';
 import { StopWatch } from 'vs/base/common/stopwatch';
-import { startTimer } from 'vs/base/node/startupTimers';
+import { time } from 'vs/base/common/performance';
 import errors = require('vs/base/common/errors');
 import { BackupFileService } from 'vs/workbench/services/backup/node/backupFileService';
 import { IBackupFileService } from 'vs/workbench/services/backup/common/backup';
@@ -320,9 +320,10 @@ export class Workbench implements IPartService {
 				}
 
 				viewletRestoreStopWatch = StopWatch.create();
-				const viewletTimer = startTimer('restore:viewlet');
-				compositeAndEditorPromises.push(viewletTimer.while(this.viewletService.openViewlet(viewletIdToRestore)).then(() => {
+				const viewletRestoreClock = time('restore:viewlet');
+				compositeAndEditorPromises.push(this.viewletService.openViewlet(viewletIdToRestore).then(() => {
 					viewletRestoreStopWatch.stop();
+					viewletRestoreClock.stop();
 				}));
 			}
 
@@ -335,9 +336,9 @@ export class Workbench implements IPartService {
 
 			// Load Editors
 			const editorRestoreStopWatch = StopWatch.create();
+			const editorRestoreClock = time('restore:editors');
 			const restoredEditors: string[] = [];
-			const editorsTimer = startTimer('restore:editors');
-			compositeAndEditorPromises.push(editorsTimer.while(this.resolveEditorsToOpen().then(inputs => {
+			compositeAndEditorPromises.push(this.resolveEditorsToOpen().then(inputs => {
 				let editorOpenPromise: TPromise<IEditor[]>;
 				if (inputs.length) {
 					editorOpenPromise = this.editorService.openEditors(inputs.map(input => { return { input, position: EditorPosition.ONE }; }));
@@ -347,8 +348,8 @@ export class Workbench implements IPartService {
 
 				return editorOpenPromise.then(editors => {
 					this.handleEditorBackground(); // make sure we show the proper background in the editor area
+					editorRestoreClock.stop();
 					editorRestoreStopWatch.stop();
-
 					for (const editor of editors) {
 						if (editor) {
 							if (editor.input) {
@@ -359,7 +360,7 @@ export class Workbench implements IPartService {
 						}
 					}
 				});
-			})));
+			}));
 
 			if (this.storageService.getBoolean(Workbench.zenModeActiveSettingKey, StorageScope.WORKSPACE, false)) {
 				this.toggleZenMode(true);

src/vs/workbench/services/extensions/electron-browser/extensionService.ts

@@ -32,7 +32,7 @@ import { ExtHostCustomersRegistry } from 'vs/workbench/api/electron-browser/extH
 import { IWindowService } from 'vs/platform/windows/common/windows';
 import { Action } from 'vs/base/common/actions';
 import { IDisposable } from 'vs/base/common/lifecycle';
-import { startTimer } from 'vs/base/node/startupTimers';
+import { mark, time } from 'vs/base/common/performance';
 import { toPromise, filterEvent } from 'vs/base/common/event';
 import { ILifecycleService, LifecyclePhase } from 'vs/platform/lifecycle/common/lifecycle';
 
@@ -336,14 +336,14 @@ export class ExtensionService implements IExtensionService {
 			let messageHandler = (msg: IMessage) => this._handleExtensionPointMessage(msg);
 
 			for (let i = 0, len = extensionPoints.length; i < len; i++) {
-				const clock = startTimer(`handleExtensionPoint:${extensionPoints[i].name}`);
+				const clock = time(`handleExtensionPoint:${extensionPoints[i].name}`);
 				try {
 					ExtensionService._handleExtensionPoint(extensionPoints[i], availableExtensions, messageHandler);
 				} finally {
 					clock.stop();
 				}
 			}
-
+			mark('extensionHostReady');
 			this._barrier.open();
 		});
 	}