Perf: visualise memory efficiency (microsoft#211837) (microsoft#213208)

* Perf: visualise memory efficiency (microsoft#211837)

* feat: add telemetry logging for startup heap statistics

* fix compile

* feat: add used heap size to startup performance telemetry

* refactor: remove allocated heap size from startup performance telemetry

* comments

src/vs/base/parts/sandbox/common/electronTypes.ts

@@ -7,7 +7,7 @@
 // #######################################################################
 // ###                                                                 ###
 // ###      electron.d.ts types we need in a common layer for reuse    ###
-// ###                    (copied from Electron 16.x)                  ###
+// ###                    (copied from Electron 29.x)                  ###
 // ###                                                                 ###
 // #######################################################################
 
@@ -148,9 +148,9 @@ export interface SaveDialogReturnValue {
 	 */
 	canceled: boolean;
 	/**
-	 * If the dialog is canceled, this will be `undefined`.
+	 * If the dialog is canceled, this will be an empty string.
 	 */
-	filePath?: string;
+	filePath: string;
 	/**
 	 * Base64 encoded string which contains the security scoped bookmark data for the
 	 * saved file. `securityScopedBookmarks` must be enabled for this to be present.
@@ -219,16 +219,20 @@ export interface FileFilter {
 
 export interface OpenDevToolsOptions {
 	/**
-	 * Opens the devtools with specified dock state, can be `right`, `bottom`,
+	 * Opens the devtools with specified dock state, can be `left`, `right`, `bottom`,
 	 * `undocked`, `detach`. Defaults to last used dock state. In `undocked` mode it's
 	 * possible to dock back. In `detach` mode it's not.
 	 */
-	mode: ('right' | 'bottom' | 'undocked' | 'detach');
+	mode: ('left' | 'right' | 'bottom' | 'undocked' | 'detach');
 	/**
 	 * Whether to bring the opened devtools window to the foreground. The default is
 	 * `true`.
 	 */
 	activate?: boolean;
+	/**
+	 * A title for the DevTools window (only in `undocked` or `detach` mode).
+	 */
+	title?: string;
 }
 
 interface InputEvent {
@@ -241,6 +245,19 @@ interface InputEvent {
 	 * `middleButtonDown`, `rightButtonDown`, `capsLock`, `numLock`, `left`, `right`.
 	 */
 	modifiers?: Array<'shift' | 'control' | 'ctrl' | 'alt' | 'meta' | 'command' | 'cmd' | 'isKeypad' | 'isAutoRepeat' | 'leftButtonDown' | 'middleButtonDown' | 'rightButtonDown' | 'capsLock' | 'numLock' | 'left' | 'right'>;
+	/**
+	 * Can be `undefined`, `mouseDown`, `mouseUp`, `mouseMove`, `mouseEnter`,
+	 * `mouseLeave`, `contextMenu`, `mouseWheel`, `rawKeyDown`, `keyDown`, `keyUp`,
+	 * `char`, `gestureScrollBegin`, `gestureScrollEnd`, `gestureScrollUpdate`,
+	 * `gestureFlingStart`, `gestureFlingCancel`, `gesturePinchBegin`,
+	 * `gesturePinchEnd`, `gesturePinchUpdate`, `gestureTapDown`, `gestureShowPress`,
+	 * `gestureTap`, `gestureTapCancel`, `gestureShortPress`, `gestureLongPress`,
+	 * `gestureLongTap`, `gestureTwoFingerTap`, `gestureTapUnconfirmed`,
+	 * `gestureDoubleTap`, `touchStart`, `touchMove`, `touchEnd`, `touchCancel`,
+	 * `touchScrollStarted`, `pointerDown`, `pointerUp`, `pointerMove`,
+	 * `pointerRawUpdate`, `pointerCancel` or `pointerCausedUaAction`.
+	 */
+	type: ('undefined' | 'mouseDown' | 'mouseUp' | 'mouseMove' | 'mouseEnter' | 'mouseLeave' | 'contextMenu' | 'mouseWheel' | 'rawKeyDown' | 'keyDown' | 'keyUp' | 'char' | 'gestureScrollBegin' | 'gestureScrollEnd' | 'gestureScrollUpdate' | 'gestureFlingStart' | 'gestureFlingCancel' | 'gesturePinchBegin' | 'gesturePinchEnd' | 'gesturePinchUpdate' | 'gestureTapDown' | 'gestureShowPress' | 'gestureTap' | 'gestureTapCancel' | 'gestureShortPress' | 'gestureLongPress' | 'gestureLongTap' | 'gestureTwoFingerTap' | 'gestureTapUnconfirmed' | 'gestureDoubleTap' | 'touchStart' | 'touchMove' | 'touchEnd' | 'touchCancel' | 'touchScrollStarted' | 'pointerDown' | 'pointerUp' | 'pointerMove' | 'pointerRawUpdate' | 'pointerCancel' | 'pointerCausedUaAction');
 }
 
 export interface MouseInputEvent extends InputEvent {

src/vs/base/parts/sandbox/electron-sandbox/electronTypes.ts

@@ -7,7 +7,7 @@
 // #######################################################################
 // ###                                                                 ###
 // ###      electron.d.ts types we expose from electron-sandbox        ###
-// ###                    (copied from Electron 25.x)                  ###
+// ###                    (copied from Electron 29.x)                  ###
 // ###                                                                 ###
 // #######################################################################
 
@@ -30,20 +30,6 @@ export interface IpcRendererEvent extends Event {
 	 * The `IpcRenderer` instance that emitted the event originally
 	 */
 	sender: IpcRenderer;
-	/**
-	 * The `webContents.id` that sent the message, you can call
-	 * `event.sender.sendTo(event.senderId, ...)` to reply to the message, see
-	 * ipcRenderer.sendTo for more information. This only applies to messages sent from
-	 * a different renderer. Messages sent directly from the main process set
-	 * `event.senderId` to `0`.
-	 */
-	senderId: number;
-	/**
-	 * Whether the message sent via ipcRenderer.sendTo was sent by the main frame. This
-	 * is relevant when `nodeIntegrationInSubFrames` is enabled in the originating
-	 * `webContents`.
-	 */
-	senderIsMainFrame?: boolean;
 }
 
 export interface IpcRenderer {
@@ -91,10 +77,6 @@ export interface IpcRenderer {
 	 * only the next time a message is sent to `channel`, after which it is removed.
 	 */
 	once(channel: string, listener: (event: IpcRendererEvent, ...args: any[]) => void): this;
-	/**
-	 * Removes the specified `listener` from the listener array for the specified
-	 * `channel`.
-	 */
 	// Note: API with `Transferable` intentionally commented out because you
 	// cannot transfer these when `contextIsolation: true`.
 	// /**
@@ -111,7 +93,11 @@ export interface IpcRenderer {
 	//  * documentation.
 	//  */
 	// postMessage(channel: string, message: any, transfer?: MessagePort[]): void;
-	removeListener(channel: string, listener: (...args: any[]) => void): this;
+	/**
+	 * Removes the specified `listener` from the listener array for the specified
+	 * `channel`.
+	 */
+	removeListener(channel: string, listener: (event: IpcRendererEvent, ...args: any[]) => void): this;
 	/**
 	 * Send an asynchronous message to the main process via `channel`, along with
 	 * arguments. Arguments will be serialized with the Structured Clone Algorithm,

src/vs/base/parts/sandbox/electron-sandbox/globals.ts

@@ -12,6 +12,11 @@ import { IpcRenderer, ProcessMemoryInfo, WebFrame } from 'vs/base/parts/sandbox/
  */
 export interface ISandboxNodeProcess extends INodeProcess {
 
+	/**
+	 * The process.pid property returns the process ID of the process.
+	 */
+	readonly pid: number;
+
 	/**
 	 * The process.platform property returns a string identifying the operating system platform
 	 * on which the Node.js process is running.

src/vs/base/parts/sandbox/electron-sandbox/preload.js

@@ -248,6 +248,7 @@
 		 * @type {ISandboxNodeProcess}
 		 */
 		process: {
+			get pid() { return process.pid; },
 			get platform() { return process.platform; },
 			get arch() { return process.arch; },
 			get env() { return { ...process.env }; },

src/vs/base/parts/sandbox/node/electronTypes.ts

@@ -11,13 +11,15 @@ export interface MessagePortMain extends NodeJS.EventEmitter {
 	 * Emitted when the remote end of a MessagePortMain object becomes disconnected.
 	 */
 	on(event: 'close', listener: Function): this;
+	off(event: 'close', listener: Function): this;
 	once(event: 'close', listener: Function): this;
 	addListener(event: 'close', listener: Function): this;
 	removeListener(event: 'close', listener: Function): this;
 	/**
 	 * Emitted when a MessagePortMain object receives a message.
 	 */
 	on(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
+	off(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
 	once(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
 	addListener(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
 	removeListener(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
@@ -51,6 +53,7 @@ export interface ParentPort extends NodeJS.EventEmitter {
 	 * be queued up until a handler is registered for this event.
 	 */
 	on(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
+	off(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
 	once(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
 	addListener(event: 'message', listener: (messageEvent: MessageEvent) => void): this;
 	removeListener(event: 'message', listener: (messageEvent: MessageEvent) => void): this;

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

@@ -141,4 +141,8 @@ export interface NativeParsedArgs {
 	'vmodule'?: string;
 	'disable-dev-shm-usage'?: boolean;
 	'ozone-platform'?: string;
+	'enable-tracing'?: string;
+	'trace-startup-format'?: string;
+	'trace-startup-file'?: string;
+	'trace-startup-duration'?: string;
 }

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

@@ -205,6 +205,10 @@ export const OPTIONS: OptionDescriptions<Required<NativeParsedArgs>> = {
 	'disable-dev-shm-usage': { type: 'boolean' },
 	'profile-temp': { type: 'boolean' },
 	'ozone-platform': { type: 'string' },
+	'enable-tracing': { type: 'string' },
+	'trace-startup-format': { type: 'string' },
+	'trace-startup-file': { type: 'string' },
+	'trace-startup-duration': { type: 'string' },
 
 	_: { type: 'string[]' } // main arguments
 };

src/vs/workbench/contrib/performance/electron-sandbox/startupTimings.ts

@@ -20,6 +20,26 @@ import { VSBuffer } from 'vs/base/common/buffer';
 import { IWorkspaceTrustManagementService } from 'vs/platform/workspace/common/workspaceTrust';
 import { IPaneCompositePartService } from 'vs/workbench/services/panecomposite/browser/panecomposite';
 import { StartupTimings } from 'vs/workbench/contrib/performance/browser/startupTimings';
+import { process } from 'vs/base/parts/sandbox/electron-sandbox/globals';
+import { coalesce } from 'vs/base/common/arrays';
+
+interface ITracingData {
+	readonly args?: {
+		readonly usedHeapSizeAfter?: number;
+		readonly usedHeapSizeBefore?: number;
+	};
+	readonly dur: number; 	// in microseconds
+	readonly name: string;	// e.g. MinorGC or MajorGC
+	readonly pid: number;
+}
+
+interface IHeapStatistics {
+	readonly used: number;
+	readonly garbage: number;
+	readonly majorGCs: number;
+	readonly minorGCs: number;
+	readonly duration: number;
+}
 
 export class NativeStartupTimings extends StartupTimings implements IWorkbenchContribution {
 
@@ -34,7 +54,7 @@ export class NativeStartupTimings extends StartupTimings implements IWorkbenchCo
 		@IUpdateService updateService: IUpdateService,
 		@INativeWorkbenchEnvironmentService private readonly _environmentService: INativeWorkbenchEnvironmentService,
 		@IProductService private readonly _productService: IProductService,
-		@IWorkspaceTrustManagementService workspaceTrustService: IWorkspaceTrustManagementService,
+		@IWorkspaceTrustManagementService workspaceTrustService: IWorkspaceTrustManagementService
 	) {
 		super(editorService, paneCompositeService, lifecycleService, updateService, workspaceTrustService);
 
@@ -62,10 +82,22 @@ export class NativeStartupTimings extends StartupTimings implements IWorkbenchCo
 			]);
 
 			const perfBaseline = await this._timerService.perfBaseline;
+			const heapStatistics = await this._resolveStartupHeapStatistics();
+			if (heapStatistics) {
+				this._telemetryLogHeapStatistics(heapStatistics);
+			}
 
 			if (appendTo) {
-				const content = `${this._timerService.startupMetrics.ellapsed}\t${this._productService.nameShort}\t${(this._productService.commit || '').slice(0, 10) || '0000000000'}\t${this._telemetryService.sessionId}\t${standardStartupError === undefined ? 'standard_start' : 'NO_standard_start : ' + standardStartupError}\t${String(perfBaseline).padStart(4, '0')}ms\n`;
-				await this.appendContent(URI.file(appendTo), content);
+				const content = coalesce([
+					this._timerService.startupMetrics.ellapsed,
+					this._productService.nameShort,
+					(this._productService.commit || '').slice(0, 10) || '0000000000',
+					this._telemetryService.sessionId,
+					standardStartupError === undefined ? 'standard_start' : `NO_standard_start : ${standardStartupError}`,
+					`${String(perfBaseline).padStart(4, '0')}ms`,
+					heapStatistics ? this._printStartupHeapStatistics(heapStatistics) : undefined
+				]).join('\t') + '\n';
+				await this._appendContent(URI.file(appendTo), content);
 			}
 
 			if (durationMarkers?.length) {
@@ -88,7 +120,7 @@ export class NativeStartupTimings extends StartupTimings implements IWorkbenchCo
 
 				const durationsContent = `${durations.join('\t')}\n`;
 				if (durationMarkersFile) {
-					await this.appendContent(URI.file(durationMarkersFile), durationsContent);
+					await this._appendContent(URI.file(durationMarkersFile), durationsContent);
 				} else {
 					console.log(durationsContent);
 				}
@@ -109,12 +141,96 @@ export class NativeStartupTimings extends StartupTimings implements IWorkbenchCo
 		return super._isStandardStartup();
 	}
 
-	private async appendContent(file: URI, content: string): Promise<void> {
+	private async _appendContent(file: URI, content: string): Promise<void> {
 		const chunks: VSBuffer[] = [];
 		if (await this._fileService.exists(file)) {
 			chunks.push((await this._fileService.readFile(file)).value);
 		}
 		chunks.push(VSBuffer.fromString(content));
 		await this._fileService.writeFile(file, VSBuffer.concat(chunks));
 	}
+
+	private async _resolveStartupHeapStatistics(): Promise<IHeapStatistics | undefined> {
+		if (
+			!this._environmentService.args['enable-tracing'] ||
+			!this._environmentService.args['trace-startup-file'] ||
+			this._environmentService.args['trace-startup-format'] !== 'json' ||
+			!this._environmentService.args['trace-startup-duration']
+		) {
+			return undefined; // unexpected arguments for startup heap statistics
+		}
+
+		const used = (performance as unknown as { memory?: { usedJSHeapSize?: number } }).memory?.usedJSHeapSize ?? 0; // https://developer.mozilla.org/en-US/docs/Web/API/Performance/memory
+
+		let minorGCs = 0;
+		let majorGCs = 0;
+		let garbage = 0;
+		let duration = 0;
+
+		try {
+			const traceContents: { traceEvents: ITracingData[] } = JSON.parse((await this._fileService.readFile(URI.file(this._environmentService.args['trace-startup-file']))).value.toString());
+			for (const event of traceContents.traceEvents) {
+				if (event.pid !== process.pid) {
+					continue;
+				}
+
+				switch (event.name) {
+
+					// Major/Minor GC Events
+					case 'MinorGC':
+						minorGCs++;
+					case 'MajorGC':
+						majorGCs++;
+						if (event.args && typeof event.args.usedHeapSizeAfter === 'number' && typeof event.args.usedHeapSizeBefore === 'number') {
+							garbage += (event.args.usedHeapSizeBefore - event.args.usedHeapSizeAfter);
+						}
+						break;
+
+					// GC Events that block the main thread
+					// Refs: https://v8.dev/blog/trash-talk
+					case 'V8.GCFinalizeMC':
+					case 'V8.GCScavenger':
+						duration += event.dur;
+						break;
+				}
+			}
+
+			return { minorGCs, majorGCs, used, garbage, duration: Math.round(duration / 1000) };
+		} catch (error) {
+			console.error(error);
+		}
+
+		return undefined;
+	}
+
+	private _telemetryLogHeapStatistics({ used, garbage, majorGCs, minorGCs, duration }: IHeapStatistics): void {
+		type StartupHeapStatisticsClassification = {
+			owner: 'bpasero';
+			comment: 'An event that reports startup heap statistics for performance analysis.';
+			heapUsed: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Used heap' };
+			heapGarbage: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Garbage heap' };
+			majorGCs: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Major GCs count' };
+			minorGCs: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Minor GCs count' };
+			gcsDuration: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'GCs duration' };
+		};
+		type StartupHeapStatisticsEvent = {
+			heapUsed: number;
+			heapGarbage: number;
+			majorGCs: number;
+			minorGCs: number;
+			gcsDuration: number;
+		};
+		this._telemetryService.publicLog2<StartupHeapStatisticsEvent, StartupHeapStatisticsClassification>('startupHeapStatistics', {
+			heapUsed: used,
+			heapGarbage: garbage,
+			majorGCs,
+			minorGCs,
+			gcsDuration: duration
+		});
+	}
+
+	private _printStartupHeapStatistics({ used, garbage, majorGCs, minorGCs, duration }: IHeapStatistics) {
+		const MB = 1024 * 1024;
+		return `Heap: ${Math.round(used / MB)}MB (used) ${Math.round(garbage / MB)}MB (garbage) ${majorGCs} (MajorGC) ${minorGCs} (MinorGC) ${duration}ms (GC duration)`;
+	}
 }

src/vs/workbench/services/timer/browser/timerService.ts

@@ -446,6 +446,12 @@ export interface ITimerService {
 	 * @param to to mark name
 	 */
 	getDuration(from: string, to: string): number;
+
+	/**
+	 * Return the timestamp of a mark.
+	 * @param mark mark name
+	 */
+	getStartTime(mark: string): number;
 }
 
 export const ITimerService = createDecorator<ITimerService>('timerService');
@@ -471,6 +477,11 @@ class PerfMarks {
 		return toEntry.startTime - fromEntry.startTime;
 	}
 
+	getStartTime(mark: string): number {
+		const entry = this._findEntry(mark);
+		return entry ? entry.startTime : -1;
+	}
+
 	private _findEntry(name: string): perf.PerformanceMark | void {
 		for (const [, marks] of this._entries) {
 			for (let i = marks.length - 1; i >= 0; i--) {
@@ -601,6 +612,10 @@ export abstract class AbstractTimerService implements ITimerService {
 		return this._marks.getDuration(from, to);
 	}
 
+	getStartTime(mark: string): number {
+		return this._marks.getStartTime(mark);
+	}
+
 	private _reportStartupTimes(metrics: IStartupMetrics): void {
 		// report IStartupMetrics as telemetry
 		/* __GDPR__