Analyse profiles in worker thread (microsoft#164468)

- profile renderer returns profile data
- analyse profiles in separate worker thread
- adjust renderer and extension host profiling
- adjust build scripts to build worker file

Author: jrieken

build/gulpfile.vscode.js

@@ -48,6 +48,7 @@ const vscodeEntryPoints = _.flatten([
 	buildfile.workerLanguageDetection,
 	buildfile.workerSharedProcess,
 	buildfile.workerLocalFileSearch,
+	buildfile.workerProfileAnalysis,
 	buildfile.workbenchDesktop,
 	buildfile.code
 ]);

build/gulpfile.vscode.web.js

@@ -71,6 +71,7 @@ const vscodeWebEntryPoints = _.flatten([
 	buildfile.workerNotebook,
 	buildfile.workerLanguageDetection,
 	buildfile.workerLocalFileSearch,
+	buildfile.workerProfileAnalysis,
 	buildfile.keyboardMaps,
 	buildfile.workbenchWeb
 ]);

src/buildfile.js

@@ -50,6 +50,7 @@ exports.workerNotebook = [createEditorWorkerModuleDescription('vs/workbench/cont
 exports.workerSharedProcess = [createEditorWorkerModuleDescription('vs/platform/sharedProcess/electron-browser/sharedProcessWorkerMain')];
 exports.workerLanguageDetection = [createEditorWorkerModuleDescription('vs/workbench/services/languageDetection/browser/languageDetectionSimpleWorker')];
 exports.workerLocalFileSearch = [createEditorWorkerModuleDescription('vs/workbench/services/search/worker/localFileSearch')];
+exports.workerProfileAnalysis = [createEditorWorkerModuleDescription('vs/platform/profiling/electron-sandbox/profileAnalysisWorker')];
 
 exports.workbenchDesktop = [
 	createEditorWorkerModuleDescription('vs/workbench/contrib/output/common/outputLinkComputer'),

src/vs/platform/native/common/native.ts

@@ -9,6 +9,7 @@ import { URI } from 'vs/base/common/uri';
 import { MessageBoxOptions, MessageBoxReturnValue, MouseInputEvent, OpenDevToolsOptions, OpenDialogOptions, OpenDialogReturnValue, SaveDialogOptions, SaveDialogReturnValue } from 'vs/base/parts/sandbox/common/electronTypes';
 import { ISerializableCommandAction } from 'vs/platform/action/common/action';
 import { INativeOpenDialogOptions } from 'vs/platform/dialogs/common/dialogs';
+import { IV8Profile } from 'vs/platform/profiling/common/profiling';
 import { IPartsSplash } from 'vs/platform/theme/common/themeService';
 import { IColorScheme, IOpenedWindow, IOpenEmptyWindowOptions, IOpenWindowOptions, IWindowOpenable } from 'vs/platform/window/common/window';
 
@@ -164,7 +165,7 @@ export interface ICommonNativeHostService {
 	sendInputEvent(event: MouseInputEvent): Promise<void>;
 
 	// Perf Introspection
-	profileRenderer(session: string, duration: number, perfBaseline: number): Promise<boolean>;
+	profileRenderer(session: string, duration: number): Promise<IV8Profile>;
 
 	// Connectivity
 	resolveProxy(url: string): Promise<string | undefined>;

src/vs/platform/native/electron-main/nativeHostMainService.ts

@@ -41,8 +41,8 @@ import { isWorkspaceIdentifier, toWorkspaceIdentifier } from 'vs/platform/worksp
 import { IWorkspacesManagementMainService } from 'vs/platform/workspaces/electron-main/workspacesManagementMainService';
 import { VSBuffer } from 'vs/base/common/buffer';
 import { hasWSLFeatureInstalled } from 'vs/platform/remote/node/wsl';
-import { ProfilingOutput, WindowProfiler } from 'vs/platform/profiling/electron-main/windowProfiling';
-import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
+import { WindowProfiler } from 'vs/platform/profiling/electron-main/windowProfiling';
+import { IV8Profile } from 'vs/platform/profiling/common/profiling';
 
 export interface INativeHostMainService extends AddFirstParameterToFunctions<ICommonNativeHostService, Promise<unknown> /* only methods, not events */, number | undefined /* window ID */> { }
 
@@ -61,8 +61,7 @@ export class NativeHostMainService extends Disposable implements INativeHostMain
 		@ILogService private readonly logService: ILogService,
 		@IProductService private readonly productService: IProductService,
 		@IThemeMainService private readonly themeMainService: IThemeMainService,
-		@IWorkspacesManagementMainService private readonly workspacesManagementMainService: IWorkspacesManagementMainService,
-		@ITelemetryService private readonly telemetryService: ITelemetryService,
+		@IWorkspacesManagementMainService private readonly workspacesManagementMainService: IWorkspacesManagementMainService
 	) {
 		super();
 	}
@@ -782,14 +781,14 @@ export class NativeHostMainService extends Disposable implements INativeHostMain
 
 	// #region Performance
 
-	async profileRenderer(windowId: number | undefined, session: string, duration: number, baseline: number): Promise<boolean> {
+	async profileRenderer(windowId: number | undefined, session: string, duration: number): Promise<IV8Profile> {
 		const win = this.windowById(windowId);
 		if (!win || !win.win) {
-			return false;
+			throw new Error();
 		}
-		const profiler = new WindowProfiler(win.win, session, this.logService, this.telemetryService);
-		const result = await profiler.inspect(duration, baseline);
-		return result === ProfilingOutput.Interesting;
+		const profiler = new WindowProfiler(win.win, session, this.logService);
+		const result = await profiler.inspect(duration);
+		return result;
 	}
 
 	// #endregion

src/vs/platform/profiling/common/profilingModel.ts

@@ -3,13 +3,12 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
-import { basename } from 'vs/base/common/path';
 import type { IV8Profile, IV8ProfileNode } from 'vs/platform/profiling/common/profiling';
 
 // #region
 // https://github.com/microsoft/vscode-js-profile-visualizer/blob/6e7401128ee860be113a916f80fcfe20ac99418e/packages/vscode-js-profile-core/src/cpu/model.ts#L4
 
-interface IProfileModel {
+export interface IProfileModel {
 	nodes: ReadonlyArray<IComputedNode>;
 	locations: ReadonlyArray<ILocation>;
 	samples: ReadonlyArray<number>;
@@ -18,7 +17,7 @@ interface IProfileModel {
 	duration: number;
 }
 
-interface IComputedNode {
+export interface IComputedNode {
 	id: number;
 	selfTime: number;
 	aggregateTime: number;
@@ -27,53 +26,53 @@ interface IComputedNode {
 	locationId: number;
 }
 
-interface ISourceLocation {
+export interface ISourceLocation {
 	lineNumber: number;
 	columnNumber: number;
 	//   source: Dap.Source;
 	relativePath?: string;
 }
 
-interface CdpCallFrame {
+export interface CdpCallFrame {
 	functionName: string;
 	scriptId: string;
 	url: string;
 	lineNumber: number;
 	columnNumber: number;
 }
 
-interface CdpPositionTickInfo {
+export interface CdpPositionTickInfo {
 	line: number;
 	ticks: number;
 }
 
-interface INode {
+export interface INode {
 	id: number;
 	//   category: Category;
 	callFrame: CdpCallFrame;
 	src?: ISourceLocation;
 }
 
-interface ILocation extends INode {
+export interface ILocation extends INode {
 	selfTime: number;
 	aggregateTime: number;
 	ticks: number;
 }
 
-interface IAnnotationLocation {
+export interface IAnnotationLocation {
 	callFrame: CdpCallFrame;
 	locations: ISourceLocation[];
 }
 
-interface IProfileNode extends IV8ProfileNode {
+export interface IProfileNode extends IV8ProfileNode {
 	locationId?: number;
 	positionTicks?: (CdpPositionTickInfo & {
 		startLocationId?: number;
 		endLocationId?: number;
 	})[];
 }
 
-interface ICpuProfileRaw extends IV8Profile {
+export interface ICpuProfileRaw extends IV8Profile {
 	//   $vscode?: IJsDebugAnnotations;
 	nodes: IProfileNode[];
 }
@@ -266,7 +265,7 @@ export const buildModel = (profile: ICpuProfileRaw): IProfileModel => {
 	};
 };
 
-class BottomUpNode {
+export class BottomUpNode {
 	public static root() {
 		return new BottomUpNode({
 			id: -1,
@@ -310,7 +309,7 @@ class BottomUpNode {
 
 }
 
-const processNode = (aggregate: BottomUpNode, node: IComputedNode, model: IProfileModel, initialNode = node) => {
+export const processNode = (aggregate: BottomUpNode, node: IComputedNode, model: IProfileModel, initialNode = node) => {
 	let child = aggregate.children[node.locationId];
 	if (!child) {
 		child = new BottomUpNode(model.locations[node.locationId], aggregate);
@@ -327,15 +326,6 @@ const processNode = (aggregate: BottomUpNode, node: IComputedNode, model: IProfi
 
 //#endregion
 
-function isSpecial(call: CdpCallFrame): boolean {
-	return call.functionName.startsWith('(') && call.functionName.endsWith(')');
-}
-
-function isModel(arg: IV8Profile | IProfileModel): arg is IProfileModel {
-	return Array.isArray((<IProfileModel>arg).locations)
-		&& Array.isArray((<IProfileModel>arg).samples)
-		&& Array.isArray((<IProfileModel>arg).timeDeltas);
-}
 
 export interface BottomUpSample {
 	selfTime: number;
@@ -346,70 +336,3 @@ export interface BottomUpSample {
 	percentage: number;
 	isSpecial: boolean;
 }
-
-export function bottomUp(profileOrModel: IV8Profile | IProfileModel, topN: number, fullPaths: boolean = false) {
-
-	const model = isModel(profileOrModel)
-		? profileOrModel
-		: buildModel(profileOrModel);
-
-	const root = BottomUpNode.root();
-	for (const node of model.nodes) {
-		processNode(root, node, model);
-		root.addNode(node);
-	}
-
-	const result = Object.values(root.children)
-		.sort((a, b) => b.selfTime - a.selfTime)
-		.slice(0, topN);
-
-
-	const samples: BottomUpSample[] = [];
-
-	function printCallFrame(frame: CdpCallFrame): string {
-		let result = frame.functionName || '(anonymous)';
-		if (frame.url) {
-			result += '#';
-			result += fullPaths ? frame.url : basename(frame.url);
-			if (frame.lineNumber >= 0) {
-				result += ':';
-				result += frame.lineNumber + 1;
-			}
-		}
-		return result;
-	}
-
-	for (const node of result) {
-
-		const sample: BottomUpSample = {
-			selfTime: Math.round(node.selfTime / 1000),
-			totalTime: Math.round(node.aggregateTime / 1000),
-			location: printCallFrame(node.callFrame),
-			url: node.callFrame.url,
-			caller: [],
-			percentage: Math.round(node.selfTime / (model.duration / 100)),
-			isSpecial: isSpecial(node.callFrame)
-		};
-
-		// follow the heaviest caller paths
-		const stack = [node];
-		while (stack.length) {
-			const node = stack.pop()!;
-			let top: BottomUpNode | undefined;
-			for (const candidate of Object.values(node.children)) {
-				if (!top || top.selfTime < candidate.selfTime) {
-					top = candidate;
-				}
-			}
-			if (top) {
-				const percentage = Math.round(top.selfTime / (node.selfTime / 100));
-				sample.caller.push({ percentage, location: printCallFrame(top.callFrame) });
-				stack.push(top);
-			}
-		}
-
-		samples.push(sample);
-	}
-
-	return samples;
-}

src/vs/platform/profiling/electron-main/windowProfiling.ts

@@ -3,111 +3,44 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
-import type { Profile, ProfileResult } from 'v8-inspect-profiler';
+import type { ProfileResult } from 'v8-inspect-profiler';
 import { BrowserWindow } from 'electron';
 import { timeout } from 'vs/base/common/async';
 import { ILogService } from 'vs/platform/log/common/log';
-import { Promises } from 'vs/base/node/pfs';
-import { tmpdir } from 'os';
-import { join } from 'vs/base/common/path';
-import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
-import { Utils } from 'vs/platform/profiling/common/profiling';
-import { bottomUp, buildModel, } from 'vs/platform/profiling/common/profilingModel';
-import { reportSample } from 'vs/platform/profiling/common/profilingTelemetrySpec';
-import { onUnexpectedError } from 'vs/base/common/errors';
-
-export const enum ProfilingOutput {
-	Failure,
-	Irrelevant,
-	Interesting,
-}
+import { IV8Profile } from 'vs/platform/profiling/common/profiling';
 
 export class WindowProfiler {
 
 	constructor(
 		private readonly _window: BrowserWindow,
 		private readonly _sessionId: string,
 		@ILogService private readonly _logService: ILogService,
-		@ITelemetryService private readonly _telemetryService: ITelemetryService,
-	) {
-		// noop
-	}
+	) { }
 
-	async inspect(duration: number, baseline: number): Promise<ProfilingOutput> {
+	async inspect(duration: number): Promise<IV8Profile> {
 
-		const success = await this._connect();
-		if (!success) {
-			return ProfilingOutput.Failure;
-		}
+		await this._connect();
 
 		const inspector = this._window.webContents.debugger;
 		await inspector.sendCommand('Profiler.start');
 		this._logService.warn('[perf] profiling STARTED', this._sessionId);
 		await timeout(duration);
 		const data: ProfileResult = await inspector.sendCommand('Profiler.stop');
 		this._logService.warn('[perf] profiling DONE', this._sessionId);
-		const result = this._digest(data.profile, baseline);
+
 		await this._disconnect();
-		return result;
+		return data.profile;
 	}
 
 	private async _connect() {
-		try {
-			const inspector = this._window.webContents.debugger;
-			inspector.attach();
-			await inspector.sendCommand('Profiler.enable');
-			return true;
-		} catch (error) {
-			this._logService.error(error, '[perf] FAILED to enable profiler', this._sessionId);
-			return false;
-		}
+		const inspector = this._window.webContents.debugger;
+		inspector.attach();
+		await inspector.sendCommand('Profiler.enable');
 	}
 
 	private async _disconnect() {
-		try {
-			const inspector = this._window.webContents.debugger;
-			await inspector.sendCommand('Profiler.disable');
-			inspector.detach();
-		} catch (error) {
-			this._logService.error(error, '[perf] FAILED to disable profiler', this._sessionId);
-		}
-	}
-
-	private _digest(profile: Profile, perfBaseline: number): ProfilingOutput {
-		if (!Utils.isValidProfile(profile)) {
-			this._logService.warn('[perf] INVALID profile: no samples or timeDeltas', this._sessionId);
-			return ProfilingOutput.Irrelevant;
-		}
-
-		const model = buildModel(profile);
-		const samples = bottomUp(model, 5, false)
-			.filter(s => !s.isSpecial);
-
-		if (samples.length === 0 || samples[1].percentage < 10) {
-			// ignore this profile because 90% of the time is spent inside "special" frames
-			// like idle, GC, or program
-			this._logService.warn('[perf] profiling did NOT reveal anything interesting', this._sessionId);
-			return ProfilingOutput.Irrelevant;
-		}
-
-		// send telemetry events
-		for (const sample of samples) {
-			reportSample(
-				{ sample, perfBaseline, source: '<<renderer>>' },
-				this._telemetryService,
-				this._logService
-			);
-		}
-
-		// save to disk
-		this._store(profile).catch(onUnexpectedError);
-
-		return ProfilingOutput.Interesting;
-	}
-
-	private async _store(profile: Profile): Promise<void> {
-		const path = join(tmpdir(), `renderer-profile-${Date.now()}.cpuprofile`);
-		await Promises.writeFile(path, JSON.stringify(profile));
-		this._logService.info(`[perf] stored profile to DISK '${path}'`, this._sessionId);
+		const inspector = this._window.webContents.debugger;
+		await inspector.sendCommand('Profiler.disable');
+		inspector.detach();
 	}
 }